Bug 1592823 - Update logs should have timestamps to make debugging easier
Summary: Update logs should have timestamps to make debugging easier
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-tripleo-common
Version: 13.0 (Queens)
Hardware: Unspecified
OS: Unspecified
medium
low
Target Milestone: z1
: 13.0 (Queens)
Assignee: Jiri Stransky
QA Contact: Raviv Bar-Tal
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-06-19 11:47 UTC by Jiri Stransky
Modified: 2022-07-09 11:34 UTC (History)
10 users (show)

Fixed In Version: openstack-tripleo-common-8.6.1-23.el7ost
Doc Type: Enhancement
Doc Text:
Logs from Ansible playbooks now include timestamps that provide information about the timing of actions during deployment, updates, and upgrades.
Clone Of:
Environment:
Last Closed: 2018-07-19 14:27:12 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Launchpad 1777467 0 None None None 2018-06-19 11:47:33 UTC
OpenStack gerrit 577103 0 None MERGED Provide timestamps in Ansible output by default 2020-05-05 18:31:23 UTC
Red Hat Issue Tracker OSP-17205 0 None None None 2022-07-09 11:34:29 UTC
Red Hat Product Errata RHSA-2018:2214 0 None None None 2018-07-19 14:28:01 UTC

Description Jiri Stransky 2018-06-19 11:47:34 UTC 
With bugs where finding root cause is difficult, timestamps on activity logs are often useful clues. Currently we don't have timestamps on logs from updates and upgrades.
Comment 1 Jiri Stransky 2018-06-29 14:22:06 UTC 
Merged to stable/queens.
Comment 8 Marius Cornea 2018-07-17 15:43:17 UTC 
Snippet of stdout of openstack overcloud update run --nodes Controller --playbook all:

2018-07-15 14:40:47 |  u'TASK [Check if /var/lib/docker-puppet/docker-puppet-tasks5.json exists] ********',
2018-07-15 14:40:47 |  u'Sunday 15 July 2018  14:40:41 -0400 (0:00:01.967)       1:17:20.600 *********** ',
2018-07-15 14:40:47 |  u'ok: [192.168.24.13] => {"changed": false, "stat": {"exists": false}}',
2018-07-15 14:40:47 |  u'',
2018-07-15 14:40:47 |  u'TASK [Run docker-puppet tasks (bootstrap tasks) for step 5] ********************',
2018-07-15 14:40:47 |  u'Sunday 15 July 2018  14:40:43 -0400 (0:00:02.370)       1:17:22.971 *********** ',
2018-07-15 14:40:47 |  u'skipping: [192.168.24.13] => {"censored": "the output has been hidden due to the fact that \'no_log: true\' was specified for this result", "changed": false}',
2018-07-15 14:40:47 |  u'',
2018-07-15 14:40:47 |  u'TASK [Debug output for task which failed: Run docker-puppet tasks (bootstrap tasks) for step 5] ***',
2018-07-15 14:40:47 |  u'Sunday 15 July 2018  14:40:43 -0400 (0:00:00.047)       1:17:23.018 *********** ',
2018-07-15 14:40:47 |  u'skipping: [192.168.24.13] => {"changed": false, "skip_reason": "Conditional result was False"}',
2018-07-15 14:40:47 |  u'',
2018-07-15 14:40:47 |  u'PLAY RECAP *********************************************************************',
2018-07-15 14:40:47 |  u'192.168.24.13              : ok=221  changed=65   unreachable=0    failed=0   ',
2018-07-15 14:40:47 |  u'192.168.24.19              : ok=216  changed=64   unreachable=0    failed=0   ',
2018-07-15 14:40:47 |  u'192.168.24.8               : ok=216  changed=64   unreachable=0    failed=0   ',
2018-07-15 14:40:47 |  u'',
2018-07-15 14:40:47 |  u'Sunday 15 July 2018  14:40:43 -0400 (0:00:00.026)       1:17:23.045 *********** ',
2018-07-15 14:40:47 |  u'=============================================================================== ']
2018-07-15 14:40:47 | Success


Snippet of var/log/mistral/package_update.log

2018-07-15 15:05:48,003 p=16680 u=mistral |  TASK [Check if /var/lib/docker-puppet/docker-puppet-tasks5.json exists] ********
2018-07-15 15:05:48,004 p=16680 u=mistral |  Sunday 15 July 2018  15:05:48 -0400 (0:00:00.065)       0:11:47.433 *********** 
2018-07-15 15:05:50,211 p=16680 u=mistral |  ok: [192.168.24.17] => {"changed": false, "stat": {"exists": false}}
2018-07-15 15:05:50,230 p=16680 u=mistral |  TASK [Run docker-puppet tasks (bootstrap tasks) for step 5] ********************
2018-07-15 15:05:50,231 p=16680 u=mistral |  Sunday 15 July 2018  15:05:50 -0400 (0:00:02.227)       0:11:49.660 *********** 
2018-07-15 15:05:50,258 p=16680 u=mistral |  skipping: [192.168.24.17] => {"censored": "the output has been hidden due to the fact that 'no_log: true' was specified for this result", "changed": false}
2018-07-15 15:05:50,273 p=16680 u=mistral |  TASK [Debug output for task which failed: Run docker-puppet tasks (bootstrap tasks) for step 5] ***
2018-07-15 15:05:50,273 p=16680 u=mistral |  Sunday 15 July 2018  15:05:50 -0400 (0:00:00.041)       0:11:49.702 *********** 
2018-07-15 15:05:50,297 p=16680 u=mistral |  skipping: [192.168.24.17] => {"changed": false, "skip_reason": "Conditional result was False"}
2018-07-15 15:05:50,300 p=16680 u=mistral |  PLAY RECAP *********************************************************************
2018-07-15 15:05:50,300 p=16680 u=mistral |  192.168.24.14              : ok=83   changed=18   unreachable=0    failed=0   
2018-07-15 15:05:50,300 p=16680 u=mistral |  192.168.24.17              : ok=83   changed=18   unreachable=0    failed=0   
2018-07-15 15:05:50,301 p=16680 u=mistral |  192.168.24.7               : ok=83   changed=18   unreachable=0    failed=0   
2018-07-15 15:05:50,301 p=16680 u=mistral |  Sunday 15 July 2018  15:05:50 -0400 (0:00:00.027)       0:11:49.730 *********** 
2018-07-15 15:05:50,301 p=16680 u=mistral |  =============================================================================== 

Timestamps are present so we can move this bug to verified.
Comment 10 errata-xmlrpc 2018-07-19 14:27:12 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2018:2214
Note You need to log in before you can comment on or make changes to this bug.