Weird 502 error on HTTP post from curl only? Seems to work on local docker, but not on fly

I’m trying out a simple container image (owntracks/recorder) on fly. The container serves a single process that serves HTTP on port 8083 (dockerfile: docker-recorder/Dockerfile at master · owntracks/docker-recorder · GitHub).

This… mostly works? Get requests work as expected, but I’m seeing a 502 Bad Gateway when trying to POST to the endpoint with curl. POSTs from a separate app seem to work ok, and GETs are fine. Running the image on local docker, and curl POST gives a 200 as expected. The POST request seems to get through to the process, but something seems to be giving a 502 on response. A proxy?

So, curl output:

$ curl -v -X POST -H"Content-type: application/json" -H "X-Limit-U: toot" -H "X-Limit-D: parp" --data '{"_type":"loation","lat":57.473939,"lon":-4.2211605,"t":"u","tid":"aa","tst":1624957301}' http://ot-recorder.fly.dev/pub
> POST /pub HTTP/1.1
> Host: ot-recorder.fly.dev
> User-Agent: curl/7.68.0
> Accept: */*
> Content-type: application/json
> X-Limit-U: toot
> X-Limit-D: parp
> Content-Length: 88
>
< HTTP/1.1 502 Bad Gateway
< server: Fly/9d41849 (2021-06-28)
< via: 1.1 fly.io
< fly-request-id: 01F9BMDJV5NQVGVKAXMBK64DXR
< content-length: 0
< date: Tue, 29 Jun 2021 10:18:15 GMT

From flyctl logs:

2021-06-29T10:18:14.009024432Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:18:15.411355878Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BMDJV5NQVGVKAXMBK64DXR" response.status=502

So the app is receiving the POST, but then the proxy process is giving a 502.

Am I holding it wrong, or is something weird happening here?

Looking at our logs, this appears to have been a fluke in the network between LHR and EWR (where the app instance our proxy chose is hosted).

Does this happen consistently? I’m just seeing the 1 error.

Happens every time I curl POST. Some more from earlier:

2021-06-29T10:03:19.408063594Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BKJ7V19M4MZVTWBG7KNJ8E" response.status=502
2021-06-29T10:04:50.623382879Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:06:54.662459922Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:11:57.398480131Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:11:58.799296949Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BM23231W8F4AD3TAS155VR" response.status=502
2021-06-29T10:15:31.210555857Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:15:32.612809888Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BM8KVQ4R0ZFHPTYRVQKQJD" response.status=502
2021-06-29T10:15:49.873232285Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:15:49.874068435Z app[ac49a66e] ewr [info] ot-recorder[519]: lat or lon for owntracks/toot/parp are NaN: {"_type":"location"}
2021-06-29T10:15:51.275555840Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BM962YZR03WKRS1W89WSVK" response.status=502
2021-06-29T10:16:13.112165089Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:16:14.514234724Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BM9WS4XXA4F2276JSFED7J" response.status=502
2021-06-29T10:16:32.583211512Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:16:33.985500419Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BMAFSM4E64AH872SRNB6DM" response.status=502
2021-06-29T10:18:12.113835281Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:18:13.516231490Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BMDGZY2PFBJA5T7JJ4NG4G" response.status=502
2021-06-29T10:18:14.009024432Z app[ac49a66e] ewr [info] ot-recorder[519]: http: POST /pub
2021-06-29T10:18:15.411355878Z proxy[ac49a66e] lhr [error] error.code=1 error.message="Undocumented" request.method="POST" request.url="/pub" request.id="01F9BMDJV5NQVGVKAXMBK64DXR" response.status=502

I’m taking a closer look now.

I curl'd your application directly (bypassing our proxy) and got an error:

$ curl -v -H"Content-type: application/json" -H "X-Limit-U: toot" -H "X-Limit-D: parp" --data '{"_type":"loation","lat":57.473939,"lon":-4.2211605,"t":"u","tid":"aa","tst":1624957301}' http://172.19.2.234:8083/pub
*   Trying 172.19.2.234...
* TCP_NODELAY set
* Connected to 172.19.2.234 (172.19.2.234) port 8083 (#0)
> POST /pub HTTP/1.1
> Host: 172.19.2.234:8083
> User-Agent: curl/7.58.0
> Accept: */*
> Content-type: application/json
> X-Limit-U: toot
> X-Limit-D: parp
> Content-Length: 88
>
* upload completely sent off: 88 out of 88 bytes
< HTTP/1.1 200 OK
< Content-Type: application/json; charset=utf-8
< Access-Control-Allow-Origin: *
* Invalid Content-Length: value
* stopped the pause stream!
* Closing connection 0
curl: (8) Invalid Content-Length: value

Our proxy is closing the connection early because of this invalid header.

Forgive me for being a bit slow - what’s invalid about it? Is the value that’s being set on the response incorrect, or something else?

Haha, not slow!

This is the first time I’ve seen this particular error. Looks like the value of the Content-Length header is value instead of being an integer representing the size of the response’s body.

It looks like a variable was not interpolated?

What framework are you using for your app?

Mongoose (yay for C!)

You’re right, something funny also happens locally on docker, I just didn’t spot it before. Curl barfs as well, but after parsing the 200. I couldn’t figure out how to get curl to actually dump the bytes on the wire, so tcpdump told me that the Content-Length header was actually empty (Content-Length:<space>/r/n), rather than “value”.

I shall file an upstream bug.

Many thanks for your help!

1 Like