Open travisbell opened 2 weeks ago
Yeah I’m also seeing some bugs, I will investigate today.
Unsure if related, but possibly/probably:
https://github.com/socketry/async-http/commit/3a5c1ccce25dbedfd9a255ea5976175cd89ae34c
After a few hours of debugging, I've found that in a Rails application, POST
requests with specified Content-Length
headers (not reading to EOF) will cause Fibers to linger/leak until the application closes.
As far as I can tell in our Rails application, nothing will actually call Finishable#read
to EOF or explicitly close the request body (pretty sure this is the default behavior.)
In the above commit, I test @body.empty?
in Finishable
to establish an additional close condition. There's probably a cleaner way to do this.
Are you able to update to the latest versions of async-http, protocol-http*, io-stream and any dependencies, it should fix all the issues.
(Also, I'll add your reported failure as a test case to async-http so we won't have any regressions).
Are you able to update to the latest versions of async-http, protocol-http*, io-stream and any dependencies, it should fix all the issues.
I am seeing the above issue with:
async (2.17.0)
async-http (0.79.0)
async-pool (0.8.1)
io-endpoint (0.13.1)
io-event (1.6.5)
io-stream (0.4.1)
protocol-http (0.37.0)
protocol-http1 (0.27.0)
protocol-http2 (0.19.2)
protocol-rack (0.10.0)
I believe these are all the latest versions.
Okay, thanks for the report, I'll investigate it today.
I have made another round of bug fixes and performance improvements. However, I have not investigated the above issue yet. Sorry.
I'm trying to reproduce the issue here: https://github.com/socketry/async-http/pull/185
So far, I'm not having a lot of luck:
Connecting to server: Async::HTTP::Protocol::HTTP10
Finishable#initialize: #<Protocol::HTTP1::Body::Fixed length=13 remaining=13 state=open>
Finishable#read: "Hello, World!"
Finishable#read: nil
Finishable#close: nil
Got response: #<Async::HTTP::Protocol::HTTP1::Response:0xc30 status=200>
Connecting to server: Async::HTTP::Protocol::HTTP11
Finishable#initialize: #<Protocol::HTTP1::Body::Fixed length=13 remaining=13 state=open>
Finishable#read: "Hello, World!"
Finishable#read: nil
Finishable#close: nil
Got response: #<Async::HTTP::Protocol::HTTP1::Response:0xc58 status=200>
Connecting to server: Async::HTTP::Protocol::HTTP2
Got response: #<Async::HTTP::Protocol::HTTP2::Response:0xc80 status=200>
@korbin do you have a reproduction that I can use?
I also made this change fairly recently: https://github.com/socketry/protocol-rack/commit/d34fabd611fb047083f6af44b2eecaebf6ff2842
Can you confirm you are using the latest version of protocol-rack
?
I wonder if we need to make the same change here: https://github.com/socketry/protocol-http/blob/8244dbf54d05619713140a113b76b74e49c680fd/lib/protocol/http/body/stream.rb#L298.
Maybe https://github.com/socketry/protocol-http/pull/71 is sufficient to fix this issue. @korbin are you able to test it?
I can confirm this issue is still happening (both with and without the protocol-http
branch) and have created a test repo for you, if you clone and execute:
bundle exec falcon host falcon.rb
curl -X POST http://127.0.0.1:3000/ -H 'Content-Type: application/json' --data '{}'
You should see that the log output I've added in falcon.rb
indicates that the call never completes. I've removed the async
block wrapping the handler for performance reasons, which I believe was masking the issue and why it's a little unobvious to reproduce. I'm of the opinion that the behavior I'm aiming for here should work and this execution should properly complete without the need for fibers to yield first.
If you uncomment my Finishable
patch in falcon.rb
, the one read
will properly set the @closed.value
when the underlying streaming body is read completely.
If we look at the underlying Rails handlers:
raw_post
calls read_body_stream
read_body_stream
calls body_stream.read(length)
Finishable
wrapping a Protocol::HTTP1::Body::Fixed
created and assigned to the request.body
(via Rack) in async-httpFinishable#read
delegates to Protocol::HTTP1::Body::Fixed#read
Protocol::HTTP1::Body::Fixed#read
does actually call @connection.receive_end_stream!
when @remaining == 0
, but the outer Finishable
never has any reason to know that his underlying @body
is closed.The issue is that if I specify a content length
(which Rails does), the underlying Protocol::HTTP::Body::Stream
never does an "extra" read
to push past the content and into EOF (closing the body
):
https://github.com/socketry/protocol-http/blob/main/lib/protocol/http/body/stream.rb#L58-L61
--
Possible fixes:
Finishable#read
checks to see if the underlying body is empty?
after reading and updates his internal value accordingly at read-time.Protocol::Rack::Input#read_next
issues an extra @body.read
(or ideally something like a @body.peek
or @body.empty?
) and then explicitly calls @body.close
after reading.Protocol::HTTP::Body::Stream
always reads an extra time, even if a length
is specified (probably not correct.)Thanks this looks really helpful. I'll work on it today.
I can confirm that even without my custom stuff (leaving async
where it is in upstream io-endpoint
), yield socket, address
never returns (no log output happens.)
Hello,
Upon upgrading to
0.77.0
, I am seeing some 303 requests that don't seem to finish (or close). I can't quite tell what's happening other than Falcon is just not letting the request complete. The request just sits there indefinitely. Not 100% of these requests do this, but in my testing a good 90% of them do. I might be lucky if 1/10 requests get the full response sent to the browser.Downgrading to 0.76.0 fixes the issue.
I might be seeing this on other responses but I am for sure seeing this on requests that return a 303 on a POST request, like say, redirecting after a login. This is in a Sinatra app, by the way. The response bodies for these requests are 0 bytes, they just contain a location header. They are also all HTTP 1.1 requests.
Hope that's enough to help troubleshoot this. I can try to get more debug info if required.
Thanks!