← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #21802

[Bug 1371620] [NEW] Setting up database schema with db_sync fails with OperationalError: (OperationalError) database is locked u'DELETE FROM user_project_metadata' ()

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

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?

** Affects: keystone
     Importance: Undecided
         Status: New

-- 
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 with OperationalError:
  (OperationalError) database is locked u'DELETE FROM
  user_project_metadata' ()

Status in OpenStack Identity (Keystone):
  New

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

Follow ups

References

  Thread Previous • Date Previous • • Thread Next