FEATURE: add instrumentation for all external net calls

This commit is contained in:
Sam 2018-02-21 15:19:59 +11:00
parent 5c40ae9e63
commit ca1a3f37e3
3 changed files with 53 additions and 1 deletions

View File

@ -8,6 +8,13 @@ if (Rails.env.production? && SiteSetting.logging_provider == 'lograge') || ENV["
Rails.application.configure do Rails.application.configure do
config.lograge.enabled = true config.lograge.enabled = true
Lograge.ignore(lambda do |event|
# this is our hijack magic status,
# no point logging this cause we log again
# direct from hijack
event.payload[:status] == 418
end)
config.lograge.custom_payload do |controller| config.lograge.custom_payload do |controller|
begin begin
username = username =
@ -46,7 +53,7 @@ if (Rails.env.production? && SiteSetting.logging_provider == 'lograge') || ENV["
database: RailsMultisite::ConnectionManagement.current_db, database: RailsMultisite::ConnectionManagement.current_db,
} }
if data = Thread.current[:_method_profiler] if data = (Thread.current[:_method_profiler] || event.payload[:timings])
sql = data[:sql] sql = data[:sql]
if sql if sql
@ -60,6 +67,13 @@ if (Rails.env.production? && SiteSetting.logging_provider == 'lograge') || ENV["
output[:redis] = redis[:duration] * 1000 output[:redis] = redis[:duration] * 1000
output[:redis_calls] = redis[:calls] output[:redis_calls] = redis[:calls]
end end
net = data[:net]
if net
output[:net] = net[:duration] * 1000
output[:net_calls] = net[:calls]
end
end end
output output

View File

@ -51,12 +51,14 @@ module Hijack
instance.response.headers[k] = v instance.response.headers[k] = v
end end
view_start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
begin begin
instance.instance_eval(&blk) instance.instance_eval(&blk)
rescue => e rescue => e
# TODO we need to reuse our exception handling in ApplicationController # TODO we need to reuse our exception handling in ApplicationController
Discourse.warn_exception(e, message: "Failed to process hijacked response correctly", env: env) Discourse.warn_exception(e, message: "Failed to process hijacked response correctly", env: env)
end end
view_runtime = Process.clock_gettime(Process::CLOCK_MONOTONIC) - view_start
unless instance.response_body || response.committed? unless instance.response_body || response.committed?
instance.status = 500 instance.status = 500
@ -94,6 +96,34 @@ module Hijack
# happens if client terminated before we responded, ignore # happens if client terminated before we responded, ignore
io = nil io = nil
ensure ensure
if Rails.configuration.lograge.enabled
if timings
db_runtime = 0
if timings[:sql]
db_runtime = timings[:sql][:duration]
end
subscriber = Lograge::RequestLogSubscriber.new
payload = ActiveSupport::HashWithIndifferentAccess.new(
controller: self.class.name,
action: action_name,
params: request.filtered_parameters,
headers: request.headers,
format: request.format.ref,
method: request.request_method,
path: request.fullpath,
view_runtime: view_runtime * 1000.0,
db_runtime: db_runtime * 1000.0,
timings: timings,
status: response.status
)
event = ActiveSupport::Notifications::Event.new("hijack", Time.now, Time.now + timings[:total_duration], "", payload)
subscriber.process_action(event)
end
end
MethodProfiler.clear MethodProfiler.clear
Thread.current[Logster::Logger::LOGSTER_ENV] = nil Thread.current[Logster::Logger::LOGSTER_ENV] = nil

View File

@ -24,6 +24,14 @@ class Middleware::RequestTracker
MethodProfiler.patch(Redis::Client, [ MethodProfiler.patch(Redis::Client, [
:call, :call_pipeline :call, :call_pipeline
], :redis) ], :redis)
MethodProfiler.patch(Net::HTTP, [
:request
], :net)
MethodProfiler.patch(Excon::Connection, [
:request
], :net)
@patched_instrumentation = true @patched_instrumentation = true
end end