Sporatic errors with nginx connection pipelining #344
Comments
|
Okay - so I'd start by trying each of the That'll give us a first pass onto what's going on. Uvicorn will respond like that if it gets a malformed request. So another route into figuring out the issue would be to change the source code so that it logs out the raw byte streams that are being sent, and examine how they look in the broken cases. |
|
Great idea. How do I swap between h11 and httptools? |
|
So. Def. also recommend trying to replicate on Daphne or Hypercorn following that too. Let's narrow it down as much as poss as a first step. |
|
The issue only happens with httptools. Hope that helps. |
|
I can confirm this issue, can see such behavior from uvicorn==0.4.3 (didn't test earlier). Seems related to websockets, going to investigate deeper next week. @nhumrich are you using ws? |
|
@leobuskin no, I am not using websockets at all |
|
Yeah, I see occasionally similar behaviour as well, quite rare though. It seems to be related to concurrent long running requests with some heavy CPU and memory usage in my case. Eg. csv files uploads (2-9 Mb) with background validation and writing to a db (yeah, via POST). So, if I make 4 requests at the same time the 3rd and/or 4th are likely to throw 502 back. Probably it might affect other requests, not sure. I’ll try to reliably recreate this one and hunt it down, happy there’s an issue already. |
|
I was able to replicate it (sort of reliable), but under some load. I've tried On the surface, it seems that it happens for the consecutive request when the former one makes the worker timed out. |
|
All in all, I think there's no issue in |
|
for me, the behavior isn't timeout related. I didn't have any timing out requests, and it didn't require much load to reproduce |
|
@nhumrich interesting, how would you reproduce it? |
|
@gvbgduh I tried it both ways. Both reproduce the error when I use httptools, but are fine when I use h11. Just a web server behind nginx. Basically, I have ALB -> nginx -> myservice. I haven't really spent the time to reproduce with a minimal example, but I imagine reproducing has moreso to do with nginx configuration then the actual code. |
|
Encountering the same issue with a similar configuration, however, I also noticed in the deployment instructions there is mention of a Are there other steps I can take to address this issue? Additional details: Headers: Here is a link to the docker image we are using for the deployment as well. Removed GUnicorn and tried running just uvicorn for testing and I'm still facing the same issue: |
|
@matthax I can't really see an occurrence of |
|
@gvbgduh Requests are not long running and there's no load on the server. We've increased the timeout to well over 30 seconds just to confirm. Quick glance at metrics puts the average response time under 5ms between nginx and the worker. Removing
|
|
interesting @matthax, would it be possible to have a look at nginx logs and, ideally, at uvicorn ones for the same timeline? |
|
I’ll get this for you tomorrow
…Sent from my iPhone
On Aug 1, 2019, at 8:00 PM, George Bogodukhov ***@***.***> wrote:
interesting @matthax, would it be possible to have a look at nginx logs and, ideally, at uvicorn ones for the same timeline?
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub, or mute the thread.
|
|
@gvbgduh Note that in this instance I wasn't hitting an actual endpoint, just posting to a route we disabled and even then we get a consistent 502 every other request. |
|
thanks a lot @matthax, i'll try to re-create this one, it gives a rough picture. |
|
I did some tcpdump'ing and found that uvicorn does not send the tcp-FIN packet to nginx and so nginx assumes the connection is still useable. nginx then sends the next http request to the open socket but uvicorn replies with a tcp-FIN packet and logs the invalid request error message. So uvicorn did not have an open connection??? Even though it did not send the FIN... Workarounds:
But I prefer to have reuse of connection available and working. Still investigating how to get that working. |
|
Hi all ! Any update on this topic ? |
|
Can anyone reduce this down into the simplest possible way to reproduce this. I'm happy to have a dig into this myself, but it'd be super helpful if there's a trivial set of instructions for me to work through and know that it's likely to reliably reproduce the issue if I follow those. Is it sufficient simply to setup nginx and uvicorn and issue some POST requests or is there more to it? |
|
I think you quite literally just need an NGINX instance set up with a reverse proxy to reproduce. Send POST/PUT/PATCH to get the error. If you're not able to reproduce it like that let me know and I'll set you up a Dockerfile with a minimal example. |
|
I think it would be great @matthax. I was trying to reproduce it for quite a while from time to time without luck. (except the case from the above). I used a simple example of the whole stack (please see below details). I tested it with plain postman and with
|
|
I have a sneaky suspicion it might be related to how errors are handled and propagated, so it crashes the uvicorn worker while nginx is still trying to communicate. |
|
I am not able to reproduce this at the moment. The applicationexample.py: async def app(scope, receive, send):
assert scope['type'] == 'http'
await send({
'type': 'http.response.start',
'status': 200,
'headers': [
[b'content-type', b'text/plain'],
]
})
await send({
'type': 'http.response.body',
'body': b'Hello, world!',
})Running with uvicorn... $ uvicorn example:app --uds /tmp/uvicorn.sockThe proxyAn nginx configuration, in http {
server {
listen 4000;
client_max_body_size 4G;
server_name example.com;
location / {
proxy_set_header Host $http_host;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
proxy_set_header X-Forwarded-Proto $scheme;
proxy_redirect off;
proxy_buffering off;
proxy_pass http://uvicorn;
}
location /static {
# path for static files
root /path/to/app/static;
}
}
upstream uvicorn {
server unix:/tmp/uvicorn.sock;
}
}
events {
}Running nginx... $ nginx -c ~/nginx.confThe client requests...wrk.post.lua: Making the requests: $ wrk -t10 -c100 -d10s -s ./wrk.post.lua http://127.0.0.1:4000/Anyone able to provide a configuration setup that does replicate the issue? I'd prefer example cases not to include docker, but just be strictly narrowed down to:
|
|
Hey all! Uvicorn 0.13.2 has been released. Feel free to try it out and report any enhanced tracebacks you can see from these errors. :-) Thank you! |
I was looking at old PR tonight @florimondmanca... |
|
If people impacted could look at their logs (if running 0.13.2 🍏 ) and tell us if they see something about a potentially malformed request that would help note to self, reproduction steps, hopefully what we see here
client result: nginx result: uvicorn result: |
|
Hi, after encountering the same issue with a web application hosted on docker in AWS (no nginx, just gunicorn and a load balancer, it is not public). I've updated to the latest version, and now I see the actual error is that the URL is invalid, and is truncated so that the error only printed the last part of the URL - around 900 chars, the full URL is longer than that (also I am aware that these things should be send via body). For example, the full URL should be like this: But the error has only the last part of the URL: Even if the browser would send a request like this (and unless some strange interaction with URL max length happens here, it doesn't, since this error happens on scheduled API calls) I would expect either a HTTP 404 or 414 response code, but instead the server just doesn't respond at all. I would guess that #778 would solve my issue, but I have too many other tasks to have the time to test that. |
|
@saulbein Thanks. Seems to be consistent with observations from @malthejorgensen and the fact that #778 solves it for them. :) I guess we can look at moving forward on the "very long URL gets processed in pieces" path. We could use a unit test, and that might need to monkeypatch socket reads to simulate a fragmented packet, but that's not clear yet. |
|
I can say that for my case the issue is not URLs longer than 65,535 characters, but rather that |
|
After shortening URLs I have not encountered this issue again, so I can confirm that at the very least my issue was URL-length related (not hitting any limits, but seems likely that |
|
Found this issue after encountering the error with long URLs as well. |
|
I received this similar error |
|
Adding a note that I've observed similar behaviour using Traefik instead of nginx. I see a mix of 502s and 200s on requests with very long request lines. Making the exact same request sequentially results in both status codes. |
@saulbein What did you use to shorten the url? |
|
We have the same issue: raising @nakulkorde question again: |
|
Looks like #1262 is an example for a reproduction. |
|
may be fixed by #1263 |
I simply put the URL parameter in the body of the request, nothing fancy. |
|
Hello, we have this issue, in our case, we have noticed that some clients were sending out invalid urls(including emojis). It seemed in our case that they were probing for a vulnerability. As a reproducible example. I have confirmed that this has been fixed. curl http://localhost:8000/👽
# We received:
# Invalid HTTP request received.% |
We are using 0.17.6. This command also return error. Did you change some code to fix the problem? |
|
Hi, It is only a warning, the error is caught and handled(returns a 400 error) This is the line: Previously, this type of error was not handled. |
|
ok I'm closing this long-standing issue, we think #1263 fixed it, and since then we received no complains so :) |
and others
There seems to be some weird issue with pipelining and or connection reuse and nginx. I have nginx sitting in front of my uvicorn/starlette app, and on patch/post requests I occasionally get 502's from nginx (about 30-40% of the time). The nginx logs say:
all over the place
and my app logs say:
with not much more information.
I forced connection reuse to not work by adding the default header
Connection: close, which forces nginx to kill the connection. Performance drops significantly, but at least I don't get 502's.potentially relevant: the 502 doesn't seem to ever happen on a GET
The text was updated successfully, but these errors were encountered: