From bbc679463acf2c5c59fddd1b9fc2acb539ba6a29 Mon Sep 17 00:00:00 2001
From: "Kay Marquardt (Gnadelwartz)" <kay@rrr.de>
Date: Wed, 6 Jan 2021 08:48:25 +0100
Subject: [PATCH] internal: printf date is 100 times faster

---
 README.txt        |  5 ++---
 bashbot.sh        | 44 ++++++++++++++++++++++++--------------------
 doc/0_install.md  |  2 +-
 doc/3_advanced.md |  2 +-
 doc/4_expert.md   |  2 +-
 doc/7_develop.md  | 16 +++++++++-------
 6 files changed, 38 insertions(+), 33 deletions(-)

diff --git a/README.txt b/README.txt
index 5ee1713..f05309f 100644
--- a/README.txt
+++ b/README.txt
@@ -158,10 +158,9 @@ start debug`
 │   ├── BASHBOT.log      # log what your bot is doing ...
 │   ├── ERROR.log        # connection errors from / to Telegram API
 │   │
-│   ├── DEBUG.log        # stdout/stderr of you bot (debug mode 
+│   ├── DEBUG.log        # stdout/stderr of you bot (debug mode enabled)
+│   └── MESSAGE.log      # full text of all message send/received (debug mode 
 enabled)
-│   └── MESSAGE.log      # full text of all message send/received 
-(debug mode enabled)
 ```
 
 ----
diff --git a/bashbot.sh b/bashbot.sh
index 25d6b61..2a1a972 100755
--- a/bashbot.sh
+++ b/bashbot.sh
@@ -30,7 +30,7 @@
 #     8 - curl/wget missing
 #     10 - not bash!
 #
-#### $$VERSION$$ v1.25-dev-15-g4582efd
+#### $$VERSION$$ v1.25-dev-23-g8be95a3
 ##################################################################
 
 # emmbeded system may claim bash but it is not
@@ -91,6 +91,10 @@ _round_float() {
 	local digit="$2"; [[ "$2" =~ ^[${o9o9o9}]+$ ]] || digit="0"
 	{ LC_ALL=C.utf-8 printf "%.${digit}f" "$1"; } 2>/dev/null
 }
+# date is external, printf is much faster
+_date(){
+	printf "%(%c)T\n" -1
+}
 setConfigKey() {
 	[[ "$1" =~ ^[-${azAZo9},._]+$ ]] || return 3
 	[ -z "${BOTCONFIG}" ] && return 1
@@ -107,11 +111,11 @@ check_token(){
 	return 1
 }
 # log $1 with date
-log_error(){ printf "%s: %s\n" "$(date)" "$*" >>"${ERRORLOG}"; }
-log_debug(){ printf "%s: %s\n" "$(date)" "$*" >>"${DEBUGLOG}"; }
-log_update(){ printf "%s: %s\n" "$(date)" "$*" >>"${UPDATELOG}"; }
+log_error(){ printf "%(%c)T: %s\n" "-1" "$*" >>"${ERRORLOG}"; }
+log_debug(){ printf "%(%c)T: %s\n" "-1" "$*" >>"${DEBUGLOG}"; }
+log_update(){ printf "%(%c)T: %s\n" "-1" "$*" >>"${UPDATELOG}"; }
 # log $1 with date, special first \n
-log_message(){ printf "\n%s: %s\n" "$(date)" "${1/\\n/$'\n'}" >>"${MESSAGELOG}"; }
+log_message(){ printf "\n%(%c)T: %s\n" "-1" "${1/\\n/$'\n'}" >>"${MESSAGELOG}"; }
 
 # additional tests if we run in debug mode
 export BASHBOTDEBUG
@@ -121,16 +125,16 @@ export BASHBOTDEBUG
 # shellcheck disable=SC2094
 debug_checks(){ {
 	[  -z "${BASHBOTDEBUG}" ] && return
-	local DATE WHERE MYTOKEN; DATE="$(date)"; WHERE="$1"; shift
-	printf "%s: debug_checks: %s: bashbot.sh %s\n" "${DATE}" "${WHERE}" "${@##*/}"
+	local where token; where="$1"; shift
+	printf "%(%c)T: debug_checks: %s: bashbot.sh %s\n" "-1" "${where}" "${1##*/}"
 	# shellcheck disable=SC2094
-	[ -z "${DEBUGLOG}" ] && printf "%s: %s\n" "${DATE}" "DEBUGLOG not set! =========="
-	MYTOKEN="$(getConfigKey "bottoken")"
-	[ -z "${MYTOKEN}" ] && printf "%s: %s\n" "${DATE}" "Bot token is missing! =========="
-	check_token "${MYTOKEN}" || printf "%s: %s\n" "${DATE}" "Invalid bot token! =========="
-	[ -z "$(getConfigKey "botadmin")" ] && printf "%s: %s\n" "${DATE}" "Bot admin is missing! =========="
+	[ -z "${DEBUGLOG}" ] && printf "%(%c)T: %s\n" "-1" "DEBUGLOG not set! =========="
+	token="$(getConfigKey "bottoken")"
+	[ -z "${token}" ] && printf "%(%c)T: %s\n" "-1" "Bot token is missing! =========="
+	check_token "${token}" || printf "%(%c)T: %s\n%s\n" "-1" "Invalid bot token! ==========" "${token}"
+	[ -z "$(getConfigKey "botadmin")" ] && printf "%(%c)T: %s\n" "-1" "Bot admin is missing! =========="
 	# call user defined debug_checks if exists
-	_exec_if_function my_debug_checks "${DATE}" "${WHERE}" "$*"
+	_exec_if_function my_debug_checks "$(_date)" "${where}" "$*"
 	} >>"${DEBUGLOG}"
 }
 
@@ -261,7 +265,6 @@ ERRORLOG="${LOGDIR}/ERROR.log"
 UPDATELOG="${LOGDIR}/BASHBOT.log"
 MESSAGELOG="${LOGDIR}/MESSAGE.log"
 
-debug_checks "start SOURCE=${SOURCE:-no}" "$@"
 # read BOTTOKEN from bot database if not set
 if [ -z "${BOTTOKEN}" ]; then
     BOTTOKEN="$(getConfigKey "bottoken")"
@@ -327,6 +330,7 @@ if [  -r "${COMMANDS}" ]; then
 else
 	[ -z "${SOURCE}" ] && printf "${RED}Warning: ${COMMANDS} does not exist or is not readable!.${NN}"
 fi
+debug_checks "start SOURCE=${SOURCE:-no}" "$@"
 
 ###############
 # load modules
@@ -536,7 +540,7 @@ fi
 sendJsonRetry(){
 	local retry="$1"; shift
 	[[ "$1" =~ ^\ *[${o9o9o9}.]+\ *$ ]] && sleep "$1"; shift
-	printf "%s: RETRY %s %s %s\n" "$(date)" "${retry}" "$1" "${2:0:60}"
+	printf "%(%c)T: RETRY %s %s %s\n" "-1" "${retry}" "$1" "${2:0:60}"
 	case "${retry}" in
 		'sendJson'*)
 			sendJson "$@"	
@@ -582,7 +586,7 @@ sendJsonResult(){
 	    # log error
 	    [[ "${BOTSENT[ERROR]}" = "400" && "${BOTSENT[DESCRIPTION]}" == *"starting at byte offset"* ]] &&\
 			 offset="${BOTSENT[DESCRIPTION]%* }"
-	    printf "%s: RESULT=%s FUNC=%s CHAT[ID]=%s ERROR=%s DESC=%s ACTION=%s\n" "$(date)"\
+	    printf "%(%c)T: RESULT=%s FUNC=%s CHAT[ID]=%s ERROR=%s DESC=%s ACTION=%s\n" "-1"\
 			"${BOTSENT[OK]}"  "$2" "$3" "${BOTSENT[ERROR]}" "${BOTSENT[DESCRIPTION]}" "${4:${offset}:100}"
 	    # warm path, do not retry on error, also if we use wegt
 	    [ -n "${BASHBOT_RETRY}${BASHBOT_WGET}" ] && return
@@ -600,7 +604,7 @@ sendJsonResult(){
 	    if [ "${BOTSENT[ERROR]}" == "999" ];then
 		# check if default curl and args are OK
 			if ! curl -sL -k -m 2 "${URL}" >/dev/null 2>&1 ; then
-				printf "%s: BASHBOT IP Address seems blocked!\n" "$(date)"
+				printf "%(%c)T: BASHBOT IP Address seems blocked!\n" "-1"
 				# user provided function to recover or notify block
 				if _exec_if_function bashbotBlockRecover; then
 					BASHBOT_RETRY="2"
@@ -706,12 +710,12 @@ process_client() {
 			MESSAGE[0]="/_edited_message "
 		fi
 		process_message "${num}" "${debug}"
-	        printf "%s: update received FROM=%s CHAT=%s CMD=%s\n" "$(date)" "${USER[USERNAME]:0:20} (${USER[ID]})"\
+	        printf "%(%c)T: update received FROM=%s CHAT=%s CMD=%s\n" "-1" "${USER[USERNAME]:0:20} (${USER[ID]})"\
 			"${CHAT[USERNAME]:0:20}${CHAT[TITLE]:0:30} (${CHAT[ID]})"\
 			"${MESSAGE:0:30}${CAPTION:0:30}${URLS[*]:0:30}" >>"${UPDATELOG}"
 	else
 		process_inline "${num}" "${debug}"
-	        printf "%s: iQuery received FROM=%s iQUERY=%s\n" "$(date)"\
+	        printf "%(%c)T: iQuery received FROM=%s iQUERY=%s\n" "-1"\
 			"${iQUERY[USERNAME]:0:20} (${iQUERY[USER_ID]})" "${iQUERY[0]}" >>"${UPDATELOG}"
 	fi
 	#####
@@ -1050,7 +1054,7 @@ start_bot() {
 	jssh_deleteKeyDB "CLEAN_COUNTER_DATABASE_ON_STARTUP" "${COUNTFILE}"
         [ -f "${COUNTFILE}.jssh.flock" ] && rm -f "${COUNTFILE}.jssh.flock"
 	# store start time and cleanup botconfig on startup
-	jssh_updateKeyDB "startup" "$(date)" "${BOTCONFIG}"
+	jssh_updateKeyDB "startup" "$(_date)" "${BOTCONFIG}"
         [ -f "${BOTCONFIG}.jssh.flock" ] && rm -f "${BOTCONFIG}.jssh.flock"
 	# read blocked users
 	jssh_readDB_async "BASHBOTBLOCKED" "${BLOCKEDFILE}"
diff --git a/doc/0_install.md b/doc/0_install.md
index 79982fa..8032701 100644
--- a/doc/0_install.md
+++ b/doc/0_install.md
@@ -127,5 +127,5 @@ You must update to [Version 1.20](https://github.com/topkecleon/telegram-bot-bas
 
 #### [Next Create Bot](1_firstbot.md)
 
-#### $$VERSION$$ v1.25-dev-14-g2fe6d4b
+#### $$VERSION$$ v1.25-dev-23-g8be95a3
 
diff --git a/doc/3_advanced.md b/doc/3_advanced.md
index e29f0c5..e16359f 100644
--- a/doc/3_advanced.md
+++ b/doc/3_advanced.md
@@ -301,5 +301,5 @@ Note: If you disable automatic retry, se above, you disable also connection prob
 #### [Prev Getting started](2_usage.md)
 #### [Next Expert Use](4_expert.md)
 
-#### $$VERSION$$ v1.21-0-gc85af77
+#### $$VERSION$$ v1.25-dev-23-g8be95a3
 
diff --git a/doc/4_expert.md b/doc/4_expert.md
index 1616cd6..b5a6f8c 100644
--- a/doc/4_expert.md
+++ b/doc/4_expert.md
@@ -434,5 +434,5 @@ for every poll until the maximum of BASHBOT_SLEEP ms.
 #### [Prev Advanced Use](3_advanced.md)
 #### [Next Best Practice](5_practice.md)
 
-#### $$VERSION$$ v1.25-dev-2-g0d678f4
+#### $$VERSION$$ v1.25-dev-23-g8be95a3
 
diff --git a/doc/7_develop.md b/doc/7_develop.md
index 8febf48..b6ced9a 100644
--- a/doc/7_develop.md
+++ b/doc/7_develop.md
@@ -11,11 +11,11 @@ If you want to get error messages (and more) start bashbot  `./bashbot.sh startb
 you can the change the level of verbosity of the debug argument: 
 
 ```
-	"debug"		all output is redirected to "DEBUG.log", in addition every incoming message is logged in "MESSAGE.log" and "INLINE.log"
-	"xdebug"	same as debug plus set bash option '-x' to log any executed command in "DEBUG.log"
+	"debug"		all output is redirected to `DEBUG.log`, in addition every incoming message is logged in `MESSAGE.log` and `INLINE.log`
+	"xdebug"	same as debug plus set bash option '-x' to log any executed command in `DEBUG.log`
 ```
 
-Use the command `tail` to watch your bot live, e.g. "tail -f DEBUG.log". To obtain more information place set -x; set +x in your code.
+Use the command `tail` to watch your bot live, e.g. `tail -f DEBUG.log`. To obtain more information place `set -x; ... set +x` around suspected code.
 
 Sometimes it's useful to watch the bot live in the terminal:
 
@@ -147,7 +147,7 @@ This means if you register an every 5 minutes callback first execution may < 5 M
     * x	execute every x minutes
     * -x execute once WITHIN the next x Minutes (next 10 Minutes since start "event")
 
-Note: If you want exact "in x minutes" use "EVENT_TIMER plus x" as time: `-(EVENT_TIMER + x)`
+Note: If you want exact "in x minutes" use "EVENT_TIMER" as reference: `(EVENT_TIMER +x)`
 
 *Example:*
 ```bash
@@ -166,8 +166,8 @@ BASHBOT_EVENT_TIMER["example_every5","5"]="example_every5min"
 # execute once on the next 10 minutes since start "event"
 BASHBOT_EVENT_TIMER["example_10min","-10"]="example_in10min"
 
-# once in exact 10 minutes
-BASHBOT_EVENT_TIMER["example_10min","$(( (EVENT_TIMER+10) * -1 ))"]="example_in10min"
+# once in exact 10 minutes, note the -
+BASHBOT_EVENT_TIMER["example_10min","-$(( EVENT_TIMER+10 ))"]="example_in10min"
 
 ```
 
@@ -252,6 +252,8 @@ data="$(cat file)" -> data="$(<"file")"
 
 DIR="$(dirname $0) -> DIR="${0%/*}"
 
+date -> printf"%(%c)T\n" -1	# 100 times faster!
+
 PROG="($basename $0)" -> PROG="${0##*/}*
 
 ADDME="$ADDME something to add" -> ADDME+=" something to add""
@@ -356,5 +358,5 @@ fi
 
 #### [Prev Function Reference](6_reference.md)
 
-#### $$VERSION$$ v1.21-24-g7cf624f
+#### $$VERSION$$ v1.25-dev-23-g8be95a3