TestNovaMigrationsMySQL randomly fails with "sqlalchemy.exc.ResourceClosedError: This result object does not return rows. It has been closed automatically."

Seen here:

http://logs.openstack.org/46/527446/4/check/openstack-tox-py27/aac3f54/testr_results.html.gz

http://logs.openstack.org/46/527446/4/check/openstack-tox-py27/aac3f54/job-output.txt.gz#_2017-12-20_21_18_29_233663

2017-12-20 21:18:29.233663 | ubuntu-xenial | {1} nova.tests.unit.db.test_migrations.TestNovaMigrationsMySQL.test_innodb_tables [652.252491s] ... FAILED
2017-12-20 21:18:29.233713 | ubuntu-xenial |
2017-12-20 21:18:29.233737 | ubuntu-xenial | Captured pythonlogging:
2017-12-20 21:18:29.233758 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~~~~~
2017-12-20 21:18:29.233808 | ubuntu-xenial | 2017-12-20 21:07:36,961 WARNING [oslo_config.cfg] Config option key_manager.api_class is deprecated. Use option key_manager.backend instead.
2017-12-20 21:18:29.233865 | ubuntu-xenial | 2017-12-20 21:07:36,985 INFO [oslo_db.sqlalchemy.provision] CREATE BACKEND mysql+pymysql://openstack_citest:openstack_citest@localhost/ TOKEN adbrpgvsfb
2017-12-20 21:18:29.233945 | ubuntu-xenial | 2017-12-20 21:18:29,205 INFO [oslo_db.sqlalchemy.provision] DROP ALL OBJECTS, BACKEND mysql+pymysql://openstack_citest:openstack_citest@localhost/adbrpgvsfb
2017-12-20 21:18:29.233964 | ubuntu-xenial |
2017-12-20 21:18:29.233979 | ubuntu-xenial |
2017-12-20 21:18:29.233998 | ubuntu-xenial | Captured traceback:
2017-12-20 21:18:29.234017 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~
2017-12-20 21:18:29.234041 | ubuntu-xenial | Traceback (most recent call last):
2017-12-20 21:18:29.234075 | ubuntu-xenial | File "nova/tests/unit/db/test_migrations.py", line 984, in test_innodb_tables
2017-12-20 21:18:29.234108 | ubuntu-xenial | sa_migration.db_sync()
2017-12-20 21:18:29.234142 | ubuntu-xenial | File "nova/db/sqlalchemy/migration.py", line 57, in db_sync
2017-12-20 21:18:29.234164 | ubuntu-xenial | repository, version)
2017-12-20 21:18:29.234215 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/api.py", line 186, in upgrade
2017-12-20 21:18:29.234250 | ubuntu-xenial | return _migrate(url, repository, version, upgrade=True, err=err, **opts)
2017-12-20 21:18:29.234277 | ubuntu-xenial | File "<decorator-gen-15>", line 2, in _migrate
2017-12-20 21:18:29.234331 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/util/__init__.py", line 167, in with_engine
2017-12-20 21:18:29.234357 | ubuntu-xenial | return f(*a, **kw)
2017-12-20 21:18:29.234409 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/api.py", line 366, in _migrate
2017-12-20 21:18:29.234437 | ubuntu-xenial | schema.runchange(ver, change, changeset.step)
2017-12-20 21:18:29.234489 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/schema.py", line 93, in runchange
2017-12-20 21:18:29.234512 | ubuntu-xenial | change.run(self.engine, step)
2017-12-20 21:18:29.234571 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/migrate/versioning/script/py.py", line 148, in run
2017-12-20 21:18:29.234596 | ubuntu-xenial | script_func(engine)
2017-12-20 21:18:29.234644 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/nova/db/sqlalchemy/migrate_repo/versions/216_havana.py", line 1409, in upgrade
2017-12-20 21:18:29.234668 | ubuntu-xenial | index.create(migrate_engine)
2017-12-20 21:18:29.234719 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/sql/schema.py", line 3437, in create
2017-12-20 21:18:29.234746 | ubuntu-xenial | bind._run_visitor(ddl.SchemaGenerator, self)
2017-12-20 21:18:29.234798 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1929, in _run_visitor
2017-12-20 21:18:29.234828 | ubuntu-xenial | conn._run_visitor(visitorcallable, element, **kwargs)
2017-12-20 21:18:29.234880 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1538, in _run_visitor
2017-12-20 21:18:29.234905 | ubuntu-xenial | **kwargs).traverse_single(element)
2017-12-20 21:18:29.235532 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/sql/visitors.py", line 121, in traverse_single
2017-12-20 21:18:29.235575 | ubuntu-xenial | return meth(obj, **kw)
2017-12-20 21:18:29.235630 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/sql/ddl.py", line 791, in visit_index
2017-12-20 21:18:29.235658 | ubuntu-xenial | self.connection.execute(CreateIndex(index))
2017-12-20 21:18:29.235708 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 945, in execute
2017-12-20 21:18:29.235734 | ubuntu-xenial | return meth(self, multiparams, params)
2017-12-20 21:18:29.235787 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/sql/ddl.py", line 68, in _execute_on_connection
2017-12-20 21:18:29.235818 | ubuntu-xenial | return connection._execute_ddl(self, multiparams, params)
2017-12-20 21:18:29.235870 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1002, in _execute_ddl
2017-12-20 21:18:29.235889 | ubuntu-xenial | compiled
2017-12-20 21:18:29.235941 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1189, in _execute_context
2017-12-20 21:18:29.235960 | ubuntu-xenial | context)
2017-12-20 21:18:29.236089 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1398, in _handle_dbapi_exception
2017-12-20 21:18:29.236139 | ubuntu-xenial | util.raise_from_cause(newraise, exc_info)
2017-12-20 21:18:29.236194 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 203, in raise_from_cause
2017-12-20 21:18:29.236225 | ubuntu-xenial | reraise(type(exception), exception, tb=exc_tb, cause=cause)
2017-12-20 21:18:29.236278 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1182, in _execute_context
2017-12-20 21:18:29.236297 | ubuntu-xenial | context)
2017-12-20 21:18:29.236349 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 470, in do_execute
2017-12-20 21:18:29.236374 | ubuntu-xenial | cursor.execute(statement, parameters)
2017-12-20 21:18:29.236422 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/cursors.py", line 166, in execute
2017-12-20 21:18:29.236446 | ubuntu-xenial | result = self._query(query)
2017-12-20 21:18:29.236494 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/cursors.py", line 322, in _query
2017-12-20 21:18:29.236514 | ubuntu-xenial | conn.query(q)
2017-12-20 21:18:29.236563 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/connections.py", line 856, in query
2017-12-20 21:18:29.236596 | ubuntu-xenial | self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2017-12-20 21:18:29.236648 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/connections.py", line 1057, in _read_query_result
2017-12-20 21:18:29.236668 | ubuntu-xenial | result.read()
2017-12-20 21:18:29.236717 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/connections.py", line 1340, in read
2017-12-20 21:18:29.236744 | ubuntu-xenial | first_packet = self.connection._read_packet()
2017-12-20 21:18:29.236795 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/connections.py", line 987, in _read_packet
2017-12-20 21:18:29.236820 | ubuntu-xenial | packet_header = self._read_bytes(4)
2017-12-20 21:18:29.236870 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/connections.py", line 1021, in _read_bytes
2017-12-20 21:18:29.236900 | ubuntu-xenial | data = self._rfile.read(num_bytes)
2017-12-20 21:18:29.236952 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/pymysql/_socketio.py", line 59, in readinto
2017-12-20 21:18:29.236976 | ubuntu-xenial | return self._sock.recv_into(b)
2017-12-20 21:18:29.237026 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 360, in recv_into
2017-12-20 21:18:29.237058 | ubuntu-xenial | return self._recv_loop(self.fd.recv_into, 0, buffer, nbytes, flags)
2017-12-20 21:18:29.237118 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 348, in _recv_loop
2017-12-20 21:18:29.237144 | ubuntu-xenial | self._read_trampoline()
2017-12-20 21:18:29.237198 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 319, in _read_trampoline
2017-12-20 21:18:29.237224 | ubuntu-xenial | timeout_exc=socket.timeout("timed out"))
2017-12-20 21:18:29.237275 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/greenio/base.py", line 203, in _trampoline
2017-12-20 21:18:29.237300 | ubuntu-xenial | mark_as_closed=self._mark_as_closed)
2017-12-20 21:18:29.237351 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/__init__.py", line 162, in trampoline
2017-12-20 21:18:29.237372 | ubuntu-xenial | return hub.switch()
2017-12-20 21:18:29.237420 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 294, in switch
2017-12-20 21:18:29.237444 | ubuntu-xenial | return self.greenlet.switch()
2017-12-20 21:18:29.237492 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 346, in run
2017-12-20 21:18:29.237514 | ubuntu-xenial | self.wait(sleep_time)
2017-12-20 21:18:29.237566 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/poll.py", line 85, in wait
2017-12-20 21:18:29.237591 | ubuntu-xenial | presult = self.do_poll(seconds)
2017-12-20 21:18:29.237641 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/epolls.py", line 62, in do_poll
2017-12-20 21:18:29.237664 | ubuntu-xenial | return self.poll.poll(seconds)
2017-12-20 21:18:29.237920 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/fixtures/_fixtures/timeout.py", line 52, in signal_handler
2017-12-20 21:18:29.237955 | ubuntu-xenial | raise TimeoutException()
2017-12-20 21:18:29.237981 | ubuntu-xenial | IndexError: tuple index out of range
2017-12-20 21:18:29.237996 | ubuntu-xenial |
2017-12-20 21:18:29.238011 | ubuntu-xenial |
2017-12-20 21:18:29.238030 | ubuntu-xenial | Captured traceback-1:
2017-12-20 21:18:29.238050 | ubuntu-xenial | ~~~~~~~~~~~~~~~~~~~~~
2017-12-20 21:18:29.238073 | ubuntu-xenial | Traceback (most recent call last):
2017-12-20 21:18:29.238133 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/fixtures/fixture.py", line 125, in cleanUp
2017-12-20 21:18:29.238166 | ubuntu-xenial | return self._cleanups(raise_errors=raise_first)
2017-12-20 21:18:29.238216 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/fixtures/callmany.py", line 89, in __call__
2017-12-20 21:18:29.238241 | ubuntu-xenial | reraise(error[0], error[1], error[2])
2017-12-20 21:18:29.238290 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/fixtures/callmany.py", line 83, in __call__
2017-12-20 21:18:29.238313 | ubuntu-xenial | cleanup(*args, **kwargs)
2017-12-20 21:18:29.238365 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/testresources/__init__.py", line 797, in tearDownResources
2017-12-20 21:18:29.238402 | ubuntu-xenial | resource[1].finishedWith(getattr(test, resource[0]), result)
2017-12-20 21:18:29.238456 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/testresources/__init__.py", line 509, in finishedWith
2017-12-20 21:18:29.238481 | ubuntu-xenial | self._clean_all(resource, result)
2017-12-20 21:18:29.238533 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/testresources/__init__.py", line 478, in _clean_all
2017-12-20 21:18:29.238554 | ubuntu-xenial | self.clean(resource)
2017-12-20 21:18:29.238606 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/provision.py", line 176, in clean
2017-12-20 21:18:29.238629 | ubuntu-xenial | resource.database.engine)
2017-12-20 21:18:29.238683 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/provision.py", line 321, in drop_all_objects
2017-12-20 21:18:29.238712 | ubuntu-xenial | self.impl.drop_all_objects(engine)
2017-12-20 21:18:29.238768 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/provision.py", line 451, in drop_all_objects
2017-12-20 21:18:29.238791 | ubuntu-xenial | with engine.begin() as conn:
2017-12-20 21:18:29.238842 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1981, in begin
2017-12-20 21:18:29.238874 | ubuntu-xenial | conn = self.contextual_connect(close_with_result=close_with_result)
2017-12-20 21:18:29.238928 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 2114, in contextual_connect
2017-12-20 21:18:29.238972 | ubuntu-xenial | **kwargs)
2017-12-20 21:18:29.239028 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 110, in __init__
2017-12-20 21:18:29.239057 | ubuntu-xenial | self.dispatch.engine_connect(self, self.__branch)
2017-12-20 21:18:29.239119 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/event/attr.py", line 256, in __call__
2017-12-20 21:18:29.239168 | ubuntu-xenial | fn(*args, **kw)
2017-12-20 21:18:29.239231 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/oslo_db/sqlalchemy/engines.py", line 73, in _connect_ping_listener
2017-12-20 21:18:29.239256 | ubuntu-xenial | connection.scalar(select([1]))
2017-12-20 21:18:29.239307 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 877, in scalar
2017-12-20 21:18:29.239338 | ubuntu-xenial | return self.execute(object, *multiparams, **params).scalar()
2017-12-20 21:18:29.239389 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/result.py", line 1221, in scalar
2017-12-20 21:18:29.239409 | ubuntu-xenial | row = self.first()
2017-12-20 21:18:29.239460 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/result.py", line 1195, in first
2017-12-20 21:18:29.239484 | ubuntu-xenial | return self._non_result(None)
2017-12-20 21:18:29.239536 | ubuntu-xenial | File "/home/zuul/src/git.openstack.org/openstack/nova/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/engine/result.py", line 1077, in _non_result
2017-12-20 21:18:29.239563 | ubuntu-xenial | "This result object does not return rows. "
2017-12-20 21:18:29.239604 | ubuntu-xenial | sqlalchemy.exc.ResourceClosedError: This result object does not return rows. It has been closed automatically.

http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22sqlalchemy.exc.ResourceClosedError%3A%20This%20result%20object%20does%20not%20return%20rows.%20It%20has%20been%20closed%20automatically.%5C%22%20AND%20tags%3A%5C%22console%5C%22&from=7d

67 hits in 7 days, check and gate, all failures. Also failing in newton and pike...