Always log xtrace to file

Makefile

@@ -19,6 +19,7 @@ install:
 	install -m 0755 scripts/dts $(DESTDIR)$(SBINDIR)
 	install -m 0755 scripts/dts-boot $(DESTDIR)$(SBINDIR)
 	install -m 0755 scripts/ec_transition $(DESTDIR)$(SBINDIR)
+	install -m 0755 scripts/logging $(DESTDIR)$(SBINDIR)/logging
 
 	install -m 0755 reports/dasharo-hcl-report $(DESTDIR)$(SBINDIR)
 	install -m 0755 reports/touchpad-info $(DESTDIR)$(SBINDIR)

include/dts-environment.sh

@@ -50,8 +50,6 @@ SSH_OPT_UP="K"
 SSH_OPT_LOW="$(echo $SSH_OPT_UP | awk '{print tolower($0)}')"
 SEND_LOGS_OPT="L"
 SEND_LOGS_OPT_LOW="$(echo $SEND_LOGS_OPT | awk '{print tolower($0)}')"
-VERBOSE_OPT="V"
-VERBOSE_OPT_LOW="$(echo $VERBOSE_OPT | awk '{print tolower($0)}')"
 
 # Hardware variables:
 SYSTEM_VENDOR="$($DMIDECODE dump_var_mock -s system-manufacturer)"
@@ -89,7 +87,6 @@ FW_BACKUP_TAR="${FW_BACKUP_DIR}.tar.gz"
 FW_BACKUP_TAR="$(echo "$FW_BACKUP_TAR" | sed 's/\ /_/g')"
 
 # Paths to system files
-ERR_LOG_FILE="/var/local/dts-err.log"
 FLASHROM_LOG_FILE="/var/local/flashrom.log"
 FLASH_INFO_FILE="/tmp/flash_info"
 OS_VERSION_FILE="/etc/os-release"

include/dts-subscription.sh

@@ -39,22 +39,22 @@ check_for_dasharo_firmware() {
   # Check for firmware binaries:
   if wait_for_network_connection; then
     if [ -n "$BIOS_LINK_DPP" ]; then
-      _check_dwn_req_resp_uefi=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null -w "%{http_code}")
+      _check_dwn_req_resp_uefi=$(curl -L -I -s -S -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null -w "%{http_code}" 2>>"$ERR_LOG_FILE")
     fi
 
     if [ -n "$BIOS_LINK_DPP_CAP" ]; then
-      _check_dwn_req_resp_uefi_cap=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null -w "%{http_code}")
+      _check_dwn_req_resp_uefi_cap=$(curl -L -I -s -S -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null -w "%{http_code}" 2>>"$ERR_LOG_FILE")
     fi
 
     if [ -n "$HEADS_LINK_DPP" ]; then
-      _check_dwn_req_resp_heads=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null -w "%{http_code}")
+      _check_dwn_req_resp_heads=$(curl -L -I -s -S -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null -w "%{http_code}" 2>>"$ERR_LOG_FILE")
     fi
 
     if [ -n "$BIOS_LINK_DPP_SEABIOS" ]; then
-      _check_dwn_req_resp_seabios=$(curl -L -I -s -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null -w "%{http_code}")
+      _check_dwn_req_resp_seabios=$(curl -L -I -s -S -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null -w "%{http_code}" 2>>"$ERR_LOG_FILE")
     fi
 
-    _check_logs_req_resp=$(curl -L -I -s -f -H "$CLOUD_REQUEST" "$TEST_LOGS_URL" -o /dev/null -w "%{http_code}")
+    _check_logs_req_resp=$(curl -L -I -s -S -f -H "$CLOUD_REQUEST" "$TEST_LOGS_URL" -o /dev/null -w "%{http_code}" 2>>"$ERR_LOG_FILE")
 
     # Return 0 if any of Dasharo Firmware binaries is available:
     if [ ${_check_dwn_req_resp_uefi} -eq 200 ] || [ ${_check_dwn_req_resp_uefi_cap} -eq 200 ] || [ ${_check_dwn_req_resp_heads} -eq 200 ] || [ ${_check_dwn_req_resp_seabios} -eq 200 ]; then

include/hal/dts-hal.sh

@@ -144,7 +144,7 @@ tool_wrapper(){
 check_for_opensource_firmware()
 {
   echo "Checking for Open Source Embedded Controller firmware..."
-  $DASHARO_ECTOOL check_for_opensource_firm_mock info > /dev/null 2>&1
+  $DASHARO_ECTOOL check_for_opensource_firm_mock info > /dev/null 2>>"$ERR_LOG_FILE"
 
   return $?
 }
@@ -190,7 +190,7 @@ check_me_op_mode(){
 # Checks ME Current Operation Mode at offset 0x40 bits 19:16:
   local _mode
 
-  _mode="$($SETPCI check_me_op_mode_mock -s 00:16.0 42.B 2> /dev/null | cut -c2-)"
+  _mode="$($SETPCI check_me_op_mode_mock -s 00:16.0 42.B 2>>"$ERR_LOG_FILE" | cut -c2-)"
 
   echo "$_mode"
 

reports/dasharo-hcl-report

@@ -219,10 +219,10 @@ printf '####################################                               |\r'
 
 # echo "Decompiling ACPI tables..."
 mkdir -p logs/acpi
-if pushd logs/acpi &> /dev/null; then
-  acpixtract -a ../acpidump.log &>/dev/null
-  iasl -d ./*.dat &>/dev/null
-  popd &> /dev/null || return 1
+if pushd logs/acpi >/dev/null 2>>"$ERR_LOG_FILE"; then
+  acpixtract -a ../acpidump.log >/dev/null 2>>"$ERR_LOG_FILE"
+  iasl -d ./*.dat >/dev/null 2>>"$ERR_LOG_FILE"
+  popd >/dev/null 2>>"$ERR_LOG_FILE" || return 1
 fi
 update_result "ACPI tables" 0 UNKNOWN
 printf '######################################                             |\r'
@@ -325,7 +325,7 @@ fi
 # warning:
 # shellcheck disable=SC2046
 MAC_ADDR=`cat /sys/class/net/$(ip route show default | head -1 | awk '/default/ {print $5}')/address`
-grep -rl "${MAC_ADDR}" logs > /dev/null && grep -rl "${MAC_ADDR}" logs | xargs sed -i 's/'${MAC_ADDR}'/MAC ADDRESS REMOVED/g'
+grep -rl "${MAC_ADDR}" logs >/dev/null && grep -rl "${MAC_ADDR}" logs | xargs sed -i 's/'${MAC_ADDR}'/MAC ADDRESS REMOVED/g'
 tar -zcf "$filename.tar.gz" logs/*
 rm -rf logs
 

scripts/cloud_list

@@ -30,7 +30,7 @@ CLOUD_REQUEST="X-Requested-With: XMLHttpRequest"
 
 tmpURL="https://cloud.3mdeb.com/public.php/webdav/"
 
-curl -L -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" -X PROPFIND "$tmpURL" -o "$TMP_RESPONSE"
+curl -L -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" -X PROPFIND "$tmpURL" -o "$TMP_RESPONSE" 2>>"$ERR_LOG_FILE"
 error_check "Cannot access list of files on cloud."
 
 # parse response
@@ -53,7 +53,7 @@ HCL_REPORT_NAME=$(cat $TMP_LIST | grep -m1 $HW_UUID)
 
 # download HCL report
 tmpURL="https://cloud.3mdeb.com/public.php/webdav/$HCL_REPORT_NAME"
-curl -L -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" -X GET "$tmpURL" -o /$HCL_REPORT_NAME
+curl -L -f -u "$USER_DETAILS" -H "$CLOUD_REQUEST" -X GET "$tmpURL" -o /$HCL_REPORT_NAME 2>>"$ERR_LOG_FILE"
 if [ -f /$HCL_REPORT_NAME ]; then
   echo "Report downloaded"
 else

scripts/dasharo-deploy

@@ -80,31 +80,31 @@ check_for_firmware_access() {
       # This firmware type require user to provide creds:
       [ "$DPP_IS_LOGGED" == "true" ] || return 1
 
-      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null
+      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP" -o /dev/null 2>>"$ERR_LOG_FILE"
 
       [ $? -ne 0 ] && return 1
       ;;
     dpp_cap)
       # This firmware type require user to provide creds:
       [ "$DPP_IS_LOGGED" == "true" ] || return 1
 
-      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null
+      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_CAP" -o /dev/null 2>>"$ERR_LOG_FILE"
 
       [ $? -ne 0 ] && return 1
       ;;
     seabios)
       # This firmware type require user to provide creds:
       [ "$DPP_IS_LOGGED" == "true" ] || return 1
 
-      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null
+      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$BIOS_LINK_DPP_SEABIOS" -o /dev/null 2>>"$ERR_LOG_FILE"
 
       [ $? -ne 0 ] && return 1
       ;;
     heads)
       # This firmware type require user to provide creds:
       [ "$DPP_IS_LOGGED" == "true" ] || return 1
 
-      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null
+      curl -sfI -u "$USER_DETAILS" -H "$CLOUD_REQUEST" "$HEADS_LINK_DPP" -o /dev/null 2>>"$ERR_LOG_FILE"
 
       [ $? -ne 0 ] && return 1
       ;;
@@ -511,16 +511,16 @@ romhole_migration() {
     if check_if_dasharo; then
       $CBFSTOOL layout_mock /tmp/rom.bin layout -w | grep -q "ROMHOLE" || return
       # This one is rather unlikely to fail, but just in case print a warning
-      $CBFSTOOL read_romhole_mock /tmp/rom.bin read -r ROMHOLE -f /tmp/romhole.bin 2> /dev/null
+      $CBFSTOOL read_romhole_mock /tmp/rom.bin read -r ROMHOLE -f /tmp/romhole.bin 2>>"$ERR_LOG_FILE"
       if [ $? -ne 0 ]; then
         print_warning "Failed to migrate MSI ROMHOLE, your platform's unique SMBIOS/DMI data may be lost"
         return
       fi
     else
-      dd if=/tmp/rom.bin of=/tmp/romhole.bin skip=$((0x17C0000)) bs=128K count=1 iflag=skip_bytes > /dev/null 2>&1
+      dd if=/tmp/rom.bin of=/tmp/romhole.bin skip=$((0x17C0000)) bs=128K count=1 iflag=skip_bytes >/dev/null 2>>"$ERR_LOG_FILE"
     fi
 
-    $CBFSTOOL "$BIOS_UPDATE_FILE" write -r ROMHOLE -f /tmp/romhole.bin -u 2> /dev/null
+    $CBFSTOOL "$BIOS_UPDATE_FILE" write -r ROMHOLE -f /tmp/romhole.bin -u 2>>"$ERR_LOG_FILE"
 }
 
 smbios_migration() {
@@ -601,10 +601,10 @@ check_vboot_keys() {
       FLASHROM_ADD_OPT_READ="--ifd -i bios"
     fi
     echo "Checking vboot keys."
-    $FLASHROM read_firm_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} ${FLASHROM_ADD_OPT_READ} -r $BIOS_DUMP_FILE > /dev/null 2>/dev/null
+    $FLASHROM read_firm_mock -p "$PROGRAMMER_BIOS" ${FLASH_CHIP_SELECT} ${FLASHROM_ADD_OPT_READ} -r $BIOS_DUMP_FILE >/dev/null 2>>"$ERR_LOG_FILE"
     if [ $? -eq 0 ] && [ -f $BIOS_DUMP_FILE ]; then
       FLASH_KEYS=$(CBFSTOOL=$(which cbfstool) $FUTILITY dump_vboot_keys show $BIOS_DUMP_FILE | grep -i 'key sha1sum')
-      diff <(echo "$BINARY_KEYS") <(echo "$FLASH_KEYS") > /dev/null 2>&1
+      diff <(echo "$BINARY_KEYS") <(echo "$FLASH_KEYS") >/dev/null 2>>"$ERR_LOG_FILE"
       # If keys are different we must additionally flash at least GBB region as well
       if [ $? -ne 0 ]; then
         FLASHROM_ADD_OPT_UPDATE+=" -i GBB"
@@ -994,7 +994,7 @@ update_workflow() {
   else
     compare_versions $DASHARO_VERSION $UPDATE_VERSION
     if [ $? -ne 1 ]; then
-      error_exit "No update available for your machine"
+      error_exit "No update available for your machine" 2
     fi
   fi
 

scripts/dts-boot

@@ -5,15 +5,36 @@
 # SPDX-License-Identifier: Apache-2.0
 
 SBIN_DIR="/usr/sbin"
-BIN_DIR="/usr/bin"
 FUM_EFIVAR="/sys/firmware/efi/efivars/FirmwareUpdateMode-d15b327e-ff2d-4fc1-abf6-c12bd08c1359"
 
 export DTS_FUNCS="$SBIN_DIR/dts-functions.sh"
 export DTS_ENV="$SBIN_DIR/dts-environment.sh"
 export DTS_SUBS="$SBIN_DIR/dts-subscription.sh"
 export DTS_HAL="$SBIN_DIR/dts-hal.sh"
 export DTS_MOCK_COMMON="$SBIN_DIR/common-mock-func.sh"
-export DTS_LOG_FILE="/tmp/dts.log"
+export BASH_ENV="$SBIN_DIR/logging"
+export ERR_LOG_FILE_REALPATH
+export DTS_LOG_FILE
+export DTS_VERBOSE_LOG_FILE
+export ERR_LOG_FILE
+export SHELLOPTS
+
+# $ERR_LOG_FILE is fd that can only be written to: '>()'. To copy logs
+# we need underlying file that can be copied
+ERR_LOG_FILE_REALPATH="/var/local/dts-err_$(basename "$(tty)").log"
+DTS_LOG_FILE="/tmp/dts_$(basename "$(tty)").log"
+DTS_VERBOSE_LOG_FILE="/tmp/dts-verbose_$(basename "$(tty)").log"
+
+# shellcheck source=./logging
+source "$BASH_ENV"
+start_trace_logging
+start_logging
+if [ -z "$ERR_LOG_FILE" ]; then
+    # pass everything written to $ERR_LOG_FILE to logger function and save it's
+    # output to $ERR_LOG_FILE_REALPATH file
+    exec {ERR_LOG_FILE}> >(logger >> "$ERR_LOG_FILE_REALPATH")
+    ERR_LOG_FILE="/proc/$$/fd/$ERR_LOG_FILE"
+fi
 
 # shellcheck source=../include/dts-environment.sh
 source $DTS_ENV
@@ -25,5 +46,5 @@ source $DTS_HAL
 if [ -f $FUM_EFIVAR ]; then
     $SBIN_DIR/dasharo-deploy update fum
 else
-    $BIN_DIR/script -c $SBIN_DIR/dts "$DTS_LOG_FILE"
+    $SBIN_DIR/dts
 fi

scripts/logging

@@ -0,0 +1,48 @@
+#!/bin/bash
+
+logger() {
+    while read -r LINE
+    do
+        echo "[$(date +%T.%3N)]: $LINE"
+    done
+}
+
+start_logging() {
+    local file="$DTS_LOG_FILE"
+    if [ -z "$LOGGING" ]; then
+        LOGGING="true"
+        if [ -z "$DESC" ]; then
+            # Create file descriptor that echoes back anything written to it
+            # and also logs that line to file with added timestamp prefix
+            exec {DESC}> >(tee >(stdbuf -i0 -oL -eL ts "[%T]: " >> "$file"))
+        fi
+        exec 1>&$DESC
+    fi
+}
+
+stop_logging() {
+    if [ -n "$LOGGING" ]; then
+        exec >&0
+        LOGGING=
+    fi
+}
+
+start_trace_logging() {
+    local file="$DTS_VERBOSE_LOG_FILE"
+    if [ -z "$BASH_XTRACEFD" ]; then
+        exec {xtrace_fd}>>"$file"
+        export BASH_XTRACEFD=${xtrace_fd}
+        set -x
+    fi
+}
+
+stop_trace_logging() {
+    if [ -n "$BASH_XTRACEFD" ]; then
+        set +x
+        BASH_XTRACEFD=
+    fi
+}
+
+export PS4="+[\$(date +%T.%3N)]:\${BASH_SOURCE[0]}:\${LINENO[0]}:\${FUNCNAME[0]:-main}: "
+export LOGGING
+export DESC