From b769f2c6cbea40656242de5a6a516d5985df5e1e Mon Sep 17 00:00:00 2001
From: Daniel Gibbs <me@danielgibbs.co.uk>
Date: Thu, 14 May 2020 00:28:53 +0100
Subject: [PATCH] fix(monitor): fix monitor timings and lockfile bug (#2882)

* adjusting timings and fix lockfile bug
* added sleep time to eol messages
---
 lgsm/functions/command_backup.sh      | 16 +++++------
 lgsm/functions/command_fastdl.sh      |  3 --
 lgsm/functions/command_mods_remove.sh |  1 -
 lgsm/functions/command_monitor.sh     | 21 ++++----------
 lgsm/functions/command_start.sh       |  2 +-
 lgsm/functions/command_stop.sh        |  6 +---
 lgsm/functions/core_messages.sh       | 41 ++++++++++++++++++++++++---
 lgsm/functions/install_logs.sh        |  1 -
 lgsm/functions/mods_core.sh           |  4 ---
 9 files changed, 52 insertions(+), 43 deletions(-)

diff --git a/lgsm/functions/command_backup.sh b/lgsm/functions/command_backup.sh
index 7666156d4..537e86f1c 100644
--- a/lgsm/functions/command_backup.sh
+++ b/lgsm/functions/command_backup.sh
@@ -22,15 +22,15 @@ fn_backup_trap(){
 	fn_print_removed_eol_nl
 	fn_script_log_info "Backup ${backupname}.tar.gz: REMOVED"
 	# Remove lock file.
-	rm -f "${lockdir:?}/.backup.lock"
+	rm -f "${lockdir:?}/backup.lock"
 	core_exit.sh
 }
 
-# Check if a backup is pending or has been aborted using .backup.lock.
+# Check if a backup is pending or has been aborted using backup.lock.
 fn_backup_check_lockfile(){
-	if [ -f "${lockdir}/.backup.lock" ]; then
+	if [ -f "${lockdir}/backup.lock" ]; then
 		fn_print_info_nl "Lock file found: Backup is currently running"
-		fn_script_log_error "Lock file found: Backup is currently running: ${lockdir}/.backup.lock"
+		fn_script_log_error "Lock file found: Backup is currently running: ${lockdir}/backup.lock"
 		core_exit.sh
 	fi
 }
@@ -115,9 +115,9 @@ fn_backup_migrate_olddir(){
 
 fn_backup_create_lockfile(){
 	# Create lockfile.
-	date '+%s' > "${lockdir}/.backup.lock"
+	date '+%s' > "${lockdir}/backup.lock"
 	fn_script_log_info "Lockfile generated"
-	fn_script_log_info "${lockdir}/.backup.lock"
+	fn_script_log_info "${lockdir}/backup.lock"
 	# trap to remove lockfile on quit.
 	trap fn_backup_trap INT
 }
@@ -138,7 +138,7 @@ fn_backup_compression(){
 		core_exit.sh
 	fi
 
-	tar -czf "${backupdir}/${backupname}.tar.gz" -C "${rootdir}" --exclude "${excludedir}" --exclude "${lockdir}/.backup.lock" ./.
+	tar -czf "${backupdir}/${backupname}.tar.gz" -C "${rootdir}" --exclude "${excludedir}" --exclude "${lockdir}/backup.lock" ./.
 	local exitcode=$?
 	if [ ${exitcode} -ne 0 ]; then
 		fn_print_fail_eol
@@ -152,7 +152,7 @@ fn_backup_compression(){
 		fn_script_log_pass "Backup created: ${backupname}.tar.gz, total size $(du -sh "${backupdir}/${backupname}.tar.gz" | awk '{print $1}')"
 	fi
 	# Remove lock file
-	rm -f "${lockdir:?}/.backup.lock"
+	rm -f "${lockdir:?}/backup.lock"
 }
 
 # Clear old backups according to maxbackups and maxbackupdays variables.
diff --git a/lgsm/functions/command_fastdl.sh b/lgsm/functions/command_fastdl.sh
index 335d02d9d..f6a5897db 100644
--- a/lgsm/functions/command_fastdl.sh
+++ b/lgsm/functions/command_fastdl.sh
@@ -77,7 +77,6 @@ fn_clear_old_fastdl(){
 			fn_print_ok_eol_nl
 			fn_script_log_pass "Clearing existing FastDL directory ${fastdldir}"
 		fi
-		fn_sleep_time
 	fi
 }
 
@@ -95,7 +94,6 @@ fn_fastdl_dirs(){
 			fn_print_ok_eol_nl
 			fn_script_log_pass "Creating web directory ${webdir}"
 		fi
-		fn_sleep_time
 	fi
 	if [ ! -d "${fastdldir}" ]; then
 		echo -en "creating fastdl directory ${fastdldir}..."
@@ -109,7 +107,6 @@ fn_fastdl_dirs(){
 			fn_print_ok_eol_nl
 			fn_script_log_pass "Creating fastdl directory ${fastdldir}"
 		fi
-		fn_sleep_time
 	fi
 }
 
diff --git a/lgsm/functions/command_mods_remove.sh b/lgsm/functions/command_mods_remove.sh
index a8149e07b..35fd41d5f 100644
--- a/lgsm/functions/command_mods_remove.sh
+++ b/lgsm/functions/command_mods_remove.sh
@@ -87,7 +87,6 @@ if [ ${exitcode} -ne 0 ]; then
 else
 	fn_print_ok_eol_nl
 fi
-fn_sleep_time
 # Remove file list.
 echo -en "removing ${modcommand}-files.txt..."
 fn_sleep_time
diff --git a/lgsm/functions/command_monitor.sh b/lgsm/functions/command_monitor.sh
index 1df51768f..4b621c0d5 100644
--- a/lgsm/functions/command_monitor.sh
+++ b/lgsm/functions/command_monitor.sh
@@ -16,17 +16,15 @@ fn_monitor_check_lockfile(){
 		fn_print_dots "Checking lockfile: "
 		fn_print_checking_eol
 		fn_script_log_info "Checking lockfile: CHECKING"
-		fn_sleep_time
 		fn_print_error "Checking lockfile: No lockfile found: "
 		fn_print_error_eol_nl
 		fn_script_log_error "Checking lockfile: No lockfile found: ERROR"
-		fn_sleep_time
 		echo -e "* Start ${selfname} to run monitor."
 		core_exit.sh
 	fi
 
 	# Fix if lockfile is not unix time or contains letters
-	if [[ "$(cat "${lockdir}/${selfname}.lock")" =~ [A-Za-z] ]]; then
+	if [ -f "${lockdir}/${selfname}.lock" ]&&[[ "$(cat "${lockdir}/${selfname}.lock")" =~ [A-Za-z] ]]; then
 			date '+%s' > "${lockdir}/${selfname}.lock"
 	fi
 }
@@ -37,11 +35,9 @@ fn_monitor_check_update(){
 		fn_print_dots "Checking active updates: "
 		fn_print_checking_eol
 		fn_script_log_info "Checking active updates: CHECKING"
-		fn_sleep_time
 		fn_print_error_nl "Checking active updates: SteamCMD is currently checking for updates: "
 		fn_print_error_eol
 		fn_script_log_error "Checking active updates: SteamCMD is currently checking for updates: ERROR"
-		fn_sleep_time
 		core_exit.sh
 	fi
 }
@@ -50,18 +46,15 @@ fn_monitor_check_session(){
 	fn_print_dots "Checking session: "
 	fn_print_checking_eol
 	fn_script_log_info "Checking session: CHECKING"
-	fn_sleep_time
 	# uses status var from check_status.sh
 	if [ "${status}" != "0" ]; then
 		fn_print_ok "Checking session: "
 		fn_print_ok_eol_nl
 		fn_script_log_pass "Checking session: OK"
-		fn_sleep_time
 	else
 		fn_print_error "Checking session: "
 		fn_print_fail_eol_nl
 		fn_script_log_fatal "Checking session: FAIL"
-		fn_sleep_time
 		alert="restart"
 		alert.sh
 		fn_script_log_info "Checking session: Monitor is restarting ${selfname}"
@@ -76,7 +69,6 @@ fn_monitor_check_queryport(){
 		fn_print_dots "Checking port: "
 		fn_print_checking_eol
 		fn_script_log_info "Checking port: CHECKING"
-		fn_sleep_time
 		if [ -n "${rconenabled}" ]&&[ "${rconenabled}" != "true" ]&&[ ${shortname} == "av" ]; then
 			fn_print_warn "Checking port: Unable to query as rconport, rcon not enabled: "
 			fn_print_warn_eol_nl
@@ -86,7 +78,6 @@ fn_monitor_check_queryport(){
 			fn_print_error_eol_nl
 			fn_script_log_error "Checking port: Unable to query as queryport is not set: ERROR"
 		fi
-		fn_sleep_time
 		core_exit.sh
 	fi
 }
@@ -112,14 +103,14 @@ for queryattempt in {1..5}; do
 	fn_print_dots "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: "
 	fn_print_querying_eol
 	fn_script_log_info "Querying port: ${querymethod}: ${ip}:${queryport} : ${queryattempt} : QUERYING"
-	fn_sleep_time
 	# querydelay
 	if [ "$(cat "${lockdir}/${selfname}.lock")" -gt "$(date "+%s" -d "${querydelay} mins ago")" ]; then
 		fn_print_ok "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: "
 		fn_print_delay_eol_nl
 		fn_script_log_info "Querying port: ${querymethod}: ${ip}:${queryport} : ${queryattempt} : DELAY"
 		fn_script_log_info "Query bypassed: ${gameservername} started less than ${querydelay} minutes ago"
-		fn_sleep_time
+		fn_script_log_info "Server started: $(date -d @$(cat lgsm/lock/bmdmserver.lock))"
+		fn_script_log_info "Current time: $(date)"
 		monitorpass=1
 		core_exit.sh
 	# will use query method selected in fn_monitor_loop
@@ -139,7 +130,6 @@ for queryattempt in {1..5}; do
 		fn_print_ok "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: "
 		fn_print_ok_eol_nl
 		fn_script_log_pass "Querying port: ${querymethod}: ${ip}:${queryport} : ${queryattempt}: OK"
-		fn_sleep_time
 		monitorpass=1
 		if [ "${querystatus}" == "0" ]; then
 			# Add query data to log.
@@ -170,7 +160,6 @@ for queryattempt in {1..5}; do
 		fn_print_fail "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: "
 		fn_print_fail_eol
 		fn_script_log_warn "Querying port: ${querymethod}: ${ip}:${queryport} : ${queryattempt}: FAIL"
-		fn_sleep_time
 		# Monitor will try gamedig (if supported) for first 30s then gsquery before restarting.
 		if [ "${querymethod}" ==  "gsquery" ]||[ "${querymethod}" ==  "tcp" ]; then
 			# gsquery will fail if longer than 60s
@@ -179,7 +168,6 @@ for queryattempt in {1..5}; do
 				fn_print_fail "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: "
 				fn_print_fail_eol_nl
 				fn_script_log_warn "Querying port: ${querymethod}: ${ip}:${queryport} : ${queryattempt}: FAIL"
-				fn_sleep_time
 				# Send alert if enabled.
 				alert="restartquery"
 				alert.sh
@@ -195,7 +183,8 @@ for queryattempt in {1..5}; do
 
 		# Second counter will wait for 15s before breaking loop.
 		for seconds in {1..15}; do
-			fn_print_fail "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: WAIT"
+			fn_print_fail "Querying port: ${querymethod}: ${ip}:${queryport} : ${totalseconds}/${queryattempt}: ${cyan}WAIT${default}"
+			sleep 0.5
 			totalseconds=$((totalseconds + 1))
 			if [ "${seconds}" == "15" ]; then
 				break
diff --git a/lgsm/functions/command_start.sh b/lgsm/functions/command_start.sh
index 497ca215a..6e4b445e8 100644
--- a/lgsm/functions/command_start.sh
+++ b/lgsm/functions/command_start.sh
@@ -62,7 +62,7 @@ fn_start_tmux(){
 	fi
 
 	# Create lockfile
-	date > "${lockdir}/${selfname}.lock"
+	date '+%s' > "${lockdir}/${selfname}.lock"
 	cd "${executabledir}" || exit
 	tmux new-session -d -x "${sessionwidth}" -y "${sessionheight}" -s "${selfname}" "${executable} ${parms}" 2> "${lgsmlogdir}/.${selfname}-tmux-error.tmp"
 
diff --git a/lgsm/functions/command_stop.sh b/lgsm/functions/command_stop.sh
index 3a27ba8d8..e8ef68fa4 100644
--- a/lgsm/functions/command_stop.sh
+++ b/lgsm/functions/command_stop.sh
@@ -33,7 +33,6 @@ fn_stop_graceful_ctrlc(){
 		fn_print_fail_eol_nl
 		fn_script_log_error "Graceful: CTRL+c: FAIL"
 	fi
-	fn_sleep_time
 }
 
 # Attempts graceful shutdown by sending a specified command.
@@ -62,7 +61,6 @@ fn_stop_graceful_cmd(){
 		fn_print_fail_eol_nl
 		fn_script_log_error "Graceful: sending \"${1}\": FAIL"
 	fi
-	fn_sleep_time
 }
 
 # Attempts graceful shutdown of goldsrc using rcon 'quit' command.
@@ -178,7 +176,6 @@ fn_stop_graceful_sdtd(){
 		fn_print_fail_eol_nl
 		fn_script_log_warn "Graceful: telnet: expect not installed: FAIL"
 	fi
-	fn_sleep_time
 }
 
 # Attempts graceful shutdown by sending /save /stop.
@@ -208,7 +205,6 @@ fn_stop_graceful_avorion(){
 		fn_print_fail_eol_nl
 		fn_script_log_error "Graceful: /save /stop: FAIL"
 	fi
-	fn_sleep_time
 }
 
 fn_stop_graceful_select(){
@@ -240,7 +236,7 @@ fn_stop_tmux(){
 	fn_script_log_info "tmux kill-session: ${servername}"
 	# Kill tmux session.
 	tmux kill-session -t "${selfname}" > /dev/null 2>&1
-	fn_sleep_time
+	sleep 0.5
 	check_status.sh
 	if [ "${status}" == "0" ]; then
 		fn_print_ok_nl "${servername}"
diff --git a/lgsm/functions/core_messages.sh b/lgsm/functions/core_messages.sh
index fd7a4b2e4..a4914bdd9 100644
--- a/lgsm/functions/core_messages.sh
+++ b/lgsm/functions/core_messages.sh
@@ -354,100 +354,133 @@ fn_prompt_yn(){
 # OK
 fn_print_ok_eol(){
 	echo -en "${green}OK${default}"
+	fn_sleep_time
 }
 
 fn_print_ok_eol_nl(){
 	echo -e "${green}OK${default}"
+	fn_sleep_time
 }
 
 # FAIL
 fn_print_fail_eol(){
 	echo -en "${red}FAIL${default}"
+	fn_sleep_time
 }
 
 fn_print_fail_eol_nl(){
 	echo -e "${red}FAIL${default}"
+	fn_sleep_time
 }
 
 # ERROR
 fn_print_error_eol(){
 	echo -en "${red}ERROR${default}"
+	fn_sleep_time
 }
 
 fn_print_error_eol_nl(){
 	echo -e "${red}ERROR${default}"
+	fn_sleep_time
+}
+
+# WAIT
+fn_print_wait_eol(){
+	echo -en "${cyan}WAIT${default}"
+	fn_sleep_time
+}
+
+fn_print_wait_eol_nl(){
+	echo -e "${cyan}WAIT${default}"
+	fn_sleep_time
 }
 
 # WARN
 fn_print_warn_eol(){
 	echo -en "${lightyellow}WARN${default}"
+	fn_sleep_time
 }
 
 fn_print_warn_eol_nl(){
 	echo -e "${lightyellow}WARN${default}"
+	fn_sleep_time
 }
 
 # INFO
 fn_print_info_eol(){
-	echo -en "${red}INFO${default}"
+	echo -en "${cyan}INFO${default}"
+	fn_sleep_time
 }
 
 fn_print_info_eol_nl(){
-	echo -e "${red}INFO${default}"
+	echo -e "${cyan}INFO${default}"
+	fn_sleep_time
 }
 
 # QUERYING
 fn_print_querying_eol(){
 	echo -en "${cyan}QUERYING${default}"
+	fn_sleep_time
 }
 
 fn_print_querying_eol_nl(){
 	echo -e "${cyan}QUERYING${default}"
+	fn_sleep_time
 }
 
 # CHECKING
 fn_print_checking_eol(){
 	echo -en "${cyan}CHECKING${default}"
+	fn_sleep_time
 }
 
 fn_print_checking_eol_nl(){
 	echo -e "${cyan}CHECKING${default}"
+	fn_sleep_time
 }
 
 # DELAY
 fn_print_delay_eol(){
 	echo -en "${green}DELAY${default}"
+	fn_sleep_time
 }
 
 fn_print_delay_eol_nl(){
 	echo -e "${green}DELAY${default}"
+	fn_sleep_time
 }
 
 # CANCELED
 fn_print_canceled_eol(){
-	echo -en "${yellow}CANCELED${default}"
+	echo -en "${lightyellow}CANCELED${default}"
+	fn_sleep_time
 }
 
 fn_print_canceled_eol_nl(){
-	echo -e "${yellow}CANCELED${default}"
+	echo -e "${lightyellow}CANCELED${default}"
+	fn_sleep_time
 }
 
 # REMOVED
 fn_print_removed_eol(){
 	echo -en "${red}REMOVED${default}"
+	fn_sleep_time
 }
 
 fn_print_removed_eol_nl(){
 	echo -e "${red}REMOVED${default}"
+	fn_sleep_time
 }
 
 # UPDATE
 fn_print_update_eol(){
 	echo -en "${cyan}UPDATE${default}"
+	fn_sleep_time
 }
 
 fn_print_update_eol_nl(){
 	echo -e "${cyan}UPDATE${default}"
+	fn_sleep_time
 }
 
 fn_print_ascii_logo(){
diff --git a/lgsm/functions/install_logs.sh b/lgsm/functions/install_logs.sh
index be54eb42d..21c63ccbb 100644
--- a/lgsm/functions/install_logs.sh
+++ b/lgsm/functions/install_logs.sh
@@ -96,5 +96,4 @@ if [ -d "${rootdir}/Steam/logs" ]; then
 		fi
 	fi
 fi
-fn_sleep_time
 fn_script_log_info "Logs installed"
diff --git a/lgsm/functions/mods_core.sh b/lgsm/functions/mods_core.sh
index 7fc030210..8108e0d0e 100644
--- a/lgsm/functions/mods_core.sh
+++ b/lgsm/functions/mods_core.sh
@@ -59,7 +59,6 @@ fn_mod_lowercase(){
 		else
 			fn_print_ok_eol_nl
 		fi
-		fn_sleep_time
 	fi
 }
 
@@ -82,7 +81,6 @@ fn_mod_create_filelist(){
 	if [ -f "${modsdir}/.removedfiles.tmp" ]; then
 		cat "${modsdir}/.removedfiles.tmp" >> "${modsdir}/${modcommand}-files.txt"
 	fi
-	fn_sleep_time
 }
 
 # Copy the mod into serverfiles.
@@ -392,7 +390,6 @@ fn_create_mods_dir(){
 			fn_print_ok_eol_nl
 			fn_script_log_pass "Creating mod download dir ${modsdir}"
 		fi
-		fn_sleep_time
 	fi
 	# Create mod install directory.
 	if [ ! -d "${modinstalldir}" ]; then
@@ -407,7 +404,6 @@ fn_create_mods_dir(){
 			fn_print_ok_eol_nl
 			fn_script_log_pass "Creating mod install directory ${modinstalldir}"
 		fi
-		fn_sleep_time
 	fi
 
 	# Create lgsm/data/${modsinstalledlist}.