Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

set gateway to router hangs

Hi *,

I am using icehouse and facing an issue while setting gateway to the router. Horizon hangs and does not return. Please help me resolve the issue I am completely stuck. Any help is greatly appreciated.

Offending error log: ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mOperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m

Little more logs from neutron and l3-agent

q-svc logs:

2015-05-18 19:17:04.865 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "bsn-port-barrier"^[[00m ^[[00;33mfrom (pid=1157) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m 2015-05-18 19:17:04.865 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_set_port_status"^[[00m ^[[00;33mfrom (pid=1157) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m 2015-05-18 19:17:04.872 ^[[00;36mINFO neutron.wsgi [^[[00;36m-^[[00;36m] ^[[01;35m^[[00;36m(1157) accepted ('10.10.50.149', 59621) ^[[00m 2015-05-18 19:17:04.873 ^[[01;31mERROR neutron.openstack.common.rpc.amqp [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mException during message handling^[[00m ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mTraceback (most recent call last): ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m *args) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m neutron_ctxt, version, method, namespace, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m result = getattr(proxyobj, method)(ctxt, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m l3plugin.auto_schedule_routers(context, host, router_ids) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self, context, host, router_ids) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.bind_router(context, router_id, l3_agent) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m 'agent_id': chosen_agent.id}) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.rollback() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compat.reraise(exc_type, exc_value, exc_tb) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.commit() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self._prepare_impl() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.session.flush() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m return f(args, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m return super(Session, self).flush(args, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self._flush(objects) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m transaction.rollback(_capture_exception=True) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compat.reraise(exc_type, exc_value, exc_tb) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m flush_context.execute() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m rec.execute(self) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m uow ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m table, insert) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m execute(statement, params) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m params) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compiled_sql, distilled_params ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m context) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m exc_info ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m context) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m cursor.execute(statement, parameters) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.errorhandler(self, exc, value) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m raise errorclass, errorvalue ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mOperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m 2015-05-18 19:17:04.874 ^[[01;31mERROR neutron.openstack.common.rpc.common [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mReturning exception (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') to caller^[[00m 2015-05-18 19:17:04.875 ^[[01;31mERROR neutron.openstack.common.rpc.common [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31m['Traceback (most recent call last):\n', ' File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data\n *args)\n', ' File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch\n neutron_ctxt, version, method, namespace, *kwargs)\n', ' File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch\n result = getattr(proxyobj, method)(ctxt, *kwargs)\n', ' File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers\n l3plugin.auto_schedule_routers(context, host, router_ids)\n', ' File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers\n self, context, host, router_ids)\n', ' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers\n self.bind_router(context, router_id, l3_agent)\n', ' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router\n \'agent_id\': chosen_agent.id})\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__\n self.rollback()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__\n self.commit()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit\n self._prepare_impl()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl\n self.session.flush()\n', ' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap\n return f(args, *kwargs)\n', ' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush\n return super(Session, self).flush(args, *kwargs)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush\n self._flush(objects)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush\n transaction.rollback(_capture_exception=True)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush\n flush_context.execute()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute\n rec.execute(self)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute\n uow\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj\n table, insert)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements\n execute(statement, params)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute\n params)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement\n compiled_sql, distilled_params\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context\n context)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception\n exc_info\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause\n reraise(type(exception), exception, tb=exc_tb)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context\n context)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute\n cursor.execute(statement, parameters)\n', ' File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute\n self.errorhandler(self, exc, value)\n', ' File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler\n raise errorclass, errorvalue\n', "OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd')\n"]^[[00m 2015-05-18 19:17:04.875 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 206a46a935c94d42aa28ffa1f22b16e5.^[[00m ^[[00;33mfrom (pid=1157) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:17:04.876 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-031a8a8e-3d97-4a8a-9ad0-76b4e2e67666 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m 2015-05-18 19:17:04.879 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-0a33a3de-d860-4b68-a9ba-1c441aa46812 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m 2015-05-18 19:17:04.882 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-fe3ff998-99bb-4726-a5de-1fd20e5a5353 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m 2015-05-18 19:17:04.885 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-031a8a8e-3d97-4a8a-9ad0-76b4e2e67666 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m 2015-05-18 19:17:04.888 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-0a33a3de-d860-4b68-a9ba-1c441aa46812 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m

l3-agent logs

2015-05-18 19:16:12.413 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mreceived {u'_context_roles': [u'admin', u'_member_'], u'_context_request_id': u'req-b6db02b3-809d-429b-a100-ebe8974089b2', u'_context_read_deleted': u'no', u'_context_user_name': u'admin', u'_context_project_name': u'admin', u'namespace': None, u'_context_tenant_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0', u'args': {u'routers': [u'8638f6f8-4495-4cf4-8dd7-8451d732451e']}, u'_context_tenant': u'c8fccba8fcfb40fe9859eb4d82a6bca0', u'_unique_id': u'c405b2bcb93746b8b8d665b2383f4d50', u'_context_is_admin': True, u'version': u'1.1', u'_context_timestamp': u'2015-05-19 02:16:12.200245', u'_context_tenant_name': u'admin', u'_context_user': u'86823f0d6ad64573b7e1fdb852874458', u'_context_user_id': u'86823f0d6ad64573b7e1fdb852874458', u'method': u'routers_updated', u'_context_project_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0'}^[[00m ^[[00;33mfrom (pid=1495) _safe_log /opt/stack/neutron/neutron/openstack/common/rpc/common.py:280^[[00m 2015-05-18 19:16:12.413 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32munpacked context: {'project_name': u'admin', 'user_id': u'86823f0d6ad64573b7e1fdb852874458', 'roles': [u'admin', u'_member_'], 'tenant_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0', 'timestamp': u'2015-05-19 02:16:12.200245', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-b6db02b3-809d-429b-a100-ebe8974089b2', 'tenant_name': u'admin', 'project_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0', 'user_name': u'admin', 'tenant': u'c8fccba8fcfb40fe9859eb4d82a6bca0', 'user': u'86823f0d6ad64573b7e1fdb852874458'}^[[00m ^[[00;33mfrom (pid=1495) _safe_log /opt/stack/neutron/neutron/openstack/common/rpc/common.py:280^[[00m 2015-05-18 19:16:12.414 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[01;36mreq-b6db02b3-809d-429b-a100-ebe8974089b2 ^[[00;36madmin c8fccba8fcfb40fe9859eb4d82a6bca0^[[00;32m] ^[[01;35m^[[00;32mGot routers updated notification :[u'8638f6f8-4495-4cf4-8dd7-8451d732451e']^[[00m ^[[00;33mfrom (pid=1495) routers_updated /opt/stack/neutron/neutron/agent/l3_agent.py:749^[[00m 2015-05-18 19:16:13.223 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m 2015-05-18 19:16:13.223 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m 2015-05-18 19:16:13.223 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mStarting RPC loop for 1 updated routers^[[00m ^[[00;33mfrom (pid=1495) _rpc_loop /opt/stack/neutron/neutron/agent/l3_agent.py:819^[[00m 2015-05-18 19:16:13.224 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking synchronous call on q-l3-plugin ...^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m 2015-05-18 19:16:13.224 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is 47bf4af6763849d59afc91ce24bd073a^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m 2015-05-18 19:16:13.224 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is b130d24e953145b28dd9aa38ad4d1b1a.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:16:14.610 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m 2015-05-18 19:16:14.610 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m 2015-05-18 19:16:14.611 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 3cf3710eda9b426e9c334bb00df572e8.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:16:14.614 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m 2015-05-18 19:16:14.645 ^[[00;32mDEBUG neutron.openstack.common.periodic_task [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mRunning periodic task L3NATAgentWithStateReport._sync_routers_task^[[00m ^[[00;33mfrom (pid=1495) run_periodic_tasks /opt/stack/neutron/neutron/openstack/common/periodic_task.py:176^[[00m 2015-05-18 19:16:44.627 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m 2015-05-18 19:16:44.627 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m 2015-05-18 19:16:44.628 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 942ffabc6bfc4c6cba7db317806411ca.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:16:44.631 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m 2015-05-18 19:17:04.917 ^[[01;31mERROR neutron.agent.l3_agent [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mFailed synchronizing routers^[[00m ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mTraceback (most recent call last): ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 829, in _rpc_loop ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m self.context, router_ids) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 76, in get_routers ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m topic=self.topic) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/proxy.py", line 125, in call ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m result = rpc.call(context, real_topic, msg, timeout) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m result = rpc.call(context, real_topic, msg, timeout) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/__init__.py", line 112, in call ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m return _get_impl().call(CONF, context, topic, msg, timeout) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/impl_kombu.py", line 818, in call ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m rpc_amqp.get_connection_pool(conf, Connection)) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 575, in call ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m rv = list(rv) ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 540, in __iter__ ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m raise result ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mRemoteError: Remote error: OperationalError (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m[u'Traceback (most recent call last):\n', u' File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data\n *args)\n', u' File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch\n neutron_ctxt, version, method, namespace, *kwargs)\n', u' File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch\n result = getattr(proxyobj, method)(ctxt, *kwargs)\n', u' File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers\n l3plugin.auto_schedule_routers(context, host, router_ids)\n', u' File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers\n self, context, host, router_ids)\n', u' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers\n self.bind_router(context, router_id, l3_agent)\n', u' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router\n \'agent_id\': chosen_agent.id})\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__\n self.rollback()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__\n self.commit()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit\n self._prepare_impl()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl\n self.session.flush()\n', u' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap\n return f(args, *kwargs)\n', u' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush\n return super(Session, self).flush(args, **kwargs)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush\n self._flush(objects)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush\n transaction.rollback(_capture_exception=True)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush\n flush_context.execute()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute\n rec.execute(self)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute\n uow\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj\n table, insert)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements\n execute(statement, params)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute\n params)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement\n compiled_sql, distilled_params\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context\n context)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception\n exc_info\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause\n reraise(type(exception), exception, tb=exc_tb)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context\n context)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute\n cursor.execute(statement, parameters)\n', u' File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute\n self.errorhandler(self, exc, value)\n', u' File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler\n raise errorclass, errorvalue\n', u"OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd')\n"]. ^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m 2015-05-18 19:17:04.917 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mSemaphore / lock released "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m 2015-05-18 19:17:04.918 ^[[01;33mWARNING neutron.openstack.common.loopingcall [^[[00;36m-^[[01;33m] ^[[01;35m^[[01;33mtask run outlasted interval by 50.695318 sec^[[00m 2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m 2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_sync_routers_task"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m 2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mStarting _sync_routers_task - fullsync:True^[[00m ^[[00;33mfrom (pid=1495) _sync_routers_task /opt/stack/neutron/neutron/agent/l3_agent.py:857^[[00m 2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking synchronous call on q-l3-plugin ...^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m 2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is 76aa931764a545edbaaeebac7115d609^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m 2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is ae8039e01edc497792db549e347a1dd8.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m 2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m 2015-05-18 19:17:14.629 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is d7ff8c0eee494af68d1a10d5f9f66784.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m @
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m 2015-05-18 19:17:04.917 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mSemaphore / lock released "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m 2015-05-18 19:17:04.918 ^[[01;33mWARNING neutron.openstack.common.loopingcall [^[[00;36m-^[[01;33m] ^[[01;35m^[[01;33mtask run outlasted interval by 50.695318 sec^[[00m 2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m 2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_sync_routers_task"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m 2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mStarting _sync_routers_task - fullsync:True^[[00m ^[[00;33mfrom (pid=1495) _sync_routers_task /opt/stack/neutron/neutron/agent/l3_agent.py:857^[[00m 2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking synchronous call on q-l3-plugin ...^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m 2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is 76aa931764a545edbaaeebac7115d609^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m 2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is ae8039e01edc497792db549e347a1dd8.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m 2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m 2015-05-18 19:17:14.629 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is d7ff8c0eee494af68d1a10d5f9f66784.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:17:14.633 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m 2015-05-18 19:17:44.643 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m 2015-05-18 19:17:44.643 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m 2015-05-18 19:17:44.644 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 492d7aefe680442187a333f18f2b4989.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m 2015-05-18 19:17:44.647 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m 2015-05-18 19:18:04.942 ^[[01;31mERROR neutron.agent.l3_agent [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mFailed synchronizing routers due to RPC error^[[00m ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mTraceback (most recent call last): ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 865, in _sync_routers_task ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m context, router_ids) ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 76, in get_routers ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m topic=self.topic) ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/proxy.py", line 129, in call ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m exc.info, real_topic, msg.get('method')) ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mTimeout: Timeout while waiting on RPC response - topic: "q-l3-plugin", RPC method: "sync_routers" info: "<unknown>" ^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m 2015-05-18 19:18:04.943 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mSemaphore / lock released "_sync_routers_task"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m 2015-05-18 19:18:04.944 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m 2015-05-18 19:18:04.944 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openst

Regards, Dev

set gateway to router hangs

Hi *,

I am using icehouse and facing an issue while setting gateway to the router. Horizon hangs and does not return. Please help me resolve the issue I am completely stuck. Any help is greatly appreciated.

Offending error log: ^[[01;31m2015-05-18 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mOperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd')

Little more logs from neutron and l3-agent

q-svc logs:

2015-05-18 19:17:04.865 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "bsn-port-barrier"^[[00m ^[[00;33mfrom (pid=1157) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m
2015-05-18 19:17:04.865 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_set_port_status"^[[00m ^[[00;33mfrom (pid=1157) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m
2015-05-18 19:17:04.872 ^[[00;36mINFO neutron.wsgi [^[[00;36m-^[[00;36m] ^[[01;35m^[[00;36m(1157) accepted ('10.10.50.149', 59621)
^[[00m
2015-05-18 19:17:04.873 ^[[01;31mERROR neutron.openstack.common.rpc.amqp [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mException during message handling^[[00m
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mTraceback (most recent call last):
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m args)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m neutron_ctxt, version, method, namespace, *kwargs)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m result = getattr(proxyobj, method)(ctxt, *
kwargs)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m l3plugin.auto_schedule_routers(context, host, router_ids)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self, context, host, router_ids)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.bind_router(context, router_id, l3_agent)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m 'agent_id': chosen_agent.id})
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.rollback()
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compat.reraise(exc_type, exc_value, exc_tb)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.commit()
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self._prepare_impl()
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.session.flush()
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m return f(args, *kwargs)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m return super(Session, self).flush(args, *kwargs)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self._flush(objects)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m transaction.rollback(_capture_exception=True)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compat.reraise(exc_type, exc_value, exc_tb)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m flush_context.execute()
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m rec.execute(self)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m uow
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m table, insert)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m execute(statement, params)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m params)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compiled_sql, distilled_params
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m context)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m exc_info
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m context)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m cursor.execute(statement, parameters)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.errorhandler(self, exc, value)
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m raise errorclass, errorvalue
*^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mOperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') 'c729bec3-5abc-4002-90cd-1166809deadd')
^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m

Little more logs from neutron and l3-agent

q-svc logs:

2015-05-18 19:17:04.865 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "bsn-port-barrier"^[[00m ^[[00;33mfrom (pid=1157) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m 2015-05-18 19:17:04.865 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_set_port_status"^[[00m ^[[00;33mfrom (pid=1157) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m 2015-05-18 19:17:04.872 ^[[00;36mINFO neutron.wsgi [^[[00;36m-^[[00;36m] ^[[01;35m^[[00;36m(1157) accepted ('10.10.50.149', 59621) ^[[00m 2015-05-18 19:17:04.873 ^[[01;31mERROR neutron.openstack.common.rpc.amqp [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mException during message handling^[[00m ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mTraceback (most recent call last): ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m *args) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m neutron_ctxt, version, method, namespace, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m result = getattr(proxyobj, method)(ctxt, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m l3plugin.auto_schedule_routers(context, host, router_ids) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self, context, host, router_ids) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.bind_router(context, router_id, l3_agent) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m 'agent_id': chosen_agent.id}) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.rollback() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compat.reraise(exc_type, exc_value, exc_tb) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.commit() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self._prepare_impl() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.session.flush() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m return f(args, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m return super(Session, self).flush(args, *kwargs) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self._flush(objects) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m transaction.rollback(_capture_exception=True) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__ ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compat.reraise(exc_type, exc_value, exc_tb) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m flush_context.execute() ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m rec.execute(self) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m uow ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m table, insert) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m execute(statement, params) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m params) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m compiled_sql, distilled_params ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m context) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m exc_info ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m context) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m cursor.execute(statement, parameters) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m self.errorhandler(self, exc, value) ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m raise errorclass, errorvalue ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00mOperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') ^[[01;31m2015-05-18 19:17:04.873 TRACE neutron.openstack.common.rpc.amqp ^[[01;35m^[[00m
2015-05-18 19:17:04.874 ^[[01;31mERROR neutron.openstack.common.rpc.common [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mReturning exception (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') to caller^[[00m caller^[[00m
2015-05-18 19:17:04.875 ^[[01;31mERROR neutron.openstack.common.rpc.common [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31m['Traceback (most recent call last):\n', ' File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data\n *args)\n', ' File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch\n neutron_ctxt, version, method, namespace, *kwargs)\n', ' File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch\n result = getattr(proxyobj, method)(ctxt, *kwargs)\n', ' File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers\n l3plugin.auto_schedule_routers(context, host, router_ids)\n', ' File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers\n self, context, host, router_ids)\n', ' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers\n self.bind_router(context, router_id, l3_agent)\n', ' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router\n \'agent_id\': chosen_agent.id})\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__\n self.rollback()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__\n self.commit()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit\n self._prepare_impl()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl\n self.session.flush()\n', ' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap\n return f(args, *kwargs)\n', ' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush\n return super(Session, self).flush(args, *kwargs)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush\n self._flush(objects)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush\n transaction.rollback(_capture_exception=True)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush\n flush_context.execute()\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute\n rec.execute(self)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute\n uow\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj\n table, insert)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements\n execute(statement, params)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute\n params)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement\n compiled_sql, distilled_params\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context\n context)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception\n exc_info\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause\n reraise(type(exception), exception, tb=exc_tb)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context\n context)\n', ' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute\n cursor.execute(statement, parameters)\n', ' File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute\n self.errorhandler(self, exc, value)\n', ' File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler\n raise errorclass, errorvalue\n', "OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd')\n"]^[[00m 'c729bec3-5abc-4002-90cd-1166809deadd')\n"]^[[00m
2015-05-18 19:17:04.875 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 206a46a935c94d42aa28ffa1f22b16e5.^[[00m ^[[00;33mfrom (pid=1157) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:17:04.876 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-031a8a8e-3d97-4a8a-9ad0-76b4e2e67666 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m /opt/stack/neutron/neutron/context.py:84^[[00m
2015-05-18 19:17:04.879 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-0a33a3de-d860-4b68-a9ba-1c441aa46812 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m /opt/stack/neutron/neutron/context.py:84^[[00m
2015-05-18 19:17:04.882 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-fe3ff998-99bb-4726-a5de-1fd20e5a5353 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m /opt/stack/neutron/neutron/context.py:84^[[00m
2015-05-18 19:17:04.885 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-031a8a8e-3d97-4a8a-9ad0-76b4e2e67666 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m /opt/stack/neutron/neutron/context.py:84^[[00m
2015-05-18 19:17:04.888 ^[[00;32mDEBUG neutron.context [^[[01;36mreq-0a33a3de-d860-4b68-a9ba-1c441aa46812 ^[[00;36mNone None^[[00;32m] ^[[01;35m^[[00;32mArguments dropped when creating context: {'project_name': None, 'tenant': None}^[[00m ^[[00;33mfrom (pid=1157) __init__ /opt/stack/neutron/neutron/context.py:84^[[00m




l3-agent logs


==========
2015-05-18 19:16:12.413 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mreceived {u'_context_roles': [u'admin', u'_member_'], u'_context_request_id': u'req-b6db02b3-809d-429b-a100-ebe8974089b2', u'_context_read_deleted': u'no', u'_context_user_name': u'admin', u'_context_project_name': u'admin', u'namespace': None, u'_context_tenant_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0', u'args': {u'routers': [u'8638f6f8-4495-4cf4-8dd7-8451d732451e']}, u'_context_tenant': u'c8fccba8fcfb40fe9859eb4d82a6bca0', u'_unique_id': u'c405b2bcb93746b8b8d665b2383f4d50', u'_context_is_admin': True, u'version': u'1.1', u'_context_timestamp': u'2015-05-19 02:16:12.200245', u'_context_tenant_name': u'admin', u'_context_user': u'86823f0d6ad64573b7e1fdb852874458', u'_context_user_id': u'86823f0d6ad64573b7e1fdb852874458', u'method': u'routers_updated', u'_context_project_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0'}^[[00m ^[[00;33mfrom (pid=1495) _safe_log /opt/stack/neutron/neutron/openstack/common/rpc/common.py:280^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/common.py:280^[[00m
2015-05-18 19:16:12.413 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32munpacked context: {'project_name': u'admin', 'user_id': u'86823f0d6ad64573b7e1fdb852874458', 'roles': [u'admin', u'_member_'], 'tenant_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0', 'timestamp': u'2015-05-19 02:16:12.200245', 'is_admin': True, 'read_deleted': u'no', 'request_id': u'req-b6db02b3-809d-429b-a100-ebe8974089b2', 'tenant_name': u'admin', 'project_id': u'c8fccba8fcfb40fe9859eb4d82a6bca0', 'user_name': u'admin', 'tenant': u'c8fccba8fcfb40fe9859eb4d82a6bca0', 'user': u'86823f0d6ad64573b7e1fdb852874458'}^[[00m ^[[00;33mfrom (pid=1495) _safe_log /opt/stack/neutron/neutron/openstack/common/rpc/common.py:280^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/common.py:280^[[00m
2015-05-18 19:16:12.414 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[01;36mreq-b6db02b3-809d-429b-a100-ebe8974089b2 ^[[00;36madmin c8fccba8fcfb40fe9859eb4d82a6bca0^[[00;32m] ^[[01;35m^[[00;32mGot routers updated notification :[u'8638f6f8-4495-4cf4-8dd7-8451d732451e']^[[00m ^[[00;33mfrom (pid=1495) routers_updated /opt/stack/neutron/neutron/agent/l3_agent.py:749^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:749^[[00m
2015-05-18 19:16:13.223 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m
2015-05-18 19:16:13.223 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m
2015-05-18 19:16:13.223 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mStarting RPC loop for 1 updated routers^[[00m ^[[00;33mfrom (pid=1495) _rpc_loop /opt/stack/neutron/neutron/agent/l3_agent.py:819^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:819^[[00m
2015-05-18 19:16:13.224 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking synchronous call on q-l3-plugin ...^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m
2015-05-18 19:16:13.224 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is 47bf4af6763849d59afc91ce24bd073a^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m
2015-05-18 19:16:13.224 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is b130d24e953145b28dd9aa38ad4d1b1a.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:16:14.610 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m
2015-05-18 19:16:14.610 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m
2015-05-18 19:16:14.611 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 3cf3710eda9b426e9c334bb00df572e8.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:16:14.614 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m
2015-05-18 19:16:14.645 ^[[00;32mDEBUG neutron.openstack.common.periodic_task [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mRunning periodic task L3NATAgentWithStateReport._sync_routers_task^[[00m ^[[00;33mfrom (pid=1495) run_periodic_tasks /opt/stack/neutron/neutron/openstack/common/periodic_task.py:176^[[00m /opt/stack/neutron/neutron/openstack/common/periodic_task.py:176^[[00m
2015-05-18 19:16:44.627 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m
2015-05-18 19:16:44.627 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m
2015-05-18 19:16:44.628 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 942ffabc6bfc4c6cba7db317806411ca.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:16:44.631 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m
2015-05-18 19:17:04.917 ^[[01;31mERROR neutron.agent.l3_agent [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mFailed synchronizing routers^[[00m routers^[[00m
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mTraceback (most recent call last): last):
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 829, in _rpc_loop _rpc_loop
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m self.context, router_ids) router_ids)
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 76, in get_routers get_routers
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m topic=self.topic) topic=self.topic)
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/proxy.py", line 125, in call call
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m result = rpc.call(context, real_topic, msg, timeout) timeout)
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m result = rpc.call(context, real_topic, msg, timeout) timeout)
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/__init__.py", line 112, in call call
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m return _get_impl().call(CONF, context, topic, msg, timeout) timeout)
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/impl_kombu.py", line 818, in call call
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m rpc_amqp.get_connection_pool(conf, Connection)) Connection))
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 575, in call call
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m rv = list(rv) list(rv)
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 540, in __iter__ __iter__
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m raise result result
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mRemoteError: Remote error: OperationalError (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd') 'c729bec3-5abc-4002-90cd-1166809deadd')
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m[u'Traceback (most recent call last):\n', u' File "/opt/stack/neutron/neutron/openstack/common/rpc/amqp.py", line 462, in _process_data\n *args)\n', u' File "/opt/stack/neutron/neutron/common/rpc.py", line 45, in dispatch\n neutron_ctxt, version, method, namespace, *kwargs)\n', u' File "/opt/stack/neutron/neutron/openstack/common/rpc/dispatcher.py", line 172, in dispatch\n result = getattr(proxyobj, method)(ctxt, *kwargs)\n', u' File "/opt/stack/neutron/neutron/db/l3_rpc_base.py", line 55, in sync_routers\n l3plugin.auto_schedule_routers(context, host, router_ids)\n', u' File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 242, in auto_schedule_routers\n self, context, host, router_ids)\n', u' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 116, in auto_schedule_routers\n self.bind_router(context, router_id, l3_agent)\n', u' File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 158, in bind_router\n \'agent_id\': chosen_agent.id})\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 447, in __exit__\n self.rollback()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 444, in __exit__\n self.commit()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 354, in commit\n self._prepare_impl()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 334, in _prepare_impl\n self.session.flush()\n', u' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 597, in _wrap\n return f(args, *kwargs)\n', u' File "/opt/stack/neutron/neutron/openstack/common/db/sqlalchemy/session.py", line 836, in flush\n return super(Session, self).flush(args, **kwargs)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1818, in flush\n self._flush(objects)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1936, in _flush\n transaction.rollback(_capture_exception=True)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 58, in __exit__\n compat.reraise(exc_type, exc_value, exc_tb)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1900, in _flush\n flush_context.execute()\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute\n rec.execute(self)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 525, in execute\n uow\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 64, in save_obj\n table, insert)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 569, in _emit_insert_statements\n execute(statement, params)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 662, in execute\n params)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 761, in _execute_clauseelement\n compiled_sql, distilled_params\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 874, in _execute_context\n context)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1024, in _handle_dbapi_exception\n exc_info\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 196, in raise_from_cause\n reraise(type(exception), exception, tb=exc_tb)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 867, in _execute_context\n context)\n', u' File "/usr/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 324, in do_execute\n cursor.execute(statement, parameters)\n', u' File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute\n self.errorhandler(self, exc, value)\n', u' File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler\n raise errorclass, errorvalue\n', u"OperationalError: (OperationalError) (1205, 'Lock wait timeout exceeded; try restarting transaction') 'INSERT INTO routerl3agentbindings (id, router_id, l3_agent_id) VALUES (%s, %s, %s)' ('cc208bee-c111-4ef8-b7e0-bdd6379e39e2', '8638f6f8-4495-4cf4-8dd7-8451d732451e', 'c729bec3-5abc-4002-90cd-1166809deadd')\n"]. 'c729bec3-5abc-4002-90cd-1166809deadd')\n"].
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m ^[[01;35m^[[00m
2015-05-18 19:17:04.917 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mSemaphore / lock released "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m
2015-05-18 19:17:04.918 ^[[01;33mWARNING neutron.openstack.common.loopingcall [^[[00;36m-^[[01;33m] ^[[01;35m^[[01;33mtask run outlasted interval by 50.695318 sec^[[00m sec^[[00m
2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m
2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_sync_routers_task"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m
2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mStarting _sync_routers_task - fullsync:True^[[00m ^[[00;33mfrom (pid=1495) _sync_routers_task /opt/stack/neutron/neutron/agent/l3_agent.py:857^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:857^[[00m
2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking synchronous call on q-l3-plugin ...^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m
2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is 76aa931764a545edbaaeebac7115d609^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m
2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is ae8039e01edc497792db549e347a1dd8.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m
2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m
2015-05-18 19:17:14.629 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is d7ff8c0eee494af68d1a10d5f9f66784.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
@
^[[01;31m2015-05-18 19:17:04.917 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m ^[[01;35m^[[00m
2015-05-18 19:17:04.917 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mSemaphore / lock released "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m
2015-05-18 19:17:04.918 ^[[01;33mWARNING neutron.openstack.common.loopingcall [^[[00;36m-^[[01;33m] ^[[01;35m^[[01;33mtask run outlasted interval by 50.695318 sec^[[00m sec^[[00m
2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m
2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_sync_routers_task"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:248^[[00m
2015-05-18 19:17:04.918 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mStarting _sync_routers_task - fullsync:True^[[00m ^[[00;33mfrom (pid=1495) _sync_routers_task /opt/stack/neutron/neutron/agent/l3_agent.py:857^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:857^[[00m
2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking synchronous call on q-l3-plugin ...^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:554^[[00m
2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMSG_ID is 76aa931764a545edbaaeebac7115d609^[[00m ^[[00;33mfrom (pid=1495) multicall /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:557^[[00m
2015-05-18 19:17:04.919 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is ae8039e01edc497792db549e347a1dd8.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m
2015-05-18 19:17:14.628 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m
2015-05-18 19:17:14.629 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is d7ff8c0eee494af68d1a10d5f9f66784.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:17:14.633 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m
2015-05-18 19:17:44.643 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task started^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:940^[[00m
2015-05-18 19:17:44.643 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mMaking asynchronous cast on q-plugin...^[[00m ^[[00;33mfrom (pid=1495) cast /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:583^[[00m
2015-05-18 19:17:44.644 ^[[00;32mDEBUG neutron.openstack.common.rpc.amqp [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mUNIQUE_ID is 492d7aefe680442187a333f18f2b4989.^[[00m ^[[00;33mfrom (pid=1495) _add_unique_id /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m /opt/stack/neutron/neutron/openstack/common/rpc/amqp.py:342^[[00m
2015-05-18 19:17:44.647 ^[[00;32mDEBUG neutron.agent.l3_agent [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mReport state task successfully completed^[[00m ^[[00;33mfrom (pid=1495) _report_state /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m /opt/stack/neutron/neutron/agent/l3_agent.py:964^[[00m
2015-05-18 19:18:04.942 ^[[01;31mERROR neutron.agent.l3_agent [^[[00;36m-^[[01;31m] ^[[01;35m^[[01;31mFailed synchronizing routers due to RPC error^[[00m error^[[00m
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mTraceback (most recent call last): last):
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 865, in _sync_routers_task _sync_routers_task
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m context, router_ids) router_ids)
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/agent/l3_agent.py", line 76, in get_routers get_routers
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m topic=self.topic) topic=self.topic)
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m File "/opt/stack/neutron/neutron/openstack/common/rpc/proxy.py", line 129, in call call
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m exc.info, real_topic, msg.get('method')) msg.get('method'))
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00mTimeout: Timeout while waiting on RPC response - topic: "q-l3-plugin", RPC method: "sync_routers" info: "<unknown>" "<unknown>"
^[[01;31m2015-05-18 19:18:04.942 TRACE neutron.agent.l3_agent ^[[01;35m^[[00m ^[[01;35m^[[00m
2015-05-18 19:18:04.943 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mSemaphore / lock released "_sync_routers_task"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:252^[[00m
2015-05-18 19:18:04.944 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore "l3-agent"^[[00m ^[[00;33mfrom (pid=1495) lock /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m /opt/stack/neutron/neutron/openstack/common/lockutils.py:168^[[00m
2015-05-18 19:18:04.944 ^[[00;32mDEBUG neutron.openstack.common.lockutils [^[[00;36m-^[[00;32m] ^[[01;35m^[[00;32mGot semaphore / lock "_rpc_loop"^[[00m ^[[00;33mfrom (pid=1495) inner /opt/stack/neutron/neutron/openst




Regards, Dev