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
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.
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-59a76b6f72 f5/add_ router_ interface. json -X PUT -H "User-Agent: python- neutronclient" -H "X-Auth-Token: gAAAAABW73XHffP D-itGuIyKwKR6Me 8oMWyNjkfGN0HKi fv0Phd2K9ZJbe- kS8Z-YFWvUP6GVQ AoNsICNwEICJVjF BqgDZSEtbSttywb SO2vD4wm_ pjLJpgMFKGtauww TtCbS-M0FiXnoJh QlPFpxmrYq0Bboa HrVI1I1TxO_ GOCmM88hu069dY" -d '{"subnet_id": "0de9368a- 24a6-40f5- 8038-b7b82bcdc9 51"}'
Failure at 04:17:39 (after 20 seconds):
2016-03-21 04:17:39 DEBUG (test_mixins) Traceback (most recent call last): ConnectionFaile d(reason= e)
...
raise exceptions.
ConnectionFailed: Connection to neutron failed:
As part of adding router interface neutron server should notify l3 agent. 6137-44b3- 8bc4-09da1d0f86 99 is for adding router interface):
Corresponding neutron logs (req-1372e3b7-
2016-03-21 04:17:20.741 21664 DEBUG oslo.messaging. _drivers. impl_rabbit [req-1372e3b7- 6137-44b3- 8bc4-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] 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-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] Received recoverable error from kombu: on_error /usr/lib/ python2. 7/dist- packages/ oslo_messaging/ _drivers/ impl_rabbit. py:678 _drivers. impl_rabbit Traceback (most recent call last): _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 436, in _ensured _drivers. impl_rabbit return fun(*args, **kwargs) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 507, in __call__ _drivers. impl_rabbit self.revive( create_ channel( )) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 242, in channel _drivers. impl_rabbit chan = self.transport. create_ channel( self.connection ) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 741, in connection _drivers. impl_rabbit self._connection = self._establish _connection( ) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 696, in _establish_ connection _drivers. impl_rabbit conn = self.transport. establish_ connection( ) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/transport /pyamqp. py", line 116, in establish_ connection _drivers. impl_rabbit conn = self.Connection (**opts) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/connection .py", line 165, in __init__ _drivers. impl_rabbit self.transport = self.Transport( host, connect_timeout, ssl) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/connection .py", line 186, in Transport _drivers. impl_rabbit return create_ transport( host, connect_timeout, ssl) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/transport. py", line 299, in create_transport _drivers. impl_rabbit return TCPTransport(host, connect_timeout) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/transport. py", line 95, in __init__ _drivers. impl_rabbit raise socket. error(last_ err) _drivers. impl_rabbit error: timed out _drivers. impl_rabbit _drivers. impl_rabbit [req-1372e3b7- 6137-44b3- 8bc4-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] AMQP server on 10.109.16.4:5673 is unreachable: timed out. Trying again in 5 seconds.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.764 21664 ERROR oslo.messaging.
2016-03-21 04:17:25.768 21664 ERROR oslo.messaging.
10 sec later:
2016-03-21 04:17:35.786 21664 DEBUG oslo.messaging. _drivers. impl_rabbit [req-1372e3b7- 6137-44b3- 8bc4-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] Received recoverable error from kombu: on_error /usr/lib/ python2. 7/dist- packages/ oslo_messaging/ _drivers/ impl_rabbit. py:678 _drivers. impl_rabbit Traceback (most recent call last): _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/utils/ __init_ _.py", line 246, in retry_over_time _drivers. impl_rabbit return fun(*args, **kwargs) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 237, in connect _drivers. impl_rabbit return self.connection _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 741, in connection _drivers. impl_rabbit self._connection = self._establish _connection( ) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/connectio n.py", line 696, in _establish_ connection _drivers. impl_rabbit conn = self.transport. establish_ connection( ) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ kombu/transport /pyamqp. py", line 116, in establish_ connection _drivers. impl_rabbit conn = self.Connection (**opts) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/connection .py", line 165, in __init__ _drivers. impl_rabbit self.transport = self.Transport( host, connect_timeout, ssl) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/connection .py", line 186, in Transport _drivers. impl_rabbit return create_ transport( host, connect_timeout, ssl) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/transport. py", line 299, in create_transport _drivers. impl_rabbit return TCPTransport(host, connect_timeout) _drivers. impl_rabbit File "/usr/lib/ python2. 7/dist- packages/ amqp/transport. py", line 95, in __init__ _drivers. impl_rabbit raise socket. error(last_ err) _drivers. impl_rabbit error: timed out _drivers. impl_rabbit _drivers. impl_rabbit [req-1372e3b7- 6137-44b3- 8bc4-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] AMQP server on 10.109.16.4:5673 is unreachable: timed out. Trying again in 5 seconds.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.786 21664 ERROR oslo.messaging.
2016-03-21 04:17:35.789 21664 ERROR oslo.messaging.
finally:
2016-03-21 04:17:40.958 21664 INFO oslo.messaging. _drivers. impl_rabbit [req-1372e3b7- 6137-44b3- 8bc4-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] 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-09da1d0f86 99 9f6df653b103400 29b51da845ba83d 9a 6d3859f589ef462 7bc14a14290652a b8 - - -] 10.109.16.3 - - [21/Mar/2016 04:17:40] "PUT /v2.0/routers/ e594f584- 168b-4ad8- a495-59a76b6f72 f5/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.