diff --git a/config/initializers/100-lograge.rb b/config/initializers/100-lograge.rb index a1089a7b273..6ab44c6abe8 100644 --- a/config/initializers/100-lograge.rb +++ b/config/initializers/100-lograge.rb @@ -8,6 +8,13 @@ if (Rails.env.production? && SiteSetting.logging_provider == 'lograge') || ENV[" Rails.application.configure do 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| begin username = @@ -46,7 +53,7 @@ if (Rails.env.production? && SiteSetting.logging_provider == 'lograge') || ENV[" database: RailsMultisite::ConnectionManagement.current_db, } - if data = Thread.current[:_method_profiler] + if data = (Thread.current[:_method_profiler] || event.payload[:timings]) sql = data[:sql] if sql @@ -60,6 +67,13 @@ if (Rails.env.production? && SiteSetting.logging_provider == 'lograge') || ENV[" output[:redis] = redis[:duration] * 1000 output[:redis_calls] = redis[:calls] end + + net = data[:net] + + if net + output[:net] = net[:duration] * 1000 + output[:net_calls] = net[:calls] + end end output diff --git a/lib/hijack.rb b/lib/hijack.rb index 9814ea4bef1..4fc49c2720e 100644 --- a/lib/hijack.rb +++ b/lib/hijack.rb @@ -51,12 +51,14 @@ module Hijack instance.response.headers[k] = v end + view_start = Process.clock_gettime(Process::CLOCK_MONOTONIC) begin instance.instance_eval(&blk) rescue => e # TODO we need to reuse our exception handling in ApplicationController Discourse.warn_exception(e, message: "Failed to process hijacked response correctly", env: env) end + view_runtime = Process.clock_gettime(Process::CLOCK_MONOTONIC) - view_start unless instance.response_body || response.committed? instance.status = 500 @@ -94,6 +96,34 @@ module Hijack # happens if client terminated before we responded, ignore io = nil 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 Thread.current[Logster::Logger::LOGSTER_ENV] = nil diff --git a/lib/middleware/request_tracker.rb b/lib/middleware/request_tracker.rb index f0ce009a6cf..d53b029ee82 100644 --- a/lib/middleware/request_tracker.rb +++ b/lib/middleware/request_tracker.rb @@ -24,6 +24,14 @@ class Middleware::RequestTracker MethodProfiler.patch(Redis::Client, [ :call, :call_pipeline ], :redis) + + MethodProfiler.patch(Net::HTTP, [ + :request + ], :net) + + MethodProfiler.patch(Excon::Connection, [ + :request + ], :net) @patched_instrumentation = true end