debug(bklog):Add minor debug msg

[EVA-2020-02.git] / exec / bklog

diff --git a/exec/bklog b/exec/bklog
index a78b19f6a7b8a975aea81600562a1b051296d1e9..188910dbe89cd77b22eb9307c72e2fe95618871d 100644 (file)
--- a/exec/bklog
+++ b/exec/bklog
@@ -11,7 +11,7 @@ dirTmpDefault="/dev/shm"; # Default parent of working directory
 
 # Script Metadata
 scriptName="bklog";             # Define basename of script file.
 
 # Script Metadata
 scriptName="bklog";             # Define basename of script file.

-scriptVersion="0.1.20";          # Define version of script.
+scriptVersion="0.1.26";          # Define version of script.

 scriptURL="https://gitlab.com/baltakatei/ninfacyzga-01"; # Define wesite hosting this script.
 scriptTimeStart="$(date +%Y%m%dT%H%M%S.%N)"; # YYYYmmddTHHMMSS.NNNNNNNNN
 scriptHostname=$(hostname);     # Save hostname of system running this script.
 scriptURL="https://gitlab.com/baltakatei/ninfacyzga-01"; # Define wesite hosting this script.
 scriptTimeStart="$(date +%Y%m%dT%H%M%S.%N)"; # YYYYmmddTHHMMSS.NNNNNNNNN
 scriptHostname=$(hostname);     # Save hostname of system running this script.


@@ -54,7 +54,7 @@ processArguments() {
            -t | --temp-dir) optionTmpDir="true" && argTempDirPriority="$2"; shift;; # Set time zone
            -b | --buffer-ttl) optionCustomBufferTTL="true" && argCustomBufferTTL="$2"; shift;; # Set custom buffer period (default: 300 seconds)
            -B | --script-ttl) optionCustomScriptTTL_TE="true" && argCustomScriptTTL_TE="$2"; shift;; # Set custom script TTL (default: "day")
            -t | --temp-dir) optionTmpDir="true" && argTempDirPriority="$2"; shift;; # Set time zone
            -b | --buffer-ttl) optionCustomBufferTTL="true" && argCustomBufferTTL="$2"; shift;; # Set custom buffer period (default: 300 seconds)
            -B | --script-ttl) optionCustomScriptTTL_TE="true" && argCustomScriptTTL_TE="$2"; shift;; # Set custom script TTL (default: "day")

-           -p | --process-string) optionProcString="true" && argProcStrings+=("$2") && argProcFileExts+=("$3") && vbm "STATUS:file extension \"$2\" for output of processing string added:\"$3\""; shift; shift;;
+           -p | --process-string) optionProcString="true" && argProcStrings+=("$2") && argProcFileExts+=("$3") && vbm "STATUS:file extension \"$3\" for output of processing string added:\"$2\""; shift; shift;;

            -l | --label) optionLabel="true" && argLabel="$2"; vbm "DEBUG :Custom label received:$argLabel"; shift;;
            -w | --store-raw) optionStoreRaw="true" && argRawFileExt="$2"; vbm "DEBUG :Raw stdin file extension received:$argRawFileExt"; shift;;
            -W | --no-store-raw) optionNoStoreRaw="true"; vbm "DEBUG :Option selected to not store raw stdin data."; shift;;
            -l | --label) optionLabel="true" && argLabel="$2"; vbm "DEBUG :Custom label received:$argLabel"; shift;;
            -w | --store-raw) optionStoreRaw="true" && argRawFileExt="$2"; vbm "DEBUG :Raw stdin file extension received:$argRawFileExt"; shift;;
            -W | --no-store-raw) optionNoStoreRaw="true"; vbm "DEBUG :Option selected to not store raw stdin data."; shift;;


@@ -66,7 +66,7 @@ processArguments() {
 vbm() {
     # Description: Prints verbose message ("vbm") to stderr if optionVerbose is set to "true".
     # Usage: vbm "DEBUG :verbose message here"
 vbm() {
     # Description: Prints verbose message ("vbm") to stderr if optionVerbose is set to "true".
     # Usage: vbm "DEBUG :verbose message here"

-    # Version 0.1.2
+    # Version 0.1.3

     # Input: arg1: string
     #        vars: optionVerbose
     # Output: stderr
     # Input: arg1: string
     #        vars: optionVerbose
     # Output: stderr


@@ -74,7 +74,7 @@ vbm() {
 
     if [ "$optionVerbose" = "true" ]; then
        functionTime=$(date --iso-8601=ns); # Save current time in nano seconds.
 
     if [ "$optionVerbose" = "true" ]; then
        functionTime=$(date --iso-8601=ns); # Save current time in nano seconds.

-       echo "[$functionTime] ""$*" 1>&2; # Display argument text.
+       echo "[$functionTime]:$0:""$*" 1>&2; # Display argument text.

     fi
 
     # End function
     fi
 
     # End function


@@ -357,17 +357,20 @@ checkMakeTar() {
     if tar --list --file="$pathTar" 1>/dev/null 2>&1; then
        ## T1: return success
        returnFlag0="tar valid";
     if tar --list --file="$pathTar" 1>/dev/null 2>&1; then
        ## T1: return success
        returnFlag0="tar valid";

+    elif { sleep 2; tar --list --file="$pathTar" 1>/dev/null 2>&1; }; then
+       ## F1: Check tar archive again after 2-second sleep
+       returnFlag0="tar valid";

     else
     else

-       ## F1: Check if file exists
+       ## F2-1: Check if file exists

        if [[ -f "$pathTar" ]]; then
            ### T: Rename file
        if [[ -f "$pathTar" ]]; then
            ### T: Rename file

-           try mv "$pathTar" "$pathTar""--broken--""$(date +%Y%m%dT%H%M%S)" && \
+           try mv "$pathTar" "$pathTar""--broken--""$(date +%Y%m%dT%H%M%S%z)" && \

                returnFlag1="tar moved";
        else
            ### F: -
            :
        fi;
                returnFlag1="tar moved";
        else
            ### F: -
            :
        fi;

-       ## F2: Create tar archive, return 0
+       ## F2-1: Create tar archive, return 0

        try tar --create --file="$pathTar" --files-from=/dev/null && \
            returnFlag2="tar created";
     fi;
        try tar --create --file="$pathTar" --files-from=/dev/null && \
            returnFlag2="tar created";
     fi;


@@ -884,7 +887,7 @@ magicParseCompressionArg() {
        cmd_compress_suffix="" && vbm "STATUS:$fn:cmd_compress_suffix:$cmd_compress_suffix";
        vbm "DEBUG :$fn:Compression not enabled.";
     fi;
        cmd_compress_suffix="" && vbm "STATUS:$fn:cmd_compress_suffix:$cmd_compress_suffix";
        vbm "DEBUG :$fn:Compression not enabled.";
     fi;

-    vbm "STATUS:$fn:Starting magicParseCompressionArg() function.";
+    vbm "STATUS:$fn:Finished magicParseCompressionArg() function.";

 } # Form compression cmd string and filename suffix
 magicParseCustomTTL() {
     # Desc: Set user-specified TTLs for buffer and script
 } # Form compression cmd string and filename suffix
 magicParseCustomTTL() {
     # Desc: Set user-specified TTLs for buffer and script


@@ -925,7 +928,7 @@ magicParseCustomTTL() {
        fi;
        ## F: do not change scriptTTL_TE
     fi;
        fi;
        ## F: do not change scriptTTL_TE
     fi;

-    vbm "STATUS:$fn:Starting magicParseCustomTTL() function.";
+    vbm "STATUS:$fn:Finished magicParseCustomTTL() function.";

 } # Sets custom script or buffer TTL if specified
 magicParseLabel() {
     # Desc: Parses -l option to set label
 } # Sets custom script or buffer TTL if specified
 magicParseLabel() {
     # Desc: Parses -l option to set label


@@ -1029,9 +1032,11 @@ magicParseProcessStrings() {
            exit 1; fi; done;
     vbm "STATUS:$fn:Quick check shows argProcStrings and argProcFileExts appear to have valid contents.";
     vbm "STATUS:$fn:argProcStrings:${argProcStrings[*]}"
            exit 1; fi; done;
     vbm "STATUS:$fn:Quick check shows argProcStrings and argProcFileExts appear to have valid contents.";
     vbm "STATUS:$fn:argProcStrings:${argProcStrings[*]}"

-    vbm "STATUS:$fn:argProcStrings:${argProcFileExts[*]}"
+    vbm "STATUS:$fn:argProcFileExts:${argProcFileExts[*]}"

     procStrings+=("${argProcStrings[@]}"); # Export process command strings
     procFileExts+=("${argProcFileExts[@]}"); # Export process command strings
     procStrings+=("${argProcStrings[@]}"); # Export process command strings
     procFileExts+=("${argProcFileExts[@]}"); # Export process command strings

+    vbm "STATUS:$fn:procStrings:${procStrings[*]}"
+    vbm "STATUS:$fn:procFileExts:${procFileExts[*]}"

     vbm "STATUS:$fn:Finished magicParseProcessStrings() function.";
 } # Validate and save process strings and file extensions to arrays procStrings, procFileExts
 magicParseRecipients() {
     vbm "STATUS:$fn:Finished magicParseProcessStrings() function.";
 } # Validate and save process strings and file extensions to arrays procStrings, procFileExts
 magicParseRecipients() {


@@ -1146,19 +1151,23 @@ magicSetScriptTTL() {
     vbm "STATUS:$fn:Starting magicSetScriptTTL() function.";
     argTimeElement="$1";
     if [[ "$argTimeElement" = "day" ]]; then
     vbm "STATUS:$fn:Starting magicSetScriptTTL() function.";
     argTimeElement="$1";
     if [[ "$argTimeElement" = "day" ]]; then

-           # Set script lifespan to end at start of next day
+       # Set script lifespan to end at start of next day
+       vbm "STATUS:$fn:Setting script lifespan to end at start of next day. argTimeElement:$argTimeElement";

        if ! scriptTTL="$(timeUntilNextDay)"; then # sets scriptTTL, then checks exit code
            if [[ "$scriptTTL" -eq 0 ]]; then
        if ! scriptTTL="$(timeUntilNextDay)"; then # sets scriptTTL, then checks exit code
            if [[ "$scriptTTL" -eq 0 ]]; then

-           ((scriptTTL++)); # Add 1 because 0 would cause 'timeout' to never timeout.
+               ((scriptTTL++)); # Add 1 because 0 would cause 'timeout' to never timeout.
+               vbm "STATUS:$fn:scriptTTL:$scriptTTL";

            else
            yell "ERROR:$fn:timeUntilNextDay exit code $?"; exit 1;
            fi;
        fi;
     elif [[ "$argTimeElement" = "hour" ]]; then
        # Set script lifespan to end at start of next hour
            else
            yell "ERROR:$fn:timeUntilNextDay exit code $?"; exit 1;
            fi;
        fi;
     elif [[ "$argTimeElement" = "hour" ]]; then
        # Set script lifespan to end at start of next hour

+       vbm "STATUS:$fn:Setting script lifespan to end at start of next hour. argTimeElement:$argTimeElement";

        if ! scriptTTL="$(timeUntilNextHour)"; then # sets scriptTTL, then checks exit code
            if [[ "$scriptTTL" -eq 0 ]]; then
                ((scriptTTL++)); # Add 1 because 0 would cause 'timeout' to never timeout.
        if ! scriptTTL="$(timeUntilNextHour)"; then # sets scriptTTL, then checks exit code
            if [[ "$scriptTTL" -eq 0 ]]; then
                ((scriptTTL++)); # Add 1 because 0 would cause 'timeout' to never timeout.

+               vbm "STATUS:$fn:scriptTTL:$scriptTTL";

            else
                yell "ERROR:$fn:timeUntilNextHour exit code $?"; exit 1;
            fi;
            else
                yell "ERROR:$fn:timeUntilNextHour exit code $?"; exit 1;
            fi;


@@ -1209,14 +1218,15 @@ magicWriteVersion() {
 } # write version data to pathout_tar via appendArgTar()
 magicProcessWriteBuffer() {
     # Desc: process and write buffer
 } # write version data to pathout_tar via appendArgTar()
 magicProcessWriteBuffer() {
     # Desc: process and write buffer

-    # In : vars: bufferTTL bufferTTL_STR scriptHostname label dir_tmp SECONDS
+    # In : vars: bufferTTL scriptHostname label dir_tmp SECONDS
+    #    : vars: timeBufferStartEpoch timeBufferEndEpoch

     #    : arry: buffer
     # Out: file:(pathout_tar)
     # Depends: Bash 5.0.3, date 8.30, yell(), vbm(), dateTimeShort(),
     ### Note: These arrays should all have the same number of elements:
     ###       pathouts, fileouts, procFileExts, procStrings
     
     #    : arry: buffer
     # Out: file:(pathout_tar)
     # Depends: Bash 5.0.3, date 8.30, yell(), vbm(), dateTimeShort(),
     ### Note: These arrays should all have the same number of elements:
     ###       pathouts, fileouts, procFileExts, procStrings
     

-    local fn timeBufferStartLong timeBufferStart fileoutBasename
+    local fn timeBufferStartLong timeBufferStart bufferDuration bufferDurationStr fileoutBasename

     local -a fileouts pathouts
     local writeCmd1 writeCmd2 writeCmd3 writeCmd4
 
     local -a fileouts pathouts
     local writeCmd1 writeCmd2 writeCmd3 writeCmd4
 


@@ -1230,12 +1240,17 @@ magicProcessWriteBuffer() {
     
     # Determine file paths (time is start of buffer period)
     ## Calculate start time
     
     # Determine file paths (time is start of buffer period)
     ## Calculate start time

-    timeBufferStartLong="$(date --date="$bufferTTL seconds ago" --iso-8601=seconds)" && \
-       vbm "DEBUG :$fn:timeBufferStartLong:$timeBufferStartLong";
+    timeBufferStartLong="$(date --date="@$timeBufferStartEpoch" --iso-8601=seconds)" && \
+       vbm "DEBUG :$fn:timeBufferStartLong:$timeBufferStartLong"; # Note start time in 'date' parsable ISO-8601

     timeBufferStart="$(dateTimeShort "$timeBufferStartLong" )" && \
        vbm "DEBUG :$fn:timeBufferStart:$timeBufferStart"; # Note start time YYYYmmddTHHMMSS+zzzz (no separators)
     timeBufferStart="$(dateTimeShort "$timeBufferStartLong" )" && \
        vbm "DEBUG :$fn:timeBufferStart:$timeBufferStart"; # Note start time YYYYmmddTHHMMSS+zzzz (no separators)

+    ## Calculate buffer duration string (ISO-8601 duration)
+    bufferDuration="$((timeBufferEndEpoch - timeBufferStartEpoch))" && \
+       vbm "DEBUG :$fn:bufferDuration:$bufferDuration"; # length of time (seconds) stdin was read
+    bufferDurationStr="$(timeDuration "$bufferDuration")" && \
+       vbm "DEBUG :$fn:bufferDurationStr:$bufferDurationStr"; # buffer duration (ISO-8601)

     ## Set common basename
     ## Set common basename

-    fileoutBasename="$timeBufferStart""--""$bufferTTL_STR""..""$scriptHostname""$label" && \
+    fileoutBasename="$timeBufferStart""--""$bufferDurationStr""..""$scriptHostname""$label" && \

        vbm "STATUS:$fn:Set fileoutBasename to:$fileoutBasename";
     ## Determine output file name array
     ### in: fileOutBasename cmd_compress_suffix cmd_encrypt_suffix procFileExts
        vbm "STATUS:$fn:Set fileoutBasename to:$fileoutBasename";
     ## Determine output file name array
     ### in: fileOutBasename cmd_compress_suffix cmd_encrypt_suffix procFileExts


@@ -1258,6 +1273,12 @@ magicProcessWriteBuffer() {
     writeCmd4="$cmd_encrypt";
     
     ## Process buffer and write to dir_tmp
     writeCmd4="$cmd_encrypt";
     
     ## Process buffer and write to dir_tmp

+    vbm "DEBUG :$fn:fileouts    element count:${#fileouts[@]}";
+    vbm "DEBUG :$fn:pathouts    element count:${#pathouts[@]}";
+    vbm "DEBUG :$fn:procStrings element count:${#pathouts[@]}";
+    vbm "DEBUG :$fn:fileouts    contents:${fileouts[*]}";
+    vbm "DEBUG :$fn:pathouts    contents:${pathouts[*]}";
+    vbm "DEBUG :$fn:procStrings contents:${pathouts[*]}";

     for index in "${!pathouts[@]}"; do
        writeCmd2="${procStrings[$index]}";
        writeCmdAll="$writeCmd1 | $writeCmd2 | $writeCmd3 | $writeCmd4" && vbm "STATUS:$fn:Assembled command:\"$writeCmdAll\"";
     for index in "${!pathouts[@]}"; do
        writeCmd2="${procStrings[$index]}";
        writeCmdAll="$writeCmd1 | $writeCmd2 | $writeCmd3 | $writeCmd4" && vbm "STATUS:$fn:Assembled command:\"$writeCmdAll\"";


@@ -1267,8 +1288,9 @@ magicProcessWriteBuffer() {
     # Append dir_tmp files to pathout_tar
     wait; # Wait to avoid collision with older magicProcessWriteBuffer() instances (see https://www.tldp.org/LDP/abs/html/x9644.html )
     for index in "${!pathouts[@]}"; do
     # Append dir_tmp files to pathout_tar
     wait; # Wait to avoid collision with older magicProcessWriteBuffer() instances (see https://www.tldp.org/LDP/abs/html/x9644.html )
     for index in "${!pathouts[@]}"; do

-       appendFileTar "${pathouts[$index]}" "${fileouts[$index]}" "$pathout_tar" "$dir_tmp" && \
+       tar --append --directory="$dir_tmp" --file="$pathout_tar" "${fileouts[$index]}" && \

            vbm "STATUS:$fn:Appended ${pathouts[$index]} to $pathout_tar";
            vbm "STATUS:$fn:Appended ${pathouts[$index]} to $pathout_tar";

+       #appendFileTar "${pathouts[$index]}" "${fileouts[$index]}" "$pathout_tar" "$dir_tmp" && \

     done;
     
     # Remove secured chunks from dir_tmp
     done;
     
     # Remove secured chunks from dir_tmp


@@ -1384,8 +1406,14 @@ main() {
     # Perform secondary setup operations
     ## Set script lifespan (scriptTTL from scriptTTL_TE)
     magicSetScriptTTL "$scriptTTL_TE";
     # Perform secondary setup operations
     ## Set script lifespan (scriptTTL from scriptTTL_TE)
     magicSetScriptTTL "$scriptTTL_TE";

-    ## File name substring (ISO-8601 duration from bufferTTL)
-    bufferTTL_STR="$(timeDuration "$bufferTTL")" && vbm "DEBUG :$fn:bufferTTL_STR:$bufferTTL_STR";
+    ## Adjust SECONDS so buffer rounds align with time elements
+    ### Advance SECONDS the remainder seconds for dividend timeUntilNextDay, divisor bufferTTL
+    if [[ "$(timeUntilNextDay)" -gt "$bufferTTL" ]]; then
+       vbm "DEBUG :$fn:SECONDS currently  :$SECONDS";
+       SECONDS="$(( $(timeUntilNextDay) % bufferTTL ))" && \
+           vbm "DEBUG :$fn:SECONDS advanced to:$SECONDS";
+       vbm "DEBUG :$fn:current time:$(date --iso-8601=seconds)";
+    fi;

     ## Init temp working dir
     try mkdir "$dir_tmp" && vbm "DEBUG :$fn:Working dir created at dir_tmp:$dir_tmp";
     ## Initialize output tar (set pathout_tar)
     ## Init temp working dir
     try mkdir "$dir_tmp" && vbm "DEBUG :$fn:Working dir created at dir_tmp:$dir_tmp";
     ## Initialize output tar (set pathout_tar)


@@ -1402,12 +1430,16 @@ main() {
     bufferRound=0;
     while [[ $SECONDS -lt "scriptTTL" ]]; do
        vbm "STATUS:$fn:Starting buffer round:$bufferRound";
     bufferRound=0;
     while [[ $SECONDS -lt "scriptTTL" ]]; do
        vbm "STATUS:$fn:Starting buffer round:$bufferRound";

-       bufferTOD="$((SECONDS + bufferTTL))"; # Set buffer round time-of-death
+       bufferTOD="$(( (1+bufferRound)*bufferTTL ))" && vbm "DEBUG :$fn:bufferTOD:$bufferTOD"; # Set buffer round time-of-death
+       # Note start time of data collection
+       timeBufferStartEpoch="$(date +%s)" && vbm "DEBUG :$fn:timeBufferStartEpoch:$timeBufferStartEpoch";

        # Consume stdin to fill buffer until buffer time-of-death (TOD) arrives
        while read -r -t "$bufferTTL" line && [[ $SECONDS -lt "$bufferTOD" ]]; do
            # Append line to buffer array
            buffer+=("$line");
        done;
        # Consume stdin to fill buffer until buffer time-of-death (TOD) arrives
        while read -r -t "$bufferTTL" line && [[ $SECONDS -lt "$bufferTOD" ]]; do
            # Append line to buffer array
            buffer+=("$line");
        done;

+       # Note end time of data collection
+       timeBufferEndEpoch="$(date +%s)" && vbm "DEBUG :$fn:timeBufferEndEpoch:$timeBufferEndEpoch";

        # Create dir_tmp if missing
        if ! [[ -d "$dir_tmp" ]]; then
            yell "ERROR:$fn:dir_tmp existence failure:$dir_tmp";
        # Create dir_tmp if missing
        if ! [[ -d "$dir_tmp" ]]; then
            yell "ERROR:$fn:dir_tmp existence failure:$dir_tmp";