arcanist diff submission/updates broken with HTTP/2 after upgrading libcurl from 7.61.1 to 7.62.0

[ngie-eign]

I did this

As described in https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=233177, arc diff --update is failing to work with HTTP/2 enabled with libcurl 7.64.1 (background: arc diff uses the libcurl extension for PHP).

I bisected the issue down to a change introduced between 7.61.1 and 7.62.0.

As noted in the bug, disabling HTTP/2 (either client or server side) unbreaks this command.

Output from arc diff --trace --update ... with 7.64.1 with curl_setopt($curl, CURLOPT_VERBOSE, true); added to /usr/local/lib/php/libphutil/src/future/http/HTTPSFuture.php on line 209 is as follows:

$ arc diff --trace --update D19851 lib/libpmc
...
>>> [34] (+4,300) <http> https://reviews.freebsd.org/api/repository.query
* Found bundle for host reviews.freebsd.org: 0x806631180 [can multiplex]
* Re-using existing connection! (#0) with host reviews.freebsd.org
* Connected to reviews.freebsd.org (96.47.72.197) port 443 (#0)
* Using Stream ID: 9 (easy handle 0x806647800)
> POST /api/repository.query HTTP/2
Host: reviews.freebsd.org
Accept: */*
Content-Length: 182
Content-Type: application/x-www-form-urlencoded

* We are completely uploaded and fine
< HTTP/2 200 
< date: Sat, 13 Apr 2019 08:10:30 GMT
< content-type: application/json
< set-cookie: phsid=A%2Fankd3tzd2b6kni2oxjmija4mm2wennwswdwzsdkr; expires=Thu, 11-Apr-2024 08:10:30 GMT; Max-Age=157680000; path=/; domain=reviews.freebsd.org; secure; httponly
< x-frame-options: Deny
< strict-transport-security: max-age=31536000; includeSubDomains
< content-security-policy: default-src 'self' https://reviews.freebsd.org/ 'unsafe-inline' wss://reviews.freebsd.org/ws/ https://www.google.com/
< referrer-policy: no-referrer
< cache-control: no-store
< expires: Sat, 01 Jan 2000 00:00:00 GMT
< x-content-type-options: nosniff
< server: CloudSoft_Enterprise/v0.01
< x-xss-protection: 1; mode=block
< 
* Connection #0 to host reviews.freebsd.org left intact
<<< [34] (+4,455) <http> 154,947 us
>>> [35] (+4,456) <http> https://reviews.freebsd.org/api/differential.creatediff
* Found bundle for host reviews.freebsd.org: 0x806631180 [can multiplex]
* Re-using existing connection! (#0) with host reviews.freebsd.org
* Connected to reviews.freebsd.org (96.47.72.197) port 443 (#0)
* Using Stream ID: b (easy handle 0x806647800)
> POST /api/differential.creatediff HTTP/2
Host: reviews.freebsd.org
Accept: */*
Content-Length: 79897
Content-Type: application/x-www-form-urlencoded

* We are completely uploaded and fine
* HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)
* stopped the pause stream!
* Connection #0 to host reviews.freebsd.org left intact
<<< [35] (+64,906) <http> 60,450,206 us

[2019-04-13 08:12:28] EXCEPTION: (HTTPFutureCURLResponseStatus) [cURL/92] (https://reviews.freebsd.org/api/differential.creatediff) The cURL library raised an error while making a request. You may be able to find more information about this error (error code: 92) on the cURL site: http://curl.haxx.se/libcurl/c/libcurl-errors.html# at [<phutil>/src/future/http/HTTPSFuture.php:410]
arcanist(), phutil()
  #0 HTTPSFuture::isReady() called at [<phutil>/src/future/Future.php:37]
  #1 Future::resolve(NULL) called at [<phutil>/src/future/FutureProxy.php:34]
  #2 FutureProxy::resolve() called at [<phutil>/src/conduit/ConduitClient.php:64]
  #3 ConduitClient::callMethodSynchronous(string, array) called at [<arcanist>/src/workflow/ArcanistDiffWorkflow.php:518]
  #4 ArcanistDiffWorkflow::run() called at [<arcanist>/scripts/arcanist.php:394]
* Closing connection 0
$

I expected the following

arc diff --update should have continued to work between 7.61.1 and 7.64.1 under normal conditions (server is up and healthy, etc).

curl/libcurl version

$ curl -V
curl 7.64.1 (amd64-portbld-freebsd11.2) libcurl/7.64.1 OpenSSL/1.0.2o zlib/1.2.11 nghttp2/1.37.0
Release-Date: 2019-03-27
Protocols: dict file ftp ftps gopher http https imap imaps pop3 pop3s rtsp smtp smtps telnet tftp 
Features: alt-svc AsynchDNS GSS-API HTTP2 HTTPS-proxy IPv6 Kerberos Largefile libz NTLM NTLM_WB SPNEGO SSL TLS-SRP UnixSockets

operating system

$ uname -a
FreeBSD picasso.local 11.2-RELEASE-p7 FreeBSD 11.2-RELEASE-p7 #0: Tue Dec 18 08:29:33 UTC 2018     root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64

[ngie-eign]

CC: @sunpoet (the port maintainer)

[bagder]

7.62.0 is the first libcurl version to enable HTTP/2 by default for HTTPS connections, so this bug was possibly already present before but not visible then since curl used 1.1 then... If you'd change your 7.61.1 test case to also set CURLOPT_HTTP_VERSION to CURL_HTTP_VERSION_2TLS it might show the same symptoms.

* HTTP/2 stream 0 was not closed cleanly: PROTOCOL_ERROR (err 1)

So curl receives a protocol error from the server. Without more details this isn't necessarily a curl problem. Until we know more, it could also be a server-side issue.

Is there any chance you can produce a recipe that allows us to reproduce this case with just curl or a tiny example code using libcurl? Or perhaps for you to run wireshark snoop on that connection to get some specific details on the HTTP/2 traffic immediately before and during this PROTOCOL_ERROR moment?

[sunpoet]

I'm afraid I might not be of more help on this issue. As mentioned in the problem report, I was not able to reproduce the problem.

[jay]

I bisected the issue down to a change introduced between 7.61.1 and 7.62.0.

Do you mean you actually bisected it or you just tried those two versions?

[bagder]

A month with no further feedback or responses. Considered abandoned and is closed.