mirror of
https://github.com/discourse/discourse.git
synced 2024-11-29 12:13:58 -06:00
8963f1af30
By default, this does nothing. Two environment variables are available: - `DISCOURSE_LOG_SIDEKIQ` Set to `"1"` to enable logging. This will log all completed jobs to `log/rails/sidekiq.log`, along with various db/redis/network statistics. This is useful to track down poorly performing jobs. - `DISCOURSE_LOG_SIDEKIQ_INTERVAL` (seconds) Check running jobs periodically, and log their current duration. They will appear in the logs with `status:pending`. This is useful to track down jobs which take a long time, then crash sidekiq before completing.
87 lines
2.4 KiB
Ruby
87 lines
2.4 KiB
Ruby
# see https://samsaffron.com/archive/2017/10/18/fastest-way-to-profile-a-method-in-ruby
|
|
class MethodProfiler
|
|
def self.patch(klass, methods, name, no_recurse: false)
|
|
patches = methods.map do |method_name|
|
|
|
|
recurse_protection = ""
|
|
if no_recurse
|
|
recurse_protection = <<~RUBY
|
|
return #{method_name}__mp_unpatched(*args, &blk) if @mp_recurse_protect_#{method_name}
|
|
@mp_recurse_protect_#{method_name} = true
|
|
RUBY
|
|
end
|
|
|
|
<<~RUBY
|
|
unless defined?(#{method_name}__mp_unpatched)
|
|
alias_method :#{method_name}__mp_unpatched, :#{method_name}
|
|
def #{method_name}(*args, &blk)
|
|
unless prof = Thread.current[:_method_profiler]
|
|
return #{method_name}__mp_unpatched(*args, &blk)
|
|
end
|
|
#{recurse_protection}
|
|
begin
|
|
start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
|
|
#{method_name}__mp_unpatched(*args, &blk)
|
|
ensure
|
|
data = (prof[:#{name}] ||= {duration: 0.0, calls: 0})
|
|
data[:duration] += Process.clock_gettime(Process::CLOCK_MONOTONIC) - start
|
|
data[:calls] += 1
|
|
#{"@mp_recurse_protect_#{method_name} = false" if no_recurse}
|
|
end
|
|
end
|
|
end
|
|
RUBY
|
|
end.join("\n")
|
|
|
|
klass.class_eval patches
|
|
end
|
|
|
|
def self.transfer
|
|
result = Thread.current[:_method_profiler]
|
|
Thread.current[:_method_profiler] = nil
|
|
result
|
|
end
|
|
|
|
def self.start(transfer = nil)
|
|
Thread.current[:_method_profiler] = transfer || {
|
|
__start: Process.clock_gettime(Process::CLOCK_MONOTONIC)
|
|
}
|
|
end
|
|
|
|
def self.clear
|
|
Thread.current[:_method_profiler] = nil
|
|
end
|
|
|
|
def self.stop
|
|
finish = Process.clock_gettime(Process::CLOCK_MONOTONIC)
|
|
if data = Thread.current[:_method_profiler]
|
|
Thread.current[:_method_profiler] = nil
|
|
start = data.delete(:__start)
|
|
data[:total_duration] = finish - start
|
|
end
|
|
data
|
|
end
|
|
|
|
def self.ensure_discourse_instrumentation!
|
|
@@instrumentation_setup ||= begin
|
|
MethodProfiler.patch(PG::Connection, [
|
|
:exec, :async_exec, :exec_prepared, :send_query_prepared, :query, :exec_params
|
|
], :sql)
|
|
|
|
MethodProfiler.patch(Redis::Client, [
|
|
:call, :call_pipeline
|
|
], :redis)
|
|
|
|
MethodProfiler.patch(Net::HTTP, [
|
|
:request
|
|
], :net, no_recurse: true)
|
|
|
|
MethodProfiler.patch(Excon::Connection, [
|
|
:request
|
|
], :net)
|
|
true
|
|
end
|
|
end
|
|
|
|
end
|