Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

RPushbullet randomly failing to send pushes on Mac OS Catalina (10.15.1) #57

Closed
ashannon opened this issue Nov 15, 2019 · 35 comments
Closed

Comments

@ashannon
Copy link
Contributor

@ashannon ashannon commented Nov 15, 2019

Hello,

I have been using RPushbullet without any issues for years on previous versions of Mac OS. However, since upgrading to Mac OS Catalina, RPushbullet randomly fails when sending pushes, giving the following error message:

"Error in curl::curl_fetch_memory(pburl, handle = h): Error in the HTTP2 framing layer"

The error is difficult to reproduce, as it is happening at random. When it does fail, immediately trying again usually ends up working, so a TryCatch workaround could address this, which is what I did. However, eventually this did not work and after too many retries, the following error message was returned:

"Error: C stack usage 7969600 is too close to the limit"

Any help in fixing this problem would be greatly appreciated. Thanks.

Here is my session info:

R version 3.6.1 (2019-07-05)
Platform: x86_64-apple-darwin15.6.0 (64-bit)
Running under: macOS Catalina 10.15.1

Matrix products: default
BLAS: /System/Library/Frameworks/Accelerate.framework/Versions/A/Frameworks/vecLib.framework/Versions/A/libBLAS.dylib
LAPACK: /Library/Frameworks/R.framework/Versions/3.6/Resources/lib/libRlapack.dylib

locale:
[1] en_CA.UTF-8/en_CA.UTF-8/en_CA.UTF-8/C/en_CA.UTF-8/en_CA.UTF-8

attached base packages:
[1] stats graphics grDevices utils datasets methods base

other attached packages:
[1] magrittr_1.5 xml2_1.2.2 rib_0.6.3 scales_1.0.0 rstudioapi_0.10 RCurl_1.95-4.12 bitops_1.0-6
[8] MASS_7.3-51.4 quantreg_5.51 SparseM_1.77 fasttime_1.0-2 RSelenium_1.7.5 sigmoid_0.3.0 corpcor_1.6.9
[15] ECOSolveR_0.5.3 RPushbullet_0.3.2 Matrix_1.2-17 timeDate_3043.102 plyr_1.8.4 openxlsx_4.1.3 IBrokers_0.9-12
[22] quantmod_0.4-15 TTR_0.23-5 xts_0.11-2 zoo_1.8-6 stringr_1.4.0 ggplot2_3.2.1 data.table_1.12.6

loaded via a namespace (and not attached):
[1] lattice_0.20-38 colorspace_1.4-1 yaml_2.2.0 XML_3.98-1.20 rlang_0.4.1 pillar_1.4.2 withr_2.1.2
[8] rappdirs_0.3.1 semver_0.2.0 MatrixModels_0.4-1 munsell_0.5.0 binman_0.1.1 gtable_0.3.0 zip_2.0.4
[15] caTools_1.17.1.2 wdman_0.2.4 curl_4.2 Rcpp_1.0.2 openssl_1.4.1 jsonlite_1.6 askpass_1.1
[22] stringi_1.4.3 grid_3.6.1 tools_3.6.1 lazyeval_0.2.2 tibble_2.1.3 crayon_1.3.4 pkgconfig_2.0.3
[29] subprocess_0.8.3 assertthat_0.2.1 httr_1.4.1 R6_2.4.0 compiler_3.6.1

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Nov 15, 2019

Well as you said, the change vector here is macOS Catalina -- rpushbullet didn't change, and didn't need to.

Maybe @jeroen know something about curl changes.

Just get the obvious question out of the way: did you recompile/reinstall the curl package?

@jeroen
Copy link

@jeroen jeroen commented Nov 15, 2019

@ashannon what is your curl::curl_version() ?

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Nov 15, 2019

Thanks for the quick responses.

I’m on the road at the moment, with no access to my computer. If it helps, I recently installed a fresh version of R 3.6.1 after upgrading to Catalina, and installed all packages from CRAN (not from source), so my guess is it is the latest version of curl that is installed. Will report back with the exact version as a soon as I can.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Nov 18, 2019

Hello again,

Here is the output provided by curl::curl_version() :

$version
[1] "7.64.1"

$ssl_version
[1] "(SecureTransport) LibreSSL/2.8.3"

$libz_version
[1] "1.2.11"

$libssh_version
[1] NA

$libidn_version
[1] NA

$host
[1] "x86_64-apple-darwin19.0"

$protocols
[1] "dict" "file" "ftp" "ftps" "gopher" "http" "https" "imap" "imaps" "ldap" "ldaps" "pop3" "pop3s" "rtsp" "smb"
[16] "smbs" "smtp" "smtps" "telnet" "tftp"

$ipv6
[1] TRUE

$http2
[1] TRUE

$idn
[1] FALSE

@jeroen
Copy link

@jeroen jeroen commented Nov 18, 2019

Hmm okay. libcurl 7.62 and up enable http/2 by default, but it seems like this server may be running a buggy older version of http/2. Maybe the safest is to disable http/2.

@jeroen
Copy link

@jeroen jeroen commented Nov 18, 2019

You didn't install a custom libcurl, right? This is the version in /usr/bin/curl --version ?

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Nov 18, 2019

Correct, this is not a custom install. Here is the output from /usr/bin/curl --version:

curl 7.64.1 (x86_64-apple-darwin19.0) libcurl/7.64.1 (SecureTransport) LibreSSL/2.8.3 zlib/1.2.11 nghttp2/1.39.2
Release-Date: 2019-03-27
Protocols: dict file ftp ftps gopher http https imap imaps ldap ldaps pop3 pop3s rtsp smb smbs smtp smtps telnet tftp 
Features: AsynchDNS GSS-API HTTP2 HTTPS-proxy IPv6 Kerberos Largefile libz MultiSSL NTLM NTLM_WB SPNEGO SSL UnixSockets

How does one disable http/2? I can give that a shot and report back.

@jeroen
Copy link

@jeroen jeroen commented Nov 18, 2019

I haven't upgraded to Calalina yet, so I can't debug this yet. From your output your libcurl seems to be compiled with two different TLS backends: LibreSSL (default) and SecureTransport.

One thing you can try is switching to SecureTransport (apple's native TLS). To do this you need to set an environment variable in your .Rprofile:

CURL_SSL_BACKEND=SecureTransport

This is explained in the vignette for the case of Windows, but apparently MacOS now also supports this. Can you try starting R with this variable, and tell us what your curl::curl_version() then is?

@jeroen
Copy link

@jeroen jeroen commented Dec 1, 2019

Is there a way I can reproduce this (without having to sign up for an account)?

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Dec 1, 2019

You probably need the token :-/ But they are not big and evil so it may not be such a big hurdle...

@jeroen
Copy link

@jeroen jeroen commented Dec 1, 2019

OK I have a token now. Also running MacOS Catalina. @ashannon any specific combination of API calls that is likely to trigger the problem?

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Dec 1, 2019

Hi @jeroen ,

I tried setting CURL_SSL_BACKEND=SecureTransport in .Renviron, but after restarting R, curl::curl:version() still shows the same output:

`$version
[1] "7.64.1"

$ssl_version
[1] "SecureTransport (LibreSSL/2.8.3)"

$libz_version
[1] "1.2.11"

$libssh_version
[1] NA

$libidn_version
[1] NA

$host
[1] "x86_64-apple-darwin19.0"

$protocols
[1] "dict" "file" "ftp" "ftps" "gopher" "http" "https" "imap" "imaps" "ldap" "ldaps" "pop3" "pop3s" "rtsp" "smb"
[16] "smbs" "smtp" "smtps" "telnet" "tftp"

$ipv6
[1] TRUE

$http2
[1] TRUE

$idn
[1] FALSE`

As for any specific combinations of API calls causing the errors, the failures appear to be happening randomly. My application has a series of preset messages which go off on a set schedule each day (every 15 minutes). These messages are all the same in nature (i.e. a message of type "note" , with a simple title and a body). Most of the time they work, but sometimes (20-30% of the time), I get the reported error message. Sometimes the errors are clustered together, sometimes not. I cannot discern a pattern of any sort.

@jeroen
Copy link

@jeroen jeroen commented Dec 1, 2019

The output is not the same, if you look closely the ssl_version is now different,

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Dec 1, 2019

Looks like "(SecureTransport) LibreSSL/2.8.3" in both cases, no?

@jeroen
Copy link

@jeroen jeroen commented Dec 1, 2019

The second shows the opposite: SecureTransport (LibreSSL/2.8.3) (the one in parenthesis is the inactive backend). See also the windows vignette: https://cran.r-project.org/web/packages/curl/vignettes/windows.html

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Dec 1, 2019

Got it. That is one obscure way of printing things...

@jeroen
Copy link

@jeroen jeroen commented Dec 2, 2019

Well for about 20 years curl had at most one ssl implementation so that feature string would just contain e.g. "openssl 1.0.2".

But a year ago they merged in a feature to build curl with multiple ssl backends to pick one at runtime. So they had to generalize that string to something that would show all back-ends and also the one in use.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Dec 2, 2019

Good catch @jeroen. I agree with @eddelbuettel that the notation could be a bit more explicit.

I will restart my production app, specifying "SecureTransport" as the curl backend in the .Renviron file, and report back in 24-48 hours.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Dec 3, 2019

Checking in again. It looks like the SecureTransport SSL backend is not making a difference. The error message still occurs in a seemingly random fashion.

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Dec 3, 2019

It will be hard to chase this without anything concrete and reproducible.

@jeroen
Copy link

@jeroen jeroen commented Dec 3, 2019

OK the best solution then is to not use HTTP/2 for this server. See this chapter for the vignette: https://cran.r-project.org/web/packages/curl/vignettes/intro.html#disabling_http2

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Dec 9, 2019

@jeroen, seems like fixing this requires changes to the RPushbullet code itself, as this is where handle_setopt(handle, http_version = 2) can be set.

@eddelbuettel , could you point me to the internal functions in RPushbullet that specify the "handles" that are fed to curl? I can think of RPushbullet:::.createPush(), but are there others that would need to be changed as well?

Thanks

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Dec 9, 2019

@ashannon There is nothing hidden -- all the code is in the repo. Beauty of REST (when it works ...), we really just fire off requests with parameters.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Dec 11, 2019

@eddelbuettel , ok I will give modifying the source code a shot to use HTTP 1.1 instead, and report back, probably sometime this weekend.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Jan 7, 2020

The issue appears to be fixed by setting http to v1.1 as per @jeroen 's suggestion.

@eddelbuettel , thanks for accepting my PR to make this change in the master branch!

Best,

A.

@ashannon ashannon closed this Jan 7, 2020
@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Jan 7, 2020

Now @jeroen said best solution then is to not use HTTP/2 for this server. (Emphasis mine.) That is different from turning back to 1.1 everywhere and unconditionally. Shall we maybe just make it an option?

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Jan 7, 2020

The benefit of making it an option is having additional flexibility, at the potential expense of adding unnecessary complexity to the package.

The benefit of hard setting it to http v1.1 avoids a (albeit rare) known issue, and, to my knowledge, does not impede RPushbullet's ability to function in any way.

As @jeroen pointed out, http v2.0 was made the default option as of libbcurl version 7.62, which was released relatively recently (oct 2018). This would imply that prior to that date, RPushbullet was using an earlier version of http (I'm guessing v1.1) the whole time without any issues.

It's you call at the end of day, but I'm ok with either approach.

@ashannon ashannon reopened this Jan 7, 2020
@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Jan 7, 2020

Good points. Making it a toggle, or an options, with a "sensible" default, may be best. I generally trust upstream, and it is hard to argue webstandards with the curl author who clearly knows what he is doing.

You and other could then set a local option in ~/.Rprofile and alike and locally override without effort. Good enough?

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Jan 7, 2020

Yes I think this is a good solution. Better to align the package with where the technology behind it is headed by default (i.e. to set http v2.0 as the default) and to allow an override mechanism providing backwards compatibility if needed.

I must admit I am not sure exactly what would be the best way to implement the override you are suggesting. Would it be to simply set an option for the curl:: package directly to use http v1.1 by default or an option for the RPushbullet:: package which, if set accordingly, would then make a modified call to RPushbullet:::.getCurlHandle() specifying curl::handle_setopt(h,http_version = 2) ?

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Jan 7, 2020

I think (and shooting from the hip here) we have models for that already in R/init.R: set up values in the per-package environment with a default, maybe even just TRUE and FALSE for something like useCurlDefaultStandard. The add an accessor function to override that default value easily. And then in the sending function reflect the value and toggle between 2.0 and 1.1 as indicated by the value.

How does that sound?

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Jan 12, 2020

@ashannon Thanks for working through this and fixing your use case. I just committed a small change to a new branch and will make that a new pull request (likely #60) is a moment. Could you test that?

The new behaviour does what your change did if and only if you run

options("rpushbullet.useHTTP11"=TRUE) 

in, say, your ~/.Rprofile, or right before running the code RPushbullet code.

@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Jan 13, 2020

@ashannon let me know if you have a chance to check out #60 which is simple generalization of your change to set the http/1.1 mode.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Jan 14, 2020

Hi @eddelbuettel , thanks for making this change. I will give that shot and report back sometime this week, Thursday at the latest.

@ashannon
Copy link
Contributor Author

@ashannon ashannon commented Jan 18, 2020

@eddelbuettel , the PR works as intended when specifying options("rpushbullet.useHTTP11"=TRUE) in ~/.Rprofile. Thanks for making this change.

@ashannon ashannon closed this Jan 26, 2020
@eddelbuettel
Copy link
Owner

@eddelbuettel eddelbuettel commented Jan 26, 2020

Thanks for closing the ticket. Looks like I missed that earlier...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
3 participants
You can’t perform that action at this time.