Duplicate callback found for Channel.CloseOk

[senseysensor]

Hello, with pika upgrade I began receive such warnings:

WARNING:pika.callback:Duplicate callback found for "54:Channel.CloseOk"

I am not sure what this means and is it bug or not, but before I didn't have such warnings. Maybe it is some implicit callbacks declared in my code? but I don't know where look for them.

thanks.

[gmr]

Which version?

import pika
print pika.__version__

This should not be in 0.9.6p5

[senseysensor]

I have exactly
'0.9.6-pre5'

maybe I did something implicitly? I have already some pika related code in the project, before I tried to use pika 0.9.5, but have never seen such warnings before

[gmr]

No, I know what it is... I had seen it myself, but thought I had fixed it. It's just a warning that the code issues when it notices a duplicate callback and bails on trying to add a new one.

[senseysensor]

Can you please specify, so here is nothing wrong with pika code and it's my fault - I try attach some callback to the same event twice? But why that started since pika update? Before I didn't have such warnings. And why in this case issue is not closed?

[gmr]

This is nothing wrong with your code and it's not a serious problem with Pika. I do wish to correct the behavior and it is on my list of things to address prior to releasing 0.9.6. Basically there is a callback being added in two different locations when you are opening a channel.

It's nothing to worry about, the fact that you are receiving the message indicates that the callback manager is functioning properly and preventing the situation from creating a more serious bug.

This is not closed because I have not had time to trace down where the 2nd callback is being created from and intend to do so once I have the channel unittests fully committed.

[senseysensor]

thanks for reply. And also thanks for your hard work, waiting for release (for now library is very hardly usable)

[shreddd]

Not sure if this is related but I seem to be seeing something strange with closed connections.

Even though I am not explicitly closing my connection, I seem to be seeing this, when I try to reuse an existing connection:

File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 244, in _send_frame
super(BlockingConnection, self)._send_frame(frame_value)

File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/connection.py", line 1304, in _send_frame
raise exceptions.ConnectionClosed

Should I open a new ticket or is this part of the same issue?

[gmr]

Can you send the full traceback?

[shreddd]

Here you go::

Traceback (most recent call last):

  File "/usr/local/lib/python2.7/dist-packages/django/utils/decorators.py", line 25, in _wrapper
    return bound_func(*args, **kwargs)

  File "/kb/deployment/services/cluster_service/cluster_service/decorators.py", line 54, in _wrapped_view
    return view_func(request, *args, **kwargs)

  File "/usr/local/lib/python2.7/dist-packages/django/utils/decorators.py", line 21, in bound_func
    return func(self, *args2, **kwargs2)

  File "/kb/deployment/services/cluster_service/cluster_service/job_service/handlers.py", line 162, in create
    body=app_info_send)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 355, in basic_publish
    (properties, body), False)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 755, in _send_method
    self.connection.send_method(self.channel_number, method_frame, content)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 119, in send_method
    self._send_method(channel_number, method_frame, content)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/connection.py", line 1324, in _send_method
    self._send_frame(frame.Method(channel_number, method_frame))

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 244, in _send_frame
    super(BlockingConnection, self)._send_frame(frame_value)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/connection.py", line 1311, in _send_frame
    self._flush_outbound()

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 204, in _flush_outbound
    if self._handle_write():

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/base_connection.py", line 320, in _handle_write
    return self._handle_error(error)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/base_connection.py", line 264, in _handle_error
    self._handle_disconnect()

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 180, in _handle_disconnect
    self._on_connection_closed(None, True)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 231, in _on_connection_closed
    self._channels[channel]._on_close(method_frame)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 670, in _on_close
    self._send_method(spec.Channel.CloseOk(), None, False)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 755, in _send_method
    self.connection.send_method(self.channel_number, method_frame, content)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 119, in send_method
    self._send_method(channel_number, method_frame, content)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/connection.py", line 1324, in _send_method
    self._send_frame(frame.Method(channel_number, method_frame))

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/adapters/blocking_connection.py", line 244, in _send_frame
    super(BlockingConnection, self)._send_frame(frame_value)

  File "/usr/local/lib/python2.7/dist-packages/pika-0.9.6_pre6-py2.7.egg/pika/connection.py", line 1304, in _send_frame
    raise exceptions.ConnectionClosed

ConnectionClosed

[gmr]

This may be expected behavior or not. This exception is raised when you try and do operations that require the connection to be open.

What I'm trying to figure out from the traceback is if RabbitMQ is closing your connection on publish for some reason, in which case you should get a different exception.

[shreddd]

Couple of additional details - I only see this for SSL connections. Non-SSL connections work fine. Also it seems to work for the first 2 channel.basic_publish() commands and fails on the 3rd.

[gmr]

So it sounds like you're being disconnected, perhaps due to timeout? Might want to tune up the timeout to .5 or 1 and see what behavior you find. You should probably handle the exception and reconnect however, as it looks like you're using it in a Django application, and so you'd want to automatically handle disconnects.

[shreddd]

I will play around with different timeout values. The odd things is that 1. I only see the error for SSL connections. 2. I am not explicitly setting the timeout anywhere. Wondering if something in the SSL code is dropping the connection. Worst case, I can always explicitly set up and tear down the connection before each publish, but I was hoping to avoid the overhead.