gke_json_structured_logs.rb

require "time"
require "json"

# stackdriver loggingで構造化されたログにするためアクセスログをその構造に沿った形にする
# References
# https://medium.com/google-cloud-jp/gae-%E3%81%AE%E3%83%AD%E3%82%B0%E3%81%AB%E6%86%A7%E3%82%8C%E3%81%A6-895ebe927c4
# https://cloud.google.com/logging/docs/agent/configuration?hl=ja#special_fields_in_structured_payloads
# https://github.com/yfuruyama/stackdriver-request-context-log/blob/master/middleware.go
# https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/lib/fluent/plugin/out_google_cloud.rb
module Rack
  class GkeJsonStructuredLogs
    DEFAULT_PARAMS_PROC = proc do |env, status, headers, _body, began_at|
      now = Time.now # rubocop:disable Rails/TimeZone
      reqtime = now.instance_eval { to_i + (usec / 1_000_000.0) } - began_at
      status_int = status ? status.to_s[0..2].to_i : 500
      severity = if status_int < 400
                   "INFO"
                 elsif status_int < 500
                   "WARNING"
                 else
                   "ERROR"
                 end
      {
        severity: severity,
        time: now.iso8601,
        "logging.googleapis.com/trace": env["action_dispatch.request_id"] || "",
        # https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#HttpRequest
        httpRequest: {
          requestMethod: env["REQUEST_METHOD"],
          requestUrl: env["REQUEST_URI"],
          requestSize: env["CONTENT_LENGTH"].to_s || "0",
          status: status_int,
          responseSize: (headers && headers["Content-Length"]) ? headers["Content-Length"].to_s : "0",
          userAgent: env["HTTP_USER_AGENT"] || "",
          remoteIp: Rrp::ForwardedIp.forwarded_ip(env["HTTP_X_FORWARDED_FOR"]) || "",
          serverIp: env["REMOTE_ADDR"] || "",
          referer: env["HTTP_REFERER"] || "",
          latency: "%0.6fs" % reqtime,
          cacheLookup: false,
          cacheHit: false,
          cacheValidatedWithOriginServer: false,
          protocol: env["HTTP_VERSION"],
        },
        request_id: env["action_dispatch.request_id"] || "",
        session_id: env["session_id"] || env["HTTP_AUTHORIZATION"]&.split(" ")&.last || "",
        user_id: env["user_id"] || "",
        app_version: env["app_version"] || "",
        controller_and_action: env["controller_and_action"] || "",
        latency_ms: (reqtime * 1000).to_i,
        error_class: env["error_class"] || "",
      }
    end

    def initialize(app, io = nil, **kwargs)
      @app = app
      @io = io || $stdout
      @params_proc = kwargs[:params_proc] || DEFAULT_PARAMS_PROC
    end

    def call(env)
      began_at = Time.now.instance_eval { to_i + (usec / 1_000_000.0) }
      status, headers, body = @app.call(env)
    ensure
      params = @params_proc.call(env, status, headers, body, began_at)
      @io.write(params.to_json + "\n")
    end
  end
end