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: Launchpad Bug Tracker <1371620@xxxxxxxxxxxxxxxxxx>
Date: Mon, 29 Sep 2014 16:16:35 -0000
Reply-to: Bug 1371620 <1371620@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
This bug was fixed in the package keystone - 1:2014.2~b3-0ubuntu2

---------------
keystone (1:2014.2~b3-0ubuntu2) utopic; urgency=medium

  * Start failing package builds on unit test failures again:
    - d/rules: Fail build on any test failures.
    - d/p/skip-pysaml2.patch: Skip federation tests for now as pysaml2 is
      not yet in Ubuntu main and federation is only a contrib module.
    - d/p/bug-1371620.patch: Cherry pick fix from upstream VCS for db locking
      issues with sqlite during package install (LP: #1371620).
    - d/p/bug-1367354.patch: Cherry pick fix from upstream VCS to ensure that
      downgrade tests on sqlite complete successfully (LP: #1367354).
    - d/control: Add missing python-ldappool to BD's.
  * d/control: Align version requirements for pycadf and six with upstream.
  * d/p/series: Re-enable disabled add-version-info.patch.
 -- James Page <james.page@xxxxxxxxxx>   Mon, 29 Sep 2014 15:34:45 +0100

** Changed in: keystone (Ubuntu)
       Status: Triaged => 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 Committed
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