Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP
Browse files

Initial commit

  • Loading branch information...
commit e0978c61d0d318edcb418f72036de859db9fd19a 0 parents
@samstokes samstokes authored
1  .gitignore
@@ -0,0 +1 @@
+rack-informant-*.gem
3  Gemfile
@@ -0,0 +1,3 @@
+source :rubygems
+
+gemspec
14 Gemfile.lock
@@ -0,0 +1,14 @@
+PATH
+ remote: .
+ specs:
+ rack-informant (1.0.0)
+
+GEM
+ remote: http://rubygems.org/
+ specs:
+
+PLATFORMS
+ ruby
+
+DEPENDENCIES
+ rack-informant!
75 lib/rack/informant.rb
@@ -0,0 +1,75 @@
+module Rack
+ # Middleware that "informs on" an application, reporting everything it does
+ # to its secret employer. Other middlewares may become hostile if they find
+ # out.
+ #
+ # After each request is processed, calls the provided block with a hash
+ # containing:
+ # * :method - HTTP request method, e.g. 'GET', 'POST'
+ # * :path - path segment of the request (no host, port or querystring),
+ # e.g. '/info'
+ # * :status - HTTP response status code, e.g. 200, 404
+ # * :runtime - total request processing time (by the server's reckoning) in
+ # *seconds*, as a float. e.g. 0.1 == 100 ms.
+ #
+ # This middleware is async-safe (i.e. should work correctly for both
+ # synchronous requests and asynchronous requests).
+ #
+ # Example usage:
+ #
+ # require 'rack/informant'
+ # use Rack::Informant do |request|
+ # # poor man's request logging (use Rack::CommonLogger instead)
+ # puts "#{request[:method]} #{request[:path]}: #{request[:status]} #{request[:runtime]}"
+ # end
+
+ class Informant
+ def initialize(app, &block)
+ @app = app
+ @callback = block || lambda {|*_|}
+ end
+
+ def call(env)
+ @start = Time.now
@ept Owner
ept added a note

@samstokes Not sure if I'm reading this right, but it looks to me as though the time measurement for async requests is off. Assuming that only one instance of the middleware is created for the whole application (not one per request), then @start will get overwritten every time a request comes in, and then inform! will see the start time of the most recent request, not the request that just completed.

What do you think?

@samstokes Owner

@ept you are quite right, both that there's only one instance of the middleware, and that the timing is wrong for async. I don't know what I was thinking. I guess that means all our latency metrics are wrong; oh well.

In particular I think it means our latency metrics are underestimates (because the effect of the bug is that an outstanding request appears to have started more recently than it did, and thus taken less time than it did). So at least it doesn't change the conclusion that we're too slow.

#1 fixes it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
+
+ if original_callback = env['async.callback']
+ env['async.callback'] = proc do |response|
+ status, headers, body = response
+
+ inform!(env, status, headers, body)
+
+ original_callback.call(response)
+ end
+ end
+
+ catch :async do
+ status, headers, body = @app.call(env)
+
+ # if we got this far, then @app.call didn't throw :async
+ return [status, headers, body] if status == -1 # alternative async API
+
+ # if we got *this* far, @app.call is definitely synchronous
+ inform!(env, status, headers, body)
+
+ return [status, headers, body]
+ end
+
+ # we only end up here if @app.call threw :async, so just throw it on.
+ throw :async
+ end
+
+ private
+ def inform!(env, status, headers, body)
+ runtime = Time.now - @start
+
+ event = {
+ method: env['REQUEST_METHOD'],
+ path: env['PATH_INFO'],
+ status: status,
+ runtime: runtime,
+ }
+
+ @callback.call(event)
+ end
+ end
+end
12 rack-informant.gemspec
@@ -0,0 +1,12 @@
+Gem::Specification.new do |s|
+ s.name = 'rack-informant'
+ s.authors = ['Rapportive Inc']
+ s.email = 'supportive@rapportive.com'
+ s.version = '1.0.0'
+ s.summary = %q{Reporting middleware.}
+ s.description = "Middleware that reports all requests to an interested party (e.g. for analytics)."
+ s.homepage = "https://github.com/rapportive-oss/rack-informant"
+ s.date = Date.today.to_s
+ s.files = `git ls-files`.split("\n")
+ s.require_paths = %w(lib)
+end
@ept

@samstokes Not sure if I'm reading this right, but it looks to me as though the time measurement for async requests is off. Assuming that only one instance of the middleware is created for the whole application (not one per request), then @start will get overwritten every time a request comes in, and then inform! will see the start time of the most recent request, not the request that just completed.

What do you think?

@samstokes

@ept you are quite right, both that there's only one instance of the middleware, and that the timing is wrong for async. I don't know what I was thinking. I guess that means all our latency metrics are wrong; oh well.

In particular I think it means our latency metrics are underestimates (because the effect of the bug is that an outstanding request appears to have started more recently than it did, and thus taken less time than it did). So at least it doesn't change the conclusion that we're too slow.

#1 fixes it.

Please sign in to comment.
Something went wrong with that request. Please try again.