From 65ddba3a9958a65998b19db21e9605c3a7899a96 Mon Sep 17 00:00:00 2001
From: Ian Wienand <iwienand@redhat.com>
Date: Mon, 18 Jul 2022 12:42:13 +1000
Subject: [PATCH] run-production-playbook: rename with original timestamp

How we got here - I3e99b80e442db0cc87f8e8c9728b7697a5e4d1d3 split the
log collection into a post-run job so we always collect logs, even if
the main run times out.  We then realised in
Ic18c89ecaf144a69e82cbe9eeed2641894af71fb that the log timestamp fact
doesn't persist across playbook runs and it's not totally clear how
getting it from hostvars interacts with dynamic inventory.

Thus take an approach that doesn't rely on passing variables; this
simply pulls the time from the stamp we put on the first line of the
log file.  We then use that to rename the stored file, which should
correspond more closely with the time the Zuul job actually started.
To further remove confusion when looking at a lot of logs, reset the
timestamps to this time as well.

Change-Id: I7a115c75286e03b09ac3b8982ff0bd01037d34dd
---
 .../zuul/run-production-playbook-post.yaml    | 25 ++++++++++++++++---
 playbooks/zuul/run-production-playbook.yaml   |  2 ++
 2 files changed, 23 insertions(+), 4 deletions(-)

diff --git a/playbooks/zuul/run-production-playbook-post.yaml b/playbooks/zuul/run-production-playbook-post.yaml
index 43c5bc27d6..ac6349ae47 100644
--- a/playbooks/zuul/run-production-playbook-post.yaml
+++ b/playbooks/zuul/run-production-playbook-post.yaml
@@ -81,11 +81,17 @@
                 metadata:
                   type: text
 
-    # If we aren't publishing logs through zuul then keep a set on
-    # bridge directly.
-    - name: Get a current timestamp
+    # Save files locally on bridge
+    - name: Get original timestamp from file header
+      shell: |
+          head -1 /var/log/ansible/{{ playbook_name.log }} | sed -n 's/^Running \(.*\):.*$/\1/p'
+      args:
+        executable: /bin/bash
+      register: _log_timestamp
+
+    - name: Turn timestamp into a string
       set_fact:
-        _log_timestamp: "{{ lookup('pipe', 'date +%Y-%m-%dT%H:%M:%S') }}"
+        _log_timestamp: '{{ _log_timestamp.stdout | trim }}'
 
     - name: Rename playbook log on bridge
       when: not infra_prod_playbook_collect_log
@@ -95,6 +101,17 @@
         src: "/var/log/ansible/{{ playbook_name }}.log"
         dest: "/var/log/ansible/{{ playbook_name }}.log.{{ _log_timestamp }}"
 
+    # Reset the access/modification time to the timestamp in the filename; this
+    # makes lining things up more logical
+    - name: Reset file time
+      file:
+        src: '/var/log/ansible/{{ playbook_name }}.log.{{ _log_timestamp }}'
+        state: touch
+        modification_time: '{{ _log_timestamp }}'
+        modification_time_format: '%Y-%m%-%dT%H:%M:%S'
+        access_time: '{{ _log_timestamp }}'
+        access_time_format: '%Y-%m%-%dT%H:%M:%S'
+
     - name: Cleanup old playbook logs on bridge
       when: not infra_prod_playbook_collect_log
       become: yes
diff --git a/playbooks/zuul/run-production-playbook.yaml b/playbooks/zuul/run-production-playbook.yaml
index 455816c27c..d26f9d3e58 100644
--- a/playbooks/zuul/run-production-playbook.yaml
+++ b/playbooks/zuul/run-production-playbook.yaml
@@ -19,6 +19,8 @@
         set_fact:
           _log_timestamp: "{{ lookup('pipe', 'date +%Y-%m-%dT%H:%M:%S') }}"
 
+      # NOTE(ianw) : this gets parsed by the post playbook.  If this
+      # is updated, that parsing should be too
       - name: Log a playbook start header
         become: yes
         shell: 'echo "Running {{ _log_timestamp }}: ansible-playbook -v -f {{ infra_prod_ansible_forks }} /home/zuul/src/opendev.org/opendev/system-config/playbooks/{{ playbook_name }}" > /var/log/ansible/{{ playbook_name }}.log'