yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1371620] Re: Setting up database schema with db_sync fails in migration 039 (SQLITE)

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Tue, 30 Sep 2014 07:06:52 -0000
Reply-to: Bug 1371620 <1371620@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: keystone
       Status: Fix Committed => Fix Released

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

Title:
  Setting up database schema with db_sync fails in migration 039
  (SQLITE)

Status in OpenStack Identity (Keystone):
  Fix Released
Status in “keystone” package in Ubuntu:
  Fix Released

Bug description:
  A fresh clone of master (commit
  ee4ee3b7f570d448f9053547febd86591e600697) won't set up the database.

  On a fresh install of ubuntu 12.04.3 (yes, I know, but it's what I had
  kicking about) in a VM (Vmware), with no special config except for web
  proxies (excluding localhost) I followed

  http://docs.openstack.org/developer/keystone/setup.html

  and, once able to import keystone

  http://docs.openstack.org/developer/keystone/developing.html

  up to the point of running

  bin/keystone-manage db_sync

  this last command results in a stack trace as follows:

  (.venv)david@ubuntu:~/keystone$ bin/keystone-manage db_sync
  2014-09-19 06:54:16.321 12991 CRITICAL keystone [-] OperationalError: (OperationalError) database is locked u'DELETE FROM user_project_metadata' ()
  2014-09-19 06:54:16.321 12991 TRACE keystone Traceback (most recent call last):
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "bin/keystone-manage", line 44, in <module>
  2014-09-19 06:54:16.321 12991 TRACE keystone     cli.main(argv=sys.argv, config_files=config_files)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/keystone/cli.py", line 307, in main
  2014-09-19 06:54:16.321 12991 TRACE keystone     CONF.command.cmd_class.main()
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/keystone/cli.py", line 74, in main
  2014-09-19 06:54:16.321 12991 TRACE keystone     migration_helpers.sync_database_to_version(extension, version)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/keystone/common/sql/migration_helpers.py", line 204, in sync_database_to_version
  2014-09-19 06:54:16.321 12991 TRACE keystone     _sync_common_repo(version)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/keystone/common/sql/migration_helpers.py", line 160, in _sync_common_repo
  2014-09-19 06:54:16.321 12991 TRACE keystone     init_version=init_version)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/oslo/db/sqlalchemy/migration.py", line 79, in db_sync
  2014-09-19 06:54:16.321 12991 TRACE keystone     return versioning_api.upgrade(engine, repository, version)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/migrate/versioning/api.py", line 186, in upgrade
  2014-09-19 06:54:16.321 12991 TRACE keystone     return _migrate(url, repository, version, upgrade=True, err=err, **opts)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "<string>", line 2, in _migrate
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/migrate/versioning/util/__init__.py", line 160, in with_engine
  2014-09-19 06:54:16.321 12991 TRACE keystone     return f(*a, **kw)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/migrate/versioning/api.py", line 366, in _migrate
  2014-09-19 06:54:16.321 12991 TRACE keystone     schema.runchange(ver, change, changeset.step)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/migrate/versioning/schema.py", line 93, in runchange
  2014-09-19 06:54:16.321 12991 TRACE keystone     change.run(self.engine, step)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/migrate/versioning/script/py.py", line 148, in run
  2014-09-19 06:54:16.321 12991 TRACE keystone     script_func(engine)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/keystone/common/sql/migrate_repo/versions/039_grant_to_assignment.py", line 223, in upgrade
  2014-09-19 06:54:16.321 12991 TRACE keystone     migrate_grant_table(meta, migrate_engine, session, table_name)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/keystone/common/sql/migrate_repo/versions/039_grant_to_assignment.py", line 85, in migrate_grant_table
  2014-09-19 06:54:16.321 12991 TRACE keystone     migrate_engine.execute(upgrade_table.delete())
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1752, in execute
  2014-09-19 06:54:16.321 12991 TRACE keystone     return connection.execute(statement, *multiparams, **params)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute
  2014-09-19 06:54:16.321 12991 TRACE keystone     return meth(self, multiparams, params)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
  2014-09-19 06:54:16.321 12991 TRACE keystone     return connection._execute_clauseelement(self, multiparams, params)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
  2014-09-19 06:54:16.321 12991 TRACE keystone     compiled_sql, distilled_params
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
  2014-09-19 06:54:16.321 12991 TRACE keystone     context)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
  2014-09-19 06:54:16.321 12991 TRACE keystone     util.raise_from_cause(newraise, exc_info)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2014-09-19 06:54:16.321 12991 TRACE keystone     reraise(type(exception), exception, tb=exc_tb)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
  2014-09-19 06:54:16.321 12991 TRACE keystone     context)
  2014-09-19 06:54:16.321 12991 TRACE keystone   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute
  2014-09-19 06:54:16.321 12991 TRACE keystone     cursor.execute(statement, parameters)
  2014-09-19 06:54:16.321 12991 TRACE keystone OperationalError: (OperationalError) database is locked u'DELETE FROM user_project_metadata' ()
  2014-09-19 06:54:16.321 12991 TRACE keystone 

  repeating the command gets the same result (same point of failure -
  039_grant_to_assignment.py).  I cannot initialise the database so it
  can be no suprise that running tools/sample_data.sh doesn't succeed.

  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 570, in _emit_insert_statements
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     execute(statement, multiparams)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     return meth(self, multiparams, params)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 321, in _execute_on_connection
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     return connection._execute_clauseelement(self, multiparams, params)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     compiled_sql, distilled_params
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     context)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1156, in _handle_dbapi_exception
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     util.raise_from_cause(newraise, exc_info)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     reraise(type(exception), exception, tb=exc_tb)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     context)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi   File "/home/david/keystone/.venv/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi     cursor.execute(statement, parameters)
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi OperationalError: (OperationalError) table service has no column named enabled u'INSERT INTO service (id, type, enabled, extra) VALUES (?, ?, ?, ?)' ('37d8cf9ccdb146e4b88b23a7152bffcc', u'object-store', 1, '{"name": "swift", "description": "Swift Service"}')
  2014-09-19 07:03:16.105 13337 TRACE keystone.common.wsgi 
  An unexpected error prevented the server from fulfilling your request. (HTTP 500)

  So I appear to be hosed.  However, I believe I cloned about a week ago
  and ran the same process on another machine (laptop, xubuntu 14.04)
  with some success - so is this a bug that has been introduced in a
  recent commit?

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

[Bug 1371620] [NEW] Setting up database schema with db_sync fails with OperationalError: (OperationalError) database is locked u'DELETE FROM user_project_metadata' ()
From: David Charles Kennedy, 2014-09-19