Skip to content

Fix timing out requests too early #2606

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.

Sign up for GitHub

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

Jump to bottom
Merged
MSP-Greg merged 2 commits into from
Apr 20, 2021
Merged

Fix timing out requests too early #2606

MSP-Greg merged 2 commits into from
Apr 20, 2021

Conversation

@wjordan
Copy link
Contributor

@wjordan wjordan commented Apr 20, 2021

Description

Fixes #2574 (a regression released in v5.0.3), with an added test to prevent future regressions.

See also

#2575 extends this fix by adding a between_bytes_timeout configuration option that allows for different timeout values for the initial data received by the client, and subsequent chunks of data. This extra option may eventually be useful but this PR is intended to more narrowly fix the regression first.

Your checklist for this pull request

  • I have reviewed the guidelines for contributing to this repository.
  • I have added (or updated) appropriate tests if this PR fixes a bug or adds a feature.
  • My pull request is 100 lines added/removed or less so that it can be easily reviewed.
  • If this PR doesn't need tests (docs change), I added [ci skip] to the title of the PR.
  • If this closes any issues, I have added "Closes #issue" to the PR description or my commit messages.
  • I have updated the documentation accordingly.
  • All new and existing tests passed, including Rubocop.

@wjordan @darkhelmet
Fix timing out when we get a slow request
7e11ad1 
Fixes puma#2574 (regression in v5.0.3).

Co-authored-by: Daniel Huckstep <[email protected]>
Co-authored-by: Will Jordan <[email protected]>
@MSP-Greg
Copy link
Member

MSP-Greg commented Apr 20, 2021

@wjordan

LGTM. Maybe change test_timeout_in_data_phase (line 385 in the PR) to the following? Using 1.1 worked locally, added 0.05 for CI:

def test_timeout_in_data_phase
  @server.first_data_timeout = 1
  server_run

  sock = send_http "POST / HTTP/1.1\r\nHost: test.com\r\nContent-Type: text/plain\r\nContent-Length: 5\r\n\r\n"
  sleep 1.15
  sock << "Hello"

  data = sock.gets

  assert_equal "HTTP/1.1 408 Request Timeout\r\n", data
end

@MSP-Greg
Copy link
Member

MSP-Greg commented Apr 20, 2021 •
edited
Loading

@wjordan

So the 'Windows' guy (me) now does 95% of his Puma work with WSL2/Ubuntu20.04. Sorry for that.

Not sure what I think of the Errno::ECONNABORTED being raised so quickly, what's your opinion?

@MSP-Greg
Copy link
Member

MSP-Greg commented Apr 20, 2021

I saw you setting the timing to zero, I'm running the following in my fork right now...

def test_timeout_in_data_phase
  @server.first_data_timeout = 1
  server_run

  sock = send_http "POST / HTTP/1.1\r\nHost: test.com\r\nContent-Type: text/plain\r\nContent-Length: 5\r\n\r\n"
  sleep 1.15
  sock << "Hello"

  if Puma::IS_WINDOWS
    assert_raises(Errno::ECONNABORTED) { sock.gets }
  else
    data = sock.gets
    assert_equal "HTTP/1.1 408 Request Timeout\r\n", data
  end
end

@wjordan
Update test_timeout_in_data_phase
9b5604b 
Complete request to ensure short timeout is used properly.
@MSP-Greg
Copy link
Member

MSP-Greg commented Apr 20, 2021

Looks like both versions are passing. I also had a nonrelated failure...

@MSP-Greg
Copy link
Member

MSP-Greg commented Apr 20, 2021

I made the change with assert_raises since it was the gets that was causing the failure, not the <</write.

@wjordan
Copy link
Contributor Author

wjordan commented Apr 20, 2021

It looks like a Windows TCPSocket raises ECONNABORTED on the next read, if a socket is written to after being closed at the other end- so skipping the write if the response is already returned (unless IO.select()) seems to work and still tests to make sure the timeout is sent in time.

@MSP-Greg
Copy link
Member

MSP-Greg commented Apr 20, 2021

tests to make sure the timeout is sent in time.

Works for me.

@MSP-Greg MSP-Greg merged commit a717b27 into puma:master Apr 20, 2021
@darkhelmet darkhelmet mentioned this pull request Jun 7, 2021
Closed
8 tasks
JuanitoFatas pushed a commit to JuanitoFatas/puma that referenced this pull request Sep 9, 2022
@wjordan @darkhelmet @JuanitoFatas
Fix timing out requests too early (puma#2606)
7dcbc5f 
* Fix timing out when we get a slow request
Fixes puma#2574 (regression in v5.0.3).

Co-authored-by: Daniel Huckstep <[email protected]>
Co-authored-by: Will Jordan <[email protected]>

* Update test_timeout_in_data_phase
Complete request to ensure short timeout is used properly.

Co-authored-by: Daniel Huckstep <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Labels

bug

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

Timeout during long file upload

3 participants

@wjordan @MSP-Greg @nateberkopec