Fix time measurement for async #1

Merged
merged 2 commits into from Nov 15, 2012

Conversation

Projects
None yet
1 participant
@samstokes
Member

samstokes commented Nov 15, 2012

@ept I've tested the fix with a trivial app, but would appreciate your eyes on it because I'm clearly a stupidhead. Then I'll push the new gem.

@samstokes

This comment has been minimized.

Show comment
Hide comment
@samstokes

samstokes Nov 15, 2012

Member

My trivial test app:

require 'eventmachine'
require 'rack/informant'
require 'sinatra'
require 'thin'

use(Rack::Informant) {|request| p request[:runtime] }

get '/hi' do
  EM::add_timer(1) { env['async.callback'].call [200, {}, 'hey'] }
  throw :async
end
Member

samstokes commented Nov 15, 2012

My trivial test app:

require 'eventmachine'
require 'rack/informant'
require 'sinatra'
require 'thin'

use(Rack::Informant) {|request| p request[:runtime] }

get '/hi' do
  EM::add_timer(1) { env['async.callback'].call [200, {}, 'hey'] }
  throw :async
end

samstokes added some commits Nov 15, 2012

Timing was broken for async endpoints, fix it...
There's only one Rack::Informant instance per app (not per request!), so
for async endpoints, @start would get overwritten by each subsequent
request.  An outstanding request would therefore appear to have started
whenever the most recent request came in, rather than when it actually
started, and thus be reported as quicker than it was.

Fix by using a local variable in #call (which *is* per-request) rather
than an instance variable.

Thanks @ept for pointing this out.

samstokes pushed a commit that referenced this pull request Nov 15, 2012

@samstokes samstokes merged commit 6b18538 into master Nov 15, 2012

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment