Comment 3 for bug 1560097

Revision history for this message
Oleg Bondarev (obondarev) wrote :

Seems like problems with connecting to AMQP in neutron caused timeout for the request in the test. More info below:

Request to add router interface issued at 04:17:19:

2016-03-21 04:17:19 DEBUG (utils) REQ: curl -i https://public.fuel.local:9696/v2.0/routers/e594f584-168b-4ad8-a495-59a76b6f72f5/add_router_interface.json -X PUT -H "User-Agent: python-neutronclient" -H "X-Auth-Token: gAAAAABW73XHffPD-itGuIyKwKR6Me8oMWyNjkfGN0HKifv0Phd2K9ZJbe-kS8Z-YFWvUP6GVQAoNsICNwEICJVjFBqgDZSEtbSttywbSO2vD4wm_pjLJpgMFKGtauwwTtCbS-M0FiXnoJhQlPFpxmrYq0BboaHrVI1I1TxO_GOCmM88hu069dY" -d '{"subnet_id": "0de9368a-24a6-40f5-8038-b7b82bcdc951"}'

Failure at 04:17:39 (after 20 seconds):

2016-03-21 04:17:39 DEBUG (test_mixins) Traceback (most recent call last):
...
    raise exceptions.ConnectionFailed(reason=e)
ConnectionFailed: Connection to neutron failed:

As part of adding router interface neutron server should notify l3 agent.
Corresponding neutron logs (req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 is for adding router interface):

2016-03-21 04:17:20.741 21664 DEBUG oslo.messaging._drivers.impl_rabbit [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] Connecting to AMQP server on 10.109.16.4:5673 __init__ /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:535

5 sec later:

2016-03-21 04:17:25.764 21664 DEBUG oslo.messaging._drivers.impl_rabbit [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] Received recoverable error from kombu: on_error /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:678
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit Traceback (most recent call last):
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 436, in _ensured
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit return fun(*args, **kwargs)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 507, in __call__
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit self.revive(create_channel())
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 242, in channel
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit chan = self.transport.create_channel(self.connection)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 741, in connection
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit self._connection = self._establish_connection()
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 696, in _establish_connection
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit conn = self.transport.establish_connection()
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqp.py", line 116, in establish_connection
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit conn = self.Connection(**opts)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/connection.py", line 165, in __init__
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit self.transport = self.Transport(host, connect_timeout, ssl)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/connection.py", line 186, in Transport
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit return create_transport(host, connect_timeout, ssl)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/transport.py", line 299, in create_transport
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit return TCPTransport(host, connect_timeout)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/transport.py", line 95, in __init__
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit raise socket.error(last_err)
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit error: timed out
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging._drivers.impl_rabbit
2016-03-21 04:17:25.768 21664 ERROR oslo.messaging._drivers.impl_rabbit [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] AMQP server on 10.109.16.4:5673 is unreachable: timed out. Trying again in 5 seconds.

10 sec later:

2016-03-21 04:17:35.786 21664 DEBUG oslo.messaging._drivers.impl_rabbit [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] Received recoverable error from kombu: on_error /usr/lib/python2.7/dist-packages/oslo_messaging/_drivers/impl_rabbit.py:678
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit Traceback (most recent call last):
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/utils/__init__.py", line 246, in retry_over_time
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit return fun(*args, **kwargs)
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 237, in connect
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit return self.connection
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 741, in connection
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit self._connection = self._establish_connection()
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 696, in _establish_connection
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit conn = self.transport.establish_connection()
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqp.py", line 116, in establish_connection
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit conn = self.Connection(**opts)
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/connection.py", line 165, in __init__
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit self.transport = self.Transport(host, connect_timeout, ssl)
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/connection.py", line 186, in Transport
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit return create_transport(host, connect_timeout, ssl)
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/transport.py", line 299, in create_transport
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit return TCPTransport(host, connect_timeout)
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit File "/usr/lib/python2.7/dist-packages/amqp/transport.py", line 95, in __init__
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit raise socket.error(last_err)
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit error: timed out
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging._drivers.impl_rabbit
2016-03-21 04:17:35.789 21664 ERROR oslo.messaging._drivers.impl_rabbit [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] AMQP server on 10.109.16.4:5673 is unreachable: timed out. Trying again in 5 seconds.

finally:

2016-03-21 04:17:40.958 21664 INFO oslo.messaging._drivers.impl_rabbit [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] Reconnected to AMQP server on 10.109.16.7:5673 via [amqp] client

and

2016-03-21 04:17:40.985 21664 INFO neutron.wsgi [req-1372e3b7-6137-44b3-8bc4-09da1d0f8699 9f6df653b10340029b51da845ba83d9a 6d3859f589ef4627bc14a14290652ab8 - - -] 10.109.16.3 - - [21/Mar/2016 04:17:40] "PUT /v2.0/routers/e594f584-168b-4ad8-a495-59a76b6f72f5/add_router_interface.json HTTP/1.1" 200 518 21.804273

So neutron finished processing request at 04:17:40 while the test failed 1 sec earlier at 04:17:39.
It took neutron >20 seconds to process the request due to problems with messaging. Reassigning to mos-oslo.