Cron trigger workflow executions fail to start

Bug #1753228 reported by Dougal Matthews
14
This bug affects 3 people
Affects Status Importance Assigned to Milestone
Mistral
Invalid
Critical
Dougal Matthews

Bug Description

Error from TripleO CI.

http://logs.openstack.org/73/549273/2/check/tripleo-ci-centos-7-3nodes-multinode/92da7fd/logs/undercloud/var/log/mistral/api.log.txt.gz?level=ERROR

2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic [req-e57997ab-83ee-427a-8090-a60de679e1d4 315af312912d4ee5808e29c8de0a4aaa 20ba51d774454f3a96e1e6f3affcd2b5 - - -] Failed to process cron trigger CronTrigger {'workflow_params': {}, 'name': u'publish-ui-logs-hourly', 'workflow_name': u'tripleo.plan_management.v1.publish_ui_logs_to_swift', 'pattern': u'0 * * * *', 'created_at': '2018-03-03 18:07:38', 'updated_at': None, 'workflow_input': {}, 'workflow_params_hash': u'4f53cda18c2baa0c0354bb5f9a3ecbe5ed12ab4d8e11ba873c2f11161202b945', 'workflow_id': u'8743ca5b-ea79-445c-8b53-2eea0063972d', 'first_execution_time': None, 'remaining_executions': None, 'workflow_input_hash': u'4f53cda18c2baa0c0354bb5f9a3ecbe5ed12ab4d8e11ba873c2f11161202b945', 'scope': u'private', 'project_id': u'20ba51d774454f3a96e1e6f3affcd2b5', 'id': u'69455d61-8029-462b-af0d-8ce5b060f9f8', 'trust_id': u'de64a4e46f374a6ba08c48ae8b1a5755', 'next_execution_time': '2018-03-03 19:00:00'}: MistralException: TypeError: unhashable type: 'dict'
Traceback (most recent call last):

  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
    res = self.dispatcher.dispatch(message)

  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
    return self._do_dispatch(endpoint, method, ctxt, args)

  File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
    result = func(ctxt, **new_args)

  File "/usr/lib/python2.7/site-packages/mistral/engine/engine_server.py", line 111, in start_workflow
    **params

  File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 81, in decorate
    return _with_auth_context(auth_ctx, func, *args, **kw)

  File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 214, in wrapped_f
    return self.call(f, *args, **kw)

  File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 295, in call
    start_time=start_time)

  File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 252, in iter
    return fut.result()

  File "/usr/lib/python2.7/site-packages/concurrent/futures/_base.py", line 422, in result
    return self.__get_result()

  File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 298, in call
    result = fn(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 50, in _with_auth_context
    return func(*args, **kw)

  File "/usr/lib/python2.7/site-packages/mistral/engine/action_queue.py", line 93, in decorate
    res = func(*args, **kw)

  File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 157, in wrapper
    result = f(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/mistral/engine/default_engine.py", line 53, in start_workflow
    params

  File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 157, in wrapper
    result = f(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/mistral/engine/workflow_handler.py", line 54, in start_workflow
    params=params

  File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 157, in wrapper
    result = f(*args, **kwargs)

  File "/usr/lib/python2.7/site-packages/mistral/engine/workflows.py", line 98, in start
    params

  File "/usr/lib/python2.7/site-packages/mistral/engine/workflows.py", line 274, in _create_execution
    'index': params.get('index', 0)

  File "/usr/lib/python2.7/site-packages/mistral/db/v2/api.py", line 266, in create_workflow_execution
    return IMPL.create_workflow_execution(values)

  File "/usr/lib/python2.7/site-packages/mistral/db/sqlalchemy/base.py", line 117, in _within_session
    result = func(*args, **kw)

  File "/usr/lib/python2.7/site-packages/mistral/db/v2/sqlalchemy/api.py", line 829, in create_workflow_execution
    wf_ex.save(session=session)

  File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/models.py", line 50, in save
    session.flush()

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2243, in flush
    self._flush(objects)

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2369, in _flush
    transaction.rollback(_capture_exception=True)

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
    compat.reraise(exc_type, exc_value, exc_tb)

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2333, in _flush
    flush_context.execute()

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute
    rec.execute(self)

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute
    uow

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 156, in save_obj
    base_mapper, states, uowtransaction

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 308, in _organize_states_for_save
    instance_key in uowtransaction.session.identity_map:

  File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/identity.py", line 97, in __contains__
    if key in self._dict:

TypeError: unhashable type: 'dict'
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic Traceback (most recent call last):
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/services/periodic.py", line 85, in process_cron_triggers_v2
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic **trigger.workflow_params
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/rpc/base.py", line 109, in decorator
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic _wrap_exception_and_reraise(e)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/rpc/base.py", line 84, in _wrap_exception_and_reraise
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic raise exc.MistralException(message)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic MistralException: TypeError: unhashable type: 'dict'
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic Traceback (most recent call last):
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 163, in _process_incoming
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic res = self.dispatcher.dispatch(message)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 220, in dispatch
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return self._do_dispatch(endpoint, method, ctxt, args)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 190, in _do_dispatch
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic result = func(ctxt, **new_args)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/engine/engine_server.py", line 111, in start_workflow
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic **params
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 81, in decorate
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return _with_auth_context(auth_ctx, func, *args, **kw)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 214, in wrapped_f
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return self.call(f, *args, **kw)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 295, in call
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic start_time=start_time)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 252, in iter
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return fut.result()
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/concurrent/futures/_base.py", line 422, in result
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return self.__get_result()
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/tenacity/__init__.py", line 298, in call
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic result = fn(*args, **kwargs)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/db/utils.py", line 50, in _with_auth_context
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return func(*args, **kw)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/engine/action_queue.py", line 93, in decorate
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic res = func(*args, **kw)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 157, in wrapper
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic result = f(*args, **kwargs)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/engine/default_engine.py", line 53, in start_workflow
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic params
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 157, in wrapper
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic result = f(*args, **kwargs)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/engine/workflow_handler.py", line 54, in start_workflow
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic params=params
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/osprofiler/profiler.py", line 157, in wrapper
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic result = f(*args, **kwargs)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/engine/workflows.py", line 98, in start
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic params
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/engine/workflows.py", line 274, in _create_execution
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic 'index': params.get('index', 0)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/db/v2/api.py", line 266, in create_workflow_execution
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic return IMPL.create_workflow_execution(values)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/db/sqlalchemy/base.py", line 117, in _within_session
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic result = func(*args, **kw)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/mistral/db/v2/sqlalchemy/api.py", line 829, in create_workflow_execution
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic wf_ex.save(session=session)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/models.py", line 50, in save
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic session.flush()
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2243, in flush
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic self._flush(objects)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2369, in _flush
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic transaction.rollback(_capture_exception=True)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 66, in __exit__
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic compat.reraise(exc_type, exc_value, exc_tb)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2333, in _flush
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic flush_context.execute()
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 391, in execute
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic rec.execute(self)
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 556, in execute
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic uow
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 156, in save_obj
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic base_mapper, states, uowtransaction
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 308, in _organize_states_for_save
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic instance_key in uowtransaction.session.identity_map:
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/identity.py", line 97, in __contains__
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic if key in self._dict:
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic TypeError: unhashable type: 'dict'
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic
2018-03-03 18:59:59.755 9268 ERROR mistral.services.periodic

Tags: tripleo
Revision history for this message
Dougal Matthews (d0ugal) wrote :

I believe this could be related to the changes made for the new event notifier functionality. We had a similar issue when the start workflow code was updated.

We really need to find a better way to test this (or at least make sure tripleo CI fails when this happens) - we don't currently check that the background are successful.

Dougal Matthews (d0ugal)
Changed in mistral:
status: Confirmed → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.