← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1227892] Re: db migration timeout in unit tests

 

*** This bug is a duplicate of bug 1216851 ***
    https://bugs.launchpad.net/bugs/1216851

** This bug has been marked a duplicate of bug 1216851
   nova unit tests occasionally fail migration tests for mysql and postgres

-- 
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/1227892

Title:
  db migration timeout in unit tests

Status in OpenStack Compute (Nova):
  Confirmed

Bug description:
  Seeing odd timeouts in the db test_migrations

  ======================================================================
  2013-09-19 20:19:52.147 | FAIL: nova.tests.db.test_migrations.TestNovaMigrations.test_mysql_opportunistically
  2013-09-19 20:19:52.147 | tags: worker-2
  2013-09-19 20:19:52.147 | ----------------------------------------------------------------------
  2013-09-19 20:19:52.147 | Empty attachments:
  2013-09-19 20:19:52.148 |   stderr
  2013-09-19 20:19:52.148 |   stdout
  2013-09-19 20:19:52.148 | 
  2013-09-19 20:19:52.148 | pythonlogging:'': {{{
  2013-09-19 20:19:52.148 | 132 -> 133... 
  2013-09-19 20:19:52.148 | done
  2013-09-19 20:19:52.148 | 133 -> 134... 
  2013-09-19 20:19:52.149 | done
  2013-09-19 20:19:52.149 | 134 -> 135... 
  2013-09-19 20:19:52.149 | done
  2013-09-19 20:19:52.149 | 135 -> 136... 
  2013-09-19 20:19:52.149 | done
  2013-09-19 20:19:52.149 | 136 -> 137... 
  2013-09-19 20:19:52.149 | done
  2013-09-19 20:19:52.150 | 137 -> 138... 
  2013-09-19 20:19:52.150 | done
  2013-09-19 20:19:52.150 | 138 -> 139... 
  2013-09-19 20:19:52.150 | done
  2013-09-19 20:19:52.150 | 139 -> 140... 
  2013-09-19 20:19:52.150 | done
  2013-09-19 20:19:52.150 | 140 -> 141... 
  2013-09-19 20:19:52.151 | done
  2013-09-19 20:19:52.151 | 141 -> 142... 
  2013-09-19 20:19:52.151 | done
  2013-09-19 20:19:52.151 | 142 -> 143... 
  2013-09-19 20:19:52.151 | done
  2013-09-19 20:19:52.151 | 143 -> 144... 
  2013-09-19 20:19:52.151 | done
  2013-09-19 20:19:52.151 | 144 -> 145... 
  2013-09-19 20:19:52.152 | done
  2013-09-19 20:19:52.152 | 145 -> 146... 
  2013-09-19 20:19:52.152 | done
  2013-09-19 20:19:52.152 | 146 -> 147... 
  2013-09-19 20:19:52.152 | done
  2013-09-19 20:19:52.152 | 147 -> 148... 
  2013-09-19 20:19:52.152 | Failed to migrate to version 148 on engine Engine(mysql+mysqldb://openstack_citest:openstack_citest@localhost/openstack_citest)
  2013-09-19 20:19:52.153 | }}}
  2013-09-19 20:19:52.153 | 
  2013-09-19 20:19:52.153 | Traceback (most recent call last):
  2013-09-19 20:19:52.153 |   File "nova/tests/db/test_migrations.py", line 162, in test_mysql_opportunistically
  2013-09-19 20:19:52.153 |     self._test_mysql_opportunistically()
  2013-09-19 20:19:52.153 |   File "nova/tests/db/test_migrations.py", line 321, in _test_mysql_opportunistically
  2013-09-19 20:19:52.153 |     self._walk_versions(engine, False, False)
  2013-09-19 20:19:52.154 |   File "nova/tests/db/test_migrations.py", line 378, in _walk_versions
  2013-09-19 20:19:52.154 |     self._migrate_up(engine, version, with_data=True)
  2013-09-19 20:19:52.154 |   File "nova/tests/db/test_migrations.py", line 436, in _migrate_up
  2013-09-19 20:19:52.154 |     self.migration_api.upgrade(engine, self.REPOSITORY, version)
  2013-09-19 20:19:52.154 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/api.py", line 186, in upgrade
  2013-09-19 20:19:52.154 |     return _migrate(url, repository, version, upgrade=True, err=err, **opts)
  2013-09-19 20:19:52.154 |   File "<string>", line 2, in _migrate
  2013-09-19 20:19:52.155 |   File "nova/db/sqlalchemy/migration.py", line 40, in patched_with_engine
  2013-09-19 20:19:52.155 |     return f(*a, **kw)
  2013-09-19 20:19:52.155 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/api.py", line 366, in _migrate
  2013-09-19 20:19:52.155 |     schema.runchange(ver, change, changeset.step)
  2013-09-19 20:19:52.155 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/schema.py", line 91, in runchange
  2013-09-19 20:19:52.155 |     change.run(self.engine, step)
  2013-09-19 20:19:52.155 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/script/py.py", line 145, in run
  2013-09-19 20:19:52.156 |     script_func(engine)
  2013-09-19 20:19:52.156 |   File "/home/jenkins/workspace/gate-nova-python27/nova/db/sqlalchemy/migrate_repo/versions/148_add_instance_actions.py", line 67, in upgrade
  2013-09-19 20:19:52.156 |     instance_actions.create()
  2013-09-19 20:19:52.156 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/schema.py", line 593, in create
  2013-09-19 20:19:52.156 |     checkfirst=checkfirst)
  2013-09-19 20:19:52.156 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 2302, in _run_visitor
  2013-09-19 20:19:52.156 |     conn._run_visitor(visitorcallable, element, **kwargs)
  2013-09-19 20:19:52.157 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1972, in _run_visitor
  2013-09-19 20:19:58.686 |     **kwargs).traverse_single(element)
  2013-09-19 20:19:58.686 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/sql/visitors.py", line 106, in traverse_single
  2013-09-19 20:19:58.686 |     return meth(obj, **kw)
  2013-09-19 20:19:58.687 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/ddl.py", line 86, in visit_table
  2013-09-19 20:19:58.687 |     self.connection.execute(schema.CreateTable(table))
  2013-09-19 20:19:58.687 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1449, in execute
  2013-09-19 20:19:58.687 |     params)
  2013-09-19 20:19:58.687 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1542, in _execute_ddl
  2013-09-19 20:19:58.688 |     compiled
  2013-09-19 20:19:58.688 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1691, in _execute_context
  2013-09-19 20:19:58.688 |     context)
  2013-09-19 20:19:58.688 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 331, in do_execute
  2013-09-19 20:19:58.688 |     cursor.execute(statement, parameters)
  2013-09-19 20:19:58.688 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/MySQLdb/cursors.py", line 201, in execute
  2013-09-19 20:19:58.688 |     self.errorhandler(self, exc, value)
  2013-09-19 20:19:58.689 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
  2013-09-19 20:19:58.689 |     raise errorclass, errorvalue
  2013-09-19 20:19:58.689 | TimeoutException
  2013-09-19 20:19:58.689 | ======================================================================
  2013-09-19 20:19:58.689 | FAIL: nova.tests.db.test_migrations.TestNovaMigrations.test_postgresql_opportunistically
  2013-09-19 20:19:58.690 | tags: worker-2
  2013-09-19 20:19:58.690 | ----------------------------------------------------------------------
  2013-09-19 20:19:58.690 | Empty attachments:
  2013-09-19 20:19:58.690 |   stderr
  2013-09-19 20:19:58.690 |   stdout
  2013-09-19 20:19:58.690 | 
  2013-09-19 20:19:58.690 | pythonlogging:'': {{{
  2013-09-19 20:19:58.691 | 132 -> 133... 
  2013-09-19 20:19:58.691 | done
  2013-09-19 20:19:58.691 | 133 -> 134... 
  2013-09-19 20:19:58.691 | done
  2013-09-19 20:19:58.691 | 134 -> 135... 
  2013-09-19 20:19:58.691 | done
  2013-09-19 20:19:58.691 | 135 -> 136... 
  2013-09-19 20:19:58.692 | done
  2013-09-19 20:19:58.692 | 136 -> 137... 
  2013-09-19 20:19:58.692 | done
  2013-09-19 20:19:58.692 | 137 -> 138... 
  2013-09-19 20:19:58.692 | done
  2013-09-19 20:19:58.692 | 138 -> 139... 
  2013-09-19 20:19:58.693 | done
  2013-09-19 20:19:58.693 | 139 -> 140... 
  2013-09-19 20:19:58.693 | done
  2013-09-19 20:19:58.693 | 140 -> 141... 
  2013-09-19 20:19:58.693 | done
  2013-09-19 20:19:58.693 | 141 -> 142... 
  2013-09-19 20:19:58.693 | done
  2013-09-19 20:19:58.694 | 142 -> 143... 
  2013-09-19 20:19:58.694 | done
  2013-09-19 20:19:58.694 | 143 -> 144... 
  2013-09-19 20:19:58.694 | done
  2013-09-19 20:19:58.694 | 144 -> 145... 
  2013-09-19 20:19:58.694 | done
  2013-09-19 20:19:58.694 | 145 -> 146... 
  2013-09-19 20:19:58.695 | done
  2013-09-19 20:19:58.695 | 146 -> 147... 
  2013-09-19 20:19:58.695 | done
  2013-09-19 20:19:58.695 | 147 -> 148... 
  2013-09-19 20:19:58.695 | done
  2013-09-19 20:19:58.695 | 148 -> 149... 
  2013-09-19 20:19:58.696 | done
  2013-09-19 20:19:58.696 | 149 -> 150... 
  2013-09-19 20:19:58.696 | done
  2013-09-19 20:19:58.696 | 150 -> 151... 
  2013-09-19 20:19:58.696 | done
  2013-09-19 20:19:58.696 | 151 -> 152... 
  2013-09-19 20:19:58.696 | done
  2013-09-19 20:19:58.697 | 152 -> 153... 
  2013-09-19 20:19:58.697 | done
  2013-09-19 20:19:58.697 | Failed to migrate to version 154 on engine Engine(postgresql+psycopg2://openstack_citest:openstack_citest@localhost/openstack_citest)
  2013-09-19 20:19:58.697 | }}}
  2013-09-19 20:19:58.698 | 
  2013-09-19 20:19:58.698 | Traceback (most recent call last):
  2013-09-19 20:19:58.698 |   File "nova/tests/db/test_migrations.py", line 174, in test_postgresql_opportunistically
  2013-09-19 20:19:58.698 |     self._test_postgresql_opportunistically()
  2013-09-19 20:19:58.698 |   File "nova/tests/db/test_migrations.py", line 357, in _test_postgresql_opportunistically
  2013-09-19 20:19:58.698 |     self._walk_versions(engine, False, False)
  2013-09-19 20:19:58.699 |   File "nova/tests/db/test_migrations.py", line 378, in _walk_versions
  2013-09-19 20:19:58.699 |     self._migrate_up(engine, version, with_data=True)
  2013-09-19 20:19:58.699 |   File "nova/tests/db/test_migrations.py", line 434, in _migrate_up
  2013-09-19 20:19:58.699 |     data = pre_upgrade(engine)
  2013-09-19 20:19:58.699 |   File "nova/tests/db/test_migrations.py", line 928, in _pre_upgrade_154
  2013-09-19 20:19:58.699 |     meta.reflect(engine)
  2013-09-19 20:19:58.700 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/schema.py", line 2548, in reflect
  2013-09-19 20:19:58.700 |     Table(name, self, **reflect_opts)
  2013-09-19 20:19:58.700 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/schema.py", line 318, in __new__
  2013-09-19 20:19:58.700 |     table._init(name, metadata, *args, **kw)
  2013-09-19 20:19:58.700 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/schema.py", line 381, in _init
  2013-09-19 20:19:58.701 |     self._autoload(metadata, autoload_with, include_columns)
  2013-09-19 20:19:58.701 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/schema.py", line 397, in _autoload
  2013-09-19 20:19:58.701 |     self, include_columns, exclude_columns
  2013-09-19 20:19:58.701 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 2425, in run_callable
  2013-09-19 20:19:58.701 |     return conn.run_callable(callable_, *args, **kwargs)
  2013-09-19 20:19:58.701 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1968, in run_callable
  2013-09-19 20:19:58.701 |     return callable_(self, *args, **kwargs)
  2013-09-19 20:26:20.634 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 260, in reflecttable
  2013-09-19 20:26:20.634 |     return insp.reflecttable(table, include_columns, exclude_columns)
  2013-09-19 20:26:20.634 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/reflection.py", line 370, in reflecttable
  2013-09-19 20:26:20.634 |     for col_d in self.get_columns(table_name, schema, **tblkw):
  2013-09-19 20:26:20.634 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/reflection.py", line 223, in get_columns
  2013-09-19 20:26:20.634 |     **kw)
  2013-09-19 20:26:20.635 |   File "<string>", line 1, in <lambda>
  2013-09-19 20:26:20.635 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/reflection.py", line 47, in cache
  2013-09-19 20:26:20.635 |     ret = fn(self, con, *args, **kw)
  2013-09-19 20:26:20.635 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/dialects/postgresql/base.py", line 1335, in get_columns
  2013-09-19 20:26:20.635 |     enums = self._load_enums(connection)
  2013-09-19 20:26:20.635 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/dialects/postgresql/base.py", line 1646, in _load_enums
  2013-09-19 20:26:20.635 |     c = connection.execute(s)
  2013-09-19 20:26:20.636 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1449, in execute
  2013-09-19 20:26:20.636 |     params)
  2013-09-19 20:26:20.636 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1584, in _execute_clauseelement
  2013-09-19 20:26:20.636 |     compiled_sql, distilled_params
  2013-09-19 20:26:20.636 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1651, in _execute_context
  2013-09-19 20:26:20.636 |     None, None)
  2013-09-19 20:26:20.637 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1647, in _execute_context
  2013-09-19 20:26:20.637 |     context = constructor(dialect, self, conn, *args)
  2013-09-19 20:26:20.637 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 452, in _init_compiled
  2013-09-19 20:26:20.637 |     processors = compiled._bind_processors
  2013-09-19 20:26:20.637 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 496, in __get__
  2013-09-19 20:26:20.637 |     obj.__dict__[self.__name__] = result = self.fget(obj)
  2013-09-19 20:26:20.637 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/sql/compiler.py", line 308, in _bind_processors
  2013-09-19 20:26:20.638 |     for bindparam in self.bind_names )
  2013-09-19 20:26:20.638 |   File "/home/jenkins/workspace/gate-nova-python27/.tox/py27/local/lib/python2.7/site-packages/fixtures/_fixtures/timeout.py", line 52, in signal_handler
  2013-09-19 20:26:20.638 |     raise TimeoutException()
  2013-09-19 20:26:20.638 | StatementError:  (original cause: TimeoutException) '\n            SELECT t.typname as "name",\n               -- no enum defaults in 8.4 at least\n               -- t.typdefault as "default",\n               pg_catalog.pg_type_is_visible(t.oid) as "visible",\n               n.nspname as "schema",\n               e.enumlabel as "label"\n            FROM pg_catalog.pg_type t\n                 LEFT JOIN pg_catalog.pg_namespace n ON n.oid = t.typnamespace\n                 LEFT JOIN pg_catalog.pg_enum e ON t.oid = e.enumtypid\n            WHERE t.typtype = \'e\'\n            ORDER BY "name", e.oid -- e.oid gives us label order\n        ' []
  2013-09-19 20:26:20.638 | ======================================================================

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