Set project correctly in Sidekiq logs when creating a project
What does this MR do?
Our Sidekiq logs take context (user, project, etc.) from the place where they were invoked - typically a controller or API endpoint. They weren't set correctly when we created a project, because in that case the project doesn't exist when we start processing the request.
Example logs from gdk tail rails-background-jobs | grep 'Projects::CreateService' - I created one project through the controller, and another by pushing.
2020-08-04_10:59:02.85576 rails-background-jobs : {"severity":"INFO","time":"2020-08-04T10:59:02.855Z","class":"AuthorizedProjectsWorker","args":["1"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"a4d45355727c7fb5ff9f2b67","created_at":"2020-08-04T10:59:02.847Z","enqueued_at":"2020-08-04T10:59:02.854Z","meta.user":"root","meta.project":"f/test-project-creation","meta.root_namespace":"f","meta.caller_id":"ProjectsController#create","meta.related_class":"Projects::CreateService","correlation_id":"i8DVD3QvqW","uber-trace-id":"62c2c2cc7f0bee29:32d139cad38d1dac:5741f35f0d1faa0d:1","pid":13784,"message":"AuthorizedProjectsWorker JID-a4d45355727c7fb5ff9f2b67: start","job_status":"start","scheduling_latency_s":0.001142}
2020-08-04_10:59:03.45424 rails-background-jobs : {"severity":"INFO","time":"2020-08-04T10:59:03.453Z","class":"AuthorizedProjectsWorker","args":["1"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"a4d45355727c7fb5ff9f2b67","created_at":"2020-08-04T10:59:02.847Z","enqueued_at":"2020-08-04T10:59:02.854Z","meta.user":"root","meta.project":"f/test-project-creation","meta.root_namespace":"f","meta.caller_id":"ProjectsController#create","meta.related_class":"Projects::CreateService","correlation_id":"i8DVD3QvqW","uber-trace-id":"62c2c2cc7f0bee29:32d139cad38d1dac:5741f35f0d1faa0d:1","pid":13784,"message":"AuthorizedProjectsWorker JID-a4d45355727c7fb5ff9f2b67: done: 0.59837 sec","job_status":"done","scheduling_latency_s":0.001142,"redis_calls":6,"redis_duration_s":0.0044,"redis_read_bytes":408,"redis_write_bytes":612,"redis_cache_calls":2,"redis_cache_duration_s":0.001779,"redis_cache_read_bytes":404,"redis_cache_write_bytes":131,"redis_queues_calls":2,"redis_queues_duration_s":0.001023,"redis_queues_read_bytes":2,"redis_queues_write_bytes":188,"redis_shared_state_calls":2,"redis_shared_state_duration_s":0.001598,"redis_shared_state_read_bytes":2,"redis_shared_state_write_bytes":293,"db_count":6,"db_write_count":0,"db_cached_count":0,"duration_s":0.59837,"cpu_s":0.479643,"completed_at":"2020-08-04T10:59:03.453Z","db_duration_s":0.041593}
2020-08-04_11:08:18.43631 rails-background-jobs : {"severity":"INFO","time":"2020-08-04T11:08:18.436Z","class":"UpdateHighestRoleWorker","args":["1"],"retry":3,"queue":"update_highest_role","backtrace":true,"jid":"e7d9e80c1a89f04eee283cda","created_at":"2020-08-04T10:58:13.744Z","meta.user":"root","meta.project":"root/test-project-creation","meta.root_namespace":"root","meta.caller_id":"ProjectsController#create","meta.related_class":"Projects::CreateService","correlation_id":"8fdf0df475fddfc0fa3f599b3fa7f877","uber-trace-id":"4578fe6b5db8d6be:4578fe6b5db8d6be:0:1","enqueued_at":"2020-08-04T11:08:18.434Z","pid":13784,"message":"UpdateHighestRoleWorker JID-e7d9e80c1a89f04eee283cda: start","job_status":"start","scheduling_latency_s":0.001282}
2020-08-04_11:08:18.63463 rails-background-jobs : {"severity":"INFO","time":"2020-08-04T11:08:18.634Z","class":"UpdateHighestRoleWorker","args":["1"],"retry":3,"queue":"update_highest_role","backtrace":true,"jid":"e7d9e80c1a89f04eee283cda","created_at":"2020-08-04T10:58:13.744Z","meta.user":"root","meta.project":"root/test-project-creation","meta.root_namespace":"root","meta.caller_id":"ProjectsController#create","meta.related_class":"Projects::CreateService","correlation_id":"8fdf0df475fddfc0fa3f599b3fa7f877","uber-trace-id":"4578fe6b5db8d6be:4578fe6b5db8d6be:0:1","enqueued_at":"2020-08-04T11:08:18.434Z","pid":13784,"message":"UpdateHighestRoleWorker JID-e7d9e80c1a89f04eee283cda: done: 0.198261 sec","job_status":"done","scheduling_latency_s":0.001282,"redis_calls":2,"redis_duration_s":0.000882,"redis_read_bytes":2,"redis_write_bytes":188,"redis_queues_calls":2,"redis_queues_duration_s":0.000882,"redis_queues_read_bytes":2,"redis_queues_write_bytes":188,"db_count":3,"db_write_count":0,"db_cached_count":0,"duration_s":0.198261,"cpu_s":0.178742,"completed_at":"2020-08-04T11:08:18.634Z","db_duration_s":0.012803}
2020-08-04_11:09:15.92497 rails-background-jobs : {"severity":"INFO","time":"2020-08-04T11:09:15.924Z","class":"AuthorizedProjectsWorker","args":["1"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"3ac407947ca52a0ab2221208","created_at":"2020-08-04T11:09:15.920Z","enqueued_at":"2020-08-04T11:09:15.923Z","meta.user":"root","meta.project":"f/test-project-creation-on-push","meta.root_namespace":"f","meta.caller_id":"Repositories::GitHttpController#info_refs","meta.related_class":"Projects::CreateService","correlation_id":"978b5ac4-85d4-4c06-8b7f-34b0ce550eec","uber-trace-id":"42019c7ad805f0da:3c142407f055cd45:5c71a75727c853f:1","pid":13784,"message":"AuthorizedProjectsWorker JID-3ac407947ca52a0ab2221208: start","job_status":"start","scheduling_latency_s":0.001015}
2020-08-04_11:09:16.16993 rails-background-jobs : {"severity":"INFO","time":"2020-08-04T11:09:16.169Z","class":"AuthorizedProjectsWorker","args":["1"],"retry":3,"queue":"authorized_projects","backtrace":true,"jid":"3ac407947ca52a0ab2221208","created_at":"2020-08-04T11:09:15.920Z","enqueued_at":"2020-08-04T11:09:15.923Z","meta.user":"root","meta.project":"f/test-project-creation-on-push","meta.root_namespace":"f","meta.caller_id":"Repositories::GitHttpController#info_refs","meta.related_class":"Projects::CreateService","correlation_id":"978b5ac4-85d4-4c06-8b7f-34b0ce550eec","uber-trace-id":"42019c7ad805f0da:3c142407f055cd45:5c71a75727c853f:1","pid":13784,"message":"AuthorizedProjectsWorker JID-3ac407947ca52a0ab2221208: done: 0.244856 sec","job_status":"done","scheduling_latency_s":0.001015,"redis_calls":4,"redis_duration_s":0.0017300000000000002,"redis_read_bytes":4,"redis_write_bytes":481,"redis_queues_calls":2,"redis_queues_duration_s":0.000749,"redis_queues_read_bytes":2,"redis_queues_write_bytes":188,"redis_shared_state_calls":2,"redis_shared_state_duration_s":0.000981,"redis_shared_state_read_bytes":2,"redis_shared_state_write_bytes":293,"db_count":5,"db_write_count":0,"db_cached_count":0,"duration_s":0.244856,"cpu_s":0.147878,"completed_at":"2020-08-04T11:09:16.169Z","db_duration_s":0.008252}