I'd like to know execution time every time I run my jobs. Seems like there is a gem sidekiq-statistic that does what I want and even has GUI, but unfortunately it doesn't work with sidekiq 5. Can I get such info from inside perform method somehow? I'd prefer to avoid writing benchmarking code manually, wrapping up my method into Benchmark block
5 Answers
I had the problem to find out which task takes the longest time, so I wrote a small task for analyzing the log Good news: I found it, so I am sharing my code :-)
Hope it does not contain any bugs
desc "sidekiq run statistics"
task sidekiq_run_statistics: :environment do
# 2021-02-19T06:04:23.088Z 20240 TID-ov75i75aw Importer::PriceJob JID-95245ccf3933fe1f5897d52b INFO: done: 193.952 sec
file = File.open( Rails.root.join("log","sidekiq.log"))
job_stats = {}
file.each_line do |line|
job_stat = line.split(" ")
if job_stat[8] == "sec"
time = job_stat[7].to_f
job_stats[ job_stat[3] ] ||= {longest_run_time: 0, total_run_time:0, total_runs: 0 }
job_stats[ job_stat[3] ][:longest_run_time] = time if job_stats[ job_stat[3] ][:longest_run_time] < time
job_stats[ job_stat[3] ][:total_run_time]+=time
job_stats[ job_stat[3] ][:total_runs]+=1
end
end
file.close
puts %w(total_runs total_run_time longest_run_time job ).collect{|i| i.rjust(16) }.join(" ")
puts "="*80
job_stats.keys.each do |key|
puts( [job_stats[key][:total_runs],job_stats[key][:total_run_time].round(3), job_stats[key][:longest_run_time].round(3), key ].collect{|i| i.to_s.rjust(16) }.join(" "))
end
end
sample output
total_runs total_run_time longest_run_time job
==================================================================
56 68.909 7.641 Job1
56 98.9 11.599 Job2
47 193.909 13.795 Job3
234 1806.76 20.644 Job4
As Mike says it's already in the logs.
To quickly see what the average completion time was yesterday for a worker:
rg MyWorker sidekiq.log.1 |rg done| awk '{ total += $8; count++ } END { print total/count }'
Related