amqp.py warns about deprecated feature

Bug #1745166 reported by Ken Giusti on 2018-01-24
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
oslo.messaging
Low
Ken Giusti

Bug Description

Occasionally this message is logged:

site-packages/amqp/connection.py:292: AMQPDeprecationWarning: The .transport attribute on the connection was accessed before the connection was established. This is supported for now, but will be deprecated in amqp 2.2.0.

We'll need to update the rabbit driver to honor the deprecation. This bug serves as a work item.

Ken Giusti (kgiusti) on 2018-01-24
Changed in oslo.messaging:
assignee: nobody → Ken Giusti (kgiusti)
Ben Nemec (bnemec) on 2018-03-23
Changed in oslo.messaging:
status: New → Confirmed

Fix proposed to branch: master
Review: https://review.openstack.org/580717

Changed in oslo.messaging:
status: Confirmed → In Progress
Ken Giusti (kgiusti) wrote :
Download full text (3.4 KiB)

This is unexpected (at least by moi):

Here's a traceback from the point where the warning log is issued:

File "oslo_messaging/_drivers/base.py", line 304, in _runner
batch_size=self.batch_size, batch_timeout=self.batch_timeout)
   File "oslo_messaging/_drivers/base.py", line 53, in wrapper
   message = func(in_self, timeout=watch.leftover(True))
      File "oslo_messaging/_drivers/amqpdriver.py", line 287, in poll
      self.conn.consume(timeout=min(self._current_timeout, left))
         File "oslo_messaging/_drivers/impl_rabbit.py", line 1070, in consume
         error_callback=_error_callback)
            File "oslo_messaging/_drivers/impl_rabbit.py", line 794, in ensure
            ret, channel = autoretry_method()
               File "/home/kgiusti/work/openstack/oslo.messaging/.tox/py27-func-rabbit/lib/python2.7/site-packages/kombu/connection.py", line 515, in _ensured
               reraise_as_library_errors=False,
                  File "/home/kgiusti/work/openstack/oslo.messaging/.tox/py27-func-rabbit/lib/python2.7/site-packages/kombu/connection.py", line 405, in ensure_connection
                  callback)
                     File "/home/kgiusti/work/openstack/oslo.messaging/.tox/py27-func-rabbit/lib/python2.7/site-packages/kombu/utils/functional.py", line 338, in retry_over_time
                     tts = float(errback(exc, interval_range, retries) if errback
                        File "/home/kgiusti/work/openstack/oslo.messaging/.tox/py27-func-rabbit/lib/python2.7/site-packages/kombu/connection.py", line 393, in on_error
                        errback(exc, interval)
                           File "oslo_messaging/_drivers/impl_rabbit.py", line 740, in on_error
                           info.update(self._get_connection_info())
                              File "oslo_messaging/_drivers/impl_rabbit.py", line 1147, in _get_connection_info
                              if (self.channel and hasattr(self.channel.connection, \'sock\')
                                 File "/home/kgiusti/work/openstack/oslo.messaging/.tox/py27-func-rabbit/lib/python2.7/site-packages/amqp/connection.py", line 733, in sock
                                 return self.transport.sock
                                    File "/home/kgiusti/work/openstack/oslo.messaging/.tox/py27-func-rabbit/lib/python2.7/site-packages/amqp/connection.py", line 317, in transport
                                    self._warn_force_connect('transport')

And the transport property method is:

    @property
    def transport(self):
        if self._transport is None:
            self._warn_force_connect('transport')
            self.connect()
        return self._transport

TL;DR - when an autoretry method fails due to connection or channel error, a log message is issued. The log message includes the client's port (likely invalid at this point), so _get_connection_info() reaches into the bowels of the amqp Channel object attempting to get the local TCP socket. The amqp code keeps the socket in the transport associated with the channel.

...but there is no transport (I'm assuming this is related to the handling of the error), so the amqp library assumes that it needs to...

Read more...

Reviewed: https://review.openstack.org/580717
Committed: https://git.openstack.org/cgit/openstack/oslo.messaging/commit/?id=361669764fd28b4f6d5f1c6896624f2da4ff5151
Submitter: Zuul
Branch: master

commit 361669764fd28b4f6d5f1c6896624f2da4ff5151
Author: Kenneth Giusti <email address hidden>
Date: Fri Jul 6 11:24:40 2018 -0400

    Do not access the connection's socket during error callback

    The _get_connection_info() method attempts to gather debug information
    from the connection, and will reach into the amqp channel to get the
    local (client's) TCP port number via the 'sock' property.

    If _get_connection_info() is called from autoretry's on_error handler
    the 'sock' property notices that the transport is not set and attempts
    to re-connect. amqp has deprecated this reconnect behavior, and in
    any case the client's socket is irrelevant since the connection may
    not be valid at this point.

    Closes-Bug: #1745166
    Change-Id: I3c42f8463605927f6f94d6c3a7f05e584476abc1

Changed in oslo.messaging:
status: In Progress → Fix Released

This issue was fixed in the openstack/oslo.messaging 8.0.0 release.

Reviewed: https://review.openstack.org/605322
Committed: https://git.openstack.org/cgit/openstack/oslo.messaging/commit/?id=34b2931f08df8e435a7e18060ff45c4dca56574a
Submitter: Zuul
Branch: stable/queens

commit 34b2931f08df8e435a7e18060ff45c4dca56574a
Author: Kenneth Giusti <email address hidden>
Date: Fri Jul 6 11:24:40 2018 -0400

    Do not access the connection's socket during error callback

    The _get_connection_info() method attempts to gather debug information
    from the connection, and will reach into the amqp channel to get the
    local (client's) TCP port number via the 'sock' property.

    If _get_connection_info() is called from autoretry's on_error handler
    the 'sock' property notices that the transport is not set and attempts
    to re-connect. amqp has deprecated this reconnect behavior, and in
    any case the client's socket is irrelevant since the connection may
    not be valid at this point.

    Closes-Bug: #1745166
    Change-Id: I3c42f8463605927f6f94d6c3a7f05e584476abc1
    (cherry picked from commit 361669764fd28b4f6d5f1c6896624f2da4ff5151)

tags: added: in-stable-queens

Reviewed: https://review.openstack.org/605324
Committed: https://git.openstack.org/cgit/openstack/oslo.messaging/commit/?id=13759e1254ce33a4c252ae4a548be4a0e4a3b4a7
Submitter: Zuul
Branch: stable/pike

commit 13759e1254ce33a4c252ae4a548be4a0e4a3b4a7
Author: Kenneth Giusti <email address hidden>
Date: Fri Jul 6 11:24:40 2018 -0400

    Do not access the connection's socket during error callback

    The _get_connection_info() method attempts to gather debug information
    from the connection, and will reach into the amqp channel to get the
    local (client's) TCP port number via the 'sock' property.

    If _get_connection_info() is called from autoretry's on_error handler
    the 'sock' property notices that the transport is not set and attempts
    to re-connect. amqp has deprecated this reconnect behavior, and in
    any case the client's socket is irrelevant since the connection may
    not be valid at this point.

    Closes-Bug: #1745166
    Change-Id: I3c42f8463605927f6f94d6c3a7f05e584476abc1
    (cherry picked from commit 361669764fd28b4f6d5f1c6896624f2da4ff5151)

tags: added: in-stable-pike

Reviewed: https://review.openstack.org/605325
Committed: https://git.openstack.org/cgit/openstack/oslo.messaging/commit/?id=d7a7230ff5273f3f16fce4a37c72e8aadd071563
Submitter: Zuul
Branch: stable/ocata

commit d7a7230ff5273f3f16fce4a37c72e8aadd071563
Author: Kenneth Giusti <email address hidden>
Date: Fri Jul 6 11:24:40 2018 -0400

    Do not access the connection's socket during error callback

    The _get_connection_info() method attempts to gather debug information
    from the connection, and will reach into the amqp channel to get the
    local (client's) TCP port number via the 'sock' property.

    If _get_connection_info() is called from autoretry's on_error handler
    the 'sock' property notices that the transport is not set and attempts
    to re-connect. amqp has deprecated this reconnect behavior, and in
    any case the client's socket is irrelevant since the connection may
    not be valid at this point.

    Closes-Bug: #1745166
    Change-Id: I3c42f8463605927f6f94d6c3a7f05e584476abc1
    (cherry picked from commit 361669764fd28b4f6d5f1c6896624f2da4ff5151)

tags: added: in-stable-ocata

This issue was fixed in the openstack/oslo.messaging 5.30.7 release.

This issue was fixed in the openstack/oslo.messaging 5.35.4 release.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers