| 2015-02-26 11:55:16 |
Kairat Kushaev |
description |
Hello Guys!
When I tested heat with tox i got the following exception:
Traceback (most recent call last):
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 457, in fire_timers
timer()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/timer.py", line 58, in __call__
cb(*args, **kw)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/eventlet/greenthread.py", line 214, in main
result = function(*args, **kwargs)
File "heat/engine/service.py", line 115, in _start_with_trace
return func(*args, **kwargs)
File "heat/engine/service.py", line 603, in _stack_create
stack.adopt()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
return f(*args, **kwargs)
File "heat/engine/stack.py", line 708, in adopt
creator(timeout=self.timeout_secs())
File "heat/engine/scheduler.py", line 174, in __call__
self.start(timeout=timeout)
File "heat/engine/scheduler.py", line 199, in start
self.step()
File "heat/engine/scheduler.py", line 222, in step
next(self._runner)
File "heat/engine/scheduler.py", line 321, in wrapper
subtask = parent.throw(*sys.exc_info())
File "heat/engine/stack.py", line 631, in stack_task
yield action_task()
File "heat/engine/scheduler.py", line 295, in wrapper
step = next(subtask)
File "heat/engine/scheduler.py", line 376, in __call__
r.start()
File "heat/engine/scheduler.py", line 199, in start
self.step()
File "heat/engine/scheduler.py", line 222, in step
next(self._runner)
File "heat/engine/scheduler.py", line 321, in wrapper
subtask = parent.throw(*sys.exc_info())
File "heat/engine/resource.py", line 536, in _do_action
yield self.action_handler_task(action, args=handler_args)
File "/usr/lib/python2.7/contextlib.py", line 35, in __exit__
self.gen.throw(type, value, traceback)
File "heat/engine/resource.py", line 475, in _action_recorder
self.state_set(action, self.FAILED, six.text_type(failure))
File "heat/engine/resource.py", line 1001, in state_set
self._add_event(action, status, reason)
File "heat/engine/resource.py", line 943, in _add_event
ev.store()
File "heat/engine/event.py", line 87, in store
new_ev = db_api.event_create(self.context, ev)
File "heat/db/api.py", line 214, in event_create
return IMPL.event_create(context, values)
File "heat/db/sqlalchemy/api.py", line 629, in event_create
if ((event_count_all_by_stack(context, values['stack_id']) >=
File "heat/db/sqlalchemy/api.py", line 609, in event_count_all_by_stack
return _query_all_by_stack(context, stack_id).count()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2640, in count
return self.from_self(col).scalar()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2426, in scalar
ret = self.one()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2395, in one
ret = list(self)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2438, in __iter__
return self._execute_and_instances(context)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2451, in _execute_and_instances
close_with_result=True)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2442, in _connection_from_session
**kw)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 854, in connection
close_with_result=close_with_result)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 858, in _connection_for_bind
return self.transaction._connection_for_bind(engine)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 305, in _connection_for_bind
self._assert_active()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 214, in _assert_active
% self._rollback_exception
InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original exception was: UPDATE statement on table 'resource' expected to update 1 row(s); 0 were matched.
Before testing i removed my previous venv in .tox.
Unfortunately, this trace is reproducing from time to time.
I did some code analysis but I am not sure if it is right or not:
1) The exception is raising when smbd is trying to flush a session that was not commited (or rollback).
2) it is very likely that exception is raising because of this code in engine.resource:
self._store_or_update(action, status, reason)
if new_state != old_state:
self._add_event(action, status, reason)
3) when _store_or_update was called the following code in models.HeatBase is updating a resource
if not session:
session = orm_session.Session.object_session(self)
if not session:
session = get_session()
session.begin()
for k, v in six.iteritems(values):
setattr(self, k, v)
session.commit()
You can see that there is not rollback and potentially get_session can be used for transaction.
4) when _add_event was called the following code is creating an event in sql_alchemy.api:
event_ref.update(values)
event_ref.save(_session(context))
The _session returns the following:
return (context and context.session) or get_session()
save method is executing flush so we have the error above.
I looked into code and it seems that sqlalchemy is creating a new session during get_sessioncall() but it is somehow using the same session for add_event and update_and_save operations. |
Hello Guys!
When I tested heat with tox i got the following exception:
Traceback (most recent call last):
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/hub.py", line 457, in fire_timers
timer()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/eventlet/hubs/timer.py", line 58, in __call__
cb(*args, **kw)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/eventlet/greenthread.py", line 214, in main
result = function(*args, **kwargs)
File "heat/engine/service.py", line 115, in _start_with_trace
return func(*args, **kwargs)
File "heat/engine/service.py", line 603, in _stack_create
stack.adopt()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/osprofiler/profiler.py", line 105, in wrapper
return f(*args, **kwargs)
File "heat/engine/stack.py", line 708, in adopt
creator(timeout=self.timeout_secs())
File "heat/engine/scheduler.py", line 174, in __call__
self.start(timeout=timeout)
File "heat/engine/scheduler.py", line 199, in start
self.step()
File "heat/engine/scheduler.py", line 222, in step
next(self._runner)
File "heat/engine/scheduler.py", line 321, in wrapper
subtask = parent.throw(*sys.exc_info())
File "heat/engine/stack.py", line 631, in stack_task
yield action_task()
File "heat/engine/scheduler.py", line 295, in wrapper
step = next(subtask)
File "heat/engine/scheduler.py", line 376, in __call__
r.start()
File "heat/engine/scheduler.py", line 199, in start
self.step()
File "heat/engine/scheduler.py", line 222, in step
next(self._runner)
File "heat/engine/scheduler.py", line 321, in wrapper
subtask = parent.throw(*sys.exc_info())
File "heat/engine/resource.py", line 536, in _do_action
yield self.action_handler_task(action, args=handler_args)
File "/usr/lib/python2.7/contextlib.py", line 35, in __exit__
self.gen.throw(type, value, traceback)
File "heat/engine/resource.py", line 475, in _action_recorder
self.state_set(action, self.FAILED, six.text_type(failure))
File "heat/engine/resource.py", line 1001, in state_set
self._add_event(action, status, reason)
File "heat/engine/resource.py", line 943, in _add_event
ev.store()
File "heat/engine/event.py", line 87, in store
new_ev = db_api.event_create(self.context, ev)
File "heat/db/api.py", line 214, in event_create
return IMPL.event_create(context, values)
File "heat/db/sqlalchemy/api.py", line 629, in event_create
if ((event_count_all_by_stack(context, values['stack_id']) >=
File "heat/db/sqlalchemy/api.py", line 609, in event_count_all_by_stack
return _query_all_by_stack(context, stack_id).count()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2640, in count
return self.from_self(col).scalar()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2426, in scalar
ret = self.one()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2395, in one
ret = list(self)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2438, in __iter__
return self._execute_and_instances(context)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2451, in _execute_and_instances
close_with_result=True)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 2442, in _connection_from_session
**kw)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 854, in connection
close_with_result=close_with_result)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 858, in _connection_for_bind
return self.transaction._connection_for_bind(engine)
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 305, in _connection_for_bind
self._assert_active()
File "/home/kairat/MyProjects/heat/.tox/py27/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 214, in _assert_active
% self._rollback_exception
InvalidRequestError: This Session's transaction has been rolled back due to a previous exception during flush. To begin a new transaction with this Session, first issue Session.rollback(). Original exception was: UPDATE statement on table 'resource' expected to update 1 row(s); 0 were matched.
Before testing i removed my previous venv in .tox.
Unfortunately, this trace is reproducing from time to time.
I did some code analysis but I am not sure if it is right or not:
1) The exception is raising when smbd is trying to flush a session that was not commited (or rollback).
2) it is very likely that exception is raising because of this code in engine.resource:
self._store_or_update(action, status, reason)
if new_state != old_state:
self._add_event(action, status, reason)
3) when _store_or_update was called the following code in models.HeatBase is updating a resource
if not session:
session = orm_session.Session.object_session(self)
if not session:
session = get_session()
session.begin()
for k, v in six.iteritems(values):
setattr(self, k, v)
session.commit()
You can see that there is not rollback and potentially get_session can be used for transaction.
4) when _add_event was called the following code is creating an event in sql_alchemy.api:
event_ref.update(values)
event_ref.save(_session(context))
The _session returns the following:
return (context and context.session) or get_session()
save method is executing flush so we have the error above.
I looked into code and it seems that sqlalchemy is creating a new session during get_sessioncall() but it is somehow using the same session for add_event and update_and_save operations.
Environment:
- Ubuntu 14.04
- tox 1.8.1
- sqlalchemy 0.9.8
- Heat is actual: the last commit was yesterday: (04e68f87ca0cdb94f47ca156d2363de4932ec911) |
|
