SuperFetch and Retry Duplicate Jobs

[Anuraj0124]

Hi, we are using SidekiqPro 5.2 with Sidekiq 6.4
The scenario is this:

1. There is a job J1 scheduled in a queue and execution has started on it. (suppose pod running this is P1)

We have implemented Auto-scaling for Sidekiq. This lead to scaling down of the node running the job.

2. P1 is sent a TSTP signal, the pod was quiet and was waiting for jobs to finish
3. Superfetch was initiated
4. But, as J1 was running, it encountered a connection was close error. It failed and in turn spawned a retry job J2
5. We also have a log, after 4, stating ERROR: Unable to remove job from private queue
6. Then a new job got spawned by superfetch (presumably) J3

This is causing duplicate jobs of J1 being running and causing issues.

Why is this happening, or am I doing something wrong?

Logs

INFO 2024-06-25T06:53:45.559046113Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:53:45.558Z pid=1 tid=3mq5 class=KlassName jid=3290909101769904ee4bf709 bid=1HsJcSoUmHiU7g elapsed=1837.136 INFO: done

INFO 2024-06-25T06:43:21.810916382Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:43:21.810Z pid=1 tid=32g5 class=KlassName jid=3290909101769904ee4bf709 bid=1HsJcSoUmHiU7g elapsed=1272.741 INFO: done

INFO 2024-06-25T06:23:08.423018710Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:23:08.422Z pid=1 tid=3mq5 class=KlassName jid=3290909101769904ee4bf709 bid=1HsJcSoUmHiU7g INFO: start

INFO 2024-06-25T06:22:09.069456082Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:22:09.069Z pid=1 tid=32g5 class=KlassName jid=3290909101769904ee4bf709 bid=1HsJcSoUmHiU7g INFO: start

INFO 2024-06-25T06:22:07.097020106Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:22:07.096Z pid=1 tid=32r9 ERROR: Unable to remove job from private queue queue:sq|company-sidekiq-container-6459c5cf8-vlwfq:1:435773d37588|long_task: 0

INFO 2024-06-25T06:22:07.095702470Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:22:07.095Z pid=1 tid=32r9 WARN: NoMethodError: private method `select' called for nil:NilClass

INFO 2024-06-25T06:22:07.095228238Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:22:07.095Z pid=1 tid=32r9 WARN: {"context":"Job raised exception","job":{"retry":true,"queue":"long_task","class":"Sidekiq::Extensions::DelayedClass","args":["some_data"],"display_class":"KlassName","jid":"3290909101769904ee4bf709","created_at":1719295317.9653757,"bid":"1HsJcSoUmHiU7g","apartment":"apartment_name","breadcrumbs":["bread_crumbs"]

INFO 2024-06-25T06:22:07.095154435Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:22:07.094Z pid=1 tid=32r9 class=KlassName jid=3290909101769904ee4bf709 bid=1HsJcSoUmHiU7g elapsed=1208.905 INFO: fail

INFO 2024-06-25T06:22:07.019493968Z [resource.labels.containerName: sidekiq-container] E, [2024-06-25T06:22:07.019328 #1] ERROR -- : [3290909101769904ee4bf709] [40ad1aea] /usr/local/bundle/gems/activesupport-6.1.7/lib/active_support/concurrency/share_lock.rb:187:in `yield_shares'

INFO 2024-06-25T06:22:07.019487275Z [resource.labels.containerName: sidekiq-container] E, [2024-06-25T06:22:07.019289 #1] ERROR -- : [3290909101769904ee4bf709] [40ad1aea] /usr/local/bundle/gems/activesupport-6.1.7/lib/active_support/dependencies/interlock.rb:48:in `block in permit_concurrent_loads'

INFO 2024-06-25T06:22:07.019479492Z [resource.labels.containerName: sidekiq-container] E, [2024-06-25T06:22:07.019246 #1] ERROR -- : [3290909101769904ee4bf709] [40ad1aea] /usr/local/bundle/gems/activerecord-6.1.7/lib/active_record/connection_adapters/postgresql/database_statements.rb:49:in `block (2 levels) in execute'

INFO 2024-06-25T06:22:07.019409479Z [resource.labels.containerName: sidekiq-container] E, [2024-06-25T06:22:07.019194 #1] ERROR -- : [3290909101769904ee4bf709] [40ad1aea] /usr/local/bundle/gems/activerecord-6.1.7/lib/active_record/connection_adapters/postgresql/database_statements.rb:49:in `exec'

INFO 2024-06-25T06:22:07.019387850Z [resource.labels.containerName: sidekiq-container] E, [2024-06-25T06:22:07.019103 #1] ERROR -- : [3290909101769904ee4bf709] [40ad1aea] connection is closed

INFO 2024-06-25T06:21:44.996348240Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:21:44.996Z pid=1 tid=8o9 WARN: Work still in progress [#<struct Sidekiq::Pro::SuperFetch::UnitOfWork queue="queue:long_task", job="{\"retry\":true,\"queue\":\"long_task\",\"class\":\"Sidekiq::Extensions::DelayedClass\",\"args\":[\"someData\"],\"display_class\":\"KlassName\",\"jid\":\"42d4339f76d5d17840e907dc\",\"created_at\":1719294760.9537988,\"bid\":\"w6RX8JoFFJ2ECw\",\"newrelic\":{"new_relic_related_data"},\"apartment\":\"apartment_name\",\"breadcrumbs\":["bread_crumbs"]

INFO 2024-06-25T06:01:58.189757053Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:01:58.189Z pid=1 tid=32r9 class=KlassName jid=3290909101769904ee4bf709 bid=1HsJcSoUmHiU7g INFO: start

INFO 2024-06-25T06:01:58.173156945Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:01:58.172Z pid=1 tid=32r9 class=KlassName jid=087d5119c22052312ad93084 bid=1HsJcSoUmHiU7g elapsed=0.7 INFO: done

INFO 2024-06-25T06:01:57.473386903Z [resource.labels.containerName: sidekiq-container] 2024-06-25T06:01:57.473Z pid=1 tid=32r9 class=KlassName jid=087d5119c22052312ad93084 bid=1HsJcSoUmHiU7g INFO: start

[mperham]

Please give the exact versions. 6.4 and 5.2 are not Sidekiq versions.

[mperham]

Can you upgrade to Sidekiq 6.5 and Pro 5.5? Quite possible this is already fixed.