1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
|
class ActionView::LogSubscriber
# In order to be more friendly to Splunk, which we use for log analysis,
# we override a few logging methods. There are not overriden if enable_splunk_logging is set to false in config/application.yml
def render_template(event)
count = event.payload[:count] || 1
hash = {:event => :render,
:template => from_rails_root(event.payload[:identifier]),
:total_ms => event.duration,
:count => count,
:ms => event.duration / count}
hash.merge(:layout => event.payload[:layout]) if event.payload[:layout]
Rails.logger.info(hash)
end
alias :render_partial :render_template
alias :render_collection :render_template
end
module ActionDispatch
class ShowExceptions
private
# This override logs in a format Splunk can more easily understand.
# @see ActionView::LogSubscriber#render_template
def log_error(exception)
return unless logger
ActiveSupport::Deprecation.silence do
message = "event=error error_class=#{exception.class} error_message='#{exception.message}' "
message << "gc_ms=#{GC.time/1000} gc_collections=#{GC.collections} gc_bytes=#{GC.growth} " if GC.respond_to?(:enable_stats)
message << "orig_error_message='#{exception.original_exception.message}'" if exception.respond_to?(:original_exception)
message << "annotated_source='#{exception.annoted_source_code.to_s}' " if exception.respond_to?(:annoted_source_code)
message << "app_backtrace='#{application_trace(exception).join(";")}'"
logger.fatal("\n\n#{message}\n\n")
end
end
end
end
class ActionController::LogSubscriber
require "#{File.dirname(__FILE__)}/active_record_instantiation_logs.rb"
include Oink::InstanceTypeCounter
def start_processing(event)
#noop
end
# This override logs in a format Splunk can more easily understand.
# @see ActionView::LogSubscriber#render_template
def process_action(event)
payload = event.payload
additions = ActionController::Base.log_process_action(payload)
params = payload[:params].except(*INTERNAL_PARAMS)
log_hash = {:event => :request_completed,
:status => payload[:status],
:controller => payload[:controller],
:action => payload[:action],
:format => payload[:formats].first.to_s.upcase,
:ms => ("%.0f" % event.duration).to_i,
:params => params.inspect}
log_hash.merge!({
:gc_ms => GC.time/1000,
:gc_collections => GC.collections,
:gc_bytes=> GC.growth}) if GC.respond_to?(:enable_stats)
log_hash.merge!({:view_ms => payload[:view_runtime],
:db_ms => payload[:db_runtime]}) unless additions.blank?
log_hash.merge!(report_hash!)
Rails.logger.info(log_hash)
end
end
module Rails
module Rack
class Logger
# This override logs in a format Splunk can more easily understand.
# @see ActionView::LogSubscriber#render_template
def before_dispatch(env)
request = ActionDispatch::Request.new(env)
path = request.fullpath
Rails.logger.info("event=request_started verb=#{env["REQUEST_METHOD"]} path=#{path} ip=#{request.ip} ")
end
end
end
end
module ActiveRecord
class LogSubscriber
# This override logs in a format Splunk can more easily understand.
# @see ActionView::LogSubscriber#render_template
def sql(event)
self.class.runtime += event.duration
return unless logger.info?
payload = event.payload
sql = payload[:sql].squeeze(' ')
binds = nil
unless (payload[:binds] || []).empty?
binds = " " + payload[:binds].map { |col,v|
[col.name, v]
}.inspect
end
log_string = "event=sql name='#{payload[:name]}' ms=#{event.duration} query='#{sql}'"
cleaned_trace = Rails.backtrace_cleaner.clean(caller)
log_string << "backtrace_hash=#{cleaned_trace.hash} binds='#{binds}' application_backtrace='#{cleaned_trace[0..2].inspect}'"
info log_string
end
end
end
|