読者です 読者をやめる 読者になる 読者になる

DelayedJobのログの実行時間に関する項目

Rails

DelayedJobのログを見ると、以下のようになっています。

$ rake jobs:work
[Worker(host:tama.local pid:931)] Starting job worker
[Worker(host:tama.local pid:931)] Content#check_values! completed after 0.2932
[Worker(host:tama.local pid:931)] Content#calculate! completed after 0.0298
[Worker(host:tama.local pid:931)] Content#calculate! completed after 0.0138
[Worker(host:tama.local pid:931)] 3 jobs processed at 7.3507 j/s, 0 failed ...

"completed after 0.2932"が実行時間のようです。check_values!にsleep(10)を追加して実行した結果は以下のようになりました。

$ rake jobs:work
[Worker(host:tama.local pid:947)] Starting job worker
[Worker(host:tama.local pid:947)] Content#check_values! completed after 10.2938
[Worker(host:tama.local pid:947)] Content#calculate! completed after 0.0392
[Worker(host:tama.local pid:947)] Content#calculate! completed after 0.0134
[Worker(host:tama.local pid:947)] 3 jobs processed at 0.2893 j/s, 0 failed ...

実行時間が10秒ほど延長していることが確認されました。"completed after"に続く数字は実行時間ということのようです。