yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1631033] Re: scary traceback if nova-manage db sync is run before nova-manage api_db sync

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Sean Dague <sean@xxxxxxxxx>
Date: Thu, 06 Oct 2016 15:04:48 -0000
Reply-to: Bug 1631033 <1631033@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Example gate run - http://logs.openstack.org/60/378560/4/check/gate-
tempest-dsvm-neutron-full-ubuntu-
xenial/b18e638/logs/devstacklog.txt.gz#_2016-10-06_13_19_15_279

** Also affects: oslo.db
   Importance: Undecided
       Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1631033

Title:
  scary traceback if nova-manage db sync is run before nova-manage
  api_db sync

Status in OpenStack Compute (nova):
  Confirmed
Status in oslo.db:
  New

Bug description:
  During gate runs we're running

  nova-manage db sync
  nova-manage api_db sync

  This leads to the following rather scary stack trace:

  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters [req-962d0663-409b-4e1a-8552-52ecb451a165 - -] DBAPIError exception wrapped from (pymysql.err.InternalError) (1049, u"Unknown database 'nova_api'")
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 2074, in _wrap_pool_connect
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return fn()
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 318, in unique_connection
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return _ConnectionFairy._checkout(self)
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 713, in _checkout
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     fairy = _ConnectionRecord.checkout(pool)
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 480, in checkout
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     rec = pool._do_get()
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 1060, in _do_get
  2016-10-06 13:19:15.279 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     self._dec_overflow()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     compat.reraise(exc_type, exc_value, exc_tb)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 1057, in _do_get
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return self._create_connection()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 323, in _create_connection
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return _ConnectionRecord(self)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 449, in __init__
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     self.connection = self.__connect()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 607, in __connect
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     connection = self.__pool._invoke_creator(self)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/strategies.py", line 97, in connect
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return dialect.connect(*cargs, **cparams)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 385, in connect
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return self.dbapi.connect(*cargs, **cparams)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/__init__.py", line 90, in Connect
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     return Connection(*args, **kwargs)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 688, in __init__
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     self.connect()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 906, in connect
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     self._request_authentication()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 1114, in _request_authentication
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     auth_packet = self._read_packet()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 981, in _read_packet
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     packet.check_error()
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 393, in check_error
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     err.raise_mysql_exception(self._data)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters   File "/usr/local/lib/python2.7/dist-packages/pymysql/err.py", line 107, in raise_mysql_exception
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters     raise errorclass(errno, errval)
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1049, u"Unknown database 'nova_api'")
  2016-10-06 13:19:15.280 | 2016-10-06 13:19:15.277 21612 ERROR oslo_db.sqlalchemy.exc_filters 
  2016-10-06 13:19:15.280 | ERROR: could not access cell mapping database - has api db been created?

  
  This is pretty scary for admins, but it turns out it's pretty useless and non fatal. While we can fix the gate to do these operations in the other order, it would be nice if we weren't spewing this scary traceback to users.

  Ideally we could tell engine fascade about issues we don't care about,
  so that it wouldn't log behind the scenes for us. The alternative is
  Nova turning off logging selectively, which is less than ideal as the
  granularity is going to be different than we might expect.

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

[Bug 1631033] [NEW] scary traceback if nova-manage db sync is run before nova-manage api_db sync
From: Sean Dague, 2016-10-06