Open promzeus opened 1 year ago
I think the separate line executing and finished
is a garbage message.
Instead of a separate start line, I added logFields["started_at"] = start.Format(time.RFC3339)
to the finish line
that is, we received the executed command in one json line, where we got the start time, finish time and how long the task took to complete.
The output of many commands looks like this:
{"command":"php artisan app:expire-mutes","crontab":"/etc/cron/cron.conf","elapsed_s":0.646084692,"level":"info","msg":"text","pid":11573,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:process-side-notifications","crontab":"/etc/cron/cron.conf","elapsed_s":0.650212608,"level":"info","msg":"Command has finished executing without any output to stdout.","pid":11567,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:archive","crontab":"/etc/cron/cron.conf","elapsed_s":0.653136418,"level":"info","msg":"text","pid":11587,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:ab-testing:experiment-status-monitor","crontab":"/etc/cron/cron.conf","elapsed_s":0.656003109,"level":"info","msg":"text","pid":11566,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:expire-bans","crontab":"/etc/cron/cron.conf","elapsed_s":0.6609906,"level":"info","msg":"text","pid":11582,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:games:single-choice-hunt-schedule","crontab":"/etc/cron/cron.conf","elapsed_s":0.698673296,"level":"info","msg":"Command has finished executing without any output to stdout.","pid":11592,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:tle:status-update","crontab":"/etc/cron/cron.conf","elapsed_s":0.739153263,"level":"info","msg":"Command has finished executing without any output to stdout.","pid":11569,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan horizon:snapshot","crontab":"/etc/cron/cron.conf","elapsed_s":0.743576053,"level":"info","msg":"Metrics snapshot stored successfully.\n","pid":11589,"result":"success","shell":"sh","spec":"*/5 * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:update-levels","crontab":"/etc/cron/cron.conf","elapsed_s":0.744559418,"level":"info","msg":"text","pid":11597,"result":"success","shell":"sh","spec":"20 * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan decoy-token:sync-token-state","crontab":"/etc/cron/cron.conf","elapsed_s":0.963715653,"level":"info","msg":"text","pid":11571,"result":"error","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:20:00Z","time":"2023-05-11T13:20:00Z","user":"root"} {"command":"php artisan app:games:single-choice-hunt-schedule","crontab":"/etc/cron/cron.conf","elapsed_s":0.46856026,"level":"info","msg":"Command has finished executing without any output to stdout.","pid":11634,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:21:00Z","time":"2023-05-11T13:21:00Z","user":"root"} {"command":"php artisan app:archive","crontab":"/etc/cron/cron.conf","elapsed_s":0.493647749,"level":"info","msg":"Archive is not writable. Terminating...\n","pid":11643,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:21:00Z","time":"2023-05-11T13:21:00Z","user":"root"} {"command":"php artisan app:ab-testing:experiment-status-monitor","crontab":"/etc/cron/cron.conf","elapsed_s":0.50054996,"level":"info","msg":"text","pid":11647,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:21:00Z","time":"2023-05-11T13:21:00Z","user":"root"} {"command":"php artisan app:handle-periodical-awards","crontab":"/etc/cron/cron.conf","elapsed_s":0.532604097,"level":"info","msg":"Command has finished executing without any output to stdout.","pid":11638,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:21:00Z","time":"2023-05-11T13:21:00Z","user":"root"} {"command":"php artisan app:tle:status-update","crontab":"/etc/cron/cron.conf","elapsed_s":0.540661165,"level":"info","msg":"Command has finished executing without any output to stdout.","pid":11631,"result":"success","shell":"sh","spec":"* * * * *","started_at":"2023-05-11T13:21:00Z","time":"2023-05-11T13:21:00Z","user":"root"}
If you mix the start and finish separately in the logs. Then we get a lot of garbage messages and we will have to compare by PID where exactly this team started and where exactly it finished, and the debug message to which start it belongs. But in my version, I got everything in one message.
Some improvements in my opinion for kubernetes