BUGFIX: replace direct calls from LOG to INFO, so that only DO_WITH_DEBUG uses LOG. INFO manages console output to log or console

Quiet mode introduced output reduction to console to limit technical info provided to end users.
Previous informational output (previous default) now outputs this now considered additional information through INFO() calls, which either outputs to console, or debug.log
Only DO_WITH_DEBUG should call LOG directly, so that stderr+stdout output is prepended with LOG into debug.log

This fixes previous implementation which called LOG in DO_WITH_DEBUG calls and modified expected output to files, which was observed by @3hhh in output of GRUB entries when selecting boot option.

Signed-off-by: Thierry Laurion <insurgo@riseup.net>
This commit is contained in:
Thierry Laurion 2025-01-13 10:57:34 -05:00
parent 8f7b1c4128
commit 930d3e6114
No known key found for this signature in database
GPG Key ID: 9A53E1BB3FF00461
9 changed files with 112 additions and 108 deletions

View File

@ -24,12 +24,12 @@ for cbfsname in `echo $cbfsfiles`; do
if [ ! -z "$filename" ]; then
mkdir -p `dirname $filename` \
|| die "$filename: mkdir failed"
LOG "Extracting CBFS file $cbfsname into $filename"
INFO "Extracting CBFS file $cbfsname into $filename"
cbfs -t 50 $CBFS_ARG -r $cbfsname > "$filename" \
|| die "$filename: cbfs file read failed"
if [ "$CONFIG_TPM" = "y" ]; then
TRACE_FUNC
LOG "TPM: Extending PCR[$CONFIG_PCR] with filename $filename and then its content"
INFO "TPM: Extending PCR[$CONFIG_PCR] with filename $filename and then its content"
# Measure both the filename and its content. This
# ensures that renaming files or pivoting file content
# will still affect the resulting PCR measurement.

View File

@ -553,7 +553,7 @@ reset_tpm() {
mount -o rw,remount /boot
#TODO: this is really problematic, we should really remove the primary handle hash
LOG "Removing rollback and primary handle hash under /boot"
INFO "Removing rollback and primary handle hash under /boot"
rm -f /boot/kexec_rollback.txt
rm -f /boot/kexec_primhdl_hash.txt

View File

@ -66,7 +66,7 @@ fi
# Override PCR 4 so that user can't read the key
TRACE_FUNC
LOG "TPM: Extending PCR[4] to prevent any future secret unsealing"
INFO "TPM: Extending PCR[4] to prevent any future secret unsealing"
tpmr extend -ix 4 -ic generic ||
die 'Unable to scramble PCR'

View File

@ -82,10 +82,10 @@ if [ "$CONFIG_TPM2_TOOLS" = "y" ]; then
fi
verify_global_hashes() {
LOG "+++ Checking verified boot hash file "
INFO "+++ Checking verified boot hash file "
# Check the hashes of all the files
if verify_checksums "$bootdir" "$gui_menu"; then
LOG "+++ Verified boot hashes "
INFO "+++ Verified boot hashes "
valid_hash='y'
valid_global_hash='y'
else
@ -208,7 +208,7 @@ parse_option() {
}
scan_options() {
LOG "+++ Scanning for unsigned boot options"
INFO "+++ Scanning for unsigned boot options"
option_file="/tmp/kexec_options.txt"
scan_boot_options "$bootdir" "$config" "$option_file"
if [ ! -s $option_file ]; then
@ -272,7 +272,7 @@ default_select() {
if [ "$CONFIG_BASIC" != "y" ]; then
# Enforce that default option hashes are valid
LOG "+++ Checking verified default boot hash file "
INFO "+++ Checking verified default boot hash file "
# Check the hashes of all the files
if (cd $bootdir && sha256sum -c "$TMP_DEFAULT_HASH_FILE" >/tmp/hash_output); then
echo "+++ Verified default boot hashes "
@ -390,7 +390,7 @@ while true; do
if [ ! -r "$TMP_KEY_DEVICES" ]; then
# Extend PCR4 as soon as possible
TRACE_FUNC
LOG "TPM: Extending PCR[4] to prevent further secret unsealing"
INFO "TPM: Extending PCR[4] to prevent further secret unsealing"
tpmr extend -ix 4 -ic generic ||
die "Failed to extend TPM PCR[4]"
fi

View File

@ -20,6 +20,6 @@ DEBUG "Removing /tmp/lukshdr-*"
rm /tmp/lukshdr-*
TRACE_FUNC
LOG "TPM: Extending PCR[6] with hash of LUKS headers from /tmp/luksDump.txt"
INFO "TPM: Extending PCR[6] with hash of LUKS headers from /tmp/luksDump.txt"
tpmr extend -ix 6 -if /tmp/luksDump.txt ||
die "Unable to extend PCR"

View File

@ -257,7 +257,7 @@ tpm2_extend() {
esac
done
tpm2 pcrextend "$index:sha256=$hash"
LOG $(tpm2 pcrread "sha256:$index" 2>&1)
INFO $(tpm2 pcrread "sha256:$index" 2>&1)
TRACE_FUNC
DEBUG "TPM: Extended PCR[$index] with hash $hash"
@ -614,7 +614,7 @@ tpm2_unseal() {
# stderr; capture stderr to log.
if ! tpm2 unseal -Q -c "$handle" -p "session:$POLICY_SESSION$UNSEAL_PASS_SUFFIX" \
-S "$ENC_SESSION_FILE" >"$file" 2> >(SINK_LOG "tpm2 stderr"); then
LOG "Unable to unseal secret from TPM NVRAM"
INFO "Unable to unseal secret from TPM NVRAM"
# should succeed, exit if it doesn't
exit 1
@ -800,7 +800,7 @@ if [ "$CONFIG_TPM2_TOOLS" != "y" ]; then
fi
TRACE_FUNC
LOG "TPM: Extending PCR[$3] with hash $hash"
INFO "TPM: Extending PCR[$3] with hash $hash"
# Silence stdout/stderr, they're only useful for debugging
# and DO_WITH_DEBUG captures them
@ -845,7 +845,7 @@ calcfuturepcr)
;;
extend)
TRACE_FUNC
LOG "TPM: Extending PCR[$2] with $4"
INFO "TPM: Extending PCR[$2] with $4"
tpm2_extend "$@"
;;
counter_read)

View File

@ -3,22 +3,22 @@
# ------- Start of functions coming from /etc/ash_functions
die() {
if [ "$CONFIG_DEBUG_OUTPUT" = "y" ];then
echo -e " !!! ERROR: $* !!!" | tee -a /tmp/debug.log /dev/kmsg > /dev/null;
if [ "$CONFIG_DEBUG_OUTPUT" = "y" ]; then
echo -e " !!! ERROR: $* !!!" | tee -a /tmp/debug.log /dev/kmsg >/dev/null
else
echo -e >&2 "!!! ERROR: $* !!!";
echo -e "!!! ERROR: $* !!!" >&2
fi
sleep 2;
exit 1;
sleep 2
exit 1
}
warn() {
if [ "$CONFIG_DEBUG_OUTPUT" = "y" ];then
echo -e " *** WARNING: $* ***" | tee -a /tmp/debug.log /dev/kmsg > /dev/null;
if [ "$CONFIG_DEBUG_OUTPUT" = "y" ]; then
echo -e " *** WARNING: $* ***" | tee -a /tmp/debug.log /dev/kmsg >/dev/null
else
echo -e >&2 " *** WARNING: $* ***";
echo -e " *** WARNING: $* ***" >&2
fi
sleep 1;
sleep 1
}
DEBUG() {
@ -31,23 +31,29 @@ DEBUG() {
}
TRACE() {
if [ "$CONFIG_ENABLE_FUNCTION_TRACING_OUTPUT" = "y" ];then
echo "TRACE: $*" | tee -a /tmp/debug.log /dev/kmsg > /dev/null;
if [ "$CONFIG_ENABLE_FUNCTION_TRACING_OUTPUT" = "y" ]; then
echo "TRACE: $*" | tee -a /tmp/debug.log /dev/kmsg >/dev/null
fi
}
# Function to manage information output level to the console/debug.log
INFO() {
#TODO: add colors to output, here green for INFO?
# if not CONFIG_QUIET_MODE=y, output to console. If not, output to debug.log
if [ "$CONFIG_DEBUG_OUTPUT" = "y" ]; then
echo "$*" | tee -a /tmp/debug.log /dev/kmsg >/dev/null
elif [ "$CONFIG_QUIET_MODE" = "y" ]; then
echo "$*" >>/tmp/debug.log
else
echo "$*"
fi
}
# Write directly to the debug log (but not kmsg), never appears on console
# Main consumer is DO_WITH_DEBUG, which uses this to log command output
LOG() {
# if not CONFIG_QUIET_MODE=y, output to console. If not, output to debug.log
if [ "$CONFIG_DEBUG_OUTPUT" = "y" ]; then
DEBUG "$*"
elif [ "$CONFIG_QUIET_MODE" = "y" ]; then
# if in quiet mode, output solely to debug.log
echo "$*" >> /tmp/debug.log
else
# if not in quiet mode, output to console
echo "$*"
fi
echo "LOG: $*" >>/tmp/debug.log
}
fw_version() {
@ -59,16 +65,16 @@ fw_version() {
preserve_rom() {
TRACE_FUNC
new_rom="$1"
old_files=`cbfs -t 50 -l 2>/dev/null | grep "^heads/"`
old_files=$(cbfs -t 50 -l 2>/dev/null | grep "^heads/")
for old_file in `echo $old_files`; do
new_file=`cbfs.sh -o $1 -l | grep -x $old_file`
for old_file in $(echo $old_files); do
new_file=$(cbfs.sh -o $1 -l | grep -x $old_file)
if [ -z "$new_file" ]; then
echo "+++ Adding $old_file to $1"
cbfs -t 50 -r $old_file >/tmp/rom.$$ \
|| die "Failed to read cbfs file from ROM"
cbfs.sh -o $1 -a $old_file -f /tmp/rom.$$ \
|| die "Failed to write cbfs file to new ROM file"
cbfs -t 50 -r $old_file >/tmp/rom.$$ ||
die "Failed to read cbfs file from ROM"
cbfs.sh -o $1 -a $old_file -f /tmp/rom.$$ ||
die "Failed to write cbfs file to new ROM file"
fi
done
}
@ -79,7 +85,6 @@ confirm_gpg_card() {
#TODO: even change logic here to try first and then ask user to confirm if not found
#TODO: or ask GPG user PIN once and cache it for the rest of the boot session for reusal
# This is getting in the way of unattended stuff and GPG prompts are confusing anyway, hide them from user.
TRACE_FUNC
#Skip prompts if we are currently using a known GPG key material Thumb drive backup and keys are unlocked pinentry
@ -141,9 +146,9 @@ confirm_gpg_card() {
gpg --pinentry-mode=loopback --passphrase-file <(echo -n "${gpg_admin_pin}") --detach-sign "$CR_NONCE" >/dev/null 2>&1 ||
die "Unable to detach-sign $CR_NONCE with GPG private signing subkey using GPG Admin PIN"
#verify detached signature against public key in rom
gpg --verify "$CR_SIG" "$CR_NONCE" > /dev/null 2>&1 && \
echo "++++ Local GPG keyring can be used to sign/encrypt/authenticate in this boot session ++++" || \
die "Unable to verify $CR_SIG detached signature against public key in ROM"
gpg --verify "$CR_SIG" "$CR_NONCE" >/dev/null 2>&1 &&
echo "++++ Local GPG keyring can be used to sign/encrypt/authenticate in this boot session ++++" ||
die "Unable to verify $CR_SIG detached signature against public key in ROM"
#Wipe any previous CR_NONCE and CR_SIG
shred -n 10 -z -u "$CR_NONCE" "$CR_SIG" >/dev/null 2>&1 || true
#TODO: maybe just an export instead of setting /etc/user.config otherwise could be flashed in weird corner case situation
@ -184,8 +189,8 @@ confirm_gpg_card() {
pin_retry_counters=$(echo "$gpg_output" | grep 'PIN retry counter' | awk -F': ' '{print $2}')
user_pin_retries=$(echo "$pin_retry_counters" | awk '{print $1}')
admin_pin_retries=$(echo "$pin_retry_counters" | awk '{print $3}')
echo ""
echo ""
echo "GPG User PIN retry attempts left before becoming locked: $user_pin_retries"
echo "GPG Admin PIN retry attempts left before becoming locked: $admin_pin_retries"
echo ""
@ -201,18 +206,18 @@ gpg_auth() {
# Wipe any existing nonce and signature
shred -n 10 -z -u "$CR_NONCE" "$CR_SIG" 2>/dev/null || true
# In case of gpg_auth, we require confirmation of the card, so loop with confirm_gpg_card until we get it
false
while [ $? -ne 0 ]; do
# Call confirm_gpg_card in subshell to ensure GPG key material presence
( confirm_gpg_card )
(confirm_gpg_card)
done
# Perform a signing-based challenge-response,
# to authencate that the card plugged in holding
# the key to sign the list of boot files.
CR_NONCE="/tmp/secret/cr_nonce"
CR_SIG="$CR_NONCE.sig"
@ -222,17 +227,17 @@ gpg_auth() {
of="$CR_NONCE" \
count=1 \
bs=20 \
2>/dev/null \
|| die "Unable to generate 20 random bytes"
2>/dev/null ||
die "Unable to generate 20 random bytes"
# Sign the nonce
for tries in 1 2 3; do
if gpg --digest-algo SHA256 \
--detach-sign \
-o "$CR_SIG" \
"$CR_NONCE" > /dev/null 2>&1 \
&& gpg --verify "$CR_SIG" "$CR_NONCE" > /dev/null 2>&1 \
; then
"$CR_NONCE" >/dev/null 2>&1 &&
gpg --verify "$CR_SIG" "$CR_NONCE" >/dev/null 2>&1 \
; then
shred -n 10 -z -u "$CR_NONCE" "$CR_SIG" 2>/dev/null || true
DEBUG "Under /etc/ash_functions:gpg_auth: success"
return 0
@ -246,7 +251,7 @@ gpg_auth() {
fi
fi
done
return 1
return 1
fi
}
@ -258,7 +263,7 @@ recovery() {
# but recreate the directory so that new tools can use it.
#safe to always be true. Otherwise "set -e" would make it exit here
shred -n 10 -z -u /tmp/secret/* 2> /dev/null || true
shred -n 10 -z -u /tmp/secret/* 2>/dev/null || true
rm -rf /tmp/secret
mkdir -p /tmp/secret
@ -269,7 +274,7 @@ recovery() {
DEBUG "Board $CONFIG_BOARD - version $(fw_version)"
if [ "$CONFIG_TPM" = "y" ]; then
LOG "TPM: Extending PCR[4] to prevent any further secret unsealing"
INFO "TPM: Extending PCR[4] to prevent any further secret unsealing"
tpmr extend -ix 4 -ic recovery
fi
@ -278,14 +283,13 @@ recovery() {
sleep 5
/bin/reboot
fi
while [ true ]
do
while [ true ]; do
#Going to recovery shell should be authenticated if supported
gpg_auth
gpg_auth
echo >&2 "!!!!! Starting recovery shell"
sleep 1
if [ -x /bin/setsid ]; then
/bin/setsid -c /bin/bash
else
@ -302,66 +306,65 @@ pause_recovery() {
combine_configs() {
TRACE_FUNC
cat /etc/config* > /tmp/config
cat /etc/config* >/tmp/config
}
replace_config() {
TRACE_FUNC
CONFIG_FILE=$1
CONFIG_OPTION=$2
NEW_SETTING=$3
TRACE_FUNC
CONFIG_FILE=$1
CONFIG_OPTION=$2
NEW_SETTING=$3
touch $CONFIG_FILE
# first pull out the existing option from the global config and place in a tmp file
awk "gsub(\"^export ${CONFIG_OPTION}=.*\",\"export ${CONFIG_OPTION}=\\\"${NEW_SETTING}\\\"\")" /tmp/config >${CONFIG_FILE}.tmp
awk "gsub(\"^${CONFIG_OPTION}=.*\",\"${CONFIG_OPTION}=\\\"${NEW_SETTING}\\\"\")" /tmp/config >>${CONFIG_FILE}.tmp
touch $CONFIG_FILE
# first pull out the existing option from the global config and place in a tmp file
awk "gsub(\"^export ${CONFIG_OPTION}=.*\",\"export ${CONFIG_OPTION}=\\\"${NEW_SETTING}\\\"\")" /tmp/config >${CONFIG_FILE}.tmp
awk "gsub(\"^${CONFIG_OPTION}=.*\",\"${CONFIG_OPTION}=\\\"${NEW_SETTING}\\\"\")" /tmp/config >>${CONFIG_FILE}.tmp
# then copy any remaining settings from the existing config file, minus the option you changed
grep -v "^export ${CONFIG_OPTION}=" ${CONFIG_FILE} | grep -v "^${CONFIG_OPTION}=" >>${CONFIG_FILE}.tmp || true
sort ${CONFIG_FILE}.tmp | uniq >${CONFIG_FILE}
rm -f ${CONFIG_FILE}.tmp
# then copy any remaining settings from the existing config file, minus the option you changed
grep -v "^export ${CONFIG_OPTION}=" ${CONFIG_FILE} | grep -v "^${CONFIG_OPTION}=" >>${CONFIG_FILE}.tmp || true
sort ${CONFIG_FILE}.tmp | uniq >${CONFIG_FILE}
rm -f ${CONFIG_FILE}.tmp
}
# Set a config variable in a specific file to a given value - replace it if it
# exists, or add it. If added, the variable will be exported.
set_config() {
CONFIG_FILE="$1"
CONFIG_OPTION="$2"
NEW_SETTING="$3"
CONFIG_FILE="$1"
CONFIG_OPTION="$2"
NEW_SETTING="$3"
if grep -q "$CONFIG_OPTION" "$CONFIG_FILE"; then
replace_config "$CONFIG_FILE" "$CONFIG_OPTION" "$NEW_SETTING"
else
echo "export $CONFIG_OPTION=\"$NEW_SETTING\"" >>"$CONFIG_FILE"
fi
if grep -q "$CONFIG_OPTION" "$CONFIG_FILE"; then
replace_config "$CONFIG_FILE" "$CONFIG_OPTION" "$NEW_SETTING"
else
echo "export $CONFIG_OPTION=\"$NEW_SETTING\"" >>"$CONFIG_FILE"
fi
}
# Set a value in config.user, re-combine configs, and update configs in the
# environment.
set_user_config() {
CONFIG_OPTION="$1"
NEW_SETTING="$2"
CONFIG_OPTION="$1"
NEW_SETTING="$2"
set_config /etc/config.user "$CONFIG_OPTION" "$NEW_SETTING"
combine_configs
. /tmp/config
set_config /etc/config.user "$CONFIG_OPTION" "$NEW_SETTING"
combine_configs
. /tmp/config
}
# Load a config value to a variable, defaulting to empty. Does not fail if the
# config is not set (since it would expand to empty by default).
load_config_value() {
local config_name="$1"
if grep -q "$config_name=" /tmp/config; then
grep "$config_name=" /tmp/config | tail -n1 | cut -f2 -d '=' | tr -d '"'
fi
local config_name="$1"
if grep -q "$config_name=" /tmp/config; then
grep "$config_name=" /tmp/config | tail -n1 | cut -f2 -d '=' | tr -d '"'
fi
}
enable_usb()
{
enable_usb() {
TRACE_FUNC
#insmod ehci_hcd prior of uhdc_hcd and ohci_hcd to suppress dmesg warning
#insmod ehci_hcd prior of uhdc_hcd and ohci_hcd to suppress dmesg warning
insmod /lib/modules/ehci-hcd.ko || die "ehci_hcd: module load failed"
if [ "$CONFIG_LINUX_USB_COMPANION_CONTROLLER" = y ]; then
insmod /lib/modules/uhci-hcd.ko || die "uhci_hcd: module load failed"
insmod /lib/modules/ohci-hcd.ko || die "ohci_hcd: module load failed"
@ -385,7 +388,6 @@ enable_usb()
# ------- End of functions coming from /etc/ash_functions
# Print <hidden> or <empty> depending on whether $1 is empty. Useful to mask an
# optional password parameter.
mask_param() {
@ -761,11 +763,11 @@ check_tpm_counter() {
if [ -r "$1" ]; then
TPM_COUNTER=$(grep counter- "$1" | cut -d- -f2)
else
LOG "$1 does not exist; creating new TPM counter"
INFO "$1 does not exist; creating new TPM counter"
tpmr counter_create \
-pwdc '' \
-la $LABEL |
tee /tmp/counter > /dev/null 2>&1 ||
tee /tmp/counter >/dev/null 2>&1 ||
die "Unable to create TPM counter"
TPM_COUNTER=$(cut -d: -f1 </tmp/counter)
fi
@ -778,7 +780,7 @@ check_tpm_counter() {
# Read the TPM counter value from the TPM.
read_tpm_counter() {
TRACE_FUNC
tpmr counter_read -ix "$1" | tee "/tmp/counter-$1" > /dev/null 2>&1 ||
tpmr counter_read -ix "$1" | tee "/tmp/counter-$1" >/dev/null 2>&1 ||
die "Counter read failed"
}
@ -786,7 +788,7 @@ read_tpm_counter() {
increment_tpm_counter() {
TRACE_FUNC
tpmr counter_increment -ix "$1" -pwdc '' |
tee /tmp/counter-$1 > /dev/null 2>&1 ||
tee /tmp/counter-$1 >/dev/null 2>&1 ||
die "TPM counter increment failed for rollback prevention. Please reset the TPM"
}
@ -816,7 +818,7 @@ check_config() {
fi
fi
LOG "+++ Found verified kexec boot params"
INFO "+++ Found verified kexec boot params"
cp $1/kexec*.txt /tmp/kexec ||
die "Failed to copy kexec boot params to tmp"
}
@ -1291,7 +1293,7 @@ generate_passphrase() {
# level. 4 bytes with modulus 1296 results in 0.000003% bias
# toward the first 1263 words.
random="$(dd if=/dev/random bs=4 count=1 status=none | hexdump -e '1/4 "%u\n"')"
((random%=lines))
((random %= lines))
((++random)) # tail's line count is 1-based
tail -n +"$random" "$dictionary_file" | head -1 | cut -d$'\t' -f2
}

View File

@ -98,9 +98,11 @@ if [ "$CONFIG_DEBUG_OUTPUT" = "y" ]; then
#Output all kernel messages to console (8=debug)
#DEBUG and TRACE calls will be in dmesg and on console
# config.user extracted and combined from CBFS had CONFIG_DEBUG_OUTPUT=y
# DO_WITH_DEBUG redirects stderr and stdout to /tmp/debug.log to not clog console
TRACE_FUNC
dmesg -n 8
DEBUG "Full debug output enabled from this point: output both in dmesg and on console (equivalent of passing debug to kernel cmdline)"
DEBUG "NOTE: DO_WITH_DEBUG std_err and std_out will be redirected to /tmp/debug.log"
fi
# report if we are in quiet mode, tell user measurements logs available under /tmp/debug.log

View File

@ -39,19 +39,19 @@ if [ ! -r /sys/class/tpm/tpm0/pcrs -o ! -x /bin/tpm ]; then
fi
if [ -z "$tpm_missing" ]; then
LOG "TPM: Extending PCR[$MODULE_PCR] with $MODULE and parameters '$*' before loading"
INFO "TPM: Extending PCR[$MODULE_PCR] with $MODULE and parameters '$*' before loading"
# Extend with the module parameters (even if they are empty) and the
# module. Changing the parameters or the module content will result in a
# different PCR measurement.
if [ -n "$*" ]; then
TRACE_FUNC
LOG "Extending with module parameters and the module's content"
INFO "Extending with module parameters and the module's content"
tpmr extend -ix "$MODULE_PCR" -ic "$*"
tpmr extend -ix "$MODULE_PCR" -if "$MODULE" \
|| die "$MODULE: tpm extend failed"
else
TRACE_FUNC
LOG "No module parameters, extending only with the module's content"
INFO "No module parameters, extending only with the module's content"
tpmr extend -ix "$MODULE_PCR" -if "$MODULE" \
|| die "$MODULE: tpm extend failed"
fi