Class: Dinie::Internal::Middleware::Logging

Inherits:
Faraday::Middleware show all
Defined in:
lib/dinie/runtime/logger.rb,
sig/dinie/runtime/logger.rbs

Overview

Faraday response middleware — the logging hook point. Faraday::Middleware is untyped.

Constant Summary collapse

ORIGIN_LOG_ID_KEY =

Thread-local key holding the origin request's log id for the current logical request.

Returns:

  • (Symbol)
:__dinie_origin_request_log_id
RETRY_COUNT_HEADER =

Request header HttpClient sets on retried attempts ("1", "2", …); absent on the first.

Returns:

  • (String)
"x-dinie-retry-count"
REQUEST_ID_HEADER =

Response header carrying the server-side request id (architecture §7 — err.request_id).

Returns:

  • (String)
"x-request-id"

Instance Method Summary collapse

Constructor Details

#initialize(app, level: nil, logger: nil) ⇒ Logging

Returns a new instance of Logging.

Parameters:

  • app (#call) —

    the next middleware/adapter in the stack

  • level (Symbol, String, nil) (defaults to: nil) —

    log level (forwarded to RuntimeLogger)

  • logger (Object, nil) (defaults to: nil) —

    custom sink (forwarded to RuntimeLogger)

  • level: (Symbol, String, nil) (defaults to: nil)
  • logger: (Object) (defaults to: nil)


273
274
275
276
# File 'lib/dinie/runtime/logger.rb', line 273

def initialize(app, level: nil, logger: nil)
  super(app)
  @logger = RuntimeLogger.new(level: level, logger: logger)
end

Instance Method Details

#call(request_env) ⇒ Faraday::Response

Parameters:

  • request_env (Faraday::Env)

Returns:

  • (Faraday::Response)


280
281
282
283
284
285
286
287
# File 'lib/dinie/runtime/logger.rb', line 280

def call(request_env)
  correlation = correlate(request_env.request_headers)
  log_request(request_env, correlation)
  started = monotonic_now
  @app.call(request_env).on_complete do |response_env|
    log_response(response_env, correlation, started)
  end
end

#correlate(request_headers) ⇒ Hash[Symbol, untyped]

Build the request_log_id / retry_of / attempt triple (see the class doc for the thread-local rationale).

Parameters:

  • request_headers (Object)

Returns:

  • (Hash[Symbol, untyped])


305
306
307
308
309
310
311
312
313
314
# File 'lib/dinie/runtime/logger.rb', line 305

def correlate(request_headers)
  attempt = request_headers[RETRY_COUNT_HEADER].to_i
  request_log_id = "req_#{SecureRandom.hex(6)}"
  if attempt.zero?
    Thread.current[ORIGIN_LOG_ID_KEY] = request_log_id
    { request_log_id: request_log_id, retry_of: nil, attempt: attempt }
  else
    { request_log_id: request_log_id, retry_of: Thread.current[ORIGIN_LOG_ID_KEY], attempt: attempt }
  end
end

#elapsed_ms(started) ⇒ Numeric

Parameters:

  • started (Float)

Returns:

  • (Numeric)


320
321
322
# File 'lib/dinie/runtime/logger.rb', line 320

def elapsed_ms(started)
  ((monotonic_now - started) * 1000).round(1)
end

#log_request(env, correlation) ⇒ void

This method returns an undefined value.

Parameters:

  • env (Object)
  • correlation (Hash[Symbol, untyped])


291
292
293
294
# File 'lib/dinie/runtime/logger.rb', line 291

def log_request(env, correlation)
  @logger.log_request(method: env.method, url: env.url.to_s,
                      headers: env.request_headers, body: env.body, correlation: correlation)
end

#log_response(env, correlation, started) ⇒ void

This method returns an undefined value.

Parameters:

  • env (Object)
  • correlation (Hash[Symbol, untyped])
  • started (Float)


296
297
298
299
300
301
# File 'lib/dinie/runtime/logger.rb', line 296

def log_response(env, correlation, started)
  @logger.log_response(status: env.status, url: env.url.to_s,
                       headers: env.response_headers, body: env.body,
                       duration_ms: elapsed_ms(started), request_id: env.response_headers[REQUEST_ID_HEADER],
                       correlation: correlation)
end

#monotonic_now ⇒ Float

Returns:

  • (Float)


316
317
318
# File 'lib/dinie/runtime/logger.rb', line 316

def monotonic_now
  ::Process.clock_gettime(::Process::CLOCK_MONOTONIC)
end