-
-
Notifications
You must be signed in to change notification settings - Fork 1.5k
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
nginx + sanic problems #2531
Comments
I'd guess likely timeout issue. What are your timeouts? |
@oren-nonamesecurity Can you see with packet capture at which point of connection this occurs? Has Sanic already handled some request(s) on that connection or does it reset prior to responding anything? If it is possible by packet timing, determine more precisely at which time this occurs (is the connection idle before, did a request go without response, or did Sanic RST right after sending a response, etc). That should narrow down the bug hunt. I assume you are not using https with the internal connection to Sanic, that could cause TLS handshake errors not being logged by Sanic (a known problem). |
I started with default timeouts, and increased keep alive timeout to 15 seconds. From the PCAP it looks like the connection was active for a while (at least 5 previous request-response pairs), and the current problem happens during a new POST request (of size a bit bigger than 1MB). The RST is the first response from the sanic side, no other response before that. The app itself always responds 200 OK with "OK" as content, nothing complicated on the response. And you're right, the nginx<=>sanic connection is http only. |
@oren-nonamesecurity It certainly looks like the idle connection timing out after five seconds and Sanic is closing it at 31781 (no logging because this is a normal operation). The default After that Nginx is expected to disconnect but why it instead sends another request 0.6 seconds later, I don't know. Technically it can because its side of the socket is still open, but since Sanic is no longer reading, it'll only lead to those resets that you are seeing. @ahopkins This is a subtle detail but we should probably make Sanic explicitly shutdown the socket in both directions when it no longer intends to read or write anything: sock.shutdown(socket.SHUT_RDWR)
sock.close() |
The FIN from sanic and the extra POST from nginx happen almost simultaneously (6ms difference). For now I increased the sanic keep alive timeout to be larger than the nginx keep alive timeout, and it prevents these errors from happening because the nginx will close from his side first. |
Oops, I misread the capture, although ~7 ms on localhost is still plenty of time. It'd be interesting to see whether the shutdown makes a difference, if you can easily reproduce this issue. It might be a one-liner addition to https://github.com/sanic-org/sanic/blob/main/sanic/server/protocols/base_protocol.py#L90 directly accessing the asyncio transport socket. The actual PR needs more careful thought and review even if that works. |
Have not looked too deeply into the above (sorry). But I did a quick experiment: sock: Optional[socket] = self.transport.get_extra_info("socket")
if sock is not None:
sock.shutdown(SHUT_RDWR)
Using |
There is an open issue (with a hacky workaround too) |
Nice find. |
This should solve the issue in practice, even though the root problem cannot be fixed. The uvloop issue is still open with no activity... |
Describe the bug
Hi,
I'm using nginx as reverse-proxy to handle TLS and route to multiple applications on same server.
My sanic app is the main route that handles most of the traffic.
The traffic is pretty high (~5000 requests per second, on 16 workers) and I get some random errors in the nginx every few minutes. The errors are from these 3 types:
On the sanic side there's nothing in the logs.
access_log=True and also debug=True didn't show any error or anything suspicious, I also tried verbosity=5 but still nothing relevant.
Going deeper, I started tshark to try to see what actually happens, and I saw that the Sanic side actually sent tcp RST in the middle of a POST request being sent to it.
I tried setting SANIC_NOISY_EXCEPTIONS, increase SANIC_KEEP_ALIVE_TIMEOUT and REQUEST_BUFFER_SIZE - but still nothing helps.
I saw #991 which is quite old and has similar errors, but I'm using latest version and still have them.
Any idea what can cause it? Or how to fix it?
Environment (please complete the following information):
FROM python:3.8-slim-buster
)The text was updated successfully, but these errors were encountered: