Structured Logging with Rails & ELK example files
# Copyright 2018 Marketplacer. MIT License. | |
require 'json' | |
require 'active_support/core_ext/class/attribute' | |
require 'active_support/log_subscriber' | |
module Elk | |
class RequestLogSubscriber < ActiveSupport::LogSubscriber | |
PAYLOAD_KEYS_TO_COPY = %i{ | |
controller | |
action | |
format | |
method | |
path | |
status | |
}.freeze | |
def logger | |
return @logger if @logger | |
@logger ||= ActiveSupport::Logger.new(Rails.root.join('log', 'elk.json.log')) | |
end | |
def process_action(event) | |
data = {} | |
if event.payload[:params] | |
# keep in mind config.filter_parameters will be removed before this | |
# point is reached: no need to check for them here. We also drop | |
# params we're logging elsewhere. | |
data["params"] = Flattener.flatten(event.payload[:params].except("controller", "action", "format")) | |
end | |
if event.payload[:exception] | |
data["exception.class"] = event.payload[:exception][0] | |
data["exception.message"] = event.payload[:exception][1] | |
end | |
PAYLOAD_KEYS_TO_COPY.each do |key| | |
data[key.to_s] = event.payload[key] | |
end | |
data.merge! location | |
data.merge! layout | |
headers = event.payload[:headers] || {} | |
data["http_host"] = headers["HTTP_HOST"] | |
data["remote_ip"] = headers["HTTP_X_REAL_IP"] | |
data["agent"] = headers["HTTP_USER_AGENT"] | |
data["original_path"] = headers["ORIGINAL_FULLPATH"] | |
session = headers["rack.session"] | |
if session | |
data["user.id"] = session["warden.user.user.key"] | |
data["admin.id"] = session["warden.user.admin.key"] | |
data["session_id"] = session.id | |
end | |
data["runtime"] = truncate_duration(event.duration) | |
data["db_runtime"] = truncate_duration(event.payload[:db_runtime]) | |
data["view_runtime"] = truncate_duration(event.payload[:view_runtime]) | |
data["route"] = event.payload[:controller] + "#" + event.payload[:action] | |
logger.send('debug', Oj.dump( | |
"rails" => data.compact, | |
"@timestamp" => Time.current.iso8601 | |
)) | |
end | |
def redirect_to(event) | |
Thread.current[:elk_location] = event.payload[:location] | |
end | |
def render_template event | |
Thread.current[:elk_layout] = event.payload[:layout] if event.payload[:layout] | |
end | |
def truncate_duration duration | |
if duration && duration > 0 | |
(format "%0.2f", duration).to_f | |
else | |
0.0 | |
end | |
end | |
class Flattener | |
LENGTH_LIMIT = 128 | |
attr_reader :result | |
# Takes a nested hash of hashes (or arrays) and flattens it into | |
# a single hash of strings, nulls or arrays only. Necessary as | |
# elasticsearch gets can't index both "{ list: 5 }" | |
# and "{ list: { subkey: 50 }", so we need to index them as | |
# "list: 5" and "list__subkey: 50" instead. | |
# This is embedded here as it's engineered directly against how | |
# we want to be sending params to elasticsearch - truncating | |
# long strings, making all numbers strings, etc. We need to | |
# ensure everything can be indexed as the "keyword" type or we | |
# risk dropping log entries on the floor due to incompatiable | |
# types (eg, by indexing something as an number and then trying | |
# to index that same key as a string later that day). | |
def self.flatten hash | |
return {} if hash.blank? | |
instance = new | |
hash.each_pair do |k, v| | |
instance.handle(k, v) | |
end | |
instance.result | |
end | |
def initialize | |
@result = {} | |
end | |
def handle key, val | |
case val | |
when Hash | |
val.each_pair do |h_key, h_val| | |
handle("#{key}__#{h_key}", h_val) | |
end | |
when Array | |
val.each do |v| | |
handle(key, v) | |
end | |
when String | |
add key, val | |
when Numeric | |
add key, val.to_s | |
when Rack::Test::UploadedFile, Rack::Multipart::UploadedFile | |
add key, "[FILE UPLOAD #{val.original_filename}]" | |
when nil | |
add key, nil | |
else | |
add key, val.inspect | |
end | |
end | |
def add key, val | |
if val.is_a?(String) && val.length > LENGTH_LIMIT | |
val = val.truncate(LENGTH_LIMIT, omission: "... [TRUNCATED #{val.length - LENGTH_LIMIT} CHARACTERS]") | |
end | |
key = key.to_s | |
if @result.key?(key) | |
if @result[key].is_a? Array | |
@result[key] += [val] | |
else | |
@result[key] = [@result[key], val] | |
end | |
else | |
@result[key] = val | |
end | |
end | |
end | |
private | |
def location | |
l = Thread.current[:elk_location] | |
if l | |
Thread.current[:elk_location] = nil | |
{ "redirect_to" => l } | |
else | |
{} | |
end | |
end | |
def layout | |
l = Thread.current[:elk_layout] | |
if l | |
Thread.current[:elk_layout] = nil | |
{ "layout": l } | |
else | |
{} | |
end | |
end | |
def debug event | |
# UNUSED - but kept here as there's no other way to work out what's | |
# going on in this event as you can't stick a binding.pry in here | |
# easily. | |
event.payload[:headers].each do |k, v| | |
if v.is_a? String | |
$stderr.puts "#{k}: #{v}" | |
else | |
$stderr.puts "#{k}: #{v.class}" | |
end | |
end | |
end | |
end | |
end | |
Elk::RequestLogSubscriber.attach_to :action_controller | |
Elk::RequestLogSubscriber.attach_to :action_view |
{ | |
"rails": { | |
"processors": [ | |
{ | |
"user_agent": { | |
"field": "rails.agent", | |
"target_field": "rails.user_agent" | |
} | |
}, | |
{ | |
"rename": { | |
"field": "rails.agent", | |
"target_field": "rails.user_agent.orig" | |
} | |
}, | |
{ | |
"geoip": { | |
"field": "rails.remote_ip", | |
"target_field": "rails.geoip" | |
} | |
} | |
], | |
"on_failure": [ | |
{ | |
"set": { | |
"field": "error", | |
"value": "{{ _ingest.on_failure_message }}" | |
} | |
} | |
] | |
} | |
} |
{ | |
"logs": { | |
"order": 0, | |
"index_patterns": [ | |
"logs-*" | |
], | |
"settings": { | |
"index": { | |
"mapping": { | |
"total_fields": { | |
"limit": "10000" | |
} | |
}, | |
"refresh_interval": "5s", | |
"number_of_shards": "1", | |
"number_of_replicas": "0" | |
} | |
}, | |
"mappings": { | |
"_default_": { | |
"_all": { | |
"norms": false | |
}, | |
"_size": { | |
"enabled": true | |
}, | |
"_meta": { | |
"version": "5.5.0" | |
}, | |
"date_detection": false, | |
"dynamic_templates": [ | |
{ | |
"strings_as_keyword": { | |
"mapping": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"match_mapping_type": "string" | |
} | |
}, | |
{ | |
"rails_params_as_keyword": { | |
"mapping": { | |
"ignore_above": 256, | |
"type": "keyword" | |
}, | |
"path_match": "rails.params.*", | |
"match_mapping_type": "string" | |
} | |
} | |
], | |
"properties": { | |
"@timestamp": { | |
"type": "date" | |
}, | |
"rails": { | |
"properties": { | |
"geoip": { | |
"properties": { | |
"continent_name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"country_iso_code": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"location": { | |
"type": "geo_point" | |
} | |
} | |
}, | |
"user_agent": { | |
"properties": { | |
"device": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"major": { | |
"type": "long" | |
}, | |
"minor": { | |
"type": "long" | |
}, | |
"name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"os": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"os_major": { | |
"type": "long" | |
}, | |
"os_minor": { | |
"type": "long" | |
}, | |
"os_name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"patch": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
} | |
} | |
}, | |
"beat": { | |
"properties": { | |
"hostname": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"version": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
}, | |
"error": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"fileset": { | |
"properties": { | |
"module": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
}, | |
"input_type": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"message": { | |
"norms": false, | |
"type": "text" | |
}, | |
"meta": { | |
"properties": { | |
"cloud": { | |
"properties": { | |
"availability_zone": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"instance_id": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"machine_type": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"project_id": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"provider": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"region": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
} | |
} | |
}, | |
"nginx": { | |
"properties": { | |
"access": { | |
"properties": { | |
"agent": { | |
"norms": false, | |
"type": "text" | |
}, | |
"body_sent": { | |
"properties": { | |
"bytes": { | |
"type": "long" | |
} | |
} | |
}, | |
"geoip": { | |
"properties": { | |
"continent_name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"country_iso_code": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"location": { | |
"type": "geo_point" | |
} | |
} | |
}, | |
"http_version": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"method": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"referrer": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"remote_ip": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"response_code": { | |
"type": "long" | |
}, | |
"url": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"user_agent": { | |
"properties": { | |
"device": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"major": { | |
"type": "long" | |
}, | |
"minor": { | |
"type": "long" | |
}, | |
"name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"os": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"os_major": { | |
"type": "long" | |
}, | |
"os_minor": { | |
"type": "long" | |
}, | |
"os_name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"patch": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
}, | |
"user_name": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
}, | |
"error": { | |
"properties": { | |
"connection_id": { | |
"type": "long" | |
}, | |
"level": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"message": { | |
"norms": false, | |
"type": "text" | |
}, | |
"pid": { | |
"type": "long" | |
}, | |
"tid": { | |
"type": "long" | |
} | |
} | |
} | |
} | |
}, | |
"offset": { | |
"type": "long" | |
}, | |
"read_timestamp": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"source": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"tags": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
}, | |
"type": { | |
"ignore_above": 1024, | |
"type": "keyword" | |
} | |
} | |
} | |
}, | |
"aliases": {} | |
} | |
} |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment