Skip to content
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

Add specs and fix logic #48

Closed
wants to merge 4 commits into from
Closed

Conversation

JackDanger
Copy link

Prior to this there were cases where the timeout did not behave as expected. All tests now pass.

Prior to this there were cases where the timeout did not behave as
expected.
@dmathieu
Copy link

cc @chadbailey59

@kch
Copy link
Contributor

kch commented Aug 21, 2014

@dmathieu well I did reference @chadbailey59 in #45

@chadbailey59
Copy link

@JackDanger thanks a lot for your work here. As @kch mentioned, I'm sort-of-taking-over on this project here. I have some other specs that I've been planning to merge in, but you've done great stuff here too, so I need to figure out how to smash all of it together.

@@ -27,9 +27,10 @@ def call(env)
request_start = env['HTTP_X_REQUEST_START'] # unix timestamp in ms
request_start = Time.at(request_start.to_f / 1000) if request_start
info.age = Time.now - request_start if request_start
time_left = MAX_REQUEST_AGE - info.age if info.age
time_left += self.class.overtime if time_left && self.class._request_has_body?(env)
info.timeout = [self.class.timeout, time_left].compact.select { |n| n >= 0 }.min
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sadly this code is super error prone. in particular, errant values in the HTTP_X_REQUEST_START header can result in a negative time_left, which is why this logic needs to stay here 😿

@PikachuEXE
Copy link

When will this be merged?

@kch
Copy link
Contributor

kch commented Sep 27, 2014

So I wasn't really sure what was getting to me about this patch, but I think I got it now: the thing is MAX_REQUEST_AGE and timeout are different things. From the README:

Normally, Rack::Timeout always times out a request using the Rack::Timeout.timeout setting. Heroku makes available the X-Request-Start HTTP header, which is a timestamp indicating the time the request first enters the routing infrastructure.

The implication here is that if X-Request-Start is present, then not always Rack::Timeout.timeout is what will be used as the timeout value.

If the X-Request-Start HTTP header is present, Rack::Timeout will take the age of the request into consideration when determining the timeout to use. If a request is older than 30 seconds, it's dropped immediately. …

The 30s amount is fixed, and that's why it's in a constant. I then explain:

The reasoning for this behavior is that the Heroku router drops requests if no data is transferred within 30s, so it makes no sense for the application to process a request it'll never be able to respond to.

And back in the previous paragraph:

… the timeout is the number of seconds left for the request to be 30 seconds old, or the value of Rack::Timeout.timeout, whichever is shorter.

And that's why MAX_REQUEST_AGE is supposed to sometimes win over timeout.

All that said, the code is clearly confusing, and I think @cjolly is right in that overtime is never used. (Mind you that the overtime stuff never made it to the last beta.)

So my thinking now is to refactor a bunch of this, and I hope the tests from this patch and from @chadbailey59 's branch will come in handy.

@kch
Copy link
Contributor

kch commented Sep 27, 2014

Now the other problem is that the whole thing around X-Request-Start comes with a lot of assumptions around behaviours from the Heroku router. Which, if you're using nginx, goes down the drain. Most especially, the MAX_REQUEST_AGE thing.

As per #38 I wanted to just get a release out, so I might get this out again without overtime support, and work on a more general/flexible implementation next.

@cjolly
Copy link

cjolly commented Sep 27, 2014

Thanks for the update @kch. We've been using this branch in production since I commented above. The big requirement for us (read-heavy app) is that we want a quick timeout for everything but PUTs, POSTs, which shouldn't be subject to theRack::Timeout.timeout or MAX_REQUEST_AGE, as stated in the README and heroku routing policy.

I'm all for getting some tests in place for a refactor and an official release, subsequently addressing the overtime. I'm definitely willing to lend a hand wherever necessary, just let me know.

@kch
Copy link
Contributor

kch commented Sep 28, 2014

Right now, even fixing overtime, MAX_REQUEST_AGE would still be respected, it would just be extended by overtime.

I'm playing with a refactoring that lets you set any of those things to false and then it'll be ignored.

As for heroku routing, it drops any request that hasn't had any transfer going in for over 30s. So strictly, it's not about being a POST or PUT, but those do tend to perform transfers while going over 30s, so effectively, it's about them too.

kch added a commit that referenced this pull request Sep 29, 2014
Some bugs squashed, hopefully none introduced. The intent of code should be much clearer, even more so with all the amazing commentary.

Hopefully addresses the issues raised in #48 and #45, plus #50 as a bonus. Not to mention #29 again.

@chadbailey59 will probably hate me.
end

it "completes successfully" do
expect { call }.to_not raise_error
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this test will fail with the new refactor (e599a9f), but I'd say the test is wrong. The refactor should make it more clear the overtime only applies to the wait timeout, not to the service timeout.

kch added a commit that referenced this pull request Sep 30, 2014
Merge remote-tracking branch 'jackdanger/add-specs' into jackdanger-tests

Conflicts:
	lib/rack/timeout.rb
@kch kch mentioned this pull request Sep 30, 2014
@kch
Copy link
Contributor

kch commented Sep 30, 2014

At this point I'm closing this. The need for tests is tracked in #52, and the logic has been fixed in the recent refactorings. (mainly e599a9f)

Thanks again @JackDanger for the patch, even though it didn't get merged, it was instrumental in the refactor.

@kch kch closed this Sep 30, 2014
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

7 participants