Comment 3 for bug 1499669

Revision history for this message
Zane Bitter (zaneb) wrote :

It appears this error results from accessing the same session in multiple threads simultaneously:

http://stackoverflow.com/questions/17317344/celery-and-sqlalchemy-this-result-object-does-not-return-rows-it-has-been-clo#17348307

I'm not sure how that could happen in Heat. In the case of the traceback from therve's comment above, it's failing in the link()ed functions that run after a thread has completed (in this case, it's being cancelled):

2016-06-04 02:51:54.091 3205 INFO heat.engine.stack [req-d3d7848b-ea6e-4557-8759-37626e7f5f63 demo demo - default default] Stopped due to GreenletExit() in create
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 457, in fire_timers
    timer()
  File "/usr/local/lib/python2.7/dist-packages/eventlet/hubs/timer.py", line 58, in __call__
    cb(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 217, in main
    self._resolve_links()
  File "/usr/local/lib/python2.7/dist-packages/eventlet/greenthread.py", line 232, in _resolve_links
    f(self, *ca, **ckw)
  File "/opt/stack/new/heat/heat/engine/service.py", line 187, in release
    stack.persist_state_and_release_lock(lock.engine_id)
  File "/opt/stack/new/heat/heat/engine/stack.py", line 913, in persist_state_and_release_lock
    stack = stack_object.Stack.get_by_id(self.context, self.id)
  File "/opt/stack/new/heat/heat/objects/stack.py", line 85, in get_by_id
    db_stack = db_api.stack_get(context, stack_id, **kwargs)
  File "/opt/stack/new/heat/heat/db/api.py", line 146, in stack_get
    eager_load=eager_load)
  File "/opt/stack/new/heat/heat/db/sqlalchemy/api.py", line 401, in stack_get
    result = query.get(stack_id)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 831, in get
    return self._get_impl(ident, loading.load_on_ident)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 864, in _get_impl
    return fallback_fn(self, key)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/loading.py", line 219, in load_on_ident
    return q.one()
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2718, in one
    ret = list(self)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2761, in __iter__
    return self._execute_and_instances(context)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2774, in _execute_and_instances
    close_with_result=True)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2765, in _connection_from_session
    **kw)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 893, in connection
    execution_options=execution_options)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 900, in _connection_for_bind
    conn = engine.contextual_connect(**kw)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 2041, in contextual_connect
    **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 92, in __init__
    self.dispatch.engine_connect(self, self.__branch)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/event/attr.py", line 256, in __call__
    fn(*args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/oslo_db/sqlalchemy/engines.py", line 72, in _connect_ping_listener
    connection.scalar(select([1]))
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 844, in scalar
    return self.execute(object, *multiparams, **params).scalar()
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/result.py", line 1066, in scalar
    row = self.first()
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/result.py", line 1040, in first
    return self._non_result(None)
  File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/result.py", line 922, in _non_result
    "This result object does not return rows. "
ResourceClosedError: This result object does not return rows. It has been closed automatically.
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool [-] Exception during reset or similar
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool Traceback (most recent call last):
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 636, in _finalize_fairy
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool fairy._reset(pool)
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/pool.py", line 776, in _reset
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool pool._dialect.do_rollback(self)
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/dialects/mysql/base.py", line 2542, in do_rollback
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool dbapi_connection.rollback()
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 772, in rollback
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool self._read_ok_packet()
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool File "/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 748, in _read_ok_packet
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool raise err.OperationalError(2014, "Command Out of Sync")
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool OperationalError: (2014, 'Command Out of Sync')
2016-06-04 02:51:54.129 3205 ERROR sqlalchemy.pool.QueuePool
Exception AssertionError: AssertionError('do not call blocking functions from the mainloop',) in <function <lambda> at 0x7f2b1241b6e0> ignored

So whatever cleanup needed to happen should have happened in that thread before it exited, but apparently it has not.