Skip to content

Overwrite caller_id at Sidekiq server middleware

This moves our caller_id overwriting to the Sidekiq server middleware instead the client.

It means that in a chain of jobs started at a controller action, the first job would have the caller_id as the calling controller action, and subsequent jobs caller_id would take its caller worker. For instance:

  1. FooController#index is called
  2. FooWorker is scheduled within that action
  3. Sidekiq will log meta.caller_id as FooController#index
  4. FooWorker schedules BarWorker
  5. BarWorker will take the current context through the Sidekiq client middleware with a caller_id FooWorker
  6. And so on..

A real example where we schedule a mail within another worker:

// ProjectExportWorker Job started with caller_id ProjectsController#generate_new_export
2020-01-16_20:51:13.24638 rails-background-jobs : {"severity":"INFO","time":"2020-01-16T20:51:13.245Z","class":"ProjectExportWorker","args":[1,19,null,{}],"retry":3,"queue":"project_export","backtrace":5,"jid":"c76137e022e5b2f980ebd195","created_at":"2020-01-16T20:51:13.190Z","meta.user":"root","meta.project":"root/asdf","meta.root_namespace":"root","meta.subscription_plan":"free","meta.caller_id":"ProjectsController#generate_new_export","correlation_id":"QHl64P5qmea","uber-trace-id":"4b98c80373634994:de6fe17ba38e2c57:82ca6c695923db35:1","enqueued_at":"2020-01-16T20:51:13.243Z","pid":12663,"message":"ProjectExportWorker JID-c76137e022e5b2f980ebd195: start","job_status":"start","scheduling_latency_s":0.00203}

// Mailer is started with caller_id ProjectExportWorker
2020-01-16_20:51:14.70620 rails-background-jobs : {"severity":"INFO","time":"2020-01-16T20:51:14.705Z","class":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper","wrapped":"ActionMailer::DeliveryJob","queue":"mailers","args":[{"job_class":"ActionMailer::DeliveryJob","job_id":"6ddaf825-3df0-49a4-9069-e97ee55cbce3","provider_job_id":null,"queue_name":"mailers","priority":null,"arguments":["Notify","project_was_exported_email","deliver_now",{"_aj_globalid":"gid://gitlab/User/1"},{"_aj_globalid":"gid://gitlab/Project/19"}],"executions":0,"locale":"en"}],"retry":3,"backtrace":true,"jid":"f330d7ab5de5f70ccb10d0da","created_at":"2020-01-16T20:51:14.702Z","meta.user":"root","meta.project":"root/asdf","meta.root_namespace":"root","meta.subscription_plan":"free","meta.caller_id":"ProjectExportWorker","correlation_id":"QHl64P5qmea","enqueued_at":"2020-01-16T20:51:14.703Z","pid":12663,"message":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper JID-f330d7ab5de5f70ccb10d0da: start","job_status":"start","scheduling_latency_s":0.002095}

// ProjectExportWorker is done with caller_id ProjectsController#generate_new_export
2020-01-16_20:51:14.71150 rails-background-jobs : {"severity":"INFO","time":"2020-01-16T20:51:14.711Z","class":"ProjectExportWorker","args":[1,19,null,{}],"retry":3,"queue":"project_export","backtrace":5,"jid":"c76137e022e5b2f980ebd195","created_at":"2020-01-16T20:51:13.190Z","meta.user":"root","meta.project":"root/asdf","meta.root_namespace":"root","meta.subscription_plan":"free","meta.caller_id":"ProjectsController#generate_new_export","correlation_id":"QHl64P5qmea","uber-trace-id":"4b98c80373634994:de6fe17ba38e2c57:82ca6c695923db35:1","enqueued_at":"2020-01-16T20:51:13.243Z","pid":12663,"message":"ProjectExportWorker JID-c76137e022e5b2f980ebd195: done: 1.465776 sec","job_status":"done","scheduling_latency_s":0.00203,"gitaly_calls":4,"gitaly_duration":26.23,"duration":1.465776,"cpu_s":1.10894,"completed_at":"2020-01-16T20:51:14.711Z","db_duration":284.1270000790246,"db_duration_s":0.2841270000790246}

// Mailer is done with caller_id ProjectExportWorker
2020-01-16_20:51:32.66346 rails-background-jobs : {"severity":"INFO","time":"2020-01-16T20:51:32.663Z","class":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper","wrapped":"ActionMailer::DeliveryJob","queue":"mailers","args":[{"job_class":"ActionMailer::DeliveryJob","job_id":"6ddaf825-3df0-49a4-9069-e97ee55cbce3","provider_job_id":null,"queue_name":"mailers","priority":null,"arguments":["Notify","project_was_exported_email","deliver_now",{"_aj_globalid":"gid://gitlab/User/1"},{"_aj_globalid":"gid://gitlab/Project/19"}],"executions":0,"locale":"en"}],"retry":3,"backtrace":true,"jid":"f330d7ab5de5f70ccb10d0da","created_at":"2020-01-16T20:51:14.702Z","meta.user":"root","meta.project":"root/asdf","meta.root_namespace":"root","meta.subscription_plan":"free","meta.caller_id":"ProjectExportWorker","correlation_id":"QHl64P5qmea","enqueued_at":"2020-01-16T20:51:14.703Z","pid":12663,"message":"ActiveJob::QueueAdapters::SidekiqAdapter::JobWrapper JID-f330d7ab5de5f70ccb10d0da: done: 17.957526 sec","job_status":"done","scheduling_latency_s":0.002095,"duration":17.957526,"cpu_s":12.889249,"completed_at":"2020-01-16T20:51:32.663Z","db_duration":25.440999947022647,"db_duration_s":0.025440999947022647}
Edited by Oswaldo Ferreira

Merge request reports