debug(bklog):Format DEBUG messages to align better
[EVA-2020-02.git] / exec / bklog
index 6fc61e4325430d2fdbf7f2880cf7e7317187fede..6e166f164e31bb03034c1a6574b1b6183df4ffee 100644 (file)
@@ -11,7 +11,7 @@ dirTmpDefault="/dev/shm"; # Default parent of working directory
 
 # Script Metadata
 scriptName="bklog";             # Define basename of script file.
-scriptVersion="0.1.8";          # Define version of script.
+scriptVersion="0.1.14";          # 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.
@@ -43,22 +43,22 @@ try() { "$@" || die "cannot $*"; } #o
 processArguments() {
     while [ ! $# -eq 0 ]; do   # While number of arguments ($#) is not (!) equal to (-eq) zero (0).
        case "$1" in
-           -v | --verbose) optionVerbose="true"; vbm "DEBUG:Verbose mode enabled.";; # Enable verbose mode.
+           -v | --verbose) optionVerbose="true"; vbm "DEBUG :Verbose mode enabled.";; # Enable verbose mode.
            -h | --help) showUsage; exit 1;; # Display usage.
            --version) showVersion; exit 1;; # Show version
-           -o | --output) if [ -d "$2" ]; then dirOut="$2"; vbm "DEBUG:dirOut:$dirOut"; shift; fi ;; # Define output directory.
-           -e | --encrypt) optionEncrypt="true"; vbm "DEBUG:Encrypted output mode enabled.";; # Enable encryption
+           -o | --output) if [ -d "$2" ]; then dirOut="$2"; vbm "DEBUG :dirOut:$dirOut"; shift; fi ;; # Define output directory.
+           -e | --encrypt) optionEncrypt="true"; vbm "DEBUG :Encrypted output mode enabled.";; # Enable encryption
            -r | --recipient) optionRecipients="true"; argRecPubKeys+=("$2"); vbm "STATUS:pubkey added:""$2"; shift;; # Add recipients
-           -c | --compress) optionCompress="true"; vbm "DEBUG:Compressed output mode enabled.";; # Enable compression
+           -c | --compress) optionCompress="true"; vbm "DEBUG :Compressed output mode enabled.";; # Enable compression
            -z | --time-zone) try setTimeZoneEV "$2"; shift;; # Set timestamp timezone
            -t | --temp-dir) optionTmpDir="true" && argTempDirPriority="$2"; shift;; # Set time zone
            -R | --recipient-dir) optionRecipients="true"; optionRecDir="true" && argRecDir="$2"; shift;; # Add recipient watch dir
            -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;;
-           -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;;
            *) yell "ERROR: Unrecognized argument: $1"; yell "STATUS:All arguments:$*"; exit 1;; # Handle unrecognized options.
        esac
        shift
@@ -66,7 +66,7 @@ processArguments() {
 } # Argument Processing
 vbm() {
     # Description: Prints verbose message ("vbm") to stderr if optionVerbose is set to "true".
-    # Usage: vbm "DEBUG:verbose message here"
+    # Usage: vbm "DEBUG :verbose message here"
     # Version 0.1.2
     # Input: arg1: string
     #        vars: optionVerbose
@@ -174,11 +174,11 @@ displayMissing() {
     #==BEGIN Display errors==
     #===BEGIN Display Missing Apps===
     missingApps="Missing apps  :";
-    #for key in "${!appRollCall[@]}"; do echo "DEBUG:$key => ${appRollCall[$key]}"; done
+    #for key in "${!appRollCall[@]}"; do echo "DEBUG :$key => ${appRollCall[$key]}"; done
     for key in "${!appRollCall[@]}"; do
        value="${appRollCall[$key]}";
        if [ "$value" = "false" ]; then
-           #echo "DEBUG:Missing apps: $key => $value";
+           #echo "DEBUG :Missing apps: $key => $value";
            missingApps="$missingApps""$key ";
            appMissing="true";
        fi;
@@ -191,11 +191,11 @@ displayMissing() {
 
     #===BEGIN Display Missing Files===
     missingFiles="Missing files:";
-    #for key in "${!fileRollCall[@]}"; do echo "DEBUG:$key => ${fileRollCall[$key]}"; done
+    #for key in "${!fileRollCall[@]}"; do echo "DEBUG :$key => ${fileRollCall[$key]}"; done
     for key in "${!fileRollCall[@]}"; do
        value="${fileRollCall[$key]}";
        if [ "$value" = "false" ]; then
-           #echo "DEBUG:Missing files: $key => $value";
+           #echo "DEBUG :Missing files: $key => $value";
            missingFiles="$missingFiles""$key ";
            fileMissing="true";
        fi;
@@ -208,11 +208,11 @@ displayMissing() {
 
     #===BEGIN Display Missing Directories===
     missingDirs="Missing dirs:";
-    #for key in "${!dirRollCall[@]}"; do echo "DEBUG:$key => ${dirRollCall[$key]}"; done
+    #for key in "${!dirRollCall[@]}"; do echo "DEBUG :$key => ${dirRollCall[$key]}"; done
     for key in "${!dirRollCall[@]}"; do
        value="${dirRollCall[$key]}";
        if [ "$value" = "false" ]; then
-           #echo "DEBUG:Missing dirs: $key => $value";
+           #echo "DEBUG :Missing dirs: $key => $value";
            missingDirs="$missingDirs""$key ";
            dirMissing="true";
        fi;
@@ -245,7 +245,7 @@ appendFileTar(){
 
     # Save function name
     fn="${FUNCNAME[0]}";
-    #yell "DEBUG:STATUS:$fn:Started appendFileTar()."
+    #yell "DEBUG :STATUS:$fn:Started appendFileTar()."
     
     # Set file name
     if ! [ -z "$2" ]; then fileName="$2"; else yell "ERROR:$fn:Not enough arguments."; exit 1; fi
@@ -264,7 +264,7 @@ appendFileTar(){
 
     # Append to tar
     try tar --append --directory="$tmpDir" --file="$tarPath" "$fileName";
-    #yell "DEBUG:STATUS:$fn:Finished appendFileTar()."
+    #yell "DEBUG :STATUS:$fn:Finished appendFileTar()."
 } # Append [processed] file to Tar archive
 checkAgePubkey() {
     # Desc: Checks if string is an age-compatible pubkey
@@ -355,6 +355,37 @@ dateShort(){
     dateCurrentShort="$(date -d "$timeInput" +%Y%m%d)"; # Produce separator-less current date with resolution 1 day.
     echo "$dateCurrentShort";
 } # Get YYYYmmdd
+dateTimeShort(){
+    # Desc: Timestamp without separators (YYYYmmddTHHMMSS+zzzz)
+    # Usage: dateTimeShort ([str date])
+    # Version 1.1.1
+    # Input: arg1: 'date'-parsable timestamp string (optional)
+    # Output: stdout: timestamp (ISO-8601, no separators)
+    # Depends: yell
+    local argTime timeCurrent timeInput timeCurrentShort
+
+    argTime="$1";
+    # Get Current Time
+    timeCurrent="$(date --iso-8601=seconds)" ; # Produce `date`-parsable current timestamp with resolution of 1 second.
+    # Decide to parse current or supplied date
+    ## Check if time argument empty
+    if [[ -z "$argTime" ]]; then
+       ## T: Time argument empty, use current time
+       timeInput="$timeCurrent";
+    else
+       ## F: Time argument exists, validate time
+       if date --date="$argTime" 1>/dev/null 2>&1; then
+           ### T: Time argument is valid; use it
+           timeInput="$argTime";
+       else
+           ### F: Time argument not valid; exit
+           yell "ERROR:Invalid time argument supplied. Exiting."; exit 1;
+       fi
+    fi
+    # Construct and deliver separator-les date string
+    timeCurrentShort="$(date -d "$timeInput" +%Y%m%dT%H%M%S%z)";
+    echo "$timeCurrentShort";
+} # Get YYYYmmddTHHMMSS±zzzz
 setTimeZoneEV(){
     # Desc: Set time zone environment variable TZ
     # Usage: setTimeZoneEV arg1
@@ -795,13 +826,17 @@ magicInitWorkingDir() {
     # Depends: bash 5.0.3, processArguments(), vbm(), yell()
     # Parse '-t' option (user-specified temporary working dir)
     ## Set dir_tmp_parent to user-specified value if specified
-    local dir_tmp_parent
+    local fn dir_tmp_parent
+
+    # Save function name
+    fn="${FUNCNAME[0]}";
     
+    vbm "STATUS:$fn:Starting magicInitWorkingDir() function.";
     if [[ "$optionTmpDir" = "true" ]]; then
        if [[ -d "$argTempDirPriority" ]]; then
            dir_tmp_parent="$argTempDirPriority"; 
        else
-           yell "WARNING:Specified temporary working directory not valid:$argTempDirPriority";
+           yell "WARNING:$fn:Specified temporary working directory not valid:$argTempDirPriority";
            exit 1; # Exit since user requires a specific temp dir and it is not available.
        fi;
     else
@@ -809,15 +844,16 @@ magicInitWorkingDir() {
        if [[ -d "$dirTmpDefault" ]]; then
            dir_tmp_parent="$dirTmpDefault";
        elif [[ -d /tmp ]]; then
-           yell "WARNING:$dirTmpDefault not available. Falling back to /tmp .";
+           yell "WARNING:$fn:$dirTmpDefault not available. Falling back to /tmp .";
            dir_tmp_parent="/tmp";
        else
-           yell "ERROR:No valid working directory available. Exiting.";
+           yell "ERROR:$fn:No valid working directory available. Exiting.";
            exit 1;
        fi;
     fi;
     ## Set dir_tmp using dir_tmp_parent and nonce (scriptTimeStart)
-    dir_tmp="$dir_tmp_parent"/"$scriptTimeStart""..bkgpslog" && vbm "DEBUG:Set dir_tmp to:$dir_tmp"; # Note: removed at end of main().
+    dir_tmp="$dir_tmp_parent"/"$scriptTimeStart""..bkgpslog" && vbm "DEBUG :$fn:Set dir_tmp to:$dir_tmp"; # Note: removed at end of main().
+    vbm "STATUS:$fn:Finished magicInitWorkingDir() function.";
 } # Sets working dir
 magicInitCheckTar() {
     # Desc: Initializes or checks output tar
@@ -825,33 +861,46 @@ magicInitCheckTar() {
     # input: vars: scriptHostname
     # output: vars: pathout_tar
     # depends: Bash 5.0.3, vbm(), dateShort(), checkMakeTar(), magicWriteVersion()
+    local fn
 
+    # Save function name
+    fn="${FUNCNAME[0]}";    
+    
+    vbm "STATUS:$fn:Starting magicInitCheckTar() function.";
     # Form pathout_tar
     pathout_tar="$dirOut"/"$(dateShort "$(date --date="$bufferTTL seconds ago" --iso-8601=seconds)")".."$scriptHostname""$label""$cmd_compress_suffix""$cmd_encrypt_suffix".tar && \
-       vbm "STATUS:Set pathout_tar to:$pathout_tar";
+       vbm "STATUS:$fn:Set pathout_tar to:$pathout_tar";
     # Validate pathout_tar as tar.
     checkMakeTar "$pathout_tar";
     ## Add VERSION file if checkMakeTar had to create a tar (exited 1) or replace one (exited 2)
-    vbm "exit status before magicWriteVersion:$?"
-    if [[ $? -eq 1 ]] || [[ $? -eq 2 ]]; then magicWriteVersion; fi    
+    vbm "STATUS:$fn:exit status before magicWriteVersion:$?"
+    if [[ $? -eq 1 ]] || [[ $? -eq 2 ]]; then magicWriteVersion; fi
+    vbm "STATUS:$fn:Finished magicInitCheckTar() function.";
 } # Initialize tar, set pathout_tar
 magicParseCompressionArg() {
     # Desc: Parses compression arguments specified by '-c' option
     # Input:  vars: optionCompress
     # Output: cmd_compress, cmd_compress_suffix
     # Depends: processArguments(), vbm(), checkapp(), gzip 1.9
+    local fn
+
+    # Save function name
+    fn="${FUNCNAME[0]}";    
+    
+    vbm "STATUS:$fn:Starting magicParseCompressionArg() function.";
     if [[ "$optionCompress" = "true" ]]; then # Check if compression option active
        if checkapp gzip; then # Check if gzip available
-           cmd_compress="gzip " && vbm "cmd_compress:$cmd_compress";
-           cmd_compress_suffix=".gz" && vbm "cmd_compress_suffix:$cmd_compress_suffix";
+           cmd_compress="gzip " && vbm "STATUS:$fn:cmd_compress:$cmd_compress";
+           cmd_compress_suffix=".gz" && vbm "STATUS:$fn:cmd_compress_suffix:$cmd_compress_suffix";
        else
-           yell "ERROR:Compression enabled but \"gzip\" not found. Exiting."; exit 1;
-       fi
+           yell "ERROR:$fn:Compression enabled but \"gzip\" not found. Exiting."; exit 1;
+       fi;
     else
-       cmd_compress="tee /dev/null " && vbm "cmd_compress:$cmd_compress";
-       cmd_compress_suffix="" && vbm "cmd_compress_suffix:$cmd_compress_suffix";
-       vbm "DEBUG:Compression not enabled.";
-    fi    
+       cmd_compress="tee /dev/null " && vbm "STATUS:$fn:cmd_compress:$cmd_compress";
+       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.";
 } # Form compression cmd string and filename suffix
 magicParseCustomTTL() {
     # Desc: Set user-specified TTLs for buffer and script
@@ -861,16 +910,21 @@ magicParseCustomTTL() {
     # Input: vars: bufferTTL (integer), scriptTTL_TE (string)
     # Output: bufferTTL (integer), scriptTTL_TE (string)
     # Depends: Bash 5.0.3, yell(), vbm(), validateInput(), showUsage()
+    local fn
+
+    # Save function name
+    fn="${FUNCNAME[0]}";    
 
+    vbm "STATUS:$fn:Starting magicParseCustomTTL() function.";
     # React to '-b, --buffer-ttl' option
     if [[ "$optionCustomBufferTTL" = "true" ]]; then
        ## T: Check if argCustomBufferTTL is an integer
        if validateInput "$argCustomBufferTTL" "integer"; then
            ### T: argCustomBufferTTL is an integer
-           bufferTTL="$argCustomBufferTTL" && vbm "Custom bufferTTL from -b:$bufferTTL";
+           bufferTTL="$argCustomBufferTTL" && vbm "STATUS:$fn:Custom bufferTTL from -b:$bufferTTL";
        else
            ### F: argcustomBufferTTL is not an integer
-           yell "ERROR:Invalid integer argument for custom buffer time-to-live."; showUsage; exit 1;
+           yell "ERROR:$fn:Invalid integer argument for custom buffer time-to-live."; showUsage; exit 1;
        fi;
        ## F: do not change bufferTTL
     fi;
@@ -880,32 +934,37 @@ magicParseCustomTTL() {
        ## T: Check if argCustomScriptTTL is a time element (ex: "day", "hour")
        if validateInput "$argCustomScriptTTL_TE" "time_element"; then
            ### T: argCustomScriptTTL is a time element
-           scriptTTL_TE="$argCustomScriptTTL_TE" && vbm "Custom scriptTTL_TE from -B:$scriptTTL_TE";
+           scriptTTL_TE="$argCustomScriptTTL_TE" && vbm "STATUS:$fn:Custom scriptTTL_TE from -B:$scriptTTL_TE";
        else
            ### F: argcustomScriptTTL is not a time element
-           yell "ERROR:Invalid time element argument for custom script time-to-live."; showUsage; exit 1;
+           yell "ERROR:$fn:Invalid time element argument for custom script time-to-live."; showUsage; exit 1;
        fi;
        ## F: do not change scriptTTL_TE
-    fi;    
+    fi;
+    vbm "STATUS:$fn:Starting magicParseCustomTTL() function.";
 } # Sets custom script or buffer TTL if specified
 magicParseLabel() {
     # Desc: Parses -l option to set label
     # In : optionLabel, argLabel
     # Out: vars: label
     # Depends: Bash 5.0.3, vbm(), yell()
+    local fn
+    
+    # Save function name
+    fn="${FUNCNAME[0]}";
     
-    vbm "STATUS:Started magicParseLabel() function.";
+    vbm "STATUS:$fn:Started magicParseLabel() function.";
     # Do nothing if optionLabel not set to true.
     if [[ ! "$optionLabel" = "true" ]]; then
-       vbm "STATUS:optionlabel not set to 'true'. Returning early.";
+       vbm "STATUS:$fn:optionlabel not set to 'true'. Returning early.";
        return;
     fi;
     # Set label if optionLabel is true
     if [[ "$optionLabel" = "true" ]]; then
        label="_""$argLabel";
-       vbm "STATUS:Set label:$label";
+       vbm "STATUS:$fn:Set label:$label";
     fi;
-    vbm "STATUS:Finished magicParseLabel() function.";
+    vbm "STATUS:$fn:Finished magicParseLabel() function.";
 } # Set label used in output file name
 magicParseProcessStrings() {
     # Desc: Processes user-supplied process strings into process commands for appendFileTar().
@@ -914,15 +973,18 @@ magicParseProcessStrings() {
     #      arry: argProcStrings, argProcFileExts
     # Out: arry: procStrings, procFileExts
     # Depends Bash 5.0.3, yell(), vbm()
-    local rawFileExt
-
-    vbm "STATUS:Starting magicParseProcessStrings() function.";
-    vbm "var:optionProcString:$optionProcString";
-    vbm "var:optionNoStoreRaw:$optionNoStoreRaw";
-    vbm "var:optionStoreRaw:$optionStoreRaw";
-    vbm "var:argRawFileExt:$argRawFileExt";
-    vbm "ary:argProcStrings:${argProcStrings[*]}";
-    vbm "ary:argProcFileExts:${argProcFileExts[*]}"
+    local fn rawFileExt
+
+    # Save function name
+    fn="${FUNCNAME[0]}";    
+    
+    vbm "STATUS:$fn:Starting magicParseProcessStrings() function.";
+    vbm "STATUS:$fn:var:optionProcString:$optionProcString";
+    vbm "STATUS:$fn:var:optionNoStoreRaw:$optionNoStoreRaw";
+    vbm "STATUS:$fn:var:optionStoreRaw:$optionStoreRaw";
+    vbm "STATUS:$fn:var:argRawFileExt:$argRawFileExt";
+    vbm "STATUS:$fn:ary:argProcStrings:${argProcStrings[*]}";
+    vbm "STATUS:$fn:ary:argProcFileExts:${argProcFileExts[*]}"
     # Validate input
     ## Validate argRawFileExt
     if [[ "$argRawFileExt" =~ ^[.][[:alnum:]]*$ ]]; then
@@ -952,27 +1014,27 @@ magicParseProcessStrings() {
 
     # Do nothing more if optionProcString not set to true.
     if [[ ! "$optionProcString" = "true" ]]; then
-       vbm "STATUS:optionProcString not set to 'true'. Returning early.";
+       vbm "STATUS:$fn:optionProcString not set to 'true'. Returning early.";
        return; fi;
     # Validate input array indices
     ## Make sure that argProcStrings and argProcFileExts have same index counts
     if ! [[ "${#argProcStrings[@]}" -eq "${#argProcFileExts[@]}" ]]; then
-       yell "ERROR:Mismatch in number of elements in arrays argProcStrings and argProcFileExts:${#argProcStrings[@]} DNE ${#argProcFileExts[@]}";
-       yell "argProcStrings:${argProcStrings[*]}"; yell "argProcFileExts:${argProcFileExts[*]}"; exit 1; fi;
+       yell "ERROR:$fn:Mismatch in number of elements in arrays argProcStrings and argProcFileExts:${#argProcStrings[@]} DNE ${#argProcFileExts[@]}";
+       yell "STATUS:$fn:argProcStrings:${argProcStrings[*]}"; yell "STATUS:$fn:argProcFileExts:${argProcFileExts[*]}"; exit 1; fi;
     ## Make sure that no array elements are blank
     for element in "${argProcStrings[@]}"; do
-       if [[ -z "$element" ]]; then yell "ERROR:Empty process string specified. Exiting."; exit 1; fi; done
+       if [[ -z "$element" ]]; then yell "ERROR:$fn:Empty process string specified. Exiting."; exit 1; fi; done
     for element in "${argProcFileExts[@]}"; do
-       if [[ -z "$element" ]]; then yell "ERROR:Empty output file extension specified. Exiting."; exit 1; fi; done
+       if [[ -z "$element" ]]; then yell "ERROR:$fn:Empty output file extension specified. Exiting."; exit 1; fi; done
     ## Make sure that no process string starts with '-' (ex: if only one arg supplied after '-p' option)
     for element in "${argProcStrings[@]}"; do
        if [[ "$element" =~ ^[-][[:print:]]*$ ]] && [[ ! "$element" =~ ^[[:print:]]*$ ]]; then
-           yell "ERROR:Illegal character '-' at start of process string element:\"$element\"";
+           yell "ERROR:$fn:Illegal character '-' at start of process string element:\"$element\"";
            exit 1; fi; done;
-    vbm "STATUS:Quick check shows argProcStrings and argProcFileExts appear to have valid contents.";
+    vbm "STATUS:$fn:Quick check shows argProcStrings and argProcFileExts appear to have valid contents.";
     procStrings=("${argProcStrings[@]}"); # Export process command strings
     procFileExts=("${argProcFileExts[@]}"); # Export process command strings
-    vbm "STATUS:Finished magicParseProcessStrings() function.";
+    vbm "STATUS:$fn:Finished magicParseProcessStrings() function.";
 } # Validate and save process strings and file extensions to arrays procStrings, procFileExts
 magicParseRecipientArgs() {
     # Desc: Parses recipient arguments specified by '-r' option
@@ -981,46 +1043,51 @@ magicParseRecipientArgs() {
     # Output: vars: cmd_encrypt, cmd_encrypt_suffix
     #         arry: recPubKeysValid, recPubKeysValidStatic
     # Depends: processArguments(), yell(), vbm(), checkapp(), checkAgePubkey(), validateInput()
-    local recipients
+    local fn recipients
 
+    # Save function name
+    fn="${FUNCNAME[0]}";
+    
+    vbm "STATUS:$fn:Starting magicParseRecipientArgs() function.";
     # Check if encryption option active.
     if [[ "$optionEncrypt" = "true" ]] && [[ "$optionRecipients" = "true" ]]; then 
        if checkapp age; then # Check that age is available.
            for pubkey in "${argRecPubKeys[@]}"; do # Validate recipient pubkey strings by forming test message
-               vbm "DEBUG:Testing pubkey string:$pubkey";
+               vbm "DEBUG :$fn:Testing pubkey string:$pubkey";
                if checkAgePubkey "$pubkey" && \
                        ( validateInput "$pubkey" "ssh_pubkey" || validateInput "$pubkey" "age_pubkey"); then
                    #### Form age recipient string
                    recipients="$recipients""-r '$pubkey' ";
-                   vbm "STATUS:Added pubkey for forming age recipient string:""$pubkey";
-                   vbm "DEBUG:recipients:""$recipients";
+                   vbm "STATUS:$fn:Added pubkey for forming age recipient string:""$pubkey";
+                   vbm "DEBUG :$fn:recipients:""$recipients";
                    #### Add validated pubkey to recPubKeysValid array
-                   recPubKeysValid+=("$pubkey") && vbm "DEBUG:recPubkeysValid:pubkey added:$pubkey";
+                   recPubKeysValid+=("$pubkey") && vbm "DEBUG :$fn:recPubkeysValid:pubkey added:$pubkey";
                else
-                   yell "ERROR:Exit code ""$?"". Invalid recipient pubkey string. Exiting."; exit 1;
+                   yell "ERROR:$fn:Exit code ""$?"". Invalid recipient pubkey string. Exiting."; exit 1;
                fi;
            done
-           vbm "DEBUG:Finished processing argRecPubKeys array";
-           vbm "STATUS:Array of validated pubkeys:${recPubKeysValid[*]}";
+           vbm "DEBUG :$fn:Finished processing argRecPubKeys array";
+           vbm "STATUS:$fn:Array of validated pubkeys:${recPubKeysValid[*]}";
            recPubKeysValidStatic=("${recPubKeysValid[@]}"); # Save static image of pubkeys validated by this function
 
            ##  Form age command string
-           cmd_encrypt="age ""$recipients " && vbm "cmd_encrypt:$cmd_encrypt";
-           cmd_encrypt_suffix=".age" && vbm "cmd_encrypt_suffix:$cmd_encrypt_suffix";
+           cmd_encrypt="age ""$recipients " && vbm "STATUS:$fn:cmd_encrypt:$cmd_encrypt";
+           cmd_encrypt_suffix=".age" && vbm "STATUS:$fn:cmd_encrypt_suffix:$cmd_encrypt_suffix";
        else
-           yell "ERROR:Encryption enabled but \"age\" not found. Exiting."; exit 1;
+           yell "ERROR:$fn:Encryption enabled but \"age\" not found. Exiting."; exit 1;
        fi;
     else
-       cmd_encrypt="tee /dev/null " && vbm "cmd_encrypt:$cmd_encrypt";
-       cmd_encrypt_suffix="" && vbm "cmd_encrypt_suffix:$cmd_encrypt_suffix";
-       vbm "DEBUG:Encryption not enabled."
+       cmd_encrypt="tee /dev/null " && vbm "STATUS:$fn:cmd_encrypt:$cmd_encrypt";
+       cmd_encrypt_suffix="" && vbm "STATUS:$fn:cmd_encrypt_suffix:$cmd_encrypt_suffix";
+       vbm "DEBUG :$fn:Encryption not enabled."
     fi;
     # Catch case if '-e' is set but '-r' or '-R' is not
     if [[ "$optionEncrypt" = "true" ]] && [[ ! "$optionRecipients" = "true" ]]; then
-       yell "ERROR:\\'-e\\' set but no \\'-r\\' or \\'-R\\' set."; exit 1; fi;
+       yell "ERROR:$fn:\\'-e\\' set but no \\'-r\\' or \\'-R\\' set."; exit 1; fi;
     # Catch case if '-r' or '-R' set but '-e' is not
     if [[ ! "$optionEncrypt" = "true" ]] && [[ "$optionRecipients" = "true" ]]; then
-       yell "ERROR:\\'-r\\' or \\'-R\\' set but \\'-e\\' is not set."; exit 1; fi; 
+       yell "ERROR:$fn:\\'-r\\' or \\'-R\\' set but \\'-e\\' is not set."; exit 1; fi;
+    vbm "STATUS:$fn:Finished magicParseRecipientArgs() function.";
 } # Populate recPubKeysValid with argRecPubKeys; form encryption cmd string and filename suffix
 magicParseRecipientDir() {
     # Desc: Updates recPubKeysValid with pubkeys in dir specified by '-R' option ("recipient directory")
@@ -1028,14 +1095,18 @@ magicParseRecipientDir() {
     #          arry: recPubKeysValid
     # Outputs: arry: recPubKeysValid
     # Depends: processArguments(), yell(), vbm(), validateInput(),  checkAgePubkey()
-    local recipientDir recFileLine updateRecipients 
+    local fn recipientDir recFileLine updateRecipients 
     declare -a candRecPubKeysValid
 
+    # Save function name
+    fn="${FUNCNAME[0]}";
+    
+    vbm "STATUS:$fn:Starting magicParseRecipientDir() function.";
     # Check that '-e' and '-R' set
     if [[ "$optionEncrypt" = "true" ]] && [[ "$optionRecDir" = "true" ]]; then
        ### Check that argRecDir is a directory.
        if [[ -d "$argRecDir" ]]; then
-           recipientDir="$argRecDir" && vbm "STATUS:Recipient watch directory detected:\"$recipientDir\"";
+           recipientDir="$argRecDir" && vbm "STATUS:$fn:Recipient watch directory detected:\"$recipientDir\"";
            #### Initialize variable indicating outcome of pubkey review
            unset updateRecipients
            #### Add existing recipients
@@ -1043,29 +1114,30 @@ magicParseRecipientDir() {
            #### Parse files in recipientDir
            for file in "$recipientDir"/*; do
                ##### Read first line of each file
-               recFileLine="$(head -n1 "$file")" && vbm "STATUS:Checking if pubkey:\"$recFileLine\"";
+               recFileLine="$(head -n1 "$file")" && vbm "STATUS:$fn:Checking if pubkey:\"$recFileLine\"";
                ##### check if first line is a valid pubkey
                if checkAgePubkey "$recFileLine" && \
                        ( validateInput "$recFileLine" "ssh_pubkey" || validateInput "$recFileLine" "age_pubkey"); then
                    ###### T: add candidate pubkey to candRecPubKeysValid
-                   candRecPubKeysValid+=("$recFileLine") && vbm "STATUS:RecDir pubkey is valid pubkey:\"$recFileLine\"";
+                   candRecPubKeysValid+=("$recFileLine") && vbm "STATUS:$fn:RecDir pubkey is valid pubkey:\"$recFileLine\"";
                else
                    ###### F: throw warning;
-                   yell "ERROR:Invalid recipient file detected. Not modifying recipient list."
+                   yell "ERROR:$fn:Invalid recipient file detected. Not modifying recipient list."
                    updateRecipients="false";
                fi;
            done
            #### Write updated recPubKeysValid array to recPubKeysValid if no failure detected
            if ! [[ "$updateRecipients" = "false" ]]; then
-               recPubKeysValid=("${candRecPubKeysValid[@]}") && vbm "STATUS:Wrote candRecPubkeysValid to recPubKeysValid:\"${recPubKeysValid[*]}\"";
+               recPubKeysValid=("${candRecPubKeysValid[@]}") && vbm "STATUS:$fn:Wrote candRecPubkeysValid to recPubKeysValid:\"${recPubKeysValid[*]}\"";
            fi;
        else
-           yell "ERROR:$0:Recipient directory $argRecDir does not exist. Exiting."; exit 1;
+           yell "ERROR:$fn:Recipient directory $argRecDir does not exist. Exiting."; exit 1;
        fi;
     fi;
     # Handle case if '-R' set but '-e' not set
     if [[ ! "$optionEncrypt" = "true" ]] && [[ "$optionRecDir" = "true" ]]; then
-       yell "ERROR: \\'-R\\' is set but \\'-e\\' is not set."; fi;
+       yell "ERROR:$fn: \\'-R\\' is set but \\'-e\\' is not set."; fi;
+    vbm "STATUS:$fn:Finished magicParseRecipientDir() function.";
 } # Update recPubKeysValid with argRecDir
 magicSetScriptTTL() {
     #Desc: Sets script_TTL seconds from provided time_element string argument
@@ -1073,8 +1145,12 @@ magicSetScriptTTL() {
     #Input: arg1: string (Ex: scriptTTL_TE; "day" or "hour")
     #Output: var: scriptTTL (integer seconds)
     #Depends: timeUntilNextHour, timeUntilNextDay
-    local argTimeElement
+    local fn argTimeElement
+
+    # Save function name
+    fn="${FUNCNAME[0]}";
     
+    vbm "STATUS:$fn:Starting magicSetScriptTTL() function.";
     argTimeElement="$1";
     if [[ "$argTimeElement" = "day" ]]; then
            # Set script lifespan to end at start of next day
@@ -1082,7 +1158,7 @@ magicSetScriptTTL() {
            if [[ "$scriptTTL" -eq 0 ]]; then
            ((scriptTTL++)); # Add 1 because 0 would cause 'timeout' to never timeout.
            else
-           yell "ERROR: timeUntilNextDay exit code $?"; exit 1;
+           yell "ERROR:$fn:timeUntilNextDay exit code $?"; exit 1;
            fi;
        fi;
     elif [[ "$argTimeElement" = "hour" ]]; then
@@ -1091,12 +1167,13 @@ magicSetScriptTTL() {
            if [[ "$scriptTTL" -eq 0 ]]; then
                ((scriptTTL++)); # Add 1 because 0 would cause 'timeout' to never timeout.
            else
-               yell "ERROR: timeUntilNextHour exit code $?"; exit 1;
+               yell "ERROR:$fn:timeUntilNextHour exit code $?"; exit 1;
            fi;
        fi;
     else
-       yell "ERROR:Invalid argument for setScriptTTL function:$argTimeElement"; exit 1;
+       yell "ERROR:$fn:Invalid argument for setScriptTTL function:$argTimeElement"; exit 1;
     fi;
+    vbm "STATUS:$fn:Finished magicSetScriptTTL() function.";
 } # Set scriptTTL in seconds until next (day|hour).
 magicWriteVersion() {
     # Desc: Appends time-stamped VERSION to pathout_tar
@@ -1106,8 +1183,12 @@ magicWriteVersion() {
     # Input: array: recPubKeysValid
     # Output: appends tar (pathout_tar)
     # Depends: bash 5.0.3, dateTimeShort(), appendArgTar()
-    local fileoutVersion contentVersion pubKeyIndex pubKeyIndex
+    local fn fileoutVersion contentVersion pubKeyIndex pubKeyIndex
+
+    # Save function name
+    fn="${FUNCNAME[0]}";
     
+    vbm "STATUS:$fn:Starting magicWriteVersion() function.";
     # Set VERSION file name
     fileoutVersion="$(dateTimeShort)..VERSION";
 
@@ -1129,7 +1210,9 @@ magicWriteVersion() {
     contentVersion="$(echo -e "$contentVersion")"
 
     # Write contentVersion as file fileoutVersion and write-append to pathout_tar
-    appendArgTar "$contentVersion" "$fileoutVersion" "$pathout_tar" "$dir_tmp";
+    appendArgTar "$contentVersion" "$fileoutVersion" "$pathout_tar" "$dir_tmp" && \
+       vbm "STATUS:$fn:Appended $fileoutVersion to $pathout_tar";
+    vbm "STATUS:$fn:Finished magicWriteVersion() function.";
 } # write version data to pathout_tar via appendArgTar()
 magicProcessWriteBuffer() {
     # Desc: process and write buffer
@@ -1144,28 +1227,28 @@ magicProcessWriteBuffer() {
     local -a fileouts pathouts
     local writeCmd1 writeCmd2 writeCmd3 writeCmd4
 
-    vbm "DEBUG:STATUS:$fn:Started magicProcessWriteBuffer().";
     # Debug:Get function name
     fn="${FUNCNAME[0]}";
-
+    
+    vbm "STATUS:$fn:Started magicProcessWriteBuffer().";
     # Determine file paths (time is start of buffer period)
     ## Calculate start time
     timeBufferStartLong="$(date --date="$bufferTTL seconds ago" --iso-8601=seconds)" && \
-       vbm "timeBufferStartLong:$timeBufferStartLong";
+       vbm "DEBUG :$fn:timeBufferStartLong:$timeBufferStartLong";
     timeBufferStart="$(dateTimeShort "$timeBufferStartLong" )" && \
-       vbm "timeBufferStart:$timeBufferStart"; # Note start time YYYYmmddTHHMMSS+zzzz (no separators)
+       vbm "DEBUG :$fn:timeBufferStart:$timeBufferStart"; # Note start time YYYYmmddTHHMMSS+zzzz (no separators)
     ## Set common basename
     fileoutBasename="$timeBufferStart""--""$bufferTTL_STR""..""$scriptHostname""$label" && \
-       vbm "STATUS:Set fileoutBasename to:$fileoutBasename";
+       vbm "STATUS:$fn:Set fileoutBasename to:$fileoutBasename";
     ## Determine output file name array
     ### in: fileOutBasename cmd_compress_suffix cmd_encrypt_suffix procFileExts
     for fileExt in "${procFileExts[@]}"; do
        fileouts+=("$fileoutBasename""$fileExt""$cmd_compress_suffix""$cmd_encrypt_suffix") && \
-           vbm "STATUS:Added $fileExt to fileouts:${fileouts[*]}";
+           vbm "STATUS:$fn:Added $fileExt to fileouts:${fileouts[*]}";
     done;
     for fileName in "${fileouts[@]}"; do
        pathouts+=("$dir_tmp"/"$fileName") && \
-           vbm "STATUS:Added $fileName to pathouts:${pathouts[*]}";
+           vbm "STATUS:$fn:Added $fileName to pathouts:${pathouts[*]}";
     done;
     ## Update pathout_tar
     magicInitCheckTar;
@@ -1179,25 +1262,38 @@ magicProcessWriteBuffer() {
     
     ## Process buffer and write to dir_tmp
     for index in "${!pathouts[@]}"; do
-       writeCmd2="${procStrings[$index]}"
-       eval "$writeCmd1 | $writeCmd2 | $writeCmd3 | $writeCmd4" >> "${pathouts[$index]}";
+       writeCmd2="${procStrings[$index]}";
+       writeCmdAll="$writeCmd1 | $writeCmd2 | $writeCmd3 | $writeCmd4" && vbm "STATUS:$fn:Assembled command:\"$writeCmdAll\"";
+       eval "$writeCmdAll" >> "${pathouts[$index]}" && vbm "STATUS:$fn:Wrote command output to ${pathouts[$index]}";
     done;
     
     # 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";
+       appendFileTar "${pathouts[$index]}" "${fileouts[$index]}" "$pathout_tar" "$dir_tmp" && \
+           vbm "STATUS:$fn:Appended ${pathouts[$index]} to $pathout_tar";
     done;
     
     # Remove secured chunks from dir_tmp
     for path in "${pathouts[@]}"; do
-       rm "$path";
+       rm "$path" && vbm "STATUS:$fn:Removed:$path";
     done;
     
-    vbm "DEBUG:STATUS:$fn:Finished magicProcessWriteBuffer().";
+    vbm "STATUS:$fn:Finished magicProcessWriteBuffer().";
 } # Process and Write buffer
 
 main() {
+    # Desc: Main function
+    # Usage: main "$@"
+    # Inputs: many
+    # Outputs: file (pathout_tar)
+    # Depends: many
+    local fn
+
+    # Debug:Get function name
+    fn="${FUNCNAME[0]}";
+
+    vbm "STATUS:$fn:Started function main().";
     # Process arguments
     processArguments "$@";
     ## Determine working directory
@@ -1220,33 +1316,31 @@ main() {
     ## Set script lifespan (scriptTTL from scriptTTL_TE)
     magicSetScriptTTL "$scriptTTL_TE";
     ## File name substring (ISO-8601 duration from bufferTTL)
-    bufferTTL_STR="$(timeDuration "$bufferTTL")" && vbm "DEBUG:bufferTTL_STR:$bufferTTL_STR";
+    bufferTTL_STR="$(timeDuration "$bufferTTL")" && vbm "DEBUG :$fn:bufferTTL_STR:$bufferTTL_STR";
     ## Init temp working dir
-    try mkdir "$dir_tmp" && vbm "DEBUG:Working dir created at dir_tmp:$dir_tmp";
+    try mkdir "$dir_tmp" && vbm "DEBUG :$fn:Working dir created at dir_tmp:$dir_tmp";
     ## Initialize output tar (set pathout_tar)
     magicInitCheckTar; 
     
     # Check vital apps, files, dirs
     if ! checkapp tar && ! checkdir "$dirOut" "dir_tmp"; then
-       yell "ERROR:Critical components missing.";
+       yell "ERROR:$fn:Critical components missing.";
        displayMissing; yell "Exiting."; exit 1; fi
 
     # MAIN LOOP: Run until script TTL seconds pass
     bufferRound=0;
     while [[ $SECONDS -lt "scriptTTL" ]]; do
+       vbm "STATUS:$fn:Starting buffer round:$bufferRound";
        bufferTOD="$((SECONDS + bufferTTL))"; # Set buffer round time-of-death
-       lineCount=0; # Debug counter
        # 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");
-           vbm "DEBUG:Processing line:$lineCount";
-           vbm "DEBUG:Current line   :$line";
-           vbm "DEBUG:buf elem count :${#buffer[@]}";
-           ((lineCount++));
        done;
        # Create dir_tmp if missing
-       if ! [[ -d "$dir_tmp" ]]; then yell "ERROR:dir_tmp existence failure:$dir_tmp"; try mkdir "$dir_tmp" && vbm "DEBUG:Working dir recreated dir_tmp:$dir_tmp"; fi
+       if ! [[ -d "$dir_tmp" ]]; then
+           yell "ERROR:$fn:dir_tmp existence failure:$dir_tmp";
+           try mkdir "$dir_tmp" && vbm "DEBUG :$fn:Working dir recreated dir_tmp:$dir_tmp"; fi
        # Update encryption recipient array 
        magicParseRecipientDir; # Update recPubKeysValid with argRecDir
        # Export buffer to asynchronous processing.
@@ -1258,9 +1352,9 @@ main() {
 
     # Cleanup
     ## Remove dir_tmp
-    try rm -r "$dir_tmp" && vbm "Removed dir_tmp:$dir_tmp";
+    try rm -r "$dir_tmp" && vbm "STATUS:$fn:Removed dir_tmp:$dir_tmp";
 
-    vbm "STATUS:Main function finished.";
+    vbm "STATUS:$fn:Finished function main().";
 } # Main function
 
 #===END Declare local script functions===