From 339cbf4c3d8b17767e630d37744507bee7386a89 Mon Sep 17 00:00:00 2001
From: Ian Wienand <iwienand@redhat.com>
Date: Thu, 9 Apr 2020 14:34:35 +1000
Subject: [PATCH] mirror-update: stats for vos release of mirrors

It's difficult to know if a release process is running too long when
we don't have a history of how long it should run for.

This is mostly the stats function from run_all.sh that has been
sending stats about runtimes there.  Wrap it in a vos_release function
with some minor refactoring, and update the scripts.

As noted inline, there's already release timer stats going to
afs.release.<volume> for the periodic release of docs/tarballs etc.

Change-Id: I3d79d1a0997af8977050b7f6e7cf3b7578cc8491
---
 .../mirror-update/files/centos-mirror-update  |  2 +-
 .../mirror-update/files/epel-mirror-update    |  2 +-
 .../mirror-update/files/fedora-mirror-update  |  2 +-
 .../roles/mirror-update/files/functions.sh    | 45 ++++++++++++++++++-
 .../files/opensuse-mirror-update              |  2 +-
 .../files/yum-puppetlabs-mirror-update        |  2 +-
 .../roles/mirror-update/tasks/rsync.yaml      |  8 +++-
 7 files changed, 56 insertions(+), 7 deletions(-)

diff --git a/playbooks/roles/mirror-update/files/centos-mirror-update b/playbooks/roles/mirror-update/files/centos-mirror-update
index 061341efa7..1022b907f7 100755
--- a/playbooks/roles/mirror-update/files/centos-mirror-update
+++ b/playbooks/roles/mirror-update/files/centos-mirror-update
@@ -93,7 +93,7 @@ done
 
 date --iso-8601=ns | $K5START tee $BASE/timestamp.txt
 echo "rsync completed successfully, running vos release."
-$VOS_RELEASE $MIRROR_VOLUME
+vos_release $MIRROR_VOLUME
 
 date --iso-8601=ns
 echo "Done."
diff --git a/playbooks/roles/mirror-update/files/epel-mirror-update b/playbooks/roles/mirror-update/files/epel-mirror-update
index 63b38c744d..3b808a6e86 100755
--- a/playbooks/roles/mirror-update/files/epel-mirror-update
+++ b/playbooks/roles/mirror-update/files/epel-mirror-update
@@ -90,7 +90,7 @@ echo "$SHA1SUM $BASE/$REPO/$REPOMD" | sha1sum -c -
 
 date --iso-8601=ns | $K5START tee $BASE/timestamp.txt
 echo "rsync completed successfully, running vos release."
-$VOS_RELEASE $MIRROR_VOLUME
+vos_release $MIRROR_VOLUME
 
 date --iso-8601=ns
 echo "Done."
diff --git a/playbooks/roles/mirror-update/files/fedora-mirror-update b/playbooks/roles/mirror-update/files/fedora-mirror-update
index 269db09acc..c1dd56a6d5 100755
--- a/playbooks/roles/mirror-update/files/fedora-mirror-update
+++ b/playbooks/roles/mirror-update/files/fedora-mirror-update
@@ -153,7 +153,7 @@ sleep $(( 20 * 60 ))
 date --iso-8601=ns | $K5START tee $BASE/timestamp.txt
 
 echo_ts "Running vos release."
-$VOS_RELEASE $MIRROR_VOLUME | \
+vos_release $MIRROR_VOLUME | \
     while IFS= read -r line; do echo_ts "$line"; done
 echo_ts "... done"
 
diff --git a/playbooks/roles/mirror-update/files/functions.sh b/playbooks/roles/mirror-update/files/functions.sh
index 9fefd29ef3..4213089ee1 100644
--- a/playbooks/roles/mirror-update/files/functions.sh
+++ b/playbooks/roles/mirror-update/files/functions.sh
@@ -2,4 +2,47 @@
 # Common definitions and functions for mirror-update scripts
 #
 
-VOS_RELEASE="ssh -i /root/.ssh/id_vos_release vos_release@afs01.dfw.openstack.org vos release "
+AFS_SERVER=afs01.dfw.openstack.org
+VOS_RELEASE="ssh -i /root/.ssh/id_vos_release vos_release@${AFS_SERVER} vos release "
+
+# Send a timer stat to statsd
+#  send_timer metric [start_time]
+# * uses timer metric afs.release.<$1> normalised for stats
+# * time will be taken from last call of start_timer, or $2 if set
+function send_timer {
+    # Only send stats under cron conditions
+    if [[ ${UNDER_CRON} != 1 ]]; then
+        return
+    fi
+
+    local current
+    current=$(date '+%s')
+    local name
+    # "." is a separator, replace with _
+    name=${1//./_}
+    local start
+    start=${2-$_START_TIME}
+    local elapsed_ms
+    elapsed_ms=$(( (current - start) * 1000 ))
+
+    # See also the release-volumes.py script which sends stats to the
+    # same place for doc, etc. volumes.
+    echo "afs.release.${name}:${elapsed_ms}|ms" | nc -w 1 -u graphite.opendev.org 8125
+    echo "End timer for $name"
+}
+
+# See send_timer
+function start_timer {
+    _START_TIME=$(date '+%s')
+}
+
+# Run vos release via ssh on the AFS server, and report the timing
+# back to graphite
+function vos_release {
+    local name
+    name=$1
+
+    start_timer
+    $VOS_RELEASE ${name}
+    send_timer ${name}
+}
diff --git a/playbooks/roles/mirror-update/files/opensuse-mirror-update b/playbooks/roles/mirror-update/files/opensuse-mirror-update
index 424aa3e99c..9a1ae277fc 100755
--- a/playbooks/roles/mirror-update/files/opensuse-mirror-update
+++ b/playbooks/roles/mirror-update/files/opensuse-mirror-update
@@ -133,7 +133,7 @@ $K5START rsync -rlptDvz \
 
 date --iso-8601=ns | $K5START tee $BASE/timestamp.txt
 echo "rsync completed successfully, running vos release."
-$VOS_RELEASE $MIRROR_VOLUME
+vos_release $MIRROR_VOLUME
 
 date --iso-8601=ns
 echo "Done."
diff --git a/playbooks/roles/mirror-update/files/yum-puppetlabs-mirror-update b/playbooks/roles/mirror-update/files/yum-puppetlabs-mirror-update
index 6ef69b192e..4f6214d7a2 100755
--- a/playbooks/roles/mirror-update/files/yum-puppetlabs-mirror-update
+++ b/playbooks/roles/mirror-update/files/yum-puppetlabs-mirror-update
@@ -60,7 +60,7 @@ $K5START rsync -rlptDvz \
 
 date --iso-8601=ns | $K5START tee $BASE/timestamp.txt
 echo "rsync completed successfully, running vos release."
-$VOS_RELEASE $MIRROR_VOLUME
+vos_release $MIRROR_VOLUME
 
 date --iso-8601=ns
 echo "Done."
diff --git a/playbooks/roles/mirror-update/tasks/rsync.yaml b/playbooks/roles/mirror-update/tasks/rsync.yaml
index daaaffa37d..a91fc6a419 100644
--- a/playbooks/roles/mirror-update/tasks/rsync.yaml
+++ b/playbooks/roles/mirror-update/tasks/rsync.yaml
@@ -55,6 +55,12 @@
     mode: '0755'
   loop: '{{ rsync_update_scripts }}'
 
+- name: Set cron flag to enable reporting stats
+  cron:
+    name: UNDER_CRON
+    env: yes
+    job: '1'
+
 - name: Install update cron jobs
   cron:
     name: '{{ item }} mirror sync'
@@ -70,4 +76,4 @@
   vars:
     logrotate_file_name: '/var/log/rsync-mirrors/{{ item }}.log'
     logrotate_frequency: 'weekly'
-  loop: '{{ rsync_update_scripts }}'
\ No newline at end of file
+  loop: '{{ rsync_update_scripts }}'