Class: RackLogger

Inherits:
Object
  • Object
show all
Defined in:
lib/rack_logger.rb,
lib/rack_logger/version.rb

Overview

Completed 404 Not Found in 105ms (Views: 4.6ms | ActiveRecord: 2.3ms | Sphinx: 0.0ms | Gateway: 86.3ms)

Constant Summary collapse

VERSION = 
"0.1.0"

Instance Attribute Summary collapse

Instance Method Summary collapse

Constructor Details

#initialize(app, logger, *log_subscribers) ⇒ RackLogger

log_subscribers:

[
  {
  :label => "label",
  :class => ActiveRecord::LogSubscriber
  }
]



14
15
16
17
18
 
# File 'lib/rack_logger.rb', line 14

def initialize(app, logger, *log_subscribers)
  @app = app
  @logger = logger
  @log_subscribers = log_subscribers
end

Instance Attribute Details

#log_subscribers ⇒ Object (readonly)

Returns the value of attribute log_subscribers.



6
7
8
 
# File 'lib/rack_logger.rb', line 6

def log_subscribers
  @log_subscribers
end

#logger ⇒ Object (readonly)

Returns the value of attribute logger.



6
7
8
 
# File 'lib/rack_logger.rb', line 6

def logger
  @logger
end

Instance Method Details

#_call(env) ⇒ Object 



24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
 
# File 'lib/rack_logger.rb', line 24

def _call(env)
  begin
    request = Rack::Request.new(env)
    time_start = Time.now
    logger.info "Started #{request.request_method} \"#{request.url}\" for #{request.ip} at #{Time.now} #{request.user_agent}"
    Thread.current[:request_id] ||= UUIDTools::UUID.random_create.to_s
    status, header, body = @app.call(env)
    # million seconds
    time_cost = (Time.now - time_start) * 1000
    header["x-runtime"] = "%.2fms" % time_cost
    header["x-request-id"] = Thread.current[:request_id]

    [status, header, body]
  ensure
    benchmarks = []
    payload = {}

    time_cost ||= (Time.now - time_start) * 1000

    log_subscribers.each do |subscriber|
      label = subscriber[:label]
      subscriber_class = subscriber[:class]

      if t = subscriber_class.send(:runtime)
        benchmarks << "#{label}: %.2fms" % t
        payload["#{label.downcase}_runtime"] = t
        subscriber_class.send(:reset_runtime)
      end
    end

    msg = "Completed #{request.request_method} #{ CGI.unescape(request.url)} #{status}"
    msg << " in %.2fms" % time_cost
    msg << " ("
    msg << benchmarks.join(' | ')
    msg << ") "

    payload[:method] = request.request_method
    payload[:url] = CGI.unescape(request.url)
    uri = URI(request.url)
    payload[:host] = uri.host
    payload[:path] = uri.path
    payload[:query] = uri.query

    payload[:status_code] = status
    payload[:duration] = time_cost
    payload[:header] = header
    payload[:request_id] = Thread.current[:request_id]
    if status >= 400
      payload[:body] = body
      body_str = ""
      if body.respond_to? :each
        body.each do |b|
          body_str << b.to_s
        end
      else
        body_str = body.inspect
      end
      msg << "body: #{body_str}"
      msg << "\n\n"
      logger.error msg
    else
      msg << "\n\n"
      logger.info msg
    end
    if defined? ActiveSupport
      ActiveSupport::Notifications.instrument "process.rack_logger", payload
    end
  end
end

#call(env) ⇒ Object 



20
21
22
 
# File 'lib/rack_logger.rb', line 20

def call(env)
  dup._call(env)
end