Red Hat Bugzilla – Bug 1592823
Update logs should have timestamps to make debugging easier
Last modified: 2018-07-19 10:28:02 EDT
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.
Merged to stable/queens.
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.
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