class ApiHammer::Faraday::RequestLogger

Faraday middleware for logging.

logs two lines:

options:

Public Class Methods

new(app, logger, options={}) click to toggle source
# File lib/api_hammer/faraday/request_logger.rb, line 24
def initialize(app, logger, options={})
  @app = app
  @logger = logger
  @options = options
end

Public Instance Methods

call(request_env) click to toggle source
# File lib/api_hammer/faraday/request_logger.rb, line 30
def call(request_env)
  began_at = Time.now
  began_ns = Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond)

  log_tags = Thread.current[:activesupport_tagged_logging_tags]
  saved_log_tags = log_tags.dup if log_tags && log_tags.any?

  request_body = request_env[:body].dup if request_env[:body]

  @app.call(request_env).on_complete do |response_env|
    now_ns = Process.clock_gettime(Process::CLOCK_MONOTONIC, :nanosecond)
    status = response_env[:status]

    if log_bodies(status)
      bodies = [
        ['request', request_body, request_env[:request_headers]],
        ['response', response_env[:body], response_env[:response_headers]]
      ].map do |(role, body_s, headers)|
        body = Body.new(body_s, headers['Content-Type'])
        if body.content_type_attrs.text?
          if @options[:filter_keys]
            body = body.filtered(:filter_keys => @options[:filter_keys])
          end
          log_body = body.jsonifiable.body
        end
        {role => log_body}
      end.inject({}, &:update)
    else
      bodies = {}
    end

    data = {
      'request_role' => 'client',
      'bound' => 'outbound',
      'request' => {
        'method' => request_env[:method],
        'uri' => request_env[:url].normalize.to_s,
        'headers' => request_env[:request_headers],
        'body' => bodies['request'],
      }.reject{|k,v| v.nil? },
      'response' => {
        'status' => status.to_s,
        'headers' => response_env[:response_headers],
        'body' => bodies['response'],
      }.reject{|k,v| v.nil? },
      'processing' => {
        'began_at' => began_at.utc.to_f,
        'duration' => (now_ns - began_ns) * 1e-9,
        'activesupport_tagged_logging_tags' => log_tags,
      }.reject{|k,v| v.nil? },
    }

    json_data = JSON.generate(data)
    dolog = proc do
      began_s = began_at.strftime('%Y-%m-%d %H:%M:%S %Z')
      @logger.info "#{bold(intense_magenta('>'))} #{status_s(status)} : #{bold(intense_magenta(request_env[:method].to_s.upcase))} #{intense_magenta(request_env[:url].normalize.to_s)} @ #{intense_magenta(began_s)}"
      @logger.info json_data
    end

    # reapply log tags from the request if they are not applied
    if @logger.respond_to?(:tagged) && saved_log_tags && Thread.current[:activesupport_tagged_logging_tags] != saved_log_tags
      @logger.tagged(saved_log_tags, &dolog)
    else
      dolog.call
    end
  end
end