#!/bin/bash

# $Id$

CONFIG=/opt/HAC/RSF-1/etc/config
RSF_LOGDIR=/opt/HAC/RSF-1/log
LOGDIR=${RSF_LOGDIR}
STANDARD_SCRIPT_DIR=/opt/HAC/RSF-1/etc/rc.appliance.c

BOLD='\033[30;1m'
UNBOLD='\033[0m'

quiet="false"

#
# Check for /usr/gnu/bin/sed - Solaris default sed has no -r option
SED=sed
if [ -f /usr/gnu/bin/sed ] ; then
    SED=/usr/gnu/bin/sed
fi

######################################################
# Function:	seconds_between()
#
# Function to calculate the number of seconds between
# 2 times.
#
# Args:		Two times in the format HH:MM:SS
#               1) Start time
#               2) End time
#
# Returns:	Prints number of seconds between 2 times
######################################################
seconds_between(){
	if [ $# -ne 2 ]; then
		echo "Internal error: Incorrect number of arguments to seconds_between():" >&2
		echo $*
		exit 2
	fi
	start=$1
	stop=$2

        # Split two times into HH MM and SS
	start_hour=${start:0:2}
	start_mins=${start:3:2}
	start_secs=${start:6:2}

	stop_hour=${stop:0:2}
	stop_mins=${stop:3:2}
	stop_secs=${stop:6:2}

        # Put HH MM and SS together without any separators (was ':'),
        # then test length and make sure it is a number
	test=${start_secs}${start_mins}${start_hour}${stop_secs}${stop_mins}${stop_hour}
	if [ ${#test} -ne 12 ] || ! [ ${test} -eq ${test} ]; then
		echo "Internal error: Incorrect arguments to seconds_between() - $1 and $2" >&2
		exit 2
	fi

        # If start HH is greater than end HH, then we must have passed midnight.
        # Subtract 24 hours from start time (23 --> -1)
	if [ ${start_hour} -gt ${stop_hour} ]; then
		start_hour=$((${start_hour} - 24))
	fi

        # Calculate differences in HH MM and SS
	diff_hour=`expr ${stop_hour} - ${start_hour}`
	diff_mins=`expr ${stop_mins} - ${start_mins}`
	diff_secs=`expr ${stop_secs} - ${start_secs}`

        # Add differences together
	diff_total=$(( $((${diff_hour} * 3600)) + $((${diff_mins} * 60)) + ${diff_secs} ))

	echo ${diff_total}
}

######################################################
# Function:	save_output()
#
# Function to save text into a buffer for later use
#
# Args:		Text string to save
#
# Returns:	Nothing
######################################################
save_output(){
	if [ "${quiet}" != "true" ]; then
		if [ -z "${output}" ]; then
			output="$*"
		else
			output="${output}%%%%%%$*"
		fi
	fi
}

######################################################
# Function:	get_output()
#
# Function to print any saved text and clear the buffer
#
# Args:		None
#
# Returns:	Prints saved output
######################################################
get_output(){
    if [ -n "${output}" ]; then
	echo "$output" | ${SED} -r -e "s:\x1B\[[0-9;]*[mK]::g" -e 's/%%%%%%/\n\t/g' -e 's/^/\t/g'
    fi
    output=
}

######################################################
# Function:	get_script_info()
#
# Function to return a summary about a given script
#
# Args:		Script name
#
# Returns:	Info string
######################################################
S01announce_info="write to log file"
S02ApplianceStarting_info="event notify"
S14res_drives_info="create initial res_drives"
S15zfs_mhdc_info="place reservations"
S20zfs_info="import pool + LUs"
S21res_drives_info="refresh res_drives"
S80plumb_info="tell rsfexec to plumb VIPs"
S90hpr_info="resume HPR for this service"
S98ApplianceStarted_info="event notify"
S99announce_info="write to log file"

K01announce_info=${S01announce_info}
K02ApplianceStopping_info=${S02ApplianceStarting_info}
K10hpr_info="suspend HPR for this service"
K20plumb_info="tell rsfexec to unplumb VIPs"
K79res_drives_info="nothing"
K80zfs_info="export pool + LUs"
K85zfs_mhdc_info="release reservations"
K86res_drives_info="nothing"
K98ApplianceStopped_info=${S98ApplianceStarted_info}
K99announce_info=${S99announce_info}

get_script_info(){
	varname=`basename ${1}`_info

	eval out=\$${varname}
	if [ -n "${out}" ]; then
		echo "($out)"
	fi
}

######################################################
# Function:	usage()
#
# Function to print a help text
#
# Args:		None
#
# Returns:	Prints help text
######################################################
usage(){
	cat <<-EOF

	Usage: `basename $0` [-l|--log <logfile|logdir>] [service]...

	Options:
	        -l --log <log>: Specify a log file or log directory to search.
	                        If a file is given, only that file will be searched.
	                        If a directory is given, that directory will be searched
	                        for rsfmon.log and rsfmon.log.[0-9].
	                        The default is to use the standard RSF-1 log directory
	                        ${RSF_LOGDIR}

	        -q --quiet:     Don't display information for individual scripts.
				Just show total start/stop/failover times

	        -h --help:      Show this help text and exit

	The config file ${CONFIG} will be scanned for services to search for
	unless a list has been provided on the command line.

	EOF
}

# Parse command line arguments
while [ $# -gt 0 ]; do
	case $1 in
	-l|--logdir)
		shift
		if [ -d "$1" ]; then
			LOGDIR="$1"
		elif [ -f "$1" ]; then
			LOGS="$1"
		else
			echo "Unable to find $1" >&2
			exit 1
		fi
		;;
	-q|--quiet)
		quiet="true"
		;;
	-h|--help)
		usage
		exit 0
		;;
	-*)
		echo "Unrecognised argument: $1" >&2
		usage >&2
		exit 1
		;;
	*)
		USER_SERVICES="${USER_SERVICES} ${1}"
		;;
	esac

	shift
done

# Work out which services to search for:
# If any have been given on command line, use them.
# If not, look in config file for configured services
if [ ${#USER_SERVICES} -eq 0 ]; then
	CONFIG_SERVICES=" `grep '^ *SERVICE ' ${CONFIG} | awk '{print $2}' | tr '\n' ' '` "
	SERVICES="${CONFIG_SERVICES}"
else
	SERVICES="${USER_SERVICES}"
fi
echo "Services to search for: ${SERVICES}"

# Work out which log files to search
# If any files have been given on command line, use them.
# If not, search the log directory (either default or command line)
# for rsfmon.log and rsfmon.log.[0-9]
if [ -z "${LOGS}" ]; then
	# Don't have log files yet, but do have a directory
	LOGS="`ls -rt ${LOGDIR}/rsfmon.log{.{9..0},} 2>/dev/null`"
	echo "Searching log files in ${LOGDIR}:"
	[ "${quiet}" != "true" ] && for log in ${LOGS}; do
		printf "%s " "`basename ${log}`"
	done
	echo
fi
# Exit if no log files found
if [ -z "${LOGS}" ]; then
	echo "No log files found in ${LOGDIR}" >&2
	exit 1
fi

# Loop through list of services
for service in ${SERVICES}; do
	echo "${BOLD}###############################################"
	echo "Service startups and shutdowns for ${service}:"
	echo "###############################################${UNBOLD}"
	START_STOP_SCRIPT_RUNNING=0
	start_num=0
	stop_num=0
	# Loop through list of log files
	for LOG in ${LOGS}; do
		if [ "${quiet}" != "true" ]; then
			echo "Reading `basename ${LOG}`..."
		fi
		# Read log file line by line
		while read pid month date time srv script line; do
			# Most of the lines we are interested in are in the format:
			# [PID MONTH DATE HH:MM:SS] [service script] <Body of line>
			# e.g. [23440 Jan 31 17:18:46] [pool4 rsfexec] Running S20zfs start 1
			if [[ "${srv}" = "[${service}" ]]; then
				# Line is about the correct service

				# Remove trailing ']' from time string. Don't do this for every line in log file - slows things down
				time=`echo ${time} | tr -d ']'`

				case ${script} in
				rsfexec|rsfexec.py|rsfexec.pyc])
					# rsfexec is the script that calls all of the S and K scripts
					if [[ "${line}" == "addresses_in_use:"* ]]; then
						# fping test is first part of service startup
						start_num=$((${start_num} + 1))
						# Print something about beginning of service start
						echo
						echo "${BOLD}Service startup #${start_num}: ${month} ${date} ${time}${UNBOLD} (`basename $LOG`)"
						# Work out which VIP is being tested
						vip=`echo $line | ${SED} -e 's/.*checking inet[46] //g' -e 's/ does not exist.*//g'`
						# Save current time
						fping_start=${time}
					elif [[ "${line}" =~ "is not in use, OK" ]]; then
						# Fping test done and OK - work out time taken
						if [ "${quiet}" != "true" ]; then
							echo "Fping test complete for ${vip}: `seconds_between ${fping_start} ${time}` seconds"
						fi
					elif [[ "${line}" =~ "Function fping took" ]]; then
						start_num=$((${start_num} + 1))
						# Print something about beginning of service start
						echo
						echo "${BOLD}Service startup #${start_num}: ${month} ${date} ${time}${UNBOLD} (`basename $LOG`)"
						fping_time=`echo $line|awk '{print $4}'`
						if [ "${quiet}" != "true" ]; then
							echo "Fping test complete: ${fping_time} seconds"
						fi
					elif [[ "${line}" == "Running "* ]] || [[ "${line}" == "Run: "* ]]; then
						# rsfexec is starting one of the start/stop scripts
						if [ ${START_STOP_SCRIPT_RUNNING} -eq 0 ]; then
							# First start/stop script
							START_STOP_SCRIPT_RUNNING=1
							first_script_start=${time}
							# Get script name
							script_running=`echo ${line} | ${SED} -e 's/Running //g' -e 's/Run: //g' -e 's/ .*//g'`
							if [ "`dirname ${script_running}`" = ${STANDARD_SCRIPT_DIR} ]; then
								script_running="`basename ${script_running}`"
							fi
						else
							# Not first script, so this marks both the end of one script and the start of another
							script_stop=${time}

							# Print info about previous script
							if [ "${quiet}" != "true" ]; then
								printf "%s %-20s %s %s\n" "Script" "${script_running}" \
									"run time: `seconds_between ${script_start} ${script_stop}` seconds" \
									"`get_script_info ${script_running}`"
							fi
							# Print any saved output from last script
							get_output

							# Get next script name
							script_running=`echo ${line} | ${SED} -e 's/Running //g' -e 's/Run: //g' -e 's/ .*//g'`
							if [ "`dirname ${script_running}`" = ${STANDARD_SCRIPT_DIR} ]; then
								script_running="`basename ${script_running}`"
							fi
						fi
						script_start=${time}
					elif [[ "${line}" =~ "Total[ run]* time for service start:" ]]; then
						# Very last line of service startup - after VIP plumbed in
						if [ "${quiet}" != "true" ]; then
							printf "%s\t\n" "Plumb in VIP interface: `seconds_between ${ifplumb_start} ${time}` seconds"
							printf "%s\n" "${line}"
						fi
						if [ -n "${ba_failover_start}" ]; then
							echo "Total failover time: `seconds_between ${ba_failover_start} ${time}` seconds"
							ba_failover_start=
						fi
					elif [[ "${line}" =~ "Total[ run]* time for service stop:" ]]; then
						# Very last line of service shutdown - after stop scripts finished
						printf "%s\n" "${line}"
					fi
					;;
				[SK]99announce])
					# Last start/stop script - output info about this script here, since there is no opportunity after
					if [ ${START_STOP_SCRIPT_RUNNING} -eq 1 ]; then
						# Start or stop?
						if [ ${script:0:1} = S ]; then
							state=start
						else
							state=stop
						fi

						# Print timing info about this script
						script_stop=${time}
						script_running=`echo $script | tr -d ']'`
						if [ "${quiet}" != "true" ]; then
							printf "%s %-20s %s %s\n" "Script" "${script_running}" \
								"run time: `seconds_between ${script_start} ${script_stop}` seconds" \
								"`get_script_info ${script_running}`"
						fi
						# Get any output saved
						get_output

						# End of start/stop scripts - work out total scripts time
						START_STOP_SCRIPT_RUNNING=0
						if [ "${quiet}" != "true" ]; then
							echo "Service ${state} scripts took `seconds_between ${first_script_start} ${script_stop}` seconds"
						fi
						script_running=

						if [[ "${state}" == "start" ]]; then
							# VIP plumbed in right after S99announce
							ifplumb_start="${time}"
						fi
					fi
					;;
				[SK][0-9]*zfs])
					# This script can take some time - import/export pool, stmfha, etc.
					# Script already puts timing info into log file, so just save the output
					if [[ "${line}" =~ "Zpool "(im|ex)"port completed" ]]; then
						save_output ${line}
					elif [[ "${line}" =~ "Comstar mapping "(restored|removed)" in" ]]; then
						save_output ${line}
					fi
					;;
				[SK][0-9]*zfs_mhdc])
					# Reservations sometimes take a while. Timing info already in log file
					if [[ "${line}" =~ "Reservations "(taken|released)" in" ]]; then
						save_output ${line}
					fi
					;;
				*)
					# Ignore any other script - we already print time taken by script in rsfexec part
					# Add another section if further breakdown of a script is necessary
					;;
				esac

			elif [[ "${line}" =~ "${service} not running, start in" ]] && [ "${quiet}" != "true" ]; then
				# RSF-1 pauses before a service startup - print this information
				delay=`echo ${line} | ${SED} -e 's/.*start in //g' -e 's/ seconds//g'`
				echo
				echo "Delay before service start - ${delay} seconds"

			elif [[ "${script} ${line}" =~ "Service ${service} is now "(stopping|bouncing) ]]; then
				# Start of service shutdown - print some information
				stop_num=$((${stop_num} + 1))
				time=`echo ${time} | tr -d ']'`
				echo
				echo "${BOLD}Service shutdown #${stop_num}: ${month} ${date} ${time}${UNBOLD} (`basename $LOG`)"
				ab_failover_start="${time}"
			elif [[ "${srv}" =~ ".${service}" ]]; then
				time=`echo ${time} | tr -d ']'`
				if [[ "${script} ${line}" == "running/"*" -> stopping/"* ]]; then
					ba_failover_start="${time}"
					echo
					echo "${BOLD}Service stopping on remote node: ${month} ${date} ${time}${UNBOLD}"

				elif [[ "${script} ${line}" == "stopping/"*" -> stopped/"* ]]; then
					if [ -n "${ba_failover_start}" ]; then
						time=`echo ${time} | tr -d ']'`
						echo "Service stopped on remote node: " \
							"`seconds_between ${ba_failover_start} ${time}` seconds"
					fi

				elif [[ "${script} ${line}" == "stopped/"*" -> starting/"* ]]; then
					echo
					echo "${BOLD}Service starting on remote node: ${month} ${date} ${time}${UNBOLD}"
					remote_start="${time}"

				elif [[ "${script} ${line}" == "starting/"*" -> running/"* ]]; then
					echo "Service started on remote note: `seconds_between ${remote_start} ${time}` seconds"
					remote_start=
					if [ -n "${ab_failover_start}" ]; then
						echo "Total failover time: `seconds_between ${ab_failover_start} ${time}` seconds"
						ab_failover_start=
					fi
				fi
			fi
		done < <(cat ${LOG})
		# End of line loop
	done
	# End of log loop
done
# End of service loop
