Fix wsgi.server shutdown for in-flight requests#912
Conversation
While doing some work on OpenStack Swift, I noticed that in-flight requests were getting their sockets closed by eventlet when the listen socket was closed. In that case, there is a server process which bound the listen socket and N fork'ed off worker processes which all run the wsgi.server loop calling accept() and handling requests. I noticed that nothing was ever setting connection state to STATE_REQUEST (i.e. unused constant in previous patch). Upon closer inspection, it turns out that the socket cleanup code for STATE_IDLE sockets got applied to the socket with an in-progress request. This caused code using the socket to get an EPIPE and exit the request's greenthread without completing the request. With some instrumentation in the code, without this patch's fix, the new test observed the code doing this: (7544) wsgi starting up on http://127.0.0.1:36745 (7544) calling accept (7544) accept got <eventlet.greenio.base.GreenSocket object at 0x7f7650d73290>, ('127.0.0.1', 50194) (7544) accepted ('127.0.0.1', 50194) (7544) completed req ('127.0.0.1', 50194) (7544) calling accept (7544) got exception 22 (7544) re-raising! (7544) wsgi exiting, calling pool.waitall() Traceback (most recent call last): File "/tmp/swiftstack-eventlet/eventlet/wsgi.py", line 602, in handle_one_response write(b'') File "/tmp/swiftstack-eventlet/eventlet/wsgi.py", line 541, in write wfile.flush() File "/usr/lib64/python2.7/socket.py", line 303, in flush self._sock.sendall(view[write_offset:write_offset+buffer_size]) File "/tmp/swiftstack-eventlet/eventlet/greenio/base.py", line 403, in sendall tail = self.send(data, flags) File "/tmp/swiftstack-eventlet/eventlet/greenio/base.py", line 397, in send return self._send_loop(self.fd.send, data, flags) File "/tmp/swiftstack-eventlet/eventlet/greenio/base.py", line 384, in _send_loop return send_method(data, *args) error: [Errno 32] Broken pipe 127.0.0.1 - - [31/Oct/2019 01:08:05] "PUT /foo-bar HTTP/1.1" 200 0 0.000696 (7544) wsgi exited, is_accepting=True In the new tests, not having the fix manifests as all greenthreads exiting before the client finishes the in-flight request. For the WebsocketWSGI app, it has a private class attribute that tells the wsgi.server() code to consider its "reqeusts" always idle, which I believe was the primary intent of the original patch.
...which apparently won't let you interpolate ints into bytestrings. Also remove some extraneous comments in the test.
Reduce chance for regression in future and show that client socket is unusable after an in-flight requet is finished.
Codecov ReportAttention: Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## master #912 +/- ##
=====================================
Coverage 56% 56%
=====================================
Files 89 89
Lines 9741 9748 +7
Branches 1812 1812
=====================================
+ Hits 5463 5471 +8
- Misses 3903 3905 +2
+ Partials 375 372 -3
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Sentry. |
|
All the If I strace the process I can see tons of: The socket file descriptor is not an open file descriptor (https://man.archlinux.org/man/accept4.2.en#EBADF). In other words a socket is closed when using the asyncio context. This is why this test seems stuck, and this is why the tox-asyncio jobs timed outs in our github actions. I'm not sure which socket is the problem (the client socket, the server socket, both sockets). Apparently only one socket seems in trouble. I don't know why this new test is not compatible with asyncio. @itamarst: any idea? Else, out of the asyncio context, I made local tests by removing the changes made in |
|
Here is more or less a complete |
|
Apparently the test start to fail at line 1992 |
|
I will try to take a look. |
|
If you close a socket, So, yeah, it'll take forever. You either don't want to close a socket (how could that ever happen in real code?), or you want to add an else clause that breaks the loop on line 1044 of wsgi.py. However, it's possible that some of the errnos in ACCEPT_ERRNO are transient, so I don't know if that's correct behavior for all of them. |
|
Indeed that could explain why we see an infinite loop. Wonder if using a Apparently after the Lines 1047 to 1056 in b6f6e7c Another concern that I have is: why this problem only appear with the asyncio hub? If I remember correctly, when I ran local tests I was not able to reproduce this problem with |
|
I confirm that when I run my local tests against a hub that is not the asyncio one, the test is successful. Here below is an example with the At first glance, I don't see why this patch behave differently depending on the used hub. |
|
Here is an isolation of the With the With the |
|
Oh, interesting! I think the test is expecting the in the posted strace. It's not clear to me how (if?) asyncio handles error states. Seems like it'll depend on selector, but |
|
I think the main difference between the In the previous epolls strace we can observe that the a file descriptor (equal to Then, we request the shutdown of this socket and start waiting for a ready file descriptor. Once this socket is ready we remove this socket file descriptor from from the interest list of the Apparently when using the asyncio hub the Complete I'm far to be a low level specialist and someone more skilled than me should double check what I say here. |
We recently observed (eventlet#912) difference in the behaviors between the asyncio hub and the other eventlet hubs. The asyncio hub behaved differenly because bad file descriptor were not properly removed from the list of readers and writers listeners. To clean these bad file descriptors we have to implement an awaitable wait method specific to the asyncio hub This patch should fix eventlet#912. I prefer to propose this patch as a separated patch to isolate topics and simplify reviews. eventlet#912
We recently observed (eventlet#912) difference in the behaviors between the asyncio hub and the other eventlet hubs. The asyncio hub behaved differenly because bad file descriptor were not properly removed from the list of readers and writers listeners. To clean these bad file descriptors we have to implement an awaitable wait method specific to the asyncio hub This patch should fix eventlet#912. I prefer to propose this patch as a separated patch to isolate topics and simplify reviews. eventlet#912
We recently observed (eventlet#912) difference in the behaviors between the asyncio hub and the other eventlet hubs. The asyncio hub behaved differenly because bad file descriptor were not properly removed from the list of readers and writers listeners. To clean these bad file descriptors we have to implement an awaitable wait method specific to the asyncio hub This patch should fix eventlet#912. I prefer to propose this patch as a separated patch to isolate topics and simplify reviews. eventlet#912
|
The root cause of the error seen when using the asyncio hub, is due to fact that all the eventlet hubs, apart the asyncio hub, implements bad file descriptors removal. As in tests we close the socket, its file descriptor is also closed and as the asyncio hub do not remove bad file descriptor from its listeners, the server continue to iterate over this socket again and again, and try to access it, this is why we see the infinite loop of accept sys calls. The other hubs implement mechanisms to remove these bad file descriptors, this is why their tests pass without problems. I just submitted a patch to implement this missing feature: #924 For now, my PR fix the problem we face here. Local tests are successful for this use case. However asyncio jobs are failing due to a side effect of my proposal, I need to dive deep to see how to fix that. I don't think we could consider the asyncio hub as production ready, while this problem is not solved. Hopefully we won't face similar issues elsewhere. IMO, from a end user point of view, all hubs should behave the same way. All hubs should be iso-behaving. |
|
Reading the man page for accept(), I think the "just ignore EBADF" behavior in wsgi.py is a bug. |
|
@4383 back to you. |
| try: | ||
| import ssl | ||
| ACCEPT_EXCEPTIONS = (socket.error, ssl.SSLError) | ||
| ACCEPT_ERRNO = {errno.EPIPE, errno.EBADF, errno.ECONNRESET, |
There was a problem hiding this comment.
The man page for accept() on Linux says "EBADF: sockfd is not an open file descriptor." I.e. it's not a recoverable error.
There was a problem hiding this comment.
Indeed, that seems logic. I think you are right, this kind of error (bad file descriptor), is not recoverable. I don't see how a server could recover from this kind of error.
By doing my previous tests, it seems that in this case (EBADF), the wsgi server is terminated properly without raising more attention than that.
In parallel, I think we should also consider that the wsgi server is only one piece of the architecture of our users. Some people may launch several greenthreads dedicated to various task, and the wsgi server greenthread could be one of them, so if the server exit abruptly, the global process will be affected and then all the other greenthreads would also exit abruptly, then killing all the other background jobs. I think this scenario is more or less the reason behind the implementation of the logic of EBADF management we observe in various hubs.
However, this logic more or less hide wsgi server errors. Without digging too far, developer should observe this kind of failure on the client side, when requests are no longer successful.
From a monitoring perspective, if developers monitors the process of their wsgi server, currently, by functionning this way, they should not be able to observe a failure on this process, as the global process could continue to run due to other greenthreads.
I'd argue that when we face this kind of scenario (EBADF), we should failed early as soon as possible.
IMO, rather than implementing specific logic in various hubs, logic dedicated to manage bad file descriptor, the wsgi module should exit with error to catch developer attention about this problem.
The current behaviour of hubs seems more a convenience to allow polymorphic architectures in the same process. A kind of fault tolerance behaviour. I'd rather encourage managing this kind of error by using things like pacemaker.
Thoughts?
4383
left a comment
4383
left a comment
There was a problem hiding this comment.
LGTM, removing EBADF from accepted errors fixed the issue we discussed previously. Thanks
|
@tipabu: if you are ok with the latest commit added by Itamar, then feel free to push the squash and merge button, else feel free to raise your concerns. Thank you. |
|
@tipabu, @itamarst: The EBADF changes are not semantically close to the original intent of this PR. The EBADF changes fix a side behavior observed during debug. As the commit introduced by Itamar is not really related to the changes initially proposed by this PR, and as I think the EBADF change is an important modification in the behaviour of the hubs and of the wsgi module, hence, I'd suggest to use "rebase and merge" rather than "squash and merge". Indeed, we will possibly face side of effects due to the EBADF removal, so, for the sake of clarity and with the goal to keep an exploitable git history (git bisect, changelog), merging this PR this way would surely simplify our lifes. Else, the EBADF changes could be proposed as a separated PR, and then merged first, but at the end the result would be the same, i.e a dedicated commit in the git history for the EBADF topic. Using "rebase and merge" here, would avoid the gymnastic of a new PR creation. Any concerns? |
|
I don't have a strong opinion, I'd do whatever is easiest. |
|
Well, even after rebasing master into this branch, the rebase feature of github doesn't work. Locally I'm able to properly merge this branch with master with no fast forward, but apparently it doesn't work in the pipes of github, I don't know why, so lets squash all commits and then wrote a meaningful commit message. |
…rsion 0.36.1 0.36.1 ====== * [fix] eventlet.websocket is not always used from eventlet.wsgi, so do not assume eventlet.set_idle exists eventlet/eventlet#949 0.36.0 ====== * [fix] Make sure asyncio hub doesn't use greendns for asyncio DNS APIs eventlet/eventlet#938 * [fix] Make asyncio.to_thread work with the same semantics as normal asyncio eventlet/eventlet#930 * [fix] Refactor congruence checks based on assert at runtime eventlet/eventlet#932 * [tests] Run tests on macOS in CI, and some fixes to get it in reasonable state (#list eventlet/eventlet#934 * [fix] Fix wsgi.server shutdown for in-flight requests eventlet/eventlet#912 * [feature] Add debug convenience helpers - asyncio, threads eventlet/eventlet#925 * [fix] Handle errors better. eventlet/eventlet#923 (NEWS truncated at 15 lines) CVEs fixed in this build: CVE-2023-29483
5 participants
Cloning from #590 (which still has some relevant discussion) -- the source repo got deleted, which prevents me from resolving the conflicts on the original PR. Original description (mostly) follows:
While doing some work on OpenStack Swift, I noticed that in-flight
requests were getting their sockets closed by eventlet when the listen
socket was closed. In that case, there is a server process which bound
the listen socket and N fork'ed off worker processes which all run the
wsgi.server loop calling accept() and handling requests.
I noticed that nothing was ever setting connection state to
STATE_REQUEST (i.e. unused constant in previous patch). Upon closer
inspection, it turns out that the socket cleanup code for STATE_IDLE
sockets got applied to the socket with an in-progress request. This
caused code using the socket to get an EPIPE and exit the request's
greenthread without completing the request.
With some instrumentation in the code, without this patch's fix, the new
test observed the code doing this:
In the new tests, not having the fix manifests as all greenthreads
exiting before the client finishes the in-flight request.