Class: RightSupport::Rack::RequestLogger

Inherits:
Object
  • Object
show all
Defined in:
lib/right_support/rack/request_logger.rb

Overview

A Rack middleware that logs information about every HTTP request received and every exception raised while processing a request.

The middleware can be configured to use its own logger, but defaults to using env for logging if it is present. If ‘rack.logger’ is not set, this middleware will set it before calling the next middleware. Therefore, RequestLogger can be used standalone to fulfill all logging needs, or combined with Rack::Logger or another middleware that provides logging services.

Constant Summary collapse

BACKTRACE_LIMIT =

default backtrace limit that can be overridden by configuring the middleware with a specific :backtrace_limit value.

10
DEBUG_MODE_ENV_KEY =

for debug-mode only logging. debug-mode can also be enabled by the “X-Debug=<anything>” header.

'rack.debug-mode'.freeze
DEBUG_MODE = 
::ENV['DEBUG_MODE'] == 'true'
DEBUG_MODE_HTTP_HEADER = 
'HTTP_X_DEBUG'
RACK_LOGGER =

defaults to STDERR by Rack but usually overridden to use syslog, etc.

'rack.logger'.freeze
RACK_LOGGING_ENABLED =

indicates whether current request is enabled for logging by filter, etc.

'rack.logging.enabled'.freeze
NORMALIZE_40X =

list of status codes that are ‘normalized’ when :normalize_40x=true normalization means stripping any developer-provided details to avoid leaking information about the service. overridden by DEBUG_MODE=true but specifically not affected by the ‘X-Debug’ header.

[401, 403, 404]

Class Method Summary collapse

Instance Method Summary collapse

Constructor Details

#initialize(app, options = {}) ⇒ RequestLogger

Initialize an instance of the middleware, optionally providing a whitelist

(:only) or a blacklist (:except) of path regexps to which request logging
will apply.

Parameters:

  • app (Object) —

    inner application or middleware layer; must respond to #call.

  • options (Hash) (defaults to: {})

Options Hash (options):

  • :only (Array) —

    log for these path Regexps unless in debug mode.

  • :except (Array) —

    log except for these path Regexps unless in debug mode; this option is ignored if :only is provided.

  • :include_query_string (Array) —

    log the contents of the query string.

  • :logger (Logger) —

    to override any previously set logger or nil. Rack sets a STDERR logger by default or it may be set by other framework middleware so this is only for when those are not used.

  • :normalize_40x (TrueClass|FalseClass) —

    to remove detail from some 40x responses for security reasons. default=false.

  • :normalize_40x_set_cookie (TrueClass|FalseClass) —

    to override the usual global session behavior of always responding with a ‘Set-Cookie’ header regardless of status code. defaults to having the same value as the :normalize_40x option.

  • :backtrace_limit (Integer) —

    maximum number of stack frames to display on error or negative for all (default = 10)



84
85
86
87
88
89
90
91
92
93
94
95
96
 
# File 'lib/right_support/rack/request_logger.rb', line 84

def initialize(app, options = {})
  @app = app
  @only = options[:only] || []
  @except = options[:except] || []
  # by default we don't log the query string contents because it may have sensitive data.
  @include_query_string = options[:include_query_string] || false
  @logger = options[:logger]
  @normalize_40x = !!options[:normalize_40x]
  @normalize_40x_set_cookie = options[:normalize_40x_set_cookie]
  @normalize_40x_set_cookie = @normalize_40x if @normalize_40x_set_cookie.nil?
  @backtrace_decoder = ::RightSupport::Notifier::Utility::BacktraceDecoder.new(
    backtrace_limit: Integer(options[:backtrace_limit] || BACKTRACE_LIMIT))
end

Class Method Details

.canonicalize_header_key(key) ⇒ Object

Deprecated.

in favor of RightSupport::Data::HashTools.canonicalize_header_key



189
190
191
192
193
 
# File 'lib/right_support/rack/request_logger.rb', line 189

def self.canonicalize_header_key(key)
  # the legacy implementation is train-case but HashTools uses the more
  # commonly accepted Canonical-Key style (preferred by golang, etc).
  key.downcase.gsub('_', '-')
end

.format_exception_message(e, backtrace_decoder = nil) ⇒ String

Formats a concise error message with limited backtrace, etc.

Parameters:

  • e (Exception) —

    to format

  • e (Exception) —

    to format

Returns:

  • (String) —

    formatted error



211
212
213
214
215
216
217
218
219
220
 
# File 'lib/right_support/rack/request_logger.rb', line 211

def self.format_exception_message(e, backtrace_decoder = nil)
  backtrace_decoder ||= ::RightSupport::Notifier::Utility::BacktraceDecoder.new
  trace = ::RightSupport::Notifier::Utility::BacktraceDecoder.format_frames(
    backtrace_decoder.decode(e.backtrace))
  kind = e.class.name
  if (msg = e.message) && !msg.empty? && msg != kind
    kind = "#{kind}: #{msg}"
  end
  [kind, trace].join("\n")
end

.header_value_get(headers, key) ⇒ Object

Deprecated.

in favor of RightSupport::Data::HashTools.header_value_get



196
197
198
 
# File 'lib/right_support/rack/request_logger.rb', line 196

def self.header_value_get(headers, key)
  return ::RightSupport::Data::HashTools.header_value_get(headers, key)
end

.header_value_set(headers, key, value) ⇒ Object

Deprecated.

in favor of RightSupport::Data::HashTools.header_value_set



201
202
203
 
# File 'lib/right_support/rack/request_logger.rb', line 201

def self.header_value_set(headers, key, value)
  return ::RightSupport::Data::HashTools.header_value_set(headers, key, value)
end

.request_uuid_from_env(env) ⇒ String

Returns accepted/generated request UUID or else ‘missing’ to indicate that the RequestTracker middleware is missing.

Returns:

  • (String) —

    accepted/generated request UUID or else ‘missing’ to indicate that the RequestTracker middleware is missing.



224
225
226
 
# File 'lib/right_support/rack/request_logger.rb', line 224

def self.request_uuid_from_env(env)
  env[RequestTracker::REQUEST_UUID_ENV_NAME] || 'missing'
end

Instance Method Details

#call(env) ⇒ Object

Add a logger to the Rack environment and call the next middleware.

Parameters:

  • env (Hash) —

    Rack environment

Options Hash (env):

  • 'rack.logging.enabled' (TrueClass|FalseClass) —

    in Rack environment to indicate whether logging is enabled for this request for use by other middleware in the call chain.

  • 'sinatra.error' (TrueClass|FalseClass) —

    is set by Sinatra to pass error info (exception object) to handlers.

  • 'sinatra.error.handled' (TrueClass|FalseClass) —

    is true to prevent any additional error handlers in the call chain from processing an error that has already handled been handled (i.e. log and response) (default = false).

Returns:

  • (Object) —

    always returns whatever value is returned by the next layer of middleware



113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
 
# File 'lib/right_support/rack/request_logger.rb', line 113

def call(env)
  # forward-declare in case of exception.
  enabled = true

  # override logger, if necessary.
  if @logger
    logger = env[RACK_LOGGER] = @logger
  else
    logger = env[RACK_LOGGER]
  end

  # determine if debug-mode is enabled.
  env[DEBUG_MODE_ENV_KEY] = debug_enabled?(env)

  # log request only when enabled.
  env[RACK_LOGGING_ENABLED] = enabled = logging_enabled?(logger, env)
  began_at = Time.now
  log_request_begin(logger, env) if enabled

  # next
  status, headers, body = @app.call(env)

  # log exception, if necessary.
  if env['sinatra.error'] && !env['sinatra.error.handled']
    if !enabled
      # after the fact but better than logging exception without its request.
      log_request_begin(logger, env)
      enabled = true
    end
    log_exception(logger, env['sinatra.error'])
  elsif !enabled && env[RACK_LOGGING_ENABLED]
    # controller can conditionally enable logging for the current request
    # even though by default such requests are not logged. an example is a
    # periodic request for a listing (scheduled tasks, etc.) that is only
    # logged when not empty.
    log_request_begin(logger, env)
    enabled = true
  end

  # respond identically to some 40Xs; do not reveal any internals by
  # varying the response headers or body (as developers tend to do for
  # debugging reasons). public APIs will receive such requests frequently
  # but this is generally not needed for internal APIs.
  #
  # note that it is important to *not* accept the "X-Debug" header override
  # and show more information in response ;)
  if @normalize_40x && !DEBUG_MODE && NORMALIZE_40X.include?(status)
    # note that ::Rack::CONTENT_LENGTH was not defined before rack v1.6+ :@
    headers = { 'Content-Length' => '0' }
    body = []
    env[DEBUG_MODE_ENV_KEY] = false  # disable any verbose debugging
  end

  # defeat global session renew, update and set-cookie for normalized 40x.
  # has no effect if the app is not using global session middleware.
  if @normalize_40x_set_cookie && NORMALIZE_40X.include?(status)
    env['global_session.req.renew'] = false
    env['global_session.req.update'] = false
  end

  # log response only when enabled.
  if enabled
    log_request_end(logger, env, status, headers, body, began_at)
  end

  return [status, headers, body]
rescue Exception => e
  if !enabled
    # after the fact but better than logging exception without its request.
    log_request_begin(logger, env)
  end
  log_exception(logger, e)
  raise
end