Skip to content

Commit 2a485c5

Browse files
committed
Refine STATUS/NOTE/INFO logging for consistent UX and accurate terminology
- doc/logging.md: rewrite INFO/NOTE sections, add sleep/blank-line table columns for NOTE/WARN/DIE, clarify when to use each level - initrd/bin/key-init.sh: streamline status messages, use 'public keys' terminology consistently (keys are for verification, not signing), consolidate under single STATUS/STATUS_OK pair - initrd/bin/gui-init.sh: remove noisy STATUS pairs (HOTP presence check, TOTP/HOTP generation, TPM reset), add STATUS_OK for HOTP verification - initrd/bin/oem-factory-reset.sh: change INFO to NOTE for user guidance (questionnaire, key generation explanations), add STATUS_OK for key generation, TPM reset, firmware flash, checksum signing steps - initrd/bin/gpg-gui.sh: change INFO to NOTE for gpg card-edit instructions (user-facing hand-off guidance) - initrd/bin/seal-totp.sh: change INFO to STATUS for PCR reading, change STATUS to NOTE for TOTP secret manual input display - initrd/bin/tpmr.sh: change INFO to WARN for TPM unseal failure (actionable problem, not just informational) - initrd/bin/cbfs-init.sh: clarify STATUS message for full SPI flash dump, add STATUS_OK for successful flash read - initrd/bin/kexec-seal-key.sh: add STATUS_OK for LUKS TPM Disk Unlock Key generation, slot addition, LUKS header measurement, PCR reads - initrd/bin/seal-hotpkey.sh: add STATUS/STATUS_OK for HOTP secret writing to security dongle - initrd/bin/unseal-hotp.sh: add STATUS/STATUS_OK for HOTP secret unsealing from TPM - initrd/bin/lock_chip.sh: add STATUS_OK for chipset write protection lock - initrd/bin/network-init-recovery.sh: add STATUS_OK for ethernet module loading, hardware clock sync, Dropbear SSH server start - initrd/etc/gui_functions.sh: remove redundant STATUS_OK for dongle detection, add STATUS_OK for signing key verification only on match, update signing key guidance message - initrd/etc/functions.sh: fix dongle VID wait loop: add sleep 0.1 to avoid busy-wait, add iteration cap (30) as hard fallback when /proc/uptime is unavailable to prevent infinite loop Signed-off-by: Thierry Laurion <insurgo@riseup.net>
1 parent 9fb61b9 commit 2a485c5

15 files changed

Lines changed: 129 additions & 79 deletions

doc/logging.md

Lines changed: 53 additions & 37 deletions
Original file line numberDiff line numberDiff line change
@@ -101,30 +101,34 @@ Use this in situations like:
101101

102102
## INFO
103103

104-
INFO is for contextual information that may be of interest to end users, but that is not required
105-
for use of Heads.
104+
INFO is for technical/security operations that advanced users want to see.
106105

107-
INFO always goes to debug.log. It is shown on the console in info and debug modes, and suppressed
108-
from the console in quiet mode (where the log file serves as the post-mortem record).
106+
INFO always goes to debug.log. It is shown on the console in **info** and **debug** modes, and suppressed
107+
from the console in **quiet** mode (where the log file serves as the post-mortem record).
109108

110-
Users might use this to troubleshoot Heads configuration or behavior, but this should not require
111-
knowledge of Heads implementation or developer experience.
109+
INFO is for operations that:
110+
- Are technically detailed (TPM PCR extends, key generation, cryptographic operations)
111+
- Advanced users want to see when troubleshooting
112+
- Are NOT hand-off guidance (use NOTE for that)
113+
- Are NOT developer-facing logic tracing (use DEBUG for that)
112114

113115
For example:
114116

115-
* "Why can't I enable USB keyboard support?" `INFO "Not showing USB keyboard option, USB keyboard is always enabled for this board"`
116-
* "Why isn't Heads booting automatically?" `INFO "Not booting automatically, automatic boot is disabled in user settings"`
117-
* "Why didn't Heads prompt me for a password?" `INFO "Password has not been changed, using default"`
117+
* `INFO "TPM: Extending PCR[4] with hash abc123..."` — technical TPM operation
118+
* `INFO "TPM: Reading PCR values for TOTP sealing policy"` — TPM state capture
119+
* `INFO "Measuring /boot/vmlinuz into TPM PCR[4]"` — integrity measurement
118120

119-
These do not include highly technical details.
120-
They can include configuration values or context, _but_ they should refer to configuration settings
121-
using the user-facing names in the configuration menus.
121+
Do NOT use INFO for:
122+
123+
* User guidance or hand-off instructions — use **NOTE** (sleeps 3s, italic white, cannot be hidden)
124+
* High-level user-facing explanations — use **NOTE** or **STATUS**
125+
* Developer-facing logic/decisions — use **DEBUG**
122126

123127
Use this in situations like:
124128

125-
* Showing very high level decision-making information, understandable for users not familiar with
126-
Heads implementation
127-
* Explaining a behavior that could reasonably be unexpected for some users
129+
* Reporting technical security operations (TPM extends, measurements, sealing)
130+
* Showing advanced configuration values that power users care about
131+
* Operations that belong in debug.log and info-mode console for audit/diagnostic purposes
128132

129133
## console
130134

@@ -182,17 +186,12 @@ The console renders `OK message` (with a leading space) in bold green; debug.log
182186

183187
## NOTE
184188

185-
NOTE is for contextual information explaining something that is _likely_ to be unexpected or
186-
confusing to users new to Heads.
187-
188-
Unlike INFO, it cannot be hidden from the console. Use this only if the behavior is likely to be
189-
unexpected or confusing to many users. If it is only possibly unexpected, consider INFO instead.
190-
191-
Do not overuse this above INFO. Adding too much output at NOTE causes users to ignore it.
189+
NOTE is for **user guidance that needs attention** — it sleeps 3 seconds and prints
190+
blank lines before/after so users cannot scroll past it unread.
192191

193-
NOTE always goes to debug.log.
192+
NOTE uses **italic white** (`\033[3;37m`) and cannot be hidden from console in any output mode.
194193

195-
Two specific patterns where NOTE is the right level:
194+
Use NOTE for two specific patterns:
196195

197196
**Security reminders** — advice about consequences or risks the user should not overlook,
198197
but that do not indicate a current problem:
@@ -208,20 +207,30 @@ tool's prompts or output rather than Heads-formatted messages:
208207
* "Nitrokey 3 requires physical presence: touch the dongle when prompted" - hardware-level event
209208
* "Please authenticate with OpenPGP smartcard/backup media" - gpg auth flow follows
210209

210+
**Questionnaire/setup guidance** — when walking users through configuration steps:
211+
212+
* "The following questionnaire will help you configure the security components of your system"
213+
* "Each prompt requires a single letter answer (Y/n)"
214+
* "Master key and subkeys will be generated in memory and backed up to a dedicated LUKS container"
215+
211216
For example:
212217

213218
* "Proceeding with unsigned ISO boot" - booting without a verified signature is unexpected and
214219
carries risk; the user needs to know it is happening deliberately.
215220
* "TOTP secret no longer accessible: TPM secrets were wiped" - mid-session secret loss requires
216221
immediate user attention.
217222

223+
Unlike INFO (technical operations for advanced users), NOTE is for **user-facing guidance**
224+
that requires the user's attention and cannot be hidden.
225+
226+
Do not overuse this above INFO. Adding too much output at NOTE causes users to ignore it.
227+
218228
## WARN
219229

220230
WARN is for output that indicates a problem. We think the user should act on it, but we are able
221231
to continue, possibly with degraded functionality.
222232

223233
This is appropriate when _all_ of the following are true:
224-
225234
* there is a _likely_ problem
226235
* we are able to continue, possibly with degraded functionality
227236
* the warning is _actionable_ - there is a reasonable change that could silence the warning
@@ -235,6 +244,9 @@ Warnings must be _actionable_ - only WARN if there is a reasonable change the us
235244

236245
WARN always goes to debug.log.
237246

247+
**WARN sleeps 1 second** and prints blank lines before/after (like NOTE) so users
248+
cannot scroll past it unread. WARN uses **bold yellow** (`\033[1;33m`).
249+
238250
For example:
239251

240252
* Warning when using default passphrases that are completely insecure is reasonable.
@@ -290,15 +302,17 @@ Users can choose one of three output levels for console information.
290302
Console output styling - chosen for accessibility across color-deficiency types (WCAG 1.4.1:
291303
color is never the sole signal; text prefixes carry meaning independently):
292304

293-
| Level | Style | ANSI code | Rationale |
294-
|-----------|--------------|--------------|---------------------------------------------------------------------------------------------------------------------|
295-
| DIE | bold red | `\033[1;31m` | Red = universal danger signal; `!!! ERROR:` prefix is the semantic carrier |
296-
| WARN | bold yellow | `\033[1;33m` | Most universally perceptible alert color across deuteranopia, protanopia, tritanopia |
297-
| NOTE | italic white | `\033[3;37m` | White = highest-contrast neutral on dark consoles; italic separates NOTE from bold STATUS/WARN, no semantic hue |
298-
| STATUS | bold only | `\033[1m` | In-progress actions - bold without hue readable in every terminal theme; `>>` prefix differentiates semantically |
299-
| STATUS_OK | bold green | `\033[1;32m` | Confirmed success - green is universally understood as success; scannable at a glance against plain bold STATUS |
300-
| INFO | green | `\033[0;32m` | Standard informational color; INFO is optional context, its absence on console is harmless |
301-
| INPUT | bold white | `\033[1;37m` | Maximum contrast (21:1) on VGA/dark consoles; no color dependency, readable under all deficiency types |
305+
| Level | Style | ANSI code | Sleep | Blank lines | Quiet mode | Purpose |
306+
|-----------|--------------|--------------|-------|-------------|------------|---------|
307+
| DIE | bold red | `\033[1;31m` | 0s | Yes | Visible | Fatal errors - execution stops |
308+
| WARN | bold yellow | `\033[1;33m` | 1s | Yes | Visible | Actionable problems - degraded operation |
309+
| NOTE | italic white | `\033[3;37m` | 3s | Yes | Visible | User guidance needing attention |
310+
| STATUS | bold only | `\033[1m` | 0s | No | Visible | In-progress action announcements |
311+
| STATUS_OK | bold green | `\033[1;32m` | 0s | No | Visible | Confirmed success outcomes |
312+
| INFO | green | `\033[0;32m` | 0s | No | Suppressed | Technical operations for advanced users |
313+
| INPUT | bold white | `\033[1;37m` | 0s | No* | Visible | Interactive input prompts |
314+
315+
\* INPUT prints a newline after user input, not before.
302316

303317
debug.log and /dev/kmsg always receive plain text without ANSI codes.
304318

@@ -310,10 +324,12 @@ This means callers never need to care about redirections: a caller that does
310324
Similarly, scripts that use stdout for a structured protocol can safely call STATUS,
311325
STATUS_OK, and any other logging function — log output never appears on stdout.
312326

313-
NOTE, WARN and DIE print a blank line before and after the message so they stand out visually
314-
from surrounding output. STATUS and STATUS_OK do **not** — they are called frequently and blank
315-
lines would make output very noisy. Use NOTE when a sleep and blank lines are needed.
327+
NOTE (3s), WARN (1s), and DIE (0s) print blank lines before and after the message
328+
so they stand out visually from surrounding output.
329+
STATUS and STATUS_OK do **not** — they are called frequently and blank
330+
lines would make output very noisy.
316331
INPUT displays the prompt inline (no leading blank line); the cursor stays on the same line as the prompt.
332+
A blank line is printed after the user's input to separate it from subsequent output.
317333

318334
### None / Quiet - minimal console output
319335

initrd/bin/cbfs-init.sh

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,10 +24,12 @@ if [ -z "$CONFIG_PCR" ]; then
2424
fi
2525

2626
if [ "$CONFIG_CBFS_VIA_FLASHPROG" = "y" ]; then
27+
#TODO: This is ugly workaround. see https://github.com/osresearch/flashtools/issues/10
2728
# Use flashrom directly, because we don't have /tmp/config with params for flash.sh yet
28-
STATUS "Reading board keys and configuration from SPI flash"
29+
STATUS "Reading board keys and configuration from full SPI flash dump"
2930
if /bin/flashprog -p internal --fmap -i COREBOOT -i FMAP -r /tmp/cbfs-init.rom; then
3031
CBFS_ARG=" -o /tmp/cbfs-init.rom"
32+
STATUS_OK "Full firmware image obtained"
3133
else
3234
WARN "Failed to read board keys and configuration from SPI flash - some features may not be available"
3335
fi

initrd/bin/gpg-gui.sh

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -57,8 +57,8 @@ while true; do
5757
"g")
5858
confirm_gpg_card
5959
STATUS "INSTRUCTIONS:"
60-
INFO "Type 'admin' then 'generate' and follow the prompts to generate a GPG key"
61-
INFO "Type 'quit' once the key is generated to exit GPG"
60+
NOTE "Type 'admin' then 'generate' and follow the prompts to generate a GPG key"
61+
NOTE "Type 'quit' once the key is generated to exit GPG"
6262
gpg --card-edit >/tmp/gpg_card_edit_output
6363
if [ $? -eq 0 ]; then
6464
gpg_post_gen_mgmt

initrd/bin/gui-init.sh

Lines changed: 3 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -249,11 +249,9 @@ gate_reseal_with_integrity_report() {
249249
# starting the NK3 CCID teardown. This safety call covers the
250250
# case where scdaemon was restarted between then and now.
251251
release_scdaemon
252-
STATUS "Checking $DONGLE_BRAND presence before sealing"
253252
DEBUG "gate_reseal_with_integrity_report: checking HOTP token presence"
254253
if hotp_verification info >/dev/null 2>&1; then
255254
token_ok="y"
256-
STATUS_OK "$DONGLE_BRAND present and accessible"
257255
break
258256
fi
259257
DEBUG "gate_reseal_with_integrity_report: HOTP token not accessible"
@@ -285,10 +283,9 @@ generate_totp_hotp() {
285283
if [ "$CONFIG_TPM" != "y" ] && [ -x /bin/hotp_verification ]; then
286284
# If we don't have a TPM, but we have a HOTP USB Security dongle
287285
TRACE_FUNC
288-
STATUS "Generating new HOTP secret"
289286
/bin/seal-hotpkey.sh ||
290287
DIE "Failed to generate HOTP secret"
291-
elif STATUS "Generating new TOTP secret" && /bin/seal-totp.sh "$BOARD_NAME" "$tpm_owner_passphrase"; then
288+
elif /bin/seal-totp.sh "$BOARD_NAME" "$tpm_owner_passphrase"; then
292289
if [ -x /bin/hotp_verification ]; then
293290
# If we have a TPM and a HOTP USB Security dongle
294291
if [ "$CONFIG_TOTP_SKIP_QRCODE" != y ]; then
@@ -474,12 +471,14 @@ update_hotp() {
474471
# PIN retry count is shown only before a retry so normal boots stay silent.
475472
for attempt in 1 2 3; do
476473
# Don't output HOTP codes to screen, so as to make replay attacks harder
474+
STATUS "Verifying HOTP code"
477475
hotp_verification check "$HOTP"
478476
hotp_exit=$?
479477
case "$hotp_exit" in
480478
0)
481479
HOTP="Success"
482480
BG_COLOR_MAIN_MENU="normal"
481+
STATUS_OK "HOTP code verified"
483482
return
484483
;;
485484
4 | 7) # 4: code incorrect, 7: not a valid HOTP code — no point retrying same code
@@ -876,7 +875,6 @@ reset_tpm() {
876875
prompt_missing_gpg_key_action || return 1
877876
wait_for_gpg_card || true
878877
else
879-
STATUS_OK "TPM reset successful - updating /boot checksums and signatures"
880878
if ! update_checksums; then
881879
whiptail_error --title 'ERROR' \
882880
--msgbox "Failed to update checksums / sign default config" 0 80
@@ -896,7 +894,6 @@ reset_tpm() {
896894
fi
897895

898896
if [ -s /boot/kexec_key_devices.txt ] || [ -s /boot/kexec_key_lvm.txt ]; then
899-
STATUS_OK "TPM reset successful - resealing TPM Disk Unlock Key (DUK)"
900897
reseal_tpm_disk_decryption_key || prompt_missing_gpg_key_action
901898
fi
902899
else

initrd/bin/kexec-seal-key.sh

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -174,6 +174,7 @@ dd \
174174
count=128 \
175175
2>/dev/null ||
176176
DIE "Unable to generate random key of 128 characters"
177+
STATUS_OK "LUKS TPM Disk Unlock Key generated"
177178

178179
previous_luks_header_version=0
179180
for dev in $key_devices; do
@@ -261,6 +262,7 @@ for dev in $key_devices; do
261262
--new-key-slot "$duk_keyslot" \
262263
"$dev" "$DUK_KEY_FILE" ||
263264
DIE "$dev: Unable to add LUKS TPM Disk Unlock Key to LUKS key slot $duk_keyslot"
265+
STATUS_OK "$dev: LUKS TPM Disk Unlock Key added to slot $duk_keyslot"
264266
done
265267

266268
# Now that we have setup the new keys, measure the PCRs
@@ -270,6 +272,7 @@ done
270272
STATUS "Measuring LUKS headers for TPM sealing policy"
271273
echo "$key_devices" | xargs /bin/qubes-measure-luks.sh ||
272274
DIE "Unable to measure the LUKS headers"
275+
STATUS_OK "LUKS headers measured for TPM sealing policy"
273276

274277
STATUS "Reading current PCR values for TPM sealing policy"
275278
pcrf="/tmp/secret/pcrf.bin"
@@ -293,6 +296,7 @@ DEBUG "Precomputing TPM future value for PCR6 sealing/unsealing of LUKS TPM Disk
293296
tpmr.sh calcfuturepcr 6 "/tmp/luksDump.txt" >>"$pcrf"
294297
# We take into consideration user files in cbfs
295298
tpmr.sh pcrread -a 7 "$pcrf"
299+
STATUS_OK "PCR values read for TPM sealing policy"
296300

297301
# tpmr.sh seal may prompt for TPM owner password; avoid DO_WITH_DEBUG here so the
298302
# prompt remains visible on console. tpmr.sh logs command details internally.

initrd/bin/key-init.sh

Lines changed: 5 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -22,17 +22,16 @@ if [ -d /.gnupg/keys ]; then
2222
# This is legacy location for user's keys. cbfs-init takes for granted that keyring and trustdb are in /.gnupg
2323
# oem-factory-reset.sh generates keyring and trustdb which cbfs-init dumps to /.gnupg
2424
# TODO: Remove individual key imports. This is still valid for distro keys only below.
25-
STATUS "Importing user GPG keys"
2625
gpg --import /.gnupg/keys/*.key /.gnupg/keys/*.asc 2>/dev/null || WARN "Importing user's keys failed"
2726
fi
2827

29-
# Import OS distribution signing keys used to authenticate ISO boots
30-
STATUS "Loading OS distribution signing keys for ISO boot authentication"
28+
# Load public keys for ISO verification
29+
STATUS "Loading public keys for ISO verification"
3130
gpg --homedir=/etc/distro/ --import /etc/distro/keys/* 2>/dev/null || WARN "Importing distro keys failed"
3231
#Set distro keys trust level to ultimate (trust anything that was signed with these keys)
3332
gpg --homedir=/etc/distro/ --list-keys --fingerprint --with-colons|sed -E -n -e 's/^fpr:::::::::([0-9A-F]+):$/\1:6:/p' |gpg --homedir=/etc/distro/ --import-ownertrust 2>/dev/null || WARN "Setting distro keys ultimate trust failed"
3433
gpg --homedir=/etc/distro/ --update-trust 2>/dev/null || WARN "Updating distro keys trust failed"
3534

36-
# Add user's key so self-signed ISOs can also be booted from USB
37-
STATUS "Adding user GPG key as trusted for ISO signing"
38-
gpg --export | gpg --homedir=/etc/distro/ --import 2>/dev/null || WARN "Adding user's keys to distro keys failed"
35+
# Add user's public key to distro keyring to verify user-signed ISOs
36+
gpg --export | gpg --homedir=/etc/distro/ --import 2>/dev/null || WARN "Adding user's public key to distro keyring failed"
37+
STATUS_OK "Public keys loaded"

initrd/bin/lock_chip.sh

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@ if [ -n "$APM_CNT" -a -n "$FIN_CODE" ]; then
2121
# until the next system reset.
2222
STATUS "Finalizing chipset write protection via SMI PR0 lockdown"
2323
io386 -o b -b x $APM_CNT $FIN_CODE
24+
STATUS_OK "Chipset write protection locked"
2425
else
2526
NOTE "NOT finalizing chipset - lock_chip.sh called without valid APM_CNT and FIN_CODE"
2627
fi

initrd/bin/network-init-recovery.sh

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -60,6 +60,7 @@ ethernet_activation()
6060
insmod.sh /lib/modules/$module.ko
6161
fi
6262
done
63+
STATUS_OK "Ethernet network modules loaded"
6364
}
6465

6566
# bring up the ethernet interface
@@ -113,10 +114,10 @@ if [ -n "$dev" ]; then
113114
STATUS_OK "NTP time sync successful"
114115
fi
115116
fi
116-
STATUS "Syncing hardware clock with system time (UTC)"
117-
hwclock -w
118-
date=$(date "+%Y-%m-%d %H:%M:%S %Z")
119-
STATUS "Time: $date"
117+
STATUS "Syncing hardware clock with system time (UTC)"
118+
hwclock -w
119+
date=$(date "+%Y-%m-%d %H:%M:%S %Z")
120+
STATUS_OK "Hardware clock synced: $date"
120121
fi
121122
fi
122123
fi
@@ -133,6 +134,7 @@ if [ -n "$dev" ]; then
133134
# -B background
134135
# -R create host keys
135136
dropbear -B -R
137+
STATUS_OK "Dropbear SSH server started"
136138
fi
137139
STATUS_OK "Network setup complete"
138140
ifconfig $dev

0 commit comments

Comments
 (0)