2010-06-04 12:49:25 -04:00
|
|
|
require 'active_support/core_ext/time/conversions'
|
2011-10-19 16:39:11 -04:00
|
|
|
require 'active_support/core_ext/object/blank'
|
2013-01-09 18:34:36 -05:00
|
|
|
require 'active_support/log_subscriber'
|
|
|
|
require 'action_dispatch/http/request'
|
|
|
|
require 'rack/body_proxy'
|
2010-01-21 07:05:30 -05:00
|
|
|
|
|
|
|
module Rails
|
|
|
|
module Rack
|
2012-09-26 18:08:25 -04:00
|
|
|
# Sets log tags, logs the request, calls the app, and flushes the logs.
|
2010-06-24 07:23:43 -04:00
|
|
|
class Logger < ActiveSupport::LogSubscriber
|
2012-09-26 18:08:25 -04:00
|
|
|
def initialize(app, taggers = nil)
|
2013-01-09 18:34:36 -05:00
|
|
|
@app = app
|
|
|
|
@taggers = taggers || []
|
|
|
|
@instrumenter = ActiveSupport::Notifications.instrumenter
|
2010-01-21 07:05:30 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
def call(env)
|
2012-09-26 18:08:25 -04:00
|
|
|
request = ActionDispatch::Request.new(env)
|
|
|
|
|
2013-01-08 13:50:28 -05:00
|
|
|
if logger.respond_to?(:tagged)
|
|
|
|
logger.tagged(compute_tags(request)) { call_app(request, env) }
|
2011-10-19 16:39:11 -04:00
|
|
|
else
|
2012-09-26 18:08:25 -04:00
|
|
|
call_app(request, env)
|
2011-10-19 16:39:11 -04:00
|
|
|
end
|
2010-01-21 07:05:30 -05:00
|
|
|
end
|
|
|
|
|
2010-06-24 07:23:43 -04:00
|
|
|
protected
|
2010-01-21 07:05:30 -05:00
|
|
|
|
2012-09-26 18:08:25 -04:00
|
|
|
def call_app(request, env)
|
2012-10-07 01:06:43 -04:00
|
|
|
# Put some space between requests in development logs.
|
2013-01-08 13:50:28 -05:00
|
|
|
if development?
|
|
|
|
logger.debug ''
|
|
|
|
logger.debug ''
|
2012-10-07 01:16:39 -04:00
|
|
|
end
|
2012-10-07 01:06:43 -04:00
|
|
|
|
2013-08-05 17:16:41 -04:00
|
|
|
@instrumenter.start 'request.action_dispatch', request: request
|
2013-01-08 13:50:28 -05:00
|
|
|
logger.info started_request_message(request)
|
2013-01-09 18:34:36 -05:00
|
|
|
resp = @app.call(env)
|
|
|
|
resp[2] = ::Rack::BodyProxy.new(resp[2]) { finish(request) }
|
|
|
|
resp
|
|
|
|
rescue
|
|
|
|
finish(request)
|
|
|
|
raise
|
2011-10-19 16:39:11 -04:00
|
|
|
ensure
|
|
|
|
ActiveSupport::LogSubscriber.flush_all!
|
2010-06-24 07:23:43 -04:00
|
|
|
end
|
2010-01-21 07:05:30 -05:00
|
|
|
|
2012-09-26 18:08:25 -04:00
|
|
|
# Started GET "/session/new" for 127.0.0.1 at 2012-09-26 14:51:42 -0700
|
|
|
|
def started_request_message(request)
|
|
|
|
'Started %s "%s" for %s at %s' % [
|
|
|
|
request.request_method,
|
|
|
|
request.filtered_path,
|
|
|
|
request.ip,
|
|
|
|
Time.now.to_default_s ]
|
|
|
|
end
|
2011-10-19 16:39:11 -04:00
|
|
|
|
2012-09-26 18:08:25 -04:00
|
|
|
def compute_tags(request)
|
|
|
|
@taggers.collect do |tag|
|
2011-10-19 16:39:11 -04:00
|
|
|
case tag
|
|
|
|
when Proc
|
|
|
|
tag.call(request)
|
|
|
|
when Symbol
|
|
|
|
request.send(tag)
|
|
|
|
else
|
|
|
|
tag
|
|
|
|
end
|
|
|
|
end
|
2010-06-24 07:23:43 -04:00
|
|
|
end
|
2013-01-08 13:50:28 -05:00
|
|
|
|
|
|
|
private
|
|
|
|
|
2013-01-09 18:34:36 -05:00
|
|
|
def finish(request)
|
2013-08-05 17:16:41 -04:00
|
|
|
@instrumenter.finish 'request.action_dispatch', request: request
|
2013-01-09 18:34:36 -05:00
|
|
|
end
|
|
|
|
|
2013-01-08 13:50:28 -05:00
|
|
|
def development?
|
|
|
|
Rails.env.development?
|
|
|
|
end
|
|
|
|
|
|
|
|
def logger
|
|
|
|
Rails.logger
|
|
|
|
end
|
2010-01-21 07:05:30 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
end
|