Timeout with MachineGun.get!, but not with HTTPoison.get!

[halostatue]

I’ve elided some secrets for a query that fails with MachineGun but succeeds with HTTPoison. I can share privately if you wish to work with this. I tried to reproduce just with gun, but don’t have enough familiarity with the Gun API to see what’s going on.

iex> endpoint = "https://b.aldodatahub.io/r/look_book_pages/c:-LJFx3L41up18hV4ngZz"
iex> headers = [
...>  {"authorization", "Bearer USERTOKEN"},
...>  {"accept", "application/json"},
...>  {"content-type", "application/json"},
...>  {"client-token", "APPTOKEN"},
...>  {"datahub-catalog", "aldo-ca"},
...>  {"datahub-client", "mce_ios"}
...>]
iex> HTTPoison.get!(endpoint, headers)
%HTTPoison.Response{
  body: "{…}",
  headers: […],
  request_url: "https://b.aldodatahub.io/r/look_book_pages/c:-LJFx3L41up18hV4ngZz",
  status_code: 200
}
iex> MachineGun.get!(endpoint, headers)
** (MachineGun.Error) :request_timeout
    (machine_gun) lib/machine_gun.ex:65: MachineGun.request!/5

This isn’t an HTTP/1 vs HTTP/2 issue, as far as I can tell (the server isn’t explicitly set up for HTTP/2, but it appears that the version of nginx we’re running as a proxy is taking care of that for us), so here’s the equivalent cURL with an appropriate log:

% curl -i -v "https://b.aldodatahub.io/r/look_book_pages/c:-LJFx3L41up18hV4ngZz" \
     -H 'Accept: application/json' \
     -H 'Authorization: Bearer USERTOKEN' \
     -H 'Client-Token: APPTOKEN' \
     -H 'Content-Type: application/json' \
     -H 'Datahub-Catalog: aldo-ca' \
     -H 'Datahub-Locale: en-CA' \
     -H 'Datahub-Client: mce_ios'

HTTP/2 200 
date: Mon, 08 Oct 2018 19:54:20 GMT
content-type: application/json; charset=utf-8
cache-control: max-age=0, private, must-revalidate
status: 200 OK
x-request-id: 67477dc7-e4b2-4f95-82a4-8455519dc86e
x-xss-protection: 1; mode=block
x-runtime: 0.065549
datahub-catalog: aldo-ca
etag: W/"41aff44003038ae2860de69aadd3c1a2"
x-content-type-options: nosniff
x-frame-options: SAMEORIGIN
x-powered-by: Phusion Passenger 5.3.5
expect-ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
server: cloudflare
cf-ray: 466b28a66bcfab66-YYZ

{…}

[petrohi]

Looks like your backend server has issues with lowercase headers, which are required by HTTP/2:

https://tools.ietf.org/html/rfc7540#section-8.1.2

You can change headers to use capitalized headers and then force MachineGun to use HTTP/1 by adding this to your config:

config :machine_gun,
  default: %{
    conn_opts: %{
      protocols: [:http]
    }
  }

[petrohi]

To see actual error you can increase request timeout:

MachineGun.get!(endpoint, headers, %{request_timeout: 30_000})

[halostatue]

Here’s the error when the request timeout is increased.

iex(3)> MachineGun.get!(endpoint, headers, %{request_timeout: 60_000})
** (MachineGun.Error) {:stream_error, :protocol_error, :"Stream reset by server."}
    (machine_gun) lib/machine_gun.ex:65: MachineGun.request!/5

At this point, I’m fairly certain that the header case is not the cause. I was just reading the HTTPoison and Hackney code and I saw nothing that transformed the headers in any way, and I literally passed the same headers structure to both HTTPoison.get! and MachineGun.get! (so both had lowercase headers). I also modified my cURL request:

curl -i --http2 \
  "https://b.aldodatahub.io/r/look_book_pages/c:-LJFx3L41up18hV4ngZz" \
  -H 'accept: application/json' \
  -H 'authorization: Bearer USERTOKEN' \
  -H 'client-token: APPTOKEN' \
  -H 'content-type: application/json' \
  -H 'datahub-catalog: aldo-ca' \
  -H 'datahub-locale: en-CA' \
  -H 'datahub-client: mce_ios'

[SSL handshake elided]
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x7fd673805800)
> GET /r/look_book_pages/c:-LJFx3L41up18hV4ngZz HTTP/2
> Host: b.aldodatahub.io
> User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/28.0.1500.95 Safari/537.36
> Referer: 
> accept: application/json
> authorization: Bearer USERTOKEN
> client-token: APPTOKEN
> content-type: application/json
> datahub-catalog: aldo-ca
> datahub-locale: en-CA
> datahub-client: mce_ios
> 
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!

  0     0    0     0    0     0      0      0 --:--:--  0:00:01 --:--:--     0< HTTP/2 200 
< date: Tue, 09 Oct 2018 15:02:29 GMT
< content-type: application/json; charset=utf-8
< cache-control: max-age=0, private, must-revalidate
< datahub-model-image-size: 1480
< status: 200 OK
< x-request-id: 46774351-b8f9-47c5-a3d9-2979c9b38822
< x-xss-protection: 1; mode=block
< x-runtime: 0.060170
< datahub-catalog: aldo-ca
< etag: W/"a7a468d10dbf226e98df0ccfea4f4b03"
< x-content-type-options: nosniff
< x-frame-options: SAMEORIGIN
< x-powered-by: Phusion Passenger 5.3.5
< expect-ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
< server: cloudflare
< cf-ray: 4671ba7918b427e0-YYZ
< 

HTTP/2 200 
date: Tue, 09 Oct 2018 15:02:29 GMT
content-type: application/json; charset=utf-8
set-cookie: __cfduid=dfcb770b92160beb4bbaac1bccf79274b1539097349; expires=Wed, 09-Oct-19 15:02:29 GMT; path=/; domain=.aldodatahub.io; HttpOnly
cache-control: max-age=0, private, must-revalidate
datahub-model-image-size: 1480
status: 200 OK
x-request-id: 46774351-b8f9-47c5-a3d9-2979c9b38822
x-xss-protection: 1; mode=block
x-runtime: 0.060170
datahub-catalog: aldo-ca
etag: W/"a7a468d10dbf226e98df0ccfea4f4b03"
x-content-type-options: nosniff
x-frame-options: SAMEORIGIN
x-powered-by: Phusion Passenger 5.3.5
expect-ct: max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"
server: cloudflare
cf-ray: 4671ba7918b427e0-YYZ

{"valid": "json lives here"}

[petrohi]

Yes, you are right. "Stream reset by server." does not happen with curl.

[petrohi]

Please try without content-type header. We have issue when content-type is specified for GET requests.

[halostatue]

That was the problem.