maas deploy loop: deploy things in a loop collect logs and such

README

this is hacked together code that i wanted to save.
When testing deployment on ppc64 of maas, I put it together to collect logs and run.

user-data: 
  the user-data that is preprocessed (replaces LAUNCH_SECONDS) and fed to maas-deploy-node.  it contains the string to look for for successful run.

deploy-run: the primary runner script.

Running:
 * run tmux, name your session 'deploy-run'
   :rename deploy-run
 * run ipmi logger in a window, and name it 'console-log'.
   :rename-window console-log
 * edit deploy-run for your host name (NAME)
 * launch deploy-run
   RUNS=4 ./deploy-run trusty.hwe-t vivid-hwe-v

Notes:
 * maas-deploy-node maas-release-node are from maas-libvirt-tools
 * maas-deploy-node utilizes/abuses http://pad.lv/1459762 to force installation / use of hwe kernels.
   (trusty.hwe-u will set arch to 'generic/hwe-u' and then deploy trusty).
 * annotate-output is from ubuntu devscripts, i modified here to put SECONDS in addition to date.
 * tmux in trusty has issues with 'pipe-pane'.  It wont work if you detach from the session, which will break logging.

annotate-output

#!/bin/bash
# this script was downloaded from:
# https://jeroen.a-eskwadraat.nl/sw/annotate
# and is part of devscripts 2.15.5

# Executes a program annotating the output linewise with time and stream
# Version 1.2

# Copyright 2003, 2004 Jeroen van Wolffelaar <jeroen@wolffelaar.nl>

# This program is free software; you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
# the Free Software Foundation; version 2 of the License
#
# This program is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License
# along with this program. If not, see <https://www.gnu.org/licenses/>.

progname=$(basename $0)

addtime ()
{
	local fmt="%06d %s %s: %s %s\n"
	while IFS= read -r line; do
		printf "$fmt" "$SECONDS" "$(date "${FMT}")" "$1" "$line"
	done
	if [ ! -z "$line" ]; then
		printf "$fmt" "$SECONDS" "$(date "${FMT}")" "$1" "$line"
	fi
}

usage ()
{
	echo \
"Usage: $progname [options] program [args ...]
  Run program and annotate STDOUT/STDERR with a timestamp.

  Options:
   +FORMAT    - Controls the timestamp format as per date(1)
   -h, --help - Show this message"
}

FMT="+%H:%M:%S"
while [ "$1" ]; do
	case "$1" in
	+*)
		FMT="$1"
		shift
		;;
	-h|-help|--help)
		usage
		exit 0
		;;
	*)
		break
		;;
	esac
done

if [ $# -lt 1 ]; then
	usage
	exit 1
fi

cleanup() { __st=$?; rm -rf "$tmp"; exit $__st; }
trap cleanup 0 TERM
trap 'exit $?' 1 2 13 15

tmp=$(mktemp -d --tmpdir annotate.XXXXXX) || exit 1
OUT=$tmp/out
ERR=$tmp/err

mkfifo $OUT $ERR || exit 1

addtime O < $OUT &
addtime E < $ERR &

echo "Started $@" | addtime I
"$@" > $OUT 2> $ERR ; EXIT=$?
rm -f $OUT $ERR
wait

echo "Finished with exitcode $EXIT" | addtime I

exit $EXIT

deploy-run

#!/bin/bash
## rename a session with: rename
## rename a window with:  rename-window
## list sesions: tmux list-sessions
## list windows: tmux list-windows -t <session>
## list panes:   tmux list-panes -t <session>:<window>
##
pane="deploy-run:console-log.0"

debug() {
   shift;
   local now="$(date -R)"
   ndebug "$now:" "$@"
   return 0
}
ndebug() { echo "$@" >> "$DEBUG_LOG"; }

LOG=${0##*/}.log
DEPLOY_TIMEOUT="$((20*60))"
RELEASE_TIMEOUT="120"
DEBUG_LOG="debug.log"
tmpf=$(mktemp "${TMPDIR:-/tmp}/${0##*/}.XXXXXX")
mydir=$(dirname "$0")
mydir=$(cd "$mydir" && pwd)
udfile="$mydir/my-userdata"
annotate_output="$mydir/annotate-output"
MARKER="= successfull boot horay ="
# set EXIT_ON_FAIL to
#   deploy: do not release the system after deploy
#   release: exit after release
#   0 (or anything else): continue on
EXIT_ON_FAIL="deploy"

name="diamond"
msg() {
    local now="$(date -R)";
    echo "$now:" "$@";
    echo "$now:" "$@" >> "$LOG";
    ndebug "$now:" "$@"
    return 0;
}

if [ $# -eq 0 ]; then
   pairs="trusty.hwe-u trusty.hwe-v vivid.hwe-v wily.hwe-w";
else
   pairs="$*"
fi
runs=${RUNS:-20}

shquoted() {
	local cmd="" t="" tick="'" quote='"'
	for t in "$@"; do
		[ "${t#*${quote}}" != "$t" -o "${t#* }" != "$t" ] &&
			cmd="${cmd} $tick$t$tick" && continue
		[ "${t#*${tick}}" != "$t" ] && cmd="${cmd} $quote$t$quote" &&
			continue
		cmd="${cmd} $t"
		
	done
	_RET="${cmd# }"
}

waitfor() {
	local v=false
	[ "$1" = "-v" ] && v=true && shift
	local timeout="$1" naplen="$2"
	shift 2
	local sstart="${SECONDS}" last="253"
	local cmd=""
	shquoted "$@"
	cmd=${_RET}
	while [ "$(($SECONDS-$sstart))" -lt "$timeout" ]; do
		"$@"
		last="$?"
		$v && debug 1 "[$last] $cmd"
		[ $last -eq 0 ] && return 0
		sleep $naplen
	done
	return $last
}

node_in_state() {
	local v=false
	[ "$1" = "-v" ] && v=true && shift
	local name="$1" out="" ns="" state=""
	shift
	out=$(maas-dump-data) || { echo "failed dump-data"; return 253; }
	ns=$(echo "$out" | awk '$1 == node { print $4 }' node="$name")
	$v && debug 1 "$name in $ns"
	for state in "$@"; do
		[ "$ns" = "$state" ] && return 0
	done
	return 1
}

maybe_exit_on_fail() {
   local stage="$1" status="$2" step="$3"
   [ "$stage" != "$EXIT_ON_FAIL" ] && return 0
   [ "${status#*/}" = "success" ] && return 0
   msg "exiting on $stage as a result of $status in $step"
   exit
}

waitfor 120 10 node_in_state -v "$name" "READY" ||
    { echo "$name not in READY"; exit 1; }
run=0
while [ $run -lt $runs ] && run=$((run+1)); do
   startrun="$SECONDS"
   for pair in ${pairs}; do
      rel=${pair%.*}
      hwe=${pair#*.}
      runpad=$(printf "%02d" "$run")
      log="$PWD/run-$runpad-$pair.log"
      pair_start="$SECONDS"
      if [ -n "$pane" ]; then
         msg "$runpad: start $pair" > "$log"
         ln -sf "$log" "current.log"
         debug 1 "tmux pipe-pane -t \"$pane\" \"${annotate_output} cat >> $log\""
         tmux pipe-pane -t "$pane" "${annotate_output} cat >> $log"
      fi
      msg "$runpad: start $name: log=$log deploy $name --hwe=$hwe $rel"
      if [ -f "$udfile" ]; then
         # "preprocess" user-data
         now=$(date "+%s")
         sed "s/LAUNCH_SECONDS/$now/" "$udfile" > "$tmpf"
      fi
      # note, on diamond, it is
      #   almost 3 minutes from power on to petiboot kernel boot.
      #   ~35 seconds from petiboot kernel boot to petiboot menu
      #   ~30 seconds from petiboot menu to choice of kernel
      #   ~10 seconds to load kernel/initramfs from network and kexec
      # in deploy, its a total of about 5 minutes 10 seconds
      # from deploy-node to cloud-init local running
      # the total install boot is just shy of 300 seconds.
      pair_status="fail"
      depstart=$SECONDS
      stage="deploy"
      maas-deploy-node -vv "$name" "--hwe=$hwe" "$rel" ${udfile:+"${tmpf}"}
      debug 1 waitfor "$DEPLOY_TIMEOUT" 5 "grep -q '$MARKER' $log"
      waitfor "$DEPLOY_TIMEOUT" 5 grep -q "$MARKER" "$log"
      ret=$?
      [ $ret -eq 0 ] && result="success" || result="timeout"
      msg "$runpad: run $name: $pair result=$result [$(($SECONDS-$depstart))s]"
      if [ -n "$pane" ]; then
         # disable the pipe-pane
         debug 1 "tmux pipe-pane -t \"$pane\""
         tmux pipe-pane -t "$pane"
         echo "" >> "$log"
         msg "$runpad: end $pair" >> "$log"
      fi
      pair_status="$stage/$result"
      maybe_exit_on_fail "$stage" "$pair_status" "$runpad/$pair"

      rstart=$SECONDS
      stage="release"
      result="fail"
      for n in 1 2 3; do
         maas-release-node "$name"
         debug 1 "$stage $name run $n"
         waitfor "$RELEASE_TIMEOUT" 10 node_in_state -v "$name" "READY" &&
            result="success" && break
         debug 1 "$stage $name run $n timed out"
      done
      msg "$runpad: $stage $name: $pair result=$result [$(($SECONDS-$rstart))s]"
      [ "$result" != "success" -a "${pair_status#*/}" = "success" ] &&
          pair_status="$stage/$result"

      [ "${pair_status#*/}" = "success" ] && pair_status="success"
      msg "$runpad: $name: result=$pair_status [$(($SECONDS-${pair_start}))s]"
      maybe_exit_on_fail "$stage" "$pair_status" "$runpad/$pair"
   done
   msg "$runpad: took $(($SECONDS-$startrun))s"
done
msg "all done"

my-userdata

#cloud-config
##
## This user-data will reboot the system once, and then
## write a message to the console stating successful boot
## the LAUNCH SECONDS string is replaced with the unix time
## immediately before deploying the system.
##

sm_misc:
 - &write_launch_info |
   f=/usr/local/bin/launch-info
   cat > "$f" <<"ENDLAUNCH"
   #!/bin/sh
   launch_sec="LAUNCH_SECONDS"
   pre="$1"
   launch=$(date -R --date="@$launch_sec")

   ran="$(date -R)"
   ran_sec=$(date --date="$ran" +%s)

   read up idle < /proc/uptime
   up_sec=${up%.*} # drop milliseconds

   kboot=$(date -R --date="$ran - $up_sec seconds")
   kboot_sec=$(date --date="$kboot" +%s)

   msg() { echo "$@" | tee -a "/var/log/${0##*/}.log"; }

   msg "$pre: uptime: $up seconds"
   msg "$pre: you launched me at: $launch"
   msg "$pre: it is now         : $ran"
   msg "$pre: kernel booted     : $kboot"
   msg "$pre: launch to kernel boot: $((${kboot_sec}-${launch_sec})) seconds"
   msg "$pre: launch to user-data  : $((${ran_sec}-${launch_sec})) seconds"
   ENDLAUNCH
   chmod 755 "$f"
 - &enable_reboot_or_message |
   f=/usr/local/bin/reboot-or-message
   [ -f "$f" ] || cat > "$f" <<"EOF"
   #!/bin/sh
   me="${0##*/}"
   marker="/$me.mark"
   PATH=$PATH:/usr/local/bin
   set -f

   set_consoles() {
      local cmdline="" tok=""
      CONSOLES=""
      read cmdline </proc/cmdline
      for tok in $cmdline; do
         [ "${tok#console=}" = "$tok" ] && continue
         tok=${tok#console=}
         tok=${tok#/dev}
         tok=${tok%%,*}
         CONSOLES="$CONSOLES /dev/$tok"
      done
      CONSOLES=${CONSOLES# }
      [ -z "$CONSOLES" ] && CONSOLES="/dev/console"
   }

   msg() {
     local c="" now=""
     now="$(date -R)"
     echo "[stdout] $now" "$@"
     for c in ${CONSOLES} "/var/log/$me.log"; do
        echo "[$c] $now" "$@" >> "$c"
     done
   }

   set_consoles

   if [ "$1" = "reboot" ]; then
      sleep "${2:-3}"
      reboot
      sleep 1m && msg ====== WARN: still around ======
      exit
   fi
   if [ ! -f $marker ]; then
      launch-info pre-reboot
      msg ====== booted, trying reboot ======
      echo "1" > "$marker"
      "$0" reboot &
      exit
   fi
   read num < $marker
   echo $(($num+1)) > "$marker"
   launch-info success-$num
   msg ====== successfull boot horay =======
   EOF
   chmod 755 "$f"

   # make cloud-init run it for us later
   pbdir="/var/lib/cloud/scripts/per-boot/"
   [ -d "$pbdir" ] || mkdir -p "$pbdir"
   [ -e "$pbdir/${f##*/}" ] || ln -s "$f" "$pbdir/${f##*/}"

bootcmd:
 - [sh, -c, *write_launch_info]
 - [sh, -c, *enable_reboot_or_message ]
 - launch-info bootcmd | tee /run/launch-info.txt