Kombu: Error 'missing message for exchange `reply.celery.pidbox`' on ping with git package

[Ashish-Bansal]

Hi there!

In attempt to try and fix https://github.com/celery/kombu/issues/1019, I tried installing kombu from master branch.

After installing git package, I tried ping the worker using celery -A app inspect ping, but in the celery logs it prints following message:

[2019-09-27 14:23:13,969: DEBUG/MainProcess] pidbox received method ping() [reply_to:{'exchange': 'reply.celery.pidbox', 'routing_key': '002a0f42-a9a6-33a2-86b6-8587884d26ee'} ti
cket:4d480db3-effd-452d-a72f-b35be19043f4]
[2019-09-27 14:23:13,973: ERROR/MainProcess] Control command error: OperationalError("\nCannot route message for exchange 'reply.celery.pidbox': Table empty or key no longer exis
ts.\nProbably the key ('_kombu.binding.reply.celery.pidbox') has been removed from the Redis database.\n",)
Traceback (most recent call last):
  File "/home/mrphantom/foo/venv/src/kombu/kombu/connection.py", line 439, in _reraise_as_library_errors
    yield
  File "/home/mrphantom/foo/venv/src/kombu/kombu/connection.py", line 518, in _ensured
    return fun(*args, **kwargs)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/messaging.py", line 203, in _publish
    mandatory=mandatory, immediate=immediate,
  File "/home/mrphantom/foo/venv/src/kombu/kombu/transport/virtual/base.py", line 605, in basic_publish
    message, exchange, routing_key, **kwargs
  File "/home/mrphantom/foo/venv/src/kombu/kombu/transport/virtual/exchange.py", line 70, in deliver
    for queue in _lookup(exchange, routing_key):
  File "/home/mrphantom/foo/venv/src/kombu/kombu/transport/redis.py", line 877, in _lookup
    exchange, redis_key))
kombu.exceptions.InconsistencyError:
Cannot route message for exchange 'reply.celery.pidbox': Table empty or key no longer exists.
Probably the key ('_kombu.binding.reply.celery.pidbox') has been removed from the Redis database.

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/mrphantom/foo/venv/lib/python3.6/site-packages/celery/worker/pidbox.py", line 46, in on_message
    self.node.handle_message(body, message)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/pidbox.py", line 145, in handle_message
    return self.dispatch(**body)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/pidbox.py", line 115, in dispatch
    ticket=ticket)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/pidbox.py", line 151, in reply
    serializer=self.mailbox.serializer)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/pidbox.py", line 285, in _publish_reply
    **opts
  File "/home/mrphantom/foo/venv/src/kombu/kombu/messaging.py", line 181, in publish
    exchange_name, declare,
  File "/home/mrphantom/foo/venv/src/kombu/kombu/connection.py", line 551, in _ensured
    errback and errback(exc, 0)
  File "/usr/lib/python3.6/contextlib.py", line 99, in __exit__
    self.gen.throw(type, value, traceback)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/connection.py", line 444, in _reraise_as_library_errors
    sys.exc_info()[2])
  File "/home/mrphantom/foo/venv/lib/python3.6/site-packages/vine/five.py", line 194, in reraise
    raise value.with_traceback(tb)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/connection.py", line 439, in _reraise_as_library_errors
    yield
  File "/home/mrphantom/foo/venv/src/kombu/kombu/connection.py", line 518, in _ensured
    return fun(*args, **kwargs)
  File "/home/mrphantom/foo/venv/src/kombu/kombu/messaging.py", line 203, in _publish
    mandatory=mandatory, immediate=immediate,
  File "/home/mrphantom/foo/venv/src/kombu/kombu/transport/virtual/base.py", line 605, in basic_publish
    message, exchange, routing_key, **kwargs
  File "/home/mrphantom/foo/venv/src/kombu/kombu/transport/virtual/exchange.py", line 70, in deliver
    for queue in _lookup(exchange, routing_key):
  File "/home/mrphantom/foo/venv/src/kombu/kombu/transport/redis.py", line 877, in _lookup
    exchange, redis_key))
kombu.exceptions.OperationalError:
Cannot route message for exchange 'reply.celery.pidbox': Table empty or key no longer exists.
Probably the key ('_kombu.binding.reply.celery.pidbox') has been removed from the Redis database.

Here are filtered out events from the redis's monitor:

1569586993.963900 [0 127.0.0.1:57444] "PING"
1569586993.964485 [0 127.0.0.1:57446] "MULTI"
1569586993.964508 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox"
1569586993.964516 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x163"
1569586993.964523 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x166"
1569586993.964530 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x169"
1569586993.964537 [0 127.0.0.1:57446] "EXEC"
1569586993.964825 [0 127.0.0.1:57446] "SADD" "_kombu.binding.reply.celery.pidbox" "002a0f42-a9a6-33a2-86b6-8587884d26ee\x06\x16\x06\x16002a0f42-a9a6-33a2-86b6-8587884d26ee.reply$
celery.pidbox"
1569586993.968350 [0 127.0.0.1:57448] "PING"
1569586993.968807 [0 127.0.0.1:57450] "PUBLISH" "/0.celery.pidbox" "{\"body\": \"eyJtZXRob2QiOiAicGluZyIsICJhcmd1bWVudHMiOiB7fSwgImRlc3RpbmF0aW9uIjogbnVsbCwgInBhdHRlcm4iOiBudWxs$
CAibWF0Y2hlciI6IG51bGwsICJ0aWNrZXQiOiAiNGQ0ODBkYjMtZWZmZC00NTJkLWE3MmYtYjM1YmUxOTA0M2Y0IiwgInJlcGx5X3RvIjogeyJleGNoYW5nZSI6ICJyZXBseS5jZWxlcnkucGlkYm94IiwgInJvdXRpbmdfa2V5IjogIj$
wMmEwZjQyLWE5YTYtMzNhMi04NmI2LTg1ODc4ODRkMjZlZSJ9fQ==\", \"content-encoding\": \"utf-8\", \"content-type\": \"application/json\", \"headers\": {\"clock\": 1, \"expires\": 156958$
994.1653507}, \"properties\": {\"delivery_mode\": 2, \"delivery_info\": {\"exchange\": \"celery.pidbox\", \"routing_key\": \"\"}, \"priority\": 0, \"body_encoding\": \"base64\",
\"delivery_tag\": \"5958a990-5254-4b94-b48f-7e9bc495cacc\"}}"
1569586993.969251 [0 127.0.0.1:57446] "MULTI"
1569586993.969257 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox"
1569586993.969265 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x163"
1569586993.969272 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x166"
1569586993.969279 [0 127.0.0.1:57446] "LLEN" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x169"
1569586993.969286 [0 127.0.0.1:57446] "EXEC"
1569586993.969563 [0 127.0.0.1:57444] "BRPOP" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x163" "002$
0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x166" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x169" "1"
1569586993.969697 [0 127.0.0.1:57428] "SCARD" "_kombu.binding.reply.celery.pidbox"
1569586993.969851 [0 127.0.0.1:57428] "SISMEMBER" "_kombu.binding.reply.celery.pidbox" "002a0f42-a9a6-33a2-86b6-8587884d26ee\x06\x16\x06\x16002a0f42-a9a6-33a2-86b6-8587884d26ee"
1569586993.973048 [0 127.0.0.1:57452] "PING"
1569586993.973484 [0 127.0.0.1:57454] "SCARD" "_kombu.binding.reply.celery.pidbox"
1569586993.973636 [0 127.0.0.1:57454] "SISMEMBER" "_kombu.binding.reply.celery.pidbox" "002a0f42-a9a6-33a2-86b6-8587884d26ee\x06\x16\x06\x16002a0f42-a9a6-33a2-86b6-8587884d26ee"
1569586993.974307 [0 127.0.0.1:57456] "SREM" "_kombu.binding.celery.pidbox" "\x06\x16\x06\[email protected]"
1569586993.974463 [0 127.0.0.1:57456] "MULTI"
1569586993.974471 [0 127.0.0.1:57456] "DEL" "[email protected]"
1569586993.974490 [0 127.0.0.1:57456] "DEL" "[email protected]\x06\x163"
1569586993.974497 [0 127.0.0.1:57456] "DEL" "[email protected]\x06\x166"
1569586993.974503 [0 127.0.0.1:57456] "DEL" "[email protected]\x06\x169"
1569586993.974510 [0 127.0.0.1:57456] "EXEC"
1569586993.975009 [0 127.0.0.1:57458] "PING"
1569586993.975448 [0 127.0.0.1:57460] "MULTI"
1569586993.975456 [0 127.0.0.1:57460] "LLEN" "[email protected]"
1569586993.975462 [0 127.0.0.1:57460] "LLEN" "[email protected]\x06\x163"
1569586993.975469 [0 127.0.0.1:57460] "LLEN" "[email protected]\x06\x166"
1569586993.975475 [0 127.0.0.1:57460] "LLEN" "[email protected]\x06\x169"
1569586993.975482 [0 127.0.0.1:57460] "EXEC"
1569586993.975735 [0 127.0.0.1:57460] "SADD" "_kombu.binding.celery.pidbox" "\x06\x16\x06\[email protected]"
1569586993.976033 [0 127.0.0.1:57458] "PSUBSCRIBE" "/0.celery.pidbox"
1569586994.170962 [0 127.0.0.1:57446] "SETNX" "unacked_mutex" "71d9eeff-6e46-4e3a-bf79-84085de659ef"
1569586994.171449 [0 127.0.0.1:57446] "TTL" "unacked_mutex"
1569586994.172638 [0 127.0.0.1:57446] "SREM" "_kombu.binding.reply.celery.pidbox" "002a0f42-a9a6-33a2-86b6-8587884d26ee\x06\x16\x06\x16002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.
celery.pidbox"
1569586994.173334 [0 127.0.0.1:57446] "MULTI"
1569586994.173372 [0 127.0.0.1:57446] "DEL" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox"
1569586994.173408 [0 127.0.0.1:57446] "DEL" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x163"
1569586994.173443 [0 127.0.0.1:57446] "DEL" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x166"
1569586994.173476 [0 127.0.0.1:57446] "DEL" "002a0f42-a9a6-33a2-86b6-8587884d26ee.reply.celery.pidbox\x06\x169"
1569586994.173513 [0 127.0.0.1:57446] "EXEC"

Does anyone know what's happening or any lead by which I can debug this out ?

software -> celery:4.3.0 (rhubarb) kombu:4.6.3 py:3.6.7
            billiard:3.6.1.0 redis:3.3.8
platform -> system:Linux arch:64bit, ELF
            kernel version:4.15.0-52-generic imp:CPython
loader   -> celery.loaders.app.AppLoader
settings -> transport:redis results:redis://localhost:6379/0

task_track_started: True
worker_send_task_events: True

Thanks!

[pbasista]

I have experienced a similar behavior and errors with kombu versions 4.6.4 and above when trying to perform the inspect ping operation.

I have tried to bisect the git history between tags 4.6.3 and 4.6.4 and found out that the first commit with which the kombu library fails to work with inspect ping operation is 052f7601d3a1e09263cc0ebda7ef8c16e6b90175. I did not investigate further.

[FelipeEmerim]

Same error happens to me in kombu 4.6.5. I cannot inspect, neither start two celery instances. Falling back to kombu:4.6.3 works for me though.

[jarshwah]

This release needs to be pulled or fixed immediately. Even though the key exists, the format must be different, because 4.6.5 can't read the key. Rolling back to 4.6.4 fixes the problem immediately.

All tasks being published failed with:

Cannot route message for exchange 'default': Table empty or key no longer exists.
Probably the key ('_kombu.binding.default') has been removed from the Redis database.

The key is certainly there, but it can't be read properly.

>>> client.scard("_kombu.binding.default")
1
>>> client.smembers("_kombu.binding.default")
{b'default\x06\x16^default$\x06\x16default'}

Edit: this is the key kombu was TRYING to look for:

default\x06\x16\x06\x16default

[BartlomiejSkwira]

I also have this issue when using Celery 4.3.0 (which has Kombu as a dependency). Downgraded Kombu to 4.6.4 and it works.

[petrprikryl]

I have same error on 4.6.5.

[auvipy]

thanks all for your report. this is going to be handled very soon and with a new release

[auvipy]

https://github.com/celery/kombu/commit/2f6f5f6a5df1cf52bf8fd45ee9fb3c93d793d637 this commit might need to be investigated