Delayed job should retry only once (!60635) · Merge requests · GitLab.org / GitLab

Nikola Milojevic requested to merge sidekiq-server-middleware-fix into master Apr 29, 2021

What does this MR do?

Screenshots (strongly suggested)

https://github.com/mperham/sidekiq/blob/master/lib/sidekiq/job_retry.rb#L152-L158 It seems that when the first exception is raised, that retry_count is still nil. The retry mechanism will set ti to 0, and continue counting on each retry.

This MR will retry the job only first time if the job['retry_count'] is not set

Does this MR meet the acceptance criteria?

Scheduled

{
   "severity":"INFO",
   "time":"2021-04-29T14:59:07.929Z",
   "class":"BuildHooksWorker",
   "args":[
      "0"
   ],
   "retry":3,
   "queue":"pipeline_hooks:build_hooks",
   "backtrace":true,
   "version":0,
   "queue_namespace":"pipeline_hooks",
   "jid":"bb727fe83549ead434ef902c",
   "created_at":"2021-04-29T14:59:07.923Z",
   "correlation_id":"021697061b3f1f2d77378ad1896cf24a",
   "worker_data_consistency":"delayed",
   "database_replica_location":null,
   "enqueued_at":"2021-04-29T14:59:07.927Z",
   "pid":69296,
   "message":"BuildHooksWorker JID-bb727fe83549ead434ef902c: start",
   "job_status":"start",
   "scheduling_latency_s":0.001175
}

Executed 1st time - Delayed

{
   "severity":"WARN",
   "time":"2021-04-29T14:59:08.099Z",
   "class":"BuildHooksWorker",
   "args":[
      "0"
   ],
   "retry":3,
   "queue":"pipeline_hooks:build_hooks",
   "backtrace":true,
   "version":0,
   "queue_namespace":"pipeline_hooks",
   "jid":"bb727fe83549ead434ef902c",
   "created_at":"2021-04-29T14:59:07.923Z",
   "correlation_id":"021697061b3f1f2d77378ad1896cf24a",
   "worker_data_consistency":"delayed",
   "database_replica_location":null,
   "enqueued_at":"2021-04-29T14:59:07.927Z",
   "pid":69296,
   "message":"BuildHooksWorker JID-bb727fe83549ead434ef902c: fail: 0.170363 sec",
   "job_status":"fail",
   "scheduling_latency_s":0.001175,
   "job_size_bytes":365,
   "cpu_s":0.000461,
   "db_count":0,
   "db_write_count":0,
   "db_cached_count":0,
   "db_replica_count":0,
   "db_replica_cached_count":0,
   "db_replica_wal_count":0,
   "db_primary_count":0,
   "db_primary_cached_count":0,
   "db_primary_wal_count":0,
   "duration_s":0.170363,
   "completed_at":"2021-04-29T14:59:08.099Z",
   "error_message":"Sidekiq job BuildHooksWorker JID-bb727fe83549ead434ef902c couldn't use the replica.  Replica was not up to date.",
   "error_class":"Gitlab::Database::LoadBalancing::SidekiqServerMiddleware::JobReplicaNotUpToDate",
   "error_backtrace":[
      "lib/gitlab/sidekiq_middleware/instrumentation_logger.rb:27:in `call'",
      "lib/gitlab/sidekiq_middleware/batch_loader.rb:7:in `call'",
      "lib/gitlab/sidekiq_middleware/extra_done_log_metadata.rb:7:in `call'",
      "lib/gitlab/sidekiq_middleware/request_store_middleware.rb:10:in `block in call'",
      "lib/gitlab/with_request_store.rb:17:in `enabling_request_store'",
      "lib/gitlab/with_request_store.rb:10:in `with_request_store'",
      "lib/gitlab/sidekiq_middleware/request_store_middleware.rb:9:in `call'",
      "lib/gitlab/sidekiq_middleware/server_metrics.rb:25:in `block in call'",
      "lib/gitlab/sidekiq_middleware/server_metrics.rb:48:in `block in instrument'",
      "lib/gitlab/metrics/background_transaction.rb:30:in `run'",
      "lib/gitlab/sidekiq_middleware/server_metrics.rb:48:in `instrument'",
      "ee/lib/ee/gitlab/sidekiq_middleware/server_metrics.rb:17:in `instrument'",
      "lib/gitlab/sidekiq_middleware/server_metrics.rb:24:in `call'",
      "lib/gitlab/sidekiq_middleware/monitor.rb:8:in `block in call'",
      "lib/gitlab/sidekiq_daemon/monitor.rb:49:in `within_job'",
      "lib/gitlab/sidekiq_middleware/monitor.rb:7:in `call'",
      "lib/gitlab/sidekiq_logging/structured_logger.rb:19:in `call'"
   ],
   "db_duration_s":0.0
}

Rescheduled

{
   "severity":"INFO",
   "time":"2021-04-29T14:59:34.884Z",
   "class":"BuildHooksWorker",
   "args":[
      "0"
   ],
   "retry":3,
   "queue":"pipeline_hooks:build_hooks",
   "backtrace":true,
   "version":0,
   "queue_namespace":"pipeline_hooks",
   "jid":"bb727fe83549ead434ef902c",
   "created_at":"2021-04-29T14:59:07.923Z",
   "correlation_id":"6b4ef3f9770a0791155b8f0d541eea1d",
   "worker_data_consistency":"delayed",
   "database_replica_location":null,
   "enqueued_at":"2021-04-29T14:59:34.882Z",
   "failed_at":"2021-04-29T14:59:08.098Z",
   "retry_count":0,
   "uber-trace-id":"487a125d3afe31f8:487a125d3afe31f8:0:1",
   "pid":69296,
   "message":"BuildHooksWorker JID-bb727fe83549ead434ef902c: start",
   "job_status":"start",
   "scheduling_latency_s":0.002487,
   "job_size_bytes":8465
}

Executed 2nd time

{
   "severity":"INFO",
   "time":"2021-04-29T14:59:35.046Z",
   "class":"BuildHooksWorker",
   "args":[
      "0"
   ],
   "retry":3,
   "queue":"pipeline_hooks:build_hooks",
   "backtrace":true,
   "version":0,
   "queue_namespace":"pipeline_hooks",
   "jid":"bb727fe83549ead434ef902c",
   "created_at":"2021-04-29T14:59:07.923Z",
   "correlation_id":"6b4ef3f9770a0791155b8f0d541eea1d",
   "worker_data_consistency":"delayed",
   "database_replica_location":null,
   "enqueued_at":"2021-04-29T14:59:34.882Z",
   "failed_at":"2021-04-29T14:59:08.098Z",
   "retry_count":0,
   "uber-trace-id":"487a125d3afe31f8:487a125d3afe31f8:0:1",
   "pid":69296,
   "message":"BuildHooksWorker JID-bb727fe83549ead434ef902c: done: 0.16151 sec",
   "job_status":"done",
   "scheduling_latency_s":0.002487,
   "job_size_bytes":8465,
   "cpu_s":0.002695,
   "db_count":1,
   "db_write_count":0,
   "db_cached_count":0,
   "db_replica_count":0,
   "db_replica_cached_count":0,
   "db_replica_wal_count":0,
   "db_primary_count":1,
   "db_primary_cached_count":0,
   "db_primary_wal_count":0,
   "duration_s":0.16151,
   "completed_at":"2021-04-29T14:59:35.045Z",
   "db_duration_s":0.002178
}

Conformity

📋 Does this MR need a changelog?
- I have included a changelog entry.
- I have not included a changelog entry because _____.
Documentation (if required)
Code review guidelines
Merge request performance guidelines
Style guides
Database guides
Separation of EE specific content

Availability and Testing

Review and add/update tests for this feature/bug. Consider all test levels. See the Test Planning Process.
Tested in all supported browsers
Informed Infrastructure department of a default or new setting change, if applicable per definition of done

Security

If this MR contains changes to processing or storing of credentials or tokens, authorization and authentication methods and other items described in the security review guidelines:

Label as security and @ mention @gitlab-com/gl-security/appsec
The MR includes necessary changes to maintain consistency between UI, API, email, or other methods
Security reports checked/validated by a reviewer from the AppSec team

Edited May 06, 2021 by Kamil Trzciński

Delayed job should retry only once