yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1381958] Re: traceback in log on concurrent SNAT scheduling

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Thu, 18 Dec 2014 14:31:04 -0000
Reply-to: Bug 1381958 <1381958@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: neutron
       Status: Fix Committed => Fix Released

** Changed in: neutron
    Milestone: None => kilo-1

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1381958

Title:
  traceback in log on concurrent SNAT scheduling

Status in OpenStack Neutron (virtual network service):
  Fix Released

Bug description:
  These show up on heavy activity nodes.

  2014-10-16 01:50:50.150 35539 TRACE neutron.api.v2.resource
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource Traceback (most recent call last):
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/resource.py", line 87, in resource
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     result = method(request=request, **args)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/v2/base.py", line 200, in _handle_action
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     return getattr(self._plugin, name)(*arg_list, **kwargs)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_dvr_db.py", line 262, in remove_router_interface
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     return router_interface_info
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_db.py", line 1128, in notify_router_interface_action
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     {'subnet_id': router_interface_info['subnet_id']})
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_db.py", line 1100, in notify_routers_updated
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     context, router_ids, operation, data)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/rpc/agentnotifiers/l3_rpc_agent_api.py", line 145, in routers_updated
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     operation, shuffle_agents)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/api/rpc/agentnotifiers/l3_rpc_agent_api.py", line 112, in _notification
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     plugin.schedule_routers(adminContext, router_ids)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 467, in schedule_routers
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self.schedule_router(context, router, candidates=None)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_agentschedulers_db.py", line 462, in schedule_router
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self, context, router, candidates=candidates)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 353, in schedule
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     plugin, context, router_id, candidates=candidates)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/scheduler/l3_agent_scheduler.py", line 240, in _schedule_router
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     plugin.schedule_snat_router(context, router_id, sync_router)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_dvrscheduler_db.py", line 302, in schedule_snat_router
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     context, router_id, snat_candidates)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_dvrscheduler_db.py", line 239, in bind_snat_servicenode
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self.bind_snat_router(context, router_id, chosen_snat_agent)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/db/l3_dvrscheduler_db.py", line 212, in bind_snat_router
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     'agent_id': chosen_agent.id})
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 470, in __exit__
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self.rollback()
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     compat.reraise(exc_type, exc_value, exc_tb)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 467, in __exit__
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self.commit()
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/opt/stack/neutron/neutron/service.py", line 334, in new_commit_func
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     return oldcommitfunc(st)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 377, in commit
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self._prepare_impl()
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 357, in _prepare_impl
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self.session.flush()
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1919, in flush
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self._flush(objects)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2037, in _flush
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     transaction.rollback(_capture_exception=True)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     compat.reraise(exc_type, exc_value, exc_tb)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 2001, in _flush
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     flush_context.execute()
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 372, in execute
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     rec.execute(self)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/unitofwork.py", line 526, in execute
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     uow
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 65, in save_obj
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     mapper, table, insert)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 570, in _emit_insert_statements
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     execute(statement, multiparams)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 729, in execute
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     return meth(self, multiparams, params)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     return connection._execute_clauseelement(self, multiparams, params)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     compiled_sql, distilled_params
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     context)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     util.raise_from_cause(newraise, exc_info)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     reraise(type(exception), exception, tb=exc_tb)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     context)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 436, in do_execute
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     cursor.execute(statement, parameters)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     self.errorhandler(self, exc, value)
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource   File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource     raise errorclass, errorvalue
  2014-10-16 01:52:13.567 35539 TRACE neutron.api.v2.resource DBDuplicateEntry: (IntegrityError) (1062, "Duplicate entry '8516d581-b704-4ab6-bf12-05da11a06b7e' for key 'PRIMARY'") 'INSERT INTO csnat_l3_agent_bindings (router_id, l3_agent_id, host_id, csnat_gw_port_id) VALUES (%s, %s, %s, %s)' ('8516d581-b704-4ab6-bf12-05da11a06b7e', '5f21fdb4-9f18-4498-8eb3-dc119332f6de', None, None)

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1381958/+subscriptions
References

[Bug 1381958] [NEW] traceback in log on concurrent SNAT scheduling
From: Kevin Benton, 2014-10-16