Skip to content

Allow job waiter keys in Sidekiq logs

Sean McGivern requested to merge allow-job-waiter-keys-in-sidekiq-logs into master

What does this MR do?

Job waiter keys do not contain sensitive information, so they're safe to log. They're also useful to log so we can inspect particular batches of jobs.

See https://gitlab.com/gitlab-org/release/tasks/-/issues/1409#note_361992771.

To test:

$ bundle exec rails r 'AuthorizedProjectsWorker.bulk_perform_and_wait(User.limit(50).pluck(:id).map { |x| [x] })'
# snip warnings about redefined constants
$ gdk tail rails-background-jobs | grep AuorizedProjectsWorker
(in /Users/smcgivern/Code/gdk)
2020-06-16_12:51:17.29869 rails-background-jobs : {"severity":"INFO","time":"2020-06-16T12:51:17.298Z","class":"AuthorizedProjectsWorker","args":["2","gitlab:job_waiter:6aadf859-e219-4dc6-8adc-c245428f5925"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"787e693660416ee414c2af5f","created_at":"2020-06-16T12:48:45.588Z","enqueued_at":"2020-06-16T12:48:45.704Z","correlation_id":"af494d189a6b4a19bfca6d6a7dea5e90","pid":59942,"message":"AuthorizedProjectsWorker JID-787e693660416ee414c2af5f: start","job_status":"start","scheduling_latency_s":151.593895}
2020-06-16_12:51:17.30657 rails-background-jobs : {"severity":"INFO","time":"2020-06-16T12:51:17.306Z","class":"AuthorizedProjectsWorker","args":["3","gitlab:job_waiter:6aadf859-e219-4dc6-8adc-c245428f5925"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"eea520766b37597e1d348bc0","created_at":"2020-06-16T12:48:45.588Z","enqueued_at":"2020-06-16T12:48:45.704Z","correlation_id":"f30e3e7bd9a8459e983ffda4c03b576e","pid":59942,"message":"AuthorizedProjectsWorker JID-eea520766b37597e1d348bc0: start","job_status":"start","scheduling_latency_s":151.601813}
# etc.

Before this change, those log lines would look like this:

2020-06-16_12:41:15.54418 rails-background-jobs : {"severity":"INFO","time":"2020-06-16T12:41:15.543Z","class":"AuthorizedProjectsWorker","args":["41","[FILTERED]"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"1e8969778d20509c9218753f","created_at":"2020-06-16T12:41:09.052Z","enqueued_at":"2020-06-16T12:41:09.182Z","correlation_id":"ebcb85a568e49c1df57ab86062f03ce5","pid":51284,"message":"AuthorizedProjectsWorker JID-1e8969778d20509c9218753f: done: 6.332328 sec","job_status":"done","scheduling_latency_s":0.029272,"redis_calls":5,"redis_duration_s":0.0030080000000000003,"redis_read_bytes":5,"redis_write_bytes":566,"db_count":280,"db_write_count":0,"db_cached_count":0,"duration_s":6.332328,"cpu_s":0.500237,"completed_at":"2020-06-16T12:41:15.543Z","db_duration_s":0.00499}

Merge request reports