Skip to content

Instantly share code, notes, and snippets.

@mipearson
Created July 5, 2018 06:07
Show Gist options
  • Save mipearson/e363504be7792c8971b851954cceb61d to your computer and use it in GitHub Desktop.
Save mipearson/e363504be7792c8971b851954cceb61d to your computer and use it in GitHub Desktop.
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