#8642 [fedora-messaging] cannot obtain exclusive access to locked queue after Re-registering
Closed: Insufficient data by jpopelka. Opened by jpopelka.

[10:30:48,253 ERROR pika.adapters.twisted_connection] connection_lost: ConnectionLost('Connection lost')
[10:30:48,253 WARNING fedora_messaging.twisted.protocol] The connection to the broker was lost (ConnectionLost('Connection lost')), consumer halted; the connection should restart and consuming will resume.
[10:30:48,259 INFO fedora_messaging.twisted.protocol] Disconnect requested, but AMQP connection already gone
[10:30:48,260 INFO twisted] <twisted.internet.tcp.Connector instance at 0x7f9d7e3ffb90 disconnected IPv4Address(type='TCP', host='rabbitmq.fedoraproject.org', port=5671)> will retry in 2 seconds
[10:30:48,260 INFO twisted] Stopping factory FedoraMessagingFactoryV2(parameters=<URLParameters host=rabbitmq.fedoraproject.org port=5671 virtual_host=/public_pubsub ssl=True>, confirms=True)
[10:30:51,245 INFO twisted] Starting factory FedoraMessagingFactoryV2(parameters=<URLParameters host=rabbitmq.fedoraproject.org port=5671 virtual_host=/public_pubsub ssl=True>, confirms=True)
[10:30:52,609 INFO fedora_messaging.twisted.factory] Re-registering the Consumer(queue=36C4424F-5FA4-4DE1-B898-A05AD6F0CB03, callback=<bound method Consumerino.fedora_messaging_callback of <packit_service_fedmsg.consumer.Consumerino object at 0x7f9d7fb7e6d0>>) consumer
[10:30:53,038 WARNING pika.channel] Received remote Channel.Close (405): "RESOURCE_LOCKED - cannot obtain exclusive access to locked queue '36C4424F-5FA4-4DE1-B898-A05AD6F0CB03' in vhost '/public_pubsub'" on <Channel number=2 OPEN conn=<pika.adapters.twisted_connection._TwistedConnectionAdapter object at 0x7f9d7cb733d0>>
[10:30:53,050 ERROR fedora_messaging.twisted.factory] The connection failed with an unexpected exception; please report this bug: Traceback (most recent call last):
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 1464, in _inlineCallbacks
    status.deferred.errback()
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 501, in errback
    self._startRunCallbacks(fail)
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/usr/lib/python3.7/site-packages/fedora_messaging/twisted/factory.py", line 330, in on_ready_connection_errback
    error.ConnectionLost,
  File "/usr/lib64/python3.7/site-packages/twisted/python/failure.py", line 460, in trap
    self.raiseException()
  File "/usr/lib64/python3.7/site-packages/twisted/python/failure.py", line 488, in raiseException
    raise self.value.with_traceback(self.tb)
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib64/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3.7/site-packages/fedora_messaging/twisted/factory.py", line 321, in on_ready
    yield client.declare_queues([queue])
  File "/usr/lib64/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/lib64/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/lib/python3.7/site-packages/fedora_messaging/twisted/protocol.py", line 539, in declare_queues
    raise BadDeclaration("queue", args, e)
fedora_messaging.exceptions.BadDeclaration: Unable to declare the queue object ({'queue': '36C4424F-5FA4-4DE1-B898-A05AD6F0CB03', 'durable': True, 'auto_delete': True, 'exclusive': True, 'arguments': {}, 'passive': False}) because (405, "RESOURCE_LOCKED - cannot obtain exclusive access to locked queue '36C4424F-5FA4-4DE1-B898-A05AD6F0CB03' in vhost '/public_pubsub'")

I've generated new queue uuid and restarted the consumer, so we don't use that queue anymore.
I just want to know whether there's anything we can do to prevent this from happening again.

Our config:

amqp_url = "amqps://fedora:@rabbitmq.fedoraproject.org/%2Fpublic_pubsub"
[exchanges."amq.topic"]
type = "topic"
durable = true
auto_delete = false
arguments = {}
[exchanges."zmq.topic"]
type = "topic"
durable = true
auto_delete = false
arguments = {}
[queues.uuid]
durable = true
auto_delete = true
exclusive = true
arguments = {}
[[bindings]]
queue = "uuid"
exchange = "amq.topic"
routing_keys = ["org.fedoraproject.prod.copr.build.start", "org.fedoraproject.prod.copr.build.end"]
[[bindings]]
queue = "uuid"
exchange = "zmq.topic"
routing_keys = ["org.fedoraproject.prod.copr.build.start", "org.fedoraproject.prod.copr.build.end"]
[consumer_config]
example_key = "for my consumer"
[qos]
prefetch_size = 0
prefetch_count = 25

Thanks


Looks like a bug to me, because the docs says that setting auto_delete = true for a queue means that "the queue should be deleted once the consumer disconnects", which IMHO did not happen in this case.

maybe setting exclusive = false instead of exclusive = true would help? I really don't know.

That would probably help, but we want to have the queue exclusive - in case someone accidentally run a consumer locally with the same queue uuid.

@abompard can you comment here?

Metadata Update from @kevin:
- Issue priority set to: Waiting on Assignee (was: Needs Review)

@abompard :)

About a month ago, after I had been told that copr now publishes messages directly to fedora-messaging, we removed the zmq.topic exchange, so now we use only the amq.topic exchange.

I haven't seen this issue since then so I can close it and reopen if it happens again.

Metadata Update from @jpopelka:
- Issue close_status updated to: Insufficient data
- Issue status updated to: Closed (was: Open)

Metadata