Workflow tripleo.plan_management.v1.publish_ui_logs_to_swift ERRORs

Bug #1717265 reported by Dougal Matthews
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Mistral
Invalid
Undecided
Brad P. Crochet
tripleo
Fix Released
High
Dougal Matthews

Bug Description

On a fresh environment today (created with quickstart and using devmode) I noticed that the UI log workflow fails to execute.

Details from the Mistral CLI...

(undercloud) [stack@925-heap--undercloud ~]$ mistral execution-get 88c8617c-db9f-4243-b5ea-b03fa79c9a37
+-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Field | Value |
+-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| ID | 88c8617c-db9f-4243-b5ea-b03fa79c9a37 |
| Workflow ID | f655fddf-975a-4bfb-8f07-a350ff47a0ac |
| Workflow name | tripleo.plan_management.v1.publish_ui_logs_to_swift |
| Description | {"triggered_by": {"type": "cron_trigger", "id": "04197a78-31c7-4f44-a90f-32f41adf9912", "name": "publish-ui-logs-hourly"}, "description": "Workflow execution created by cron trigger '(04197a78-31c7-4f44-a90f-32f41adf9912)'."} |
| Task Execution ID | <none> |
| State | ERROR |
| State info | None |
| Created at | 2017-09-14 12:59:59 |
| Updated at | 2017-09-14 13:00:06 |
+-------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
(undercloud) [stack@925-heap--undercloud ~]$ mistral execution-get-output 88c8617c-db9f-4243-b5ea-b03fa79c9a37
{
    "status": "FAILED",
    "message": "Failed to run action [action_ex_id=512304ab-98d1-4b80-9234-338231ac91f5, action_cls='<class 'mistral.actions.action_factory.PublishUILogToSwiftAction'>', attributes='{}', params='{u'logging_data': u'', u'logging_container': u'tripleo-ui-logs'}']\n ",
    "messages": "",
    "result": null
}
(undercloud) [stack@925-heap--undercloud ~]$ mistral task-list 88c8617c-db9f-4243-b5ea-b03fa79c9a37
+--------------------------------------+-----------------------------------+-----------------------------------------------------+--------------------------------------+---------+------------------------------+---------------------+---------------------+
| ID | Name | Workflow name | Execution ID | State | State info | Created at | Updated at |
+--------------------------------------+-----------------------------------+-----------------------------------------------------+--------------------------------------+---------+------------------------------+---------------------+---------------------+
| 37bd933a-603a-439d-9e51-2ee8b9a3f1d1 | get_messages | tripleo.plan_management.v1.publish_ui_logs_to_swift | 88c8617c-db9f-4243-b5ea-b03fa79c9a37 | SUCCESS | None | 2017-09-14 12:59:59 | 2017-09-14 13:00:02 |
| 55e56760-e01f-448a-8ee9-3ef716e9f837 | upload_to_swift_set_status_failed | tripleo.plan_management.v1.publish_ui_logs_to_swift | 88c8617c-db9f-4243-b5ea-b03fa79c9a37 | SUCCESS | None | 2017-09-14 13:00:02 | 2017-09-14 13:00:03 |
| 65c977dd-6c20-457e-a64c-e786e6bf2a03 | format_messages | tripleo.plan_management.v1.publish_ui_logs_to_swift | 88c8617c-db9f-4243-b5ea-b03fa79c9a37 | SUCCESS | None | 2017-09-14 13:00:02 | 2017-09-14 13:00:02 |
| 6d3becc7-15c3-4ef2-8d4c-6557165ad256 | upload_to_swift | tripleo.plan_management.v1.publish_ui_logs_to_swift | 88c8617c-db9f-4243-b5ea-b03fa79c9a37 | ERROR | Failed to run action [act... | 2017-09-14 13:00:02 | 2017-09-14 13:00:02 |
| 48f02d20-dbcb-4150-a737-91c0da79e39e | notify_zaqar | tripleo.plan_management.v1.publish_ui_logs_to_swift | 88c8617c-db9f-4243-b5ea-b03fa79c9a37 | SUCCESS | None | 2017-09-14 13:00:03 | 2017-09-14 13:00:06 |
+--------------------------------------+-----------------------------------+-----------------------------------------------------+--------------------------------------+---------+------------------------------+---------------------+---------------------+

And the traceback from the logs...

2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor [req-1f29021f-02f6-4701-a1e3-a04009f8c6c5 f6766a837fd141caab9b9f1b46294f83 b2369236c0e04741a97f3eb99248c8e7 - default default] Failed to run action [action_ex_id=512304ab-98d1-4b80-9234-338231ac91f5, action_cls='<class 'mistral.actions.action_factory.PublishUILogToSwiftAction'>', attributes='{}', params='{u'logging_data': u'', u'logging_container': u'tripleo-ui-logs'}']
 : UnauthorizedException
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor Traceback (most recent call last):
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/mistral/executors/default_executor.py", line 109, in run_action
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor result = action.run(context.ctx())
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/tripleo_common/actions/logging_to_swift.py", line 125, in run
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor swift = self.get_object_client(context)
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/tripleo_common/actions/base.py", line 38, in get_object_client
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor obj_ep = keystone_utils.get_endpoint_for_project(context, 'swift')
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/tripleo_common/utils/keystone.py", line 47, in get_endpoint_for_project
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor service_catalog = obtain_service_catalog(ctx)
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor File "/usr/lib/python2.7/site-packages/tripleo_common/utils/keystone.py", line 111, in obtain_service_catalog
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor raise exception.UnauthorizedException()
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor UnauthorizedException
2017-09-14 13:00:02.748 20437 ERROR mistral.executors.default_executor

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

I looked at a recent CI run to see if I could find it in another env. It was in the first one I looked.

http://logs.openstack.org/02/503002/1/check/gate-tripleo-ci-centos-7-containers-multinode/d6b526a/logs/undercloud/var/log/mistral/executor.log.txt.gz#_2017-09-12_15_00_04_852

As this is a background task, CI will never fail when it fails - we maybe need to make that happen, just so we can verify it more easily.

description: updated
summary: - tripleo.plan_management.v1.publish_ui_logs_to_swift ERRORs
+ Workflow tripleo.plan_management.v1.publish_ui_logs_to_swift ERRORs
Changed in tripleo:
status: Confirmed → Triaged
Revision history for this message
Honza Pokorny (hpokorny) wrote :

The context passed to the run function is empty when the workflow is run from the cron trigger, and properly populated when triggered manually from the CLI.

This is likely caused by the MistralContext being initialized as empty here:

https://github.com/openstack/mistral/blob/b8d1e096e4cd5869e868cb7ad7101c52f93ea7d1/mistral/services/periodic.py#L141-L146

Revision history for this message
Dougal Matthews (d0ugal) wrote :
Download full text (11.4 KiB)

I hacked a line in my environment to log out the context. It looks like this for a cron-trigger execution.

2017-09-22 07:45:02.823 11294 ERROR tripleo_common.actions.logging_to_swift [req-22ba8884-1804-4184-8a5f-b83c28854d1a 8d3cc74390c74c8fa873b45758f24783 2d7aaea6a4d647a598cf3fa11f6a9682 - - -] {'insecure': False, 'is_target': False, 'domain': None, 'project_name': None, 'global_request_id': None, 'region_name': None, 'project_domain': None, 'user_domain_name': None, 'expires_at': None, 'resource_uuid': None, 'auth_uri': None, 'is_admin': False, 'user': u'8d3cc74390c74c8fa873b45758f24783', 'service_catalog': None, 'tenant': u'2d7aaea6a4d647a598cf3fa11f6a9682', 'read_only': False, 'is_trust_scoped': True, 'show_deleted': False, 'roles': [], 'user_identity': u'8d3cc74390c74c8fa873b45758f24783 2d7aaea6a4d647a598cf3fa11f6a9682 - - -', 'domain_name': None, 'is_admin_project': True, 'auth_cacert': None, 'trust_id': u'40f7428e89384578a8ef246acbbd8b84', 'request_id': u'req-25a46ac0-7c34-4dde-b374-e5f0cf911410', 'redelivered': False, 'user_domain': None, 'user_name': None, 'auth_token': u'gAAAAABZxL97H_p4hDR1ycy7TmoyDs0FuMxgaGhhc4a0_HE3olltt8Zu17c_3IBHEFaTkO5NM45uA3RLvJHFwbvxoKHgGChWXOb3_thG74yn0nmKi7sGoqf_quhwzts3CPMyySiUaLt_P5y0j4Xz2cavTz8hkbmIXxD4eSWTeu7uP4Vle8gXJZCuRP4rkLr-DsJTv4s1dRKL', 'project_domain_name': None}

For a regular execution of the same workflow that I manually started. It looks like this.

2017-09-22 07:35:46.354 11294 ERROR tripleo_common.actions.logging_to_swift [req-22ba8884-1804-4184-8a5f-b83c28854d1a 8d3cc74390c74c8fa873b45758f24783 2d7aaea6a4d647a598cf3fa11f6a9682 - - -] {'insecure': False,
'is_target': False, 'domain': None, 'project_name': u'admin', 'global_request_id': None, 'region_name': None, 'project_domain': u'default', 'user_domain_name': u'Default', 'expires_at': u'2017-09-22T11:35:45.000
000Z', 'resource_uuid': None, 'auth_uri': u'http://192.168.24.1:5000/v3', 'is_admin': True, 'user': u'8d3cc74390c74c8fa873b45758f24783', 'service_catalog': {u'is_domain': False, u'methods': [u'password'], u'role
s': [{u'id': u'9fe2ff9ee4384b1894a90878d3e92bab', u'name': u'_member_'}, {u'id': u'61636027cdd8441da0828652b71e3f7c', u'name': u'admin'}], u'auth_token': u'gAAAAABZxL1R8zPzJdZShZW5VqIprjMVVB7mDI4YJ1bOJbd8cCZDsE7DbUySF_Qa8WIhzfTRLYYIKohDp-DeY7_uXaYVTyKl53AI3wIthVQFH9Tw0dcRZi0VZfonBCKl_abt-uEsuPrx3YFlqeE2-JCBHXiyw_OgexVndKjfIjWEovg07o_m4Gw', u'expires_at': u'2017-09-22T11:35:45.000000Z', u'project': {u'domain': {u'id': u
'default', u'name': u'Default'}, u'id': u'2d7aaea6a4d647a598cf3fa11f6a9682', u'name': u'admin'}, u'catalog': [{u'endpoints': [{u'url': u'http://192.168.24.1:6385', u'interface': u'internal', u'region': u'regionO
ne', u'region_id': u'regionOne', u'id': u'12f09d143c164c478742b697e7908e46'}, {u'url': u'http://192.168.24.1:6385', u'interface': u'public', u'region': u'regionOne', u'region_id': u'regionOne', u'id': u'6eaecc0fd24e4eefb4f8ce7f6a52c4f9'}, {u'url': u'http://192.168.24.1:6385', u'interface': u'admin', u'region': u'regionOne', u'region_id': u'regionOne', u'id': u'f28c987cc22a4abe8bcdafb34226b37d'}], u'type': u'baremetal',
 u'id': u'17fff7197e2f48d38a9e6fbc481be711', u'name': u'ironic'}, {u'endpoint...

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

The interesting part of the above is that while it isn't empty, it doesn't have anywhere near as much as a regular context. All of the values set to None in preiodic.py[1] do have a value, so I am not sure that is likely the issue.

[1]: https://github.com/openstack/mistral/blob/b8d1e096e4cd5869e868cb7ad7101c52f93ea7d1/mistral/services/periodic.py#L141-L146

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

I have added Mistral to the bug, it seems clear to me that this is a Mistral issue and not a tripleo one.

Brad P. Crochet (brad-9)
Changed in mistral:
assignee: nobody → Brad P. Crochet (brad-9)
assignee: Brad P. Crochet (brad-9) → nobody
status: New → In Progress
assignee: nobody → Brad P. Crochet (brad-9)
Brad P. Crochet (brad-9)
Changed in tripleo:
assignee: nobody → Brad P. Crochet (brad-9)
Changed in mistral:
status: In Progress → Invalid
status: Invalid → In Progress
Revision history for this message
Brad P. Crochet (brad-9) wrote :

Not a Mistral bug per se. The error lies in the fact that the utils.keystone carried in tripleo-common got out of date with how Mistral was doing auth. I will be posting a patch to tripleo-common to fix.

Changed in mistral:
status: In Progress → Invalid
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to tripleo-common (master)

Fix proposed to branch: master
Review: https://review.openstack.org/508165

Changed in tripleo:
status: Triaged → In Progress
Changed in tripleo:
assignee: Brad P. Crochet (brad-9) → Dougal Matthews (d0ugal)
Honza Pokorny (hpokorny)
tags: added: pike-backport-potential
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to tripleo-common (master)

Reviewed: https://review.openstack.org/508165
Committed: https://git.openstack.org/cgit/openstack/tripleo-common/commit/?id=7fa4d9d95ff1499378b18189714e130179859373
Submitter: Jenkins
Branch: master

commit 7fa4d9d95ff1499378b18189714e130179859373
Author: Brad P. Crochet <email address hidden>
Date: Thu Sep 28 10:04:14 2017 -0400

    Bring the keystone utils up-to-date with Mistral

    The Mistral keystone utils had diverged a bit from what was in
    tripleo-common. Mistral had slightly different authentication
    semantics, so some tripleo-common actions were failing.

    Change-Id: Ib8c9e5a0da125b4c42702e38bd0a900f8ef3de58
    Closes-Bug: #1717265

Changed in tripleo:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to tripleo-common (stable/pike)

Fix proposed to branch: stable/pike
Review: https://review.openstack.org/510527

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/tripleo-common 8.0.0

This issue was fixed in the openstack/tripleo-common 8.0.0 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to tripleo-common (stable/pike)

Reviewed: https://review.openstack.org/510527
Committed: https://git.openstack.org/cgit/openstack/tripleo-common/commit/?id=d35837a33947da4bb461a74efa81543eaf0e1fc6
Submitter: Jenkins
Branch: stable/pike

commit d35837a33947da4bb461a74efa81543eaf0e1fc6
Author: Brad P. Crochet <email address hidden>
Date: Thu Sep 28 10:04:14 2017 -0400

    Bring the keystone utils up-to-date with Mistral

    The Mistral keystone utils had diverged a bit from what was in
    tripleo-common. Mistral had slightly different authentication
    semantics, so some tripleo-common actions were failing.

    Change-Id: Ib8c9e5a0da125b4c42702e38bd0a900f8ef3de58
    Closes-Bug: #1717265
    (cherry picked from commit 7fa4d9d95ff1499378b18189714e130179859373)

tags: added: in-stable-pike
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/tripleo-common 7.6.3

This issue was fixed in the openstack/tripleo-common 7.6.3 release.

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.