Multiple requests to the post-the-build-status-to-a-commit API endpoint produces duplicate jobs

Summary

The customers TeamCity instance sends multiple requests to the post-the-build-status-to-a-commit API endpoint. This results in the creation of duplicate jobs in a single pipeline.

Later, multiple requests are sent to set the status to complete. Only one job gets the update, duplicate jobs remain stuck in a non-complete state and the pipeline does not complete. See attached image.

Customer is using TeamCity CI/CD builds on GitLab projects on two nodes.

Builds are triggered either using GitLabs TeamCity integration or by TeamCity itself on new commits/refs in a repository.

For the majority of builds where multiple requests are sent the behaviour observed is:

1st Request: POST /projects/:id/statuses/:sha returns 200 OK
2nd Request: POST /projects/:id/statuses/:sha returns HTTP 400 - Cannot transition status via :run from :running (Reason(s): Status cannot transition via "run")

For the requests where duplicate jobs are created (460 occurrences from total 20,000 builds) the behaviour observed is:

1st Request: POST /projects/:id/statuses/:sha returns 200 OK
2nd Request: POST /projects/:id/statuses/:sha returns 200 OK

ZD Ticket: (293448)

Steps to reproduce

Unable to reproduce with bash script sending multiple requests.

We do not have TeamCity instance and the behaviour occurs intermittently - 460 occurrences from total 20,000 builds on customer side.

What is the current bug behaviour?

Duplicate jobs are created intermittently for multiple requests to the post-the-build-status-to-a-commit API endpoint and for the same commit and status.

What is the expected correct behaviour?

Duplicate requests should always be rejected returning HTTP 400 - Cannot transition status via :run from :running (Reason(s): Status cannot transition via "run".

Relevant logs and/or screenshots

Pipeline screenshot.png

Duplicate Job scenario


——Request 1————

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/service_measurement.log
603:{"severity":"INFO","time":"2022-06-13T12:08:52.345Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","message":"Optimistic Lock released with retries","name":"ci_stage_set_status","retries":1,"time_s":0.04573369771242142}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/application_json.log
7522:{"severity":"ERROR","time":"2022-06-13T12:08:52.293Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","message":"Cannot obtain an exclusive lease for ci/pipeline_processing/atomic_processing_service::pipeline_id:174731. There must be another instance already in execution."}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/api_json.log
1067:{"time":"2022-06-13T12:08:52.281Z","severity":"INFO","duration_s":4.11611,"db_duration_s":0.02019,"view_duration_s":4.09592,"status":201,"method":"POST","path":"/api/v4/projects/commerce-prod%2Fcustomer-website-service/statuses/0cc3a7ae358e1875fec57e962fb935330d140afe","params":[{"key":"state","value":"running"},{"key":"name","value":"CI"},{"key":"target_url","value":"https://teamcity_host/viewLog.html?buildId=11630087&buildTypeId=Commerce_Scx_CustomerWebsiteService_Ci"},{"key":"description","value":"[FILTERED]"}],"host":"dunmmy_host","remote_ip":"192.168.0.2, 127.0.0.1","ua":"TeamCity Server 2021.2.3 (build 99711)","route":"/api/:version/projects/:id/statuses/:sha","user_id":3421,"username":"dummy_username","queue_duration_s":1.050216,"gitaly_calls":3,"gitaly_duration_s":0.009433,"redis_calls":7,"redis_duration_s":0.004045,"redis_read_bytes":693,"redis_write_bytes":4998,"redis_cache_calls":4,"redis_cache_duration_s":0.003019,"redis_cache_read_bytes":561,"redis_cache_write_bytes":707,"redis_queues_read_bytes":126,"redis_queues_write_bytes":3738,"redis_shared_state_calls":3,"redis_shared_state_duration_s":0.001026,"redis_shared_state_read_bytes":6,"redis_shared_state_write_bytes":553,"db_count":22,"db_write_count":6,"db_cached_count":2,"db_replica_count":0,"db_primary_count":22,"db_main_count":22,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":2,"db_main_cached_count":2,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.021,"db_main_duration_s":0.021,"db_main_replica_duration_s":0.0,"cpu_s":0.091875,"pid":8116,"correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","content_length":"206","request_urgency":"default","target_duration_s":1}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/gitaly.log
3813:time="2022-06-13T12:08:48.201Z" level=info msg="finished unary call with code OK" correlation_id=01G5EFEV8SCCZW93ZAM9HJ2EW3 grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=FindCommit grpc.request.deadline="2022-06-13T05:09:18.097" grpc.request.fullMethod=/gitaly.CommitService/FindCommit grpc.request.glProjectPath=commerce-prod/customer-website-service grpc.request.glRepository=project-4350 grpc.request.payload_bytes=192 grpc.request.repoPath=@hashed/3e/0c/3e0cbdb59cf8a8edaf262fa5147f25e3bad06cd1eea3f6156aab3a96bf1e4be8.git grpc.request.repoStorage=default grpc.response.payload_bytes=386 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:48.197" grpc.time_ms=3.809 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3873:time="2022-06-13T12:08:52.269Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFEV8SCCZW93ZAM9HJ2EW3 grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=server_stream grpc.method=ListCommitsByOid grpc.request.deadline="2022-06-13T05:09:22.069" grpc.request.fullMethod=/gitaly.CommitService/ListCommitsByOid grpc.request.glProjectPath=commerce-prod/customer-website-service grpc.request.glRepository=project-4350 grpc.request.payload_bytes=192 grpc.request.repoPath=@hashed/3e/0c/3e0cbdb59cf8a8edaf262fa5147f25e3bad06cd1eea3f6156aab3a96bf1e4be8.git grpc.request.repoStorage=default grpc.response.payload_bytes=386 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:52.269" grpc.time_ms=0.345 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3874:time="2022-06-13T12:08:52.271Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFEV8SCCZW93ZAM9HJ2EW3 grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=server_stream grpc.method=ListCommitsByRefName grpc.request.deadline="2022-06-13T05:09:22.071" grpc.request.fullMethod=/gitaly.CommitService/ListCommitsByRefName grpc.request.glProjectPath=commerce-prod/customer-website-service grpc.request.glRepository=project-4350 grpc.request.payload_bytes=174 grpc.request.repoPath=@hashed/3e/0c/3e0cbdb59cf8a8edaf262fa5147f25e3bad06cd1eea3f6156aab3a96bf1e4be8.git grpc.request.repoStorage=default grpc.response.payload_bytes=413 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:52.271" grpc.time_ms=0.508 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/sidekiq.log
7758:{"severity":"INFO","time":"2022-06-13T12:08:52.258Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"51113ca2610d7cf6f9d6b3e5","created_at":"2022-06-13T12:08:52.254Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.256Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-51113ca2610d7cf6f9d6b3e5: start","job_status":"start","scheduling_latency_s":0.001932}
7759:{"severity":"INFO","time":"2022-06-13T12:08:52.265Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"c6708749a274a6829eb3d33f","created_at":"2022-06-13T12:08:52.262Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.263Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-c6708749a274a6829eb3d33f: start","job_status":"start","scheduling_latency_s":0.001879}
7760:{"severity":"INFO","time":"2022-06-13T12:08:52.270Z","retry":3,"queue":"pipeline_processing:stage_update","version":0,"queue_namespace":"pipeline_processing","args":["193990"],"class":"StageUpdateWorker","jid":"61a20216ef4e142db9e0253a","created_at":"2022-06-13T12:08:52.265Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:stage_update:5d6f46fedcc68d5f8764c2d06226a64ebc4c228886e934efc48349fcecf91ecc","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.266Z","job_size_bytes":8,"pid":11428,"message":"StageUpdateWorker JID-61a20216ef4e142db9e0253a: start","job_status":"start","scheduling_latency_s":0.003775}
7761:{"severity":"INFO","time":"2022-06-13T12:08:52.297Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"c6708749a274a6829eb3d33f","created_at":"2022-06-13T12:08:52.262Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.263Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-c6708749a274a6829eb3d33f: done: 0.032442 sec","job_status":"done","scheduling_latency_s":0.001879,"redis_calls":2,"redis_duration_s":0.005469,"redis_read_bytes":10,"redis_write_bytes":506,"redis_queues_calls":1,"redis_queues_duration_s":0.003558,"redis_queues_read_bytes":10,"redis_queues_write_bytes":370,"redis_shared_state_calls":1,"redis_shared_state_duration_s":0.001911,"redis_shared_state_write_bytes":136,"db_count":2,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":2,"db_main_count":2,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.006,"db_main_duration_s":0.006,"db_main_replica_duration_s":0.0,"cpu_s":0.006099,"duration_s":0.032442,"completed_at":"2022-06-13T12:08:52.297Z","load_balancing_strategy":"primary","db_duration_s":0.006082}
7762:{"severity":"INFO","time":"2022-06-13T12:08:52.314Z","retry":3,"queue":"pipeline_hooks:pipeline_hooks","version":0,"queue_namespace":"pipeline_hooks","args":["174731"],"class":"PipelineHooksWorker","jid":"4bd98011e60f5e32807c6e87","created_at":"2022-06-13T12:08:52.307Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"PipelineProcessWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"delayed","wal_locations":{},"idempotency_key":"resque:gitlab:duplicate:pipeline_hooks:pipeline_hooks:0aed684aba378e6b758b1478055e72ac024fd9be1712815d3589ffcbfb9c9740","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.311Z","job_size_bytes":8,"pid":11428,"message":"PipelineHooksWorker JID-4bd98011e60f5e32807c6e87: start","job_status":"start","scheduling_latency_s":0.002922}
7763:{"severity":"INFO","time":"2022-06-13T12:08:52.354Z","retry":3,"queue":"pipeline_processing:stage_update","version":0,"queue_namespace":"pipeline_processing","args":["193990"],"class":"StageUpdateWorker","jid":"61a20216ef4e142db9e0253a","created_at":"2022-06-13T12:08:52.265Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:stage_update:5d6f46fedcc68d5f8764c2d06226a64ebc4c228886e934efc48349fcecf91ecc","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.266Z","job_size_bytes":8,"pid":11428,"message":"StageUpdateWorker JID-61a20216ef4e142db9e0253a: done: 0.08463 sec","job_status":"done","scheduling_latency_s":0.003775,"redis_calls":1,"redis_duration_s":0.00027,"redis_read_bytes":10,"redis_write_bytes":362,"redis_queues_calls":1,"redis_queues_duration_s":0.00027,"redis_queues_read_bytes":10,"redis_queues_write_bytes":362,"db_count":8,"db_write_count":3,"db_cached_count":0,"db_replica_count":0,"db_primary_count":8,"db_main_count":8,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.032,"db_main_duration_s":0.032,"db_main_replica_duration_s":0.0,"cpu_s":0.018062,"duration_s":0.08463,"completed_at":"2022-06-13T12:08:52.354Z","load_balancing_strategy":"primary","db_duration_s":0.031296}
7765:{"severity":"INFO","time":"2022-06-13T12:08:52.453Z","retry":0,"queue":"file_hook","version":0,"class":"FileHookWorker","args":["/home/git/gitlab/file_hooks/merge_hook.py","[FILTERED]"],"jid":"3d8ed58027e305a832b47698","created_at":"2022-06-13T12:08:52.446Z","enqueued_at":"2022-06-13T12:08:52.447Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"PipelineHooksWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"integrations","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:file_hook:952724dd74b6a478b94869c65015d7dd9e561a085ff71543c1cede645cd95684","size_limiter":"validated","job_size_bytes":1626,"pid":11428,"message":"FileHookWorker JID-3d8ed58027e305a832b47698: start","job_status":"start","scheduling_latency_s":0.005542}
7766:{"severity":"INFO","time":"2022-06-13T12:08:52.462Z","retry":3,"queue":"pipeline_hooks:pipeline_hooks","version":0,"queue_namespace":"pipeline_hooks","args":["174731"],"class":"PipelineHooksWorker","jid":"4bd98011e60f5e32807c6e87","created_at":"2022-06-13T12:08:52.307Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"PipelineProcessWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"delayed","wal_locations":{},"idempotency_key":"resque:gitlab:duplicate:pipeline_hooks:pipeline_hooks:0aed684aba378e6b758b1478055e72ac024fd9be1712815d3589ffcbfb9c9740","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.311Z","job_size_bytes":8,"pid":11428,"message":"PipelineHooksWorker JID-4bd98011e60f5e32807c6e87: done: 0.147993 sec","job_status":"done","scheduling_latency_s":0.002922,"rugged_calls":1,"rugged_duration_s":0.001914,"redis_calls":5,"redis_duration_s":0.047961,"redis_read_bytes":502,"redis_write_bytes":3270,"redis_cache_calls":4,"redis_cache_duration_s":0.047714,"redis_cache_read_bytes":450,"redis_cache_write_bytes":281,"redis_queues_calls":1,"redis_queues_duration_s":0.000247,"redis_queues_read_bytes":52,"redis_queues_write_bytes":2989,"db_count":13,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":13,"db_main_count":13,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.045,"db_main_duration_s":0.045,"db_main_replica_duration_s":0.0,"cpu_s":0.040628,"duration_s":0.147993,"completed_at":"2022-06-13T12:08:52.462Z","load_balancing_strategy":"primary_no_wal","db_duration_s":0.044034}
7767:{"severity":"INFO","time":"2022-06-13T12:08:52.464Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"51113ca2610d7cf6f9d6b3e5","created_at":"2022-06-13T12:08:52.254Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.256Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-51113ca2610d7cf6f9d6b3e5: done: 0.20668 sec","job_status":"done","scheduling_latency_s":0.001932,"rugged_calls":3,"rugged_duration_s":0.041963,"redis_calls":4,"redis_duration_s":0.00967,"redis_read_bytes":199,"redis_write_bytes":4067,"redis_cache_calls":1,"redis_cache_duration_s":0.001078,"redis_cache_read_bytes":109,"redis_cache_write_bytes":67,"redis_queues_calls":1,"redis_queues_duration_s":0.00471,"redis_queues_read_bytes":52,"redis_queues_write_bytes":1573,"redis_shared_state_calls":2,"redis_shared_state_duration_s":0.003882,"redis_shared_state_read_bytes":38,"redis_shared_state_write_bytes":2427,"db_count":32,"db_write_count":7,"db_cached_count":3,"db_replica_count":0,"db_primary_count":32,"db_main_count":32,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":3,"db_main_cached_count":3,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.081,"db_main_duration_s":0.081,"db_main_replica_duration_s":0.0,"cpu_s":0.121134,"duration_s":0.20668,"completed_at":"2022-06-13T12:08:52.464Z","load_balancing_strategy":"primary","db_duration_s":0.079528}
7768:{"severity":"INFO","time":"2022-06-13T12:08:52.662Z","retry":0,"queue":"file_hook","version":0,"class":"FileHookWorker","args":["/home/git/gitlab/file_hooks/merge_hook.py","[FILTERED]"],"jid":"3d8ed58027e305a832b47698","created_at":"2022-06-13T12:08:52.446Z","enqueued_at":"2022-06-13T12:08:52.447Z","correlation_id":"01G5EFEV8SCCZW93ZAM9HJ2EW3","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"PipelineHooksWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"integrations","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:file_hook:952724dd74b6a478b94869c65015d7dd9e561a085ff71543c1cede645cd95684","size_limiter":"validated","job_size_bytes":1626,"pid":11428,"message":"FileHookWorker JID-3d8ed58027e305a832b47698: done: 0.209508 sec","job_status":"done","scheduling_latency_s":0.005542,"redis_calls":1,"redis_duration_s":0.000434,"redis_read_bytes":10,"redis_write_bytes":316,"redis_queues_calls":1,"redis_queues_duration_s":0.000434,"redis_queues_read_bytes":10,"redis_queues_write_bytes":316,"db_count":0,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":0,"db_main_count":0,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.0,"db_main_duration_s":0.0,"db_main_replica_duration_s":0.0,"cpu_s":0.003504,"duration_s":0.209508,"completed_at":"2022-06-13T12:08:52.662Z","load_balancing_strategy":"primary","db_duration_s":0.0}

——Request 2————

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/application_json.log
7523:{"severity":"ERROR","time":"2022-06-13T12:08:52.712Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","message":"Cannot obtain an exclusive lease for ci/pipeline_processing/atomic_processing_service::pipeline_id:174731. There must be another instance already in execution."}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/gitaly.log
3865:time="2022-06-13T12:08:51.123Z" level=info msg="finished unary call with code OK" correlation_id=01G5EFEY41PBS168Q2EDKJAA9B grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=FindCommit grpc.request.deadline="2022-06-13T05:09:21.018" grpc.request.fullMethod=/gitaly.CommitService/FindCommit grpc.request.glProjectPath=commerce-prod/customer-website-service grpc.request.glRepository=project-4350 grpc.request.payload_bytes=192 grpc.request.repoPath=@hashed/3e/0c/3e0cbdb59cf8a8edaf262fa5147f25e3bad06cd1eea3f6156aab3a96bf1e4be8.git grpc.request.repoStorage=default grpc.response.payload_bytes=386 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:51.119" grpc.time_ms=4.261 peer.address=@ pid=6707 remote_ip=10.41.11.84 span.kind=server system=grpc username=dummy_username
3879:time="2022-06-13T12:08:52.691Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFEY41PBS168Q2EDKJAA9B grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=server_stream grpc.method=ListCommitsByOid grpc.request.deadline="2022-06-13T05:09:22.091" grpc.request.fullMethod=/gitaly.CommitService/ListCommitsByOid grpc.request.glProjectPath=commerce-prod/customer-website-service grpc.request.glRepository=project-4350 grpc.request.payload_bytes=192 grpc.request.repoPath=@hashed/3e/0c/3e0cbdb59cf8a8edaf262fa5147f25e3bad06cd1eea3f6156aab3a96bf1e4be8.git grpc.request.repoStorage=default grpc.response.payload_bytes=386 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:52.691" grpc.time_ms=0.295 peer.address=@ pid=6707 remote_ip=10.41.11.84 span.kind=server system=grpc username=dummy_username
3880:time="2022-06-13T12:08:52.694Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFEY41PBS168Q2EDKJAA9B grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=server_stream grpc.method=ListCommitsByRefName grpc.request.deadline="2022-06-13T05:09:22.093" grpc.request.fullMethod=/gitaly.CommitService/ListCommitsByRefName grpc.request.glProjectPath=commerce-prod/customer-website-service grpc.request.glRepository=project-4350 grpc.request.payload_bytes=174 grpc.request.repoPath=@hashed/3e/0c/3e0cbdb59cf8a8edaf262fa5147f25e3bad06cd1eea3f6156aab3a96bf1e4be8.git grpc.request.repoStorage=default grpc.response.payload_bytes=413 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:52.693" grpc.time_ms=0.438 peer.address=@ pid=6707 remote_ip=10.41.11.84 span.kind=server system=grpc username=dummy_username

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/sidekiq.log
7769:{"severity":"INFO","time":"2022-06-13T12:08:52.679Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"034ead4863ff67678d419de9","created_at":"2022-06-13T12:08:52.676Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.677Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-034ead4863ff67678d419de9: start","job_status":"start","scheduling_latency_s":0.001447}
7770:{"severity":"INFO","time":"2022-06-13T12:08:52.687Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"4d966b746c98e5f7de913723","created_at":"2022-06-13T12:08:52.684Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.685Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-4d966b746c98e5f7de913723: start","job_status":"start","scheduling_latency_s":0.001334}
7771:{"severity":"INFO","time":"2022-06-13T12:08:52.693Z","retry":3,"queue":"pipeline_processing:stage_update","version":0,"queue_namespace":"pipeline_processing","args":["193990"],"class":"StageUpdateWorker","jid":"3d00a19a60401d18411ecb49","created_at":"2022-06-13T12:08:52.687Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:stage_update:5d6f46fedcc68d5f8764c2d06226a64ebc4c228886e934efc48349fcecf91ecc","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.688Z","job_size_bytes":8,"pid":11428,"message":"StageUpdateWorker JID-3d00a19a60401d18411ecb49: start","job_status":"start","scheduling_latency_s":0.00443}
7772:{"severity":"INFO","time":"2022-06-13T12:08:52.713Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"4d966b746c98e5f7de913723","created_at":"2022-06-13T12:08:52.684Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.685Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-4d966b746c98e5f7de913723: done: 0.026421 sec","job_status":"done","scheduling_latency_s":0.001334,"redis_calls":2,"redis_duration_s":0.004445,"redis_read_bytes":10,"redis_write_bytes":506,"redis_queues_calls":1,"redis_queues_duration_s":0.000319,"redis_queues_read_bytes":10,"redis_queues_write_bytes":370,"redis_shared_state_calls":1,"redis_shared_state_duration_s":0.004126,"redis_shared_state_write_bytes":136,"db_count":2,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":2,"db_main_count":2,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.008,"db_main_duration_s":0.008,"db_main_replica_duration_s":0.0,"cpu_s":0.006334,"duration_s":0.026421,"completed_at":"2022-06-13T12:08:52.713Z","load_balancing_strategy":"primary","db_duration_s":0.008138}
7773:{"severity":"INFO","time":"2022-06-13T12:08:52.724Z","retry":3,"queue":"pipeline_processing:stage_update","version":0,"queue_namespace":"pipeline_processing","args":["193990"],"class":"StageUpdateWorker","jid":"3d00a19a60401d18411ecb49","created_at":"2022-06-13T12:08:52.687Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:stage_update:5d6f46fedcc68d5f8764c2d06226a64ebc4c228886e934efc48349fcecf91ecc","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.688Z","job_size_bytes":8,"pid":11428,"message":"StageUpdateWorker JID-3d00a19a60401d18411ecb49: done: 0.03074 sec","job_status":"done","scheduling_latency_s":0.00443,"redis_calls":1,"redis_duration_s":0.00028,"redis_read_bytes":10,"redis_write_bytes":362,"redis_queues_calls":1,"redis_queues_duration_s":0.00028,"redis_queues_read_bytes":10,"redis_queues_write_bytes":362,"db_count":3,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":3,"db_main_count":3,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.012,"db_main_duration_s":0.012,"db_main_replica_duration_s":0.0,"cpu_s":0.010358,"duration_s":0.03074,"completed_at":"2022-06-13T12:08:52.724Z","load_balancing_strategy":"primary","db_duration_s":0.011379}
7774:{"severity":"INFO","time":"2022-06-13T12:08:52.777Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174731"],"class":"PipelineProcessWorker","jid":"034ead4863ff67678d419de9","created_at":"2022-06-13T12:08:52.676Z","correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:098c55f506027e8a4380ce8e9b2a6561da086be62a95d16dc9ce8153cf54e254","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:52.677Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-034ead4863ff67678d419de9: done: 0.098023 sec","job_status":"done","scheduling_latency_s":0.001447,"rugged_calls":2,"rugged_duration_s":0.00847,"redis_calls":4,"redis_duration_s":0.002059,"redis_read_bytes":139,"redis_write_bytes":1836,"redis_cache_calls":1,"redis_cache_duration_s":0.000256,"redis_cache_read_bytes":109,"redis_cache_write_bytes":67,"redis_queues_calls":1,"redis_queues_duration_s":0.000272,"redis_queues_read_bytes":10,"redis_queues_write_bytes":370,"redis_shared_state_calls":2,"redis_shared_state_duration_s":0.001531,"redis_shared_state_read_bytes":20,"redis_shared_state_write_bytes":1399,"db_count":19,"db_write_count":1,"db_cached_count":2,"db_replica_count":0,"db_primary_count":19,"db_main_count":19,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":2,"db_main_cached_count":2,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.03,"db_main_duration_s":0.03,"db_main_replica_duration_s":0.0,"cpu_s":0.058295,"duration_s":0.098023,"completed_at":"2022-06-13T12:08:52.777Z","load_balancing_strategy":"primary","db_duration_s":0.029217}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/api_json.log
1068:{"time":"2022-06-13T12:08:52.703Z","severity":"INFO","duration_s":1.61817,"db_duration_s":0.01853,"view_duration_s":1.59964,"status":201,"method":"POST","path":"/api/v4/projects/commerce-prod%2Fcustomer-website-service/statuses/0cc3a7ae358e1875fec57e962fb935330d140afe","params":[{"key":"state","value":"running"},{"key":"name","value":"CI"},{"key":"target_url","value":"https://teamcity_host/viewLog.html?buildId=11630087&buildTypeId=Commerce_Scx_CustomerWebsiteService_Ci"},{"key":"description","value":"[FILTERED]"}],"host":"dunmmy_host","remote_ip":"10.41.11.84, 127.0.0.1","ua":"TeamCity Server 2021.2.3 (build 99711)","route":"/api/:version/projects/:id/statuses/:sha","user_id":3421,"username":"dummy_username","queue_duration_s":0.009983,"gitaly_calls":3,"gitaly_duration_s":0.010125,"redis_calls":9,"redis_duration_s":0.003572,"redis_read_bytes":490,"redis_write_bytes":5207,"redis_cache_calls":3,"redis_cache_duration_s":0.000872,"redis_cache_read_bytes":358,"redis_cache_write_bytes":630,"redis_queues_read_bytes":126,"redis_queues_write_bytes":3739,"redis_shared_state_calls":6,"redis_shared_state_duration_s":0.0027,"redis_shared_state_read_bytes":6,"redis_shared_state_write_bytes":838,"db_count":22,"db_write_count":6,"db_cached_count":2,"db_replica_count":0,"db_primary_count":22,"db_main_count":22,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":2,"db_main_cached_count":2,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.019,"db_main_duration_s":0.019,"db_main_replica_duration_s":0.0,"cpu_s":0.097578,"pid":31579,"correlation_id":"01G5EFEY41PBS168Q2EDKJAA9B","meta.user":"dummy_username","meta.project":"commerce-prod/customer-website-service","meta.root_namespace":"commerce-prod","meta.client_id":"user/3421","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","content_length":"206","request_urgency":"default","target_duration_s":1}

Expected Behaviour scenario

——Request 1————

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/service_measurement.log
602:{"severity":"INFO","time":"2022-06-13T12:08:03.068Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","message":"Optimistic Lock released with retries","name":"ci_stage_set_status","retries":1,"time_s":0.02481628954410553}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/application_json.log
7515:{"severity":"ERROR","time":"2022-06-13T12:08:03.038Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","message":"Cannot obtain an exclusive lease for ci/pipeline_processing/atomic_processing_service::pipeline_id:174934. There must be another instance already in execution."}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/api_json.log
711:{"time":"2022-06-13T12:08:03.027Z","severity":"INFO","duration_s":0.19755,"db_duration_s":0.02504,"view_duration_s":0.17251,"status":201,"method":"POST","path":"/api/v4/projects/mobile%2Fios%2Fns-for-ios/statuses/1117c60e08291f5e99e4d143d43393e4780b9fc7","params":[{"key":"state","value":"running"},{"key":"name","value":"Quick"},{"key":"target_url","value":"https://teamcity_host/viewLog.html?buildId=11630080&buildTypeId=Mobile_IPhone_QuickNew"},{"key":"description","value":"[FILTERED]"},{"key":"ref","value":"MOBK-2389_Qa_fix_testcreateexpensereportfromexpenselog_multiple_tapping_on_same_add_in_machine"}],"host":"dummy_host","remote_ip":"192.168.0.2, 127.0.0.1","ua":"TeamCity Server 2021.2.3 (build 99711)","route":"/api/:version/projects/:id/statuses/:sha","user_id":179,"username":"dummy_username","queue_duration_s":0.012532,"gitaly_calls":6,"gitaly_duration_s":0.075031,"redis_calls":8,"redis_duration_s":0.002443,"redis_read_bytes":586,"redis_write_bytes":5123,"redis_cache_calls":5,"redis_cache_duration_s":0.001351,"redis_cache_read_bytes":454,"redis_cache_write_bytes":967,"redis_queues_read_bytes":126,"redis_queues_write_bytes":3638,"redis_shared_state_calls":3,"redis_shared_state_duration_s":0.001092,"redis_shared_state_read_bytes":6,"redis_shared_state_write_bytes":518,"db_count":28,"db_write_count":11,"db_cached_count":2,"db_replica_count":0,"db_primary_count":28,"db_main_count":28,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":2,"db_main_cached_count":2,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.025,"db_main_duration_s":0.025,"db_main_replica_duration_s":0.0,"cpu_s":0.113266,"pid":31579,"correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","content_length":"296","request_urgency":"default","target_duration_s":1}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/gitaly.log
3075:time="2022-06-13T12:08:02.865Z" level=info msg="finished unary call with code OK" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=FindCommit grpc.request.deadline="2022-06-13T05:08:32.061" grpc.request.fullMethod=/gitaly.CommitService/FindCommit grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=174 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=308 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:02.861" grpc.time_ms=3.487 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3076:time="2022-06-13T12:08:02.892Z" level=info msg="finished unary call with code OK" command.count=1 command.cpu_time_ms=2 command.inblock=0 command.majflt=0 command.maxrss=416392 command.minflt=157 command.oublock=0 command.real_time_ms=3 command.system_time_ms=2 command.user_time_ms=0 correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=RefExists grpc.request.deadline="2022-06-13T05:08:12.008" grpc.request.fullMethod=/gitaly.RefService/RefExists grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=191 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=0 grpc.service=gitaly.RefService grpc.start_time="2022-06-13T05:08:02.888" grpc.time_ms=3.21 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3077:time="2022-06-13T12:08:02.922Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.deadline_type=none grpc.meta.method_type=bidi_stream grpc.method=ReferenceTransactionHook grpc.request.fullMethod=/gitaly.HookService/ReferenceTransactionHook grpc.request.glProjectPath= grpc.request.glRepository= grpc.request.payload_bytes=2520 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=2 grpc.service=gitaly.HookService grpc.start_time="2022-06-13T05:08:02.921" grpc.time_ms=0.273 peer.address=@ pid=6707 span.kind=server system=grpc
3078:time="2022-06-13T12:08:02.947Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.deadline_type=none grpc.meta.method_type=bidi_stream grpc.method=ReferenceTransactionHook grpc.request.fullMethod=/gitaly.HookService/ReferenceTransactionHook grpc.request.glProjectPath= grpc.request.glRepository= grpc.request.payload_bytes=2522 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=2 grpc.service=gitaly.HookService grpc.start_time="2022-06-13T05:08:02.947" grpc.time_ms=0.153 peer.address=@ pid=6707 span.kind=server system=grpc
3079:time="2022-06-13T12:08:02.951Z" level=info msg="diskcache state change" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS diskcache=c583f984-bf3f-419d-8384-4c33734929d0 grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=WriteRef grpc.request.deadline="2022-06-13T05:08:12.003" grpc.request.fullMethod=/gitaly.RepositoryService/WriteRef grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.service=gitaly.RepositoryService grpc.start_time="2022-06-13T05:08:02.893" peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3080:time="2022-06-13T12:08:02.951Z" level=info msg="finished unary call with code OK" command.count=1 command.cpu_time_ms=81 command.inblock=0 command.majflt=0 command.maxrss=416392 command.minflt=5519 command.oublock=8 command.real_time_ms=55 command.system_time_ms=42 command.user_time_ms=38 correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=WriteRef grpc.request.deadline="2022-06-13T05:08:12.003" grpc.request.fullMethod=/gitaly.RepositoryService/WriteRef grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=233 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=0 grpc.service=gitaly.RepositoryService grpc.start_time="2022-06-13T05:08:02.893" grpc.time_ms=57.974 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3081:time="2022-06-13T12:08:02.953Z" level=info msg="finished unary call with code OK" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=FindCommit grpc.request.deadline="2022-06-13T05:08:32.053" grpc.request.fullMethod=/gitaly.CommitService/FindCommit grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=174 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=0 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:02.953" grpc.time_ms=0.221 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3082:time="2022-06-13T12:08:03.015Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=server_stream grpc.method=ListCommitsByOid grpc.request.deadline="2022-06-13T05:08:33.014" grpc.request.fullMethod=/gitaly.CommitService/ListCommitsByOid grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=174 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=308 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:03.014" grpc.time_ms=0.398 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username
3083:time="2022-06-13T12:08:03.017Z" level=info msg="finished streaming call with code OK" correlation_id=01G5EFDEZZJ4NDVW5T5CHH5SYS grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=server_stream grpc.method=ListCommitsByRefName grpc.request.deadline="2022-06-13T05:08:33.017" grpc.request.fullMethod=/gitaly.CommitService/ListCommitsByRefName grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=228 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=407 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:03.017" grpc.time_ms=0.606 peer.address=@ pid=6707 remote_ip=192.168.0.2 span.kind=server system=grpc username=dummy_username


gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/sidekiq.log
7723:{"severity":"INFO","time":"2022-06-13T12:08:03.002Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174934"],"class":"PipelineProcessWorker","jid":"9b09997c6f6104bc81a0dab9","created_at":"2022-06-13T12:08:02.998Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:c10b8ab5bbc3ebbbb26a987750186eb2c2646b31744ddeb52e85927998c6916f","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.000Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-9b09997c6f6104bc81a0dab9: start","job_status":"start","scheduling_latency_s":0.001647}
7724:{"severity":"INFO","time":"2022-06-13T12:08:03.011Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174934"],"class":"PipelineProcessWorker","jid":"3a3e927dc830a725de2422eb","created_at":"2022-06-13T12:08:03.007Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:c10b8ab5bbc3ebbbb26a987750186eb2c2646b31744ddeb52e85927998c6916f","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.008Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-3a3e927dc830a725de2422eb: start","job_status":"start","scheduling_latency_s":0.002076}
7725:{"severity":"INFO","time":"2022-06-13T12:08:03.013Z","retry":3,"queue":"pipeline_processing:stage_update","version":0,"queue_namespace":"pipeline_processing","args":["194192"],"class":"StageUpdateWorker","jid":"e6882980b6c509784297d040","created_at":"2022-06-13T12:08:03.010Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:stage_update:b4618da7b0e9ec578f32e294cc6136e460d8b9fbadfdaba78c9c28a6aece0665","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.011Z","job_size_bytes":8,"pid":11428,"message":"StageUpdateWorker JID-e6882980b6c509784297d040: start","job_status":"start","scheduling_latency_s":0.002016}
7726:{"severity":"INFO","time":"2022-06-13T12:08:03.040Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174934"],"class":"PipelineProcessWorker","jid":"3a3e927dc830a725de2422eb","created_at":"2022-06-13T12:08:03.007Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:c10b8ab5bbc3ebbbb26a987750186eb2c2646b31744ddeb52e85927998c6916f","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.008Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-3a3e927dc830a725de2422eb: done: 0.029982 sec","job_status":"done","scheduling_latency_s":0.002076,"redis_calls":2,"redis_duration_s":0.003974,"redis_read_bytes":10,"redis_write_bytes":506,"redis_queues_calls":1,"redis_queues_duration_s":0.000905,"redis_queues_read_bytes":10,"redis_queues_write_bytes":370,"redis_shared_state_calls":1,"redis_shared_state_duration_s":0.003069,"redis_shared_state_write_bytes":136,"db_count":2,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":2,"db_main_count":2,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.007,"db_main_duration_s":0.007,"db_main_replica_duration_s":0.0,"cpu_s":0.006024,"duration_s":0.029982,"completed_at":"2022-06-13T12:08:03.040Z","load_balancing_strategy":"primary","db_duration_s":0.007228}
7727:{"severity":"INFO","time":"2022-06-13T12:08:03.069Z","retry":3,"queue":"pipeline_processing:stage_update","version":0,"queue_namespace":"pipeline_processing","args":["194192"],"class":"StageUpdateWorker","jid":"e6882980b6c509784297d040","created_at":"2022-06-13T12:08:03.010Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:stage_update:b4618da7b0e9ec578f32e294cc6136e460d8b9fbadfdaba78c9c28a6aece0665","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.011Z","job_size_bytes":8,"pid":11428,"message":"StageUpdateWorker JID-e6882980b6c509784297d040: done: 0.055362 sec","job_status":"done","scheduling_latency_s":0.002016,"redis_calls":1,"redis_duration_s":0.00023,"redis_read_bytes":10,"redis_write_bytes":362,"redis_queues_calls":1,"redis_queues_duration_s":0.00023,"redis_queues_read_bytes":10,"redis_queues_write_bytes":362,"db_count":8,"db_write_count":3,"db_cached_count":0,"db_replica_count":0,"db_primary_count":8,"db_main_count":8,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.034,"db_main_duration_s":0.034,"db_main_replica_duration_s":0.0,"cpu_s":0.016939,"duration_s":0.055362,"completed_at":"2022-06-13T12:08:03.069Z","load_balancing_strategy":"primary","db_duration_s":0.033125}
7728:{"severity":"INFO","time":"2022-06-13T12:08:03.088Z","retry":3,"queue":"pipeline_hooks:pipeline_hooks","version":0,"queue_namespace":"pipeline_hooks","args":["174934"],"class":"PipelineHooksWorker","jid":"c357418416fe6aa532824500","created_at":"2022-06-13T12:08:03.055Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"PipelineProcessWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"delayed","wal_locations":{},"idempotency_key":"resque:gitlab:duplicate:pipeline_hooks:pipeline_hooks:4cffe72508e500a7e653462eb0ffb509bdb89b62b62b6005d44bc08d0b8e87df","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.082Z","job_size_bytes":8,"pid":11428,"message":"PipelineHooksWorker JID-c357418416fe6aa532824500: start","job_status":"start","scheduling_latency_s":0.00586}
7729:{"severity":"INFO","time":"2022-06-13T12:08:03.174Z","retry":3,"queue":"pipeline_default:pipeline_metrics","version":0,"queue_namespace":"pipeline_default","args":["174934"],"class":"PipelineMetricsWorker","jid":"56450a136ea22727e1ea8543","created_at":"2022-06-13T12:08:03.159Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"PipelineProcessWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_default:pipeline_metrics:0c00ab87ef6ecd9b7029f345f624efec70649de42786441ec10cc8333c673166","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.160Z","job_size_bytes":8,"pid":11428,"message":"PipelineMetricsWorker JID-56450a136ea22727e1ea8543: start","job_status":"start","scheduling_latency_s":0.013379}
7731:{"severity":"INFO","time":"2022-06-13T12:08:03.214Z","retry":3,"queue":"pipeline_default:pipeline_metrics","version":0,"queue_namespace":"pipeline_default","args":["174934"],"class":"PipelineMetricsWorker","jid":"56450a136ea22727e1ea8543","created_at":"2022-06-13T12:08:03.159Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"PipelineProcessWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_default:pipeline_metrics:0c00ab87ef6ecd9b7029f345f624efec70649de42786441ec10cc8333c673166","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.160Z","job_size_bytes":8,"pid":11428,"message":"PipelineMetricsWorker JID-56450a136ea22727e1ea8543: done: 0.04035 sec","job_status":"done","scheduling_latency_s":0.013379,"redis_calls":1,"redis_duration_s":0.002186,"redis_read_bytes":10,"redis_write_bytes":364,"redis_queues_calls":1,"redis_queues_duration_s":0.002186,"redis_queues_read_bytes":10,"redis_queues_write_bytes":364,"db_count":3,"db_write_count":1,"db_cached_count":0,"db_replica_count":0,"db_primary_count":3,"db_main_count":3,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.019,"db_main_duration_s":0.019,"db_main_replica_duration_s":0.0,"cpu_s":0.006079,"duration_s":0.04035,"completed_at":"2022-06-13T12:08:03.214Z","load_balancing_strategy":"primary","db_duration_s":0.019018}
7732:{"severity":"INFO","time":"2022-06-13T12:08:03.227Z","retry":0,"queue":"file_hook","version":0,"class":"FileHookWorker","args":["/home/git/gitlab/file_hooks/merge_hook.py","[FILTERED]"],"jid":"4f9a77996d52bbb09e1204b5","created_at":"2022-06-13T12:08:03.216Z","enqueued_at":"2022-06-13T12:08:03.217Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"PipelineHooksWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"integrations","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:file_hook:6261c3b205625b20aab1c05ba1f1bcef38db6cae75adf77d10d562eabf9a406a","size_limiter":"validated","job_size_bytes":1710,"pid":11428,"message":"FileHookWorker JID-4f9a77996d52bbb09e1204b5: start","job_status":"start","scheduling_latency_s":0.00968}
7733:{"severity":"INFO","time":"2022-06-13T12:08:03.234Z","retry":3,"queue":"pipeline_hooks:pipeline_hooks","version":0,"queue_namespace":"pipeline_hooks","args":["174934"],"class":"PipelineHooksWorker","jid":"c357418416fe6aa532824500","created_at":"2022-06-13T12:08:03.055Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"PipelineProcessWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"delayed","wal_locations":{},"idempotency_key":"resque:gitlab:duplicate:pipeline_hooks:pipeline_hooks:4cffe72508e500a7e653462eb0ffb509bdb89b62b62b6005d44bc08d0b8e87df","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.082Z","job_size_bytes":8,"pid":11428,"message":"PipelineHooksWorker JID-c357418416fe6aa532824500: done: 0.146358 sec","job_status":"done","scheduling_latency_s":0.00586,"rugged_calls":1,"rugged_duration_s":0.001932,"redis_calls":6,"redis_duration_s":0.008256,"redis_read_bytes":794,"redis_write_bytes":3315,"redis_cache_calls":5,"redis_cache_duration_s":0.005402,"redis_cache_read_bytes":742,"redis_cache_write_bytes":275,"redis_queues_calls":1,"redis_queues_duration_s":0.002854,"redis_queues_read_bytes":52,"redis_queues_write_bytes":3040,"db_count":14,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":14,"db_main_count":14,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.076,"db_main_duration_s":0.076,"db_main_replica_duration_s":0.0,"cpu_s":0.043601,"duration_s":0.146358,"completed_at":"2022-06-13T12:08:03.234Z","load_balancing_strategy":"primary_no_wal","db_duration_s":0.075212}
7734:{"severity":"INFO","time":"2022-06-13T12:08:03.238Z","retry":3,"queue":"pipeline_processing:pipeline_process","version":0,"queue_namespace":"pipeline_processing","args":["174934"],"class":"PipelineProcessWorker","jid":"9b09997c6f6104bc81a0dab9","created_at":"2022-06-13T12:08:02.998Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"192.168.0.2","meta.feature_category":"continuous_integration","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:pipeline_processing:pipeline_process:c10b8ab5bbc3ebbbb26a987750186eb2c2646b31744ddeb52e85927998c6916f","size_limiter":"validated","enqueued_at":"2022-06-13T12:08:03.000Z","job_size_bytes":8,"pid":11428,"message":"PipelineProcessWorker JID-9b09997c6f6104bc81a0dab9: done: 0.236028 sec","job_status":"done","scheduling_latency_s":0.001647,"rugged_calls":3,"rugged_duration_s":0.018652,"redis_calls":14,"redis_duration_s":0.014666,"redis_read_bytes":2259,"redis_write_bytes":5112,"redis_cache_calls":11,"redis_cache_duration_s":0.009583,"redis_cache_read_bytes":2135,"redis_cache_write_bytes":630,"redis_queues_calls":1,"redis_queues_duration_s":0.001276,"redis_queues_read_bytes":94,"redis_queues_write_bytes":2717,"redis_shared_state_calls":2,"redis_shared_state_duration_s":0.003807,"redis_shared_state_read_bytes":30,"redis_shared_state_write_bytes":1765,"db_count":30,"db_write_count":7,"db_cached_count":1,"db_replica_count":0,"db_primary_count":30,"db_main_count":30,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":1,"db_main_cached_count":1,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.107,"db_main_duration_s":0.107,"db_main_replica_duration_s":0.0,"cpu_s":0.117799,"duration_s":0.236028,"completed_at":"2022-06-13T12:08:03.238Z","load_balancing_strategy":"primary","db_duration_s":0.10558}
7735:{"severity":"INFO","time":"2022-06-13T12:08:03.423Z","retry":0,"queue":"file_hook","version":0,"class":"FileHookWorker","args":["/home/git/gitlab/file_hooks/merge_hook.py","[FILTERED]"],"jid":"4f9a77996d52bbb09e1204b5","created_at":"2022-06-13T12:08:03.216Z","enqueued_at":"2022-06-13T12:08:03.217Z","correlation_id":"01G5EFDEZZJ4NDVW5T5CHH5SYS","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"PipelineHooksWorker","meta.remote_ip":"192.168.0.2","meta.feature_category":"integrations","worker_data_consistency":"always","idempotency_key":"resque:gitlab:duplicate:file_hook:6261c3b205625b20aab1c05ba1f1bcef38db6cae75adf77d10d562eabf9a406a","size_limiter":"validated","job_size_bytes":1710,"pid":11428,"message":"FileHookWorker JID-4f9a77996d52bbb09e1204b5: done: 0.195572 sec","job_status":"done","scheduling_latency_s":0.00968,"redis_calls":1,"redis_duration_s":0.000417,"redis_read_bytes":10,"redis_write_bytes":316,"redis_queues_calls":1,"redis_queues_duration_s":0.000417,"redis_queues_read_bytes":10,"redis_queues_write_bytes":316,"db_count":0,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":0,"db_main_count":0,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.0,"db_main_duration_s":0.0,"db_main_replica_duration_s":0.0,"cpu_s":0.00406,"duration_s":0.195572,"completed_at":"2022-06-13T12:08:03.423Z","load_balancing_strategy":"primary","db_duration_s":0.0}

——Request 2————

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/gitlab/api_json.log
761:{"time":"2022-06-13T12:08:09.624Z","severity":"INFO","duration_s":0.07077,"db_duration_s":0.00955,"view_duration_s":0.06122,"status":400,"method":"POST","path":"/api/v4/projects/mobile%2Fios%2Fns-for-ios/statuses/1117c60e08291f5e99e4d143d43393e4780b9fc7","params":[{"key":"state","value":"running"},{"key":"name","value":"Quick"},{"key":"target_url","value":"https://teamcity_host/viewLog.html?buildId=11630080&buildTypeId=Mobile_IPhone_QuickNew"},{"key":"description","value":"[FILTERED]"},{"key":"ref","value":"MOBK-2389_Qa_fix_testcreateexpensereportfromexpenselog_multiple_tapping_on_same_add_in_machine"}],"host":"dummy_host","remote_ip":"10.41.11.84, 127.0.0.1","ua":"TeamCity Server 2021.2.3 (build 99711)","route":"/api/:version/projects/:id/statuses/:sha","user_id":179,"username":"dummy_username","api_error":["{\"message\":\"Cannot transition status via :run from :running (Reason(s): Status cannot transition via \\\"run\\\")\"}"],"queue_duration_s":0.010334,"gitaly_calls":1,"gitaly_duration_s":0.005346,"redis_calls":7,"redis_duration_s":0.002231,"redis_read_bytes":563,"redis_write_bytes":1086,"redis_cache_calls":4,"redis_cache_duration_s":0.001145,"redis_cache_read_bytes":561,"redis_cache_write_bytes":742,"redis_shared_state_calls":3,"redis_shared_state_duration_s":0.001086,"redis_shared_state_read_bytes":2,"redis_shared_state_write_bytes":344,"db_count":10,"db_write_count":0,"db_cached_count":0,"db_replica_count":0,"db_primary_count":10,"db_main_count":10,"db_main_replica_count":0,"db_replica_cached_count":0,"db_primary_cached_count":0,"db_main_cached_count":0,"db_main_replica_cached_count":0,"db_replica_wal_count":0,"db_primary_wal_count":0,"db_main_wal_count":0,"db_main_replica_wal_count":0,"db_replica_wal_cached_count":0,"db_primary_wal_cached_count":0,"db_main_wal_cached_count":0,"db_main_replica_wal_cached_count":0,"db_replica_duration_s":0.0,"db_primary_duration_s":0.01,"db_main_duration_s":0.01,"db_main_replica_duration_s":0.0,"cpu_s":0.06488,"pid":21379,"correlation_id":"01G5EFDNJ5FD0PWJR6J433DX56","meta.user":"dummy_username","meta.project":"mobile/ios/ns-for-ios","meta.root_namespace":"mobile","meta.client_id":"user/179","meta.caller_id":"POST /api/:version/projects/:id/statuses/:sha","meta.remote_ip":"10.41.11.84","meta.feature_category":"continuous_integration","content_length":"296","request_urgency":"default","target_duration_s":1}

gitlabsos.e1cfe37efcf0_20220613051526/var/log/gitlab/supervisor/gitaly.log
3250:time="2022-06-13T12:08:09.588Z" level=info msg="finished unary call with code OK" correlation_id=01G5EFDNJ5FD0PWJR6J433DX56 grpc.code=OK grpc.meta.auth_version=v2 grpc.meta.client_name=gitlab-web grpc.meta.deadline_type=regular grpc.meta.method_type=unary grpc.method=FindCommit grpc.request.deadline="2022-06-13T05:08:39.084" grpc.request.fullMethod=/gitaly.CommitService/FindCommit grpc.request.glProjectPath=mobile/ios/ns-for-ios grpc.request.glRepository=project-549 grpc.request.payload_bytes=174 grpc.request.repoPath=@hashed/06/88/068814875fcdfb8faf539ef43cf5d109a22b7cfd28770e90b00be8c48bfc722f.git grpc.request.repoStorage=default grpc.response.payload_bytes=308 grpc.service=gitaly.CommitService grpc.start_time="2022-06-13T05:08:09.584" grpc.time_ms=3.545 peer.address=@ pid=6707 remote_ip=10.41.11.84 span.kind=server system=grpc username=dummy_username

Output of checks

Results of GitLab environment info

NAME="Ubuntu" VERSION="20.04.4 LTS (Focal Fossa)"

Results of GitLab application Check

Gitlab 14.9.3 from Source.

RCA & Possible fixes

This is a race-condition. Here's what's happening:

Request 1: Calls find_or_initialize_by → finds nothing, creates new job object (not saved yet)
Request 2: Calls find_or_initialize_by → finds nothing (because Request 1 hasn't saved yet), creates new job object
Request 1: Saves the job via apply_job_state! → job exists in DB
Request 2: Saves the job → DUPLICATE!

The lock doesn't help because both requests get past find_or_initialize_by before either has saved to the database. The fix should be to use proper duplicate handling like a lock and upsert.

We should also consider using database constraints to prevents duplicates as well, although that may be tricky on p_ci_builds.

Edited Aug 12, 2025 by 🤖 GitLab Bot 🤖