add timer and debug.log

cm.sh

@@ -32,6 +32,7 @@
 # 2022-04-07  <axel.hahn@iml.unibe.ch>  fix missing key in public_ensure before calling public_add too.
 # 2022-04-20  <axel.hahn@iml.unibe.ch>  fix multiple domains using domain alias
 # 2022-04-21  <axel.hahn@iml.unibe.ch>  mix multiple domains using domain alias or not
+# 2022-05-19  <axel.hahn@iml.unibe.ch>  add timer and debug.log
 # ======================================================================
 
 
@@ -44,15 +45,23 @@
 logdir="./log"
 touchfile="$logdir/lastchange.txt"
 logfile="$logdir/certmanager.log"
+debuglogfile="$logdir/debug.log"
 
 # CSR USAGE WAS REMOVED
 # csrfile="./templates/csr.txt"
 
 line="_______________________________________________________________________________"
 
-showdebug=1
-writelog=1
+# flag: show debug infos on console (STDOUT)
+CM_showdebug=0
 
+# flag: write a log for created/ renewd/ deleted certs
+CM_writelog=1
+
+# flag: write a log for executed functions with timer and process count
+CM_writedebuglog=0
+
+CM_timer_start=$( date +%s.%N )
 
 # ----------------------------------------------------------------------
 #
@@ -313,36 +322,61 @@ function _testUser(){
 
 }
 
+# set update message into access log file
+# global bool CM_writedebuglog flag to write access log.
+# param  string(s)  message
+function _debuglog(){
+	if [ ${CM_writedebuglog} -eq 1 ]; then
+		local _sProcesses
+		typeset -i local _iProcesses
+		typeset -i local _iPos
+		_sProcesses=$( ps -ef | grep "bash.*$0" | grep -v "ssh.*@" | grep -v "grep" | sort -k 2 -n )
+		_iProcesses=$( echo "$_sProcesses" | wc -l )
+		_iPos=$( echo "$_sProcesses" | grep -n " $$ " | head -1 | cut -f 1 -d ':' )
+		echo "$( date ) $CM_fqdn [$$] | $(show_timer) | pos $_iPos of $_iProcesses processes | $*" >> ${debuglogfile}
+	fi
+}
+
+
 # set update message in a file
 # param  string(s)  message
 function _update(){
 	echo "[$( date )] $*" > ${touchfile}
-	test ${writelog} && echo "[$( date )] $*" >> ${logfile}
+	test ${CM_writelog} -ne 0 && echo "[$( date )] $*" >> ${logfile}
 }
 
 # "neverending" loop that waits until the current process is
 # the one with lowest PID
 function _wait_for_free_slot(){
     local _bWait=true
+	_debuglog "start in _wait_for_free_slot"
     typeset -i local _iFirstPID=0
-    _wd "--- Need to wait until own process PID $$ is on top ... "
+    local _sProcesses
+	
+	_wd "--- Need to wait until own process PID $$ is on top ... "
     while [ $_bWait = true ];
     do
-        _iFirstPID=$( ps -ef | grep "bash.*$0" | grep -v "ssh.*@" | grep -v "grep" | sort -k 2 -n | head -1 | awk '{ print $2}' )
+		_sProcesses=$( ps -ef | grep "bash.*$0" | grep -v "ssh.*@" | grep -v "grep" | sort -k 2 -n )
+        # _iFirstPID=$( ps -ef | grep "bash.*$0" | grep -v "ssh.*@" | grep -v "grep" | sort -k 2 -n | head -1 | awk '{ print $2}' )
+        _iFirstPID=$( echo "$_sProcesses" | head -1 | awk '{ print $2}' )
+
         if [ $_iFirstPID -eq $$ ]; then
             _bWait=false
             _wd "OK. Go!"
         else
             _wd "- all instances"
-            test ${showdebug} && ps -ef | grep "bash.*$0" | grep -v "ssh.*@" | grep -v "grep" | sort -k 2 -n
+			_debuglog "waiting in _wait_for_free_slot"
+            # test ${CM_showdebug} && ps -ef | grep "bash.*$0" | grep -v "ssh.*@" | grep -v "grep" | sort -k 2 -n
+            test ${CM_showdebug} -ne 0 && echo "$_sProcesses"
             sleep 10
         fi
     done
+	_debuglog "end _wait_for_free_slot"
 }
 
-# write debug output if showdebug is set to 1
+# write debug output if CM_showdebug is set to 1
 function _wd(){
-	test ${showdebug} && echo "DEBUG: $*"
+	test ${CM_showdebug} -ne 0 && echo "DEBUG: $*"
 }
 
 # set environment for a single certificate based on FQDN
@@ -387,6 +421,21 @@ function _testFqdncount(){
 		exit 1
 	fi
 }
+
+# get time in sec and milliseconds since start
+# no parameter is required
+function show_timer(){
+         local timer_end=$( date +%s.%N )
+         local totaltime=$( awk "BEGIN {print $timer_end - $CM_timer_start }" )
+
+         local sec_time=$( echo $totaltime | cut -f 1 -d "." )
+         test -z "$sec_time" && sec_time=0
+
+         local ms_time=$( echo $totaltime | cut -f 2 -d "." | cut -c 1-3 )
+
+         echo "$sec_time.$ms_time sec"
+}
+
 # ----------------------------------------------------------------------
 #
 # PUBLIC FUNCTIONS
@@ -399,6 +448,7 @@ function _testFqdncount(){
 function public_add(){
 	local _params=""
 
+	_debuglog "start public_add"
 	_wait_for_free_slot
 	_requiresFqdn
     _certMustNotExist
@@ -434,6 +484,7 @@ function public_add(){
 	_certMatching
 
 	_update "added $CM_fqdn $*"
+	_debuglog "end public_add"
 }
 
 # CSR USAGE WAS REMOVED
@@ -508,6 +559,7 @@ function public_ensure(){
 # public function to delete a cert
 #
 function public_delete(){
+	_debuglog "start public_delete"
 	_wait_for_free_slot
 	_requiresFqdn
 	_certMustExist
@@ -522,6 +574,7 @@ function public_delete(){
 	# CSR USAGE WAS REMOVED
 	rm -rf ${CM_dircerts} ${CM_filecnf} ${CM_filekey} ${CM_filecsr} ~/.acme.sh/${CM_fqdn} && echo OK
 	_update "deleted ${CM_fqdn}"
+	_debuglog "end public_delete"
 }
 
 
@@ -576,6 +629,7 @@ function public_list-old(){
 # public function - renew a certificate
 # param  string  fqdn of domain to renew
 function public_renew(){
+	_debuglog "start public_renew"
 	_wait_for_free_slot
 	_requiresFqdn
 	_certMustExist
@@ -598,6 +652,7 @@ function public_renew(){
 			_wd "Error ocured."
 			exit $_rc
 	esac
+	_debuglog "end public_renew"
 }
 
 #
@@ -788,7 +843,10 @@ if [ $# -gt 0 -a $? -eq 0 ]; then
 	_setenv $CM_fqdn
 
 	_wd "A C T I O N -->> $action <<--"
+	_debuglog ">>> START public_$action $CM_fqdn $*"
 	eval "public_$action $*"
+	_debuglog ">>> DONE public_$action $CM_fqdn $*"
+
 else
 	self=$( basename $0 )
 	cat <<EOF

inc_config.sh.dist

@@ -49,4 +49,16 @@ export ACME=../acme.sh/acme.sh
 # like Ansible or puppet; default: none (=any user can run cm.sh)
 # export CM_user="ansible"
 
+# flag: show debug infos on console (STDOUT)
+# default: 0
+export CM_showdebug=1
+
+# flag: write a log for created/ renewd/ deleted certs
+# default: 1
+# export CM_writelog=1
+
+# flag: write a log for executed functions with timer and process count
+# default: 0
+# export CM_writedebuglog=0
+
 # ----------------------------------------------------------------------