lib/rack/common_logger.rb

   1 # frozen_string_literal: true
   2
   3 require_relative 'constants'
   4 require_relative 'utils'
   5 require_relative 'body_proxy'
   6 require_relative 'request'
   7
   8 module Rack
   9   # Rack::CommonLogger forwards every request to the given +app+, and
  10   # logs a line in the
  11   # {Apache common log format}[http://httpd.apache.org/docs/1.3/logs.html#common]
  12   # to the configured logger.
  13   class CommonLogger
  14     # Common Log Format: http://httpd.apache.org/docs/1.3/logs.html#common
  15     #
  16     #   lilith.local - - [07/Aug/2006 23:58:02 -0400] "GET / HTTP/1.1" 500 -
  17     #
  18     #   %{%s - %s [%s] "%s %s%s %s" %d %s\n} %
  19     #
  20     # The actual format is slightly different than the above due to the
  21     # separation of SCRIPT_NAME and PATH_INFO, and because the elapsed
  22     # time in seconds is included at the end.
  23     FORMAT = %{%s - %s [%s] "%s %s%s%s %s" %d %s %0.4f\n}
  24
  25     # +logger+ can be any object that supports the +write+ or +<<+ methods,
  26     # which includes the standard library Logger.  These methods are called
  27     # with a single string argument, the log message.
  28     # If +logger+ is nil, CommonLogger will fall back <tt>env['rack.errors']</tt>.
  29     def initialize(app, logger = nil)
  30       @app = app
  31       @logger = logger
  32     end
  33
  34     # Log all requests in common_log format after a response has been
  35     # returned.  Note that if the app raises an exception, the request
  36     # will not be logged, so if exception handling middleware are used,
  37     # they should be loaded after this middleware.  Additionally, because
  38     # the logging happens after the request body has been fully sent, any
  39     # exceptions raised during the sending of the response body will
  40     # cause the request not to be logged.
  41     def call(env)
  42       began_at = Utils.clock_time
  43       status, headers, body = response = @app.call(env)
  44
  45       response[2] = BodyProxy.new(body) { log(env, status, headers, began_at) }
  46       response
  47     end
  48
  49     private
  50
  51     # Log the request to the configured logger.
  52     def log(env, status, response_headers, began_at)
  53       request = Rack::Request.new(env)
  54       length = extract_content_length(response_headers)
  55
  56       msg = sprintf(FORMAT,
  57         request.ip || "-",
  58         request.get_header("REMOTE_USER") || "-",
  59         Time.now.strftime("%d/%b/%Y:%H:%M:%S %z"),
  60         request.request_method,
  61         request.script_name,
  62         request.path_info,
  63         request.query_string.empty? ? "" : "?#{request.query_string}",
  64         request.get_header(SERVER_PROTOCOL),
  65         status.to_s[0..3],
  66         length,
  67         Utils.clock_time - began_at)
  68
  69       msg.gsub!(/[^[:print:]\n]/) { |c| sprintf("\\x%x", c.ord) }
  70
  71       logger = @logger || request.get_header(RACK_ERRORS)
  72       # Standard library logger doesn't support write but it supports << which actually
  73       # calls to write on the log device without formatting
  74       if logger.respond_to?(:write)
  75         logger.write(msg)
  76       else
  77         logger << msg
  78       end
  79     end
  80
  81     # Attempt to determine the content length for the response to
  82     # include it in the logged data.
  83     def extract_content_length(headers)
  84       value = headers[CONTENT_LENGTH]
  85       !value || value.to_s == '0' ? '-' : value
  86     end
  87   end
  88 end