yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1739517] Re: TestNovaMigrationsMySQL randomly fails with "sqlalchemy.exc.ResourceClosedError: This result object does not return rows. It has been closed automatically."

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem.os@xxxxxxxxx>
Date: Wed, 21 Mar 2018 01:59:05 -0000
Reply-to: Bug 1739517 <1739517@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
I'm not seeing this in logstash anymore, not sure what might have fixed
it.

** Changed in: nova
       Status: Confirmed => Invalid

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

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

Status in OpenStack Compute (nova):
  Invalid

Bug description:
  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...

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

[Bug 1739517] [NEW] TestNovaMigrationsMySQL randomly fails with "sqlalchemy.exc.ResourceClosedError: This result object does not return rows. It has been closed automatically."
From: Matt Riedemann, 2017-12-21