Worker restarted and visibility timeout not exceeded - task will not be re-executed

[galCohen88]

Checklist

• I have included the output of celery -A proj report in the issue.
  (if you are not able to do this, then at least specify the Celery
  version affected).
• I have verified that the issue exists against the master branch of Celery.

Using 4.2.1

[2018-08-12 08:39:27,855: INFO/MainProcess] Connected to redis://***:6379
[2018-08-12 08:39:27,865: INFO/MainProcess] mingle: searching for neighbors
[2018-08-12 08:39:28,934: INFO/MainProcess] mingle: all alone
[2018-08-12 08:39:28,997: INFO/MainProcess] e547ccc ready.

==> app-celery-stdout---supervisor-er5uXH.log <==

Steps to reproduce

Using redis transport

1. Create new job with acks_late flag as True
2. Use gevent and patch it using monkey.patch_all()
3. Execute the task
4. While task is executed (and visibility_timeout is far from expiry) kill the worker
5. Task is not re-executed after new worker is initiated

Expected behavior

Task should be executed after new worker initiated

Actual behaviour

Task is not re-executed

The problem is that querying unacked_index zset with score timeframe based on visibility_timeout only once (polling loop is disabled when using gevent). Meaning if the visibility_timeout is not expired the task will not be re-executed ever

[auvipy]

thanks!

[vinayinvicible]

Issue described here is nothing specific to gevent.
If the worker gets killed while task is in unacked state, then it is not executed until visibility timeout.

And the patch provided (celery/kombu#905) for this fix is actually causing the following issue.

In an event when a gevent worker is (re)started, it restores all unacked tasks. This includes tasks with ETA.
Tasks with ETA are redelivered multiple times depending on the number of worker (re)starts. And when the ETA arrives same task (same task id) gets executed multiple times at the exact same time.

I suspect #4400, #6358, #6236 and #6229 are because of this patch.

I propose to revert the patch (celery/kombu#1259) since it is causing inconsistent behavior across environments.

To fix the actual issue, we might need a way to differentiate unacked tasks with and without ETA and restore them accordingly.

[fengsi]

I can confirm this. We were using Celery 4.4.7 + gevent + Flower. Duplicate task runs were observed when Flower was enabled (and maybe during scaling-out Celery workers). Downgrading to Celery 4.2.2 and Kombu 4.2.2.post1 worked.

This is a critical bug and it's hard to believe it's even been there for 2 years.

[galCohen88]

At the time, task didn't execute even after visibility timeout was expired, in gevent context. This is an ugly patch - yes, but at least the jobs were re-executed.

Sorry for the trouble

[galCohen88]

@vinayinvicible The only issue that might be related is #6236, since its in gevent context

[alexign]

Duplicate task happened not only if we have ETA task.
I have visibilitytimeout =3600 sес and while been in debug session leave ide for about 12 hours. In the end while i returned to continuing debuging I have for about 12 same tasks %).
Will try to reproduce it with smaller visibility_timeout
Broker manager is Redis

[auvipy]

related celery/kombu#1098 (comment)