Skip to content

Conversation

@JonathonHall-Purism
Copy link
Collaborator

Start documenting some design aspects of Heads to aid future PR discussions.

Logging has changed quite a few times, and it tends to be difficult to review because we don't have established expectations for how logging behaves. Logging guidelines are helpful when adding features to keep logging consistent.

We have a lot more config variables now than in the past. Only some of them are intended to be configured by the user in config.user, and it's not always clear which those are.

The logging documentation is fairly complete if we all agree on it 🙂 Comments welcome, let's establish a common expectation.

The config documentation is not complete, there are many more variables not documented. Help appreciated 🙂 If we agree on the structure, we could merge and do this incrementally. Some doc is better than none, it doesn't have to be blocked waiting for "perfect" docs IMO.

I've documented the updated logging behavior in #1875 since we agree on the changes in that PR.

  • Agree on logging conventions
  • Agree on config document structure
  • Document more config variables, or agree to do this incrementally as we find time 😉

@JonathonHall-Purism JonathonHall-Purism changed the title Draft: doc: Start documenting Heads logging and configuration variables doc: Start documenting Heads logging and configuration variables Mar 21, 2025
@JonathonHall-Purism
Copy link
Collaborator Author

@tlaurion Thinking on this again, I think this is mergeable if you agree with the logging conventions I described. Or if not, please comment and let's reach a consensus 🙂

I didn't document every variable yet, but docs for some variables are better than docs for none. We can add them over time.

Thought about this again because I came across some "warnings" that should not be warnings:

./etc/functions:        warn "Your GPG User PIN, followed by Enter key will be required for input at: 'Please unlock the card' next prompt"

That's not a warning, we are doing exactly what is expected. This is informational and should be INFO. (warn is for output that indicates a problem. We think the user should act on it, but we are able to continue, possibly with degraded functionality.)

./etc/functions:                warn "Rebooting in 3 seconds to enable booting default boot option"

Same, in this context "boot default option" is exactly what the user expects us to do. This message is informational since rebooting to achieve this might be surprising, it should be INFO.

@tlaurion
Copy link
Collaborator

@tlaurion Thinking on this again, I think this is mergeable if you agree with the logging conventions I described. Or if not, please comment and let's reach a consensus 🙂

I didn't document every variable yet, but docs for some variables are better than docs for none. We can add them over time.

Thought about this again because I came across some "warnings" that should not be warnings:

./etc/functions:        warn "Your GPG User PIN, followed by Enter key will be required for input at: 'Please unlock the card' next prompt"

That's not a warning, we are doing exactly what is expected. This is informational and should be INFO. (warn is for output that indicates a problem. We think the user should act on it, but we are able to continue, possibly with degraded functionality.)

./etc/functions:                warn "Rebooting in 3 seconds to enable booting default boot option"

Same, in this context "boot default option" is exactly what the user expects us to do. This message is informational since rebooting to achieve this might be surprising, it should be INFO.

@JonathonHall-Purism the two examples you bring here is where the crux of the issue is. Turning those warn into INFO would make them silent to the unexperienced user:

  • He would not be warned that the GPG User PIN is what he needs to type on the next gpg prompt. This is why this is currently a warning.
  • He would not be warned that the system will reboot in 3 seconds.

This leads to redefining what a warning is. Otherwise I love what was written here and agree with this pr content.

A warning would:

  • informs the user of something that is not preventing the system from functionning (not an error), to bring his attention on something that is important. Everything else is either INFO, or DEBUG.

Thoughts?

@JonathonHall-Purism
Copy link
Collaborator Author

@JonathonHall-Purism the two examples you bring here is where the crux of the issue is. Turning those warn into INFO would make them silent to the unexperienced user:

* He would not be warned that the GPG User PIN is what he needs to type on the next gpg prompt. This is why this is currently a warning.

* He would not be warned that the system will reboot in 3 seconds.

OK, I see your point here. These two messages are important because the behavior is not clear without them. The GPG prompts are confusing, so we need to try to clear that up with this message. The reboot is normal and accomplishes what the user asks, but could be surprising.

So INFO is not appropriate - INFO messages are less important and can be hidden. These messages should always appear, they shouldn't hide.

However, I don't think warn is appropriate either. If we start displaying *** WARNING: $* *** for things that are normal and not actionable (even if they are potentially surprising), users will become accustomed to ignoring *** WARNING: $* ***. We won't be able to get their attention when it is important and the user SHOULD take action.

I think this is a justifiable example for a level in between INFO and warn, say NOTE. NOTE would be for potentially-surprising but normal behaviors. It cannot be hidden like INFO, but it is not actionable like warn.

Let me try putting together a change for this. BTW, I think it is a huge documentation win if documenting our behavior exposes something that's confusing, and we fix it 💪

Signed-off-by: Jonathon Hall <jonathon.hall@puri.sm>
Add NOTE level between INFO and warn.  NOTE is appropriate for context
that is required to understand confusing/surprising behavior in Heads,
but that does not indicate a problem.

Clarify warn level based on discussion.

Fix LOG output in tables, LOG actually does go to the debug log
currently in any configuration.

Signed-off-by: Jonathon Hall <jonathon.hall@puri.sm>
These messages don't indicate a problem, and they are not actionable.
They aren't warnings.

They _are_ important enough to clarify a confusing behavior that they
should not be hidden with INFO messages, though.  Use NOTE.

Signed-off-by: Jonathon Hall <jonathon.hall@puri.sm>
# doc/logging.md.
NOTE() {
echo "NOTE:" "$@" | tee -a /tmp/debug.log
}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@JonathonHall-Purism I love eveyrhing I see here, but the change to warn to note removing the 2 seconds that was added by warn. Not a big blocker, but sometimes, the note happening before a clear, a reboot, or a binary input might just pass as silence.

Your call, but its also part of why warn was used (the sleep) permitting user to acknoeldge in absence of output and action on the console.

Copy link
Collaborator

@tlaurion tlaurion left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

warn -> note : no 2 seconds sleep on note?

@tlaurion
Copy link
Collaborator

Ping @JonathonHall-Purism

@tlaurion
Copy link
Collaborator

tlaurion commented Apr 28, 2025

warn -> note : no 2 seconds sleep on note?

A sleep of 1 second would be enough.

This PR is LGTM and the proposed additional change can be discussed in another PR.

@tlaurion tlaurion merged commit 6256c7b into linuxboot:master Apr 28, 2025
47 checks passed
tlaurion added a commit to tlaurion/heads that referenced this pull request Apr 29, 2025
… prompt for recovery shell access, state where debug logs are in centralized way

Note for linuxboot#1888:
warn in code is used mostly to actually warn user of something requiring his attention, and pausing for 2 seconds.

Goal is:
die: blocking: tell user that something failed, requiring acknowledgement for corrective actions.
warn: display "WARNING:" prepended messages which pauses for 2 seconds prior of continuing. This is not an error, nor INFO
INFO: gives a trace to the user when in QUIET mode, under /tmp/debug.log related to core components output, typically related to measurements traces.

Consequently, putting what is currently under warn->INFO wold be console silenced. We want to get rid of manual "echo +++++" messages.
So it seems we lack what is currently named INFO to go into measurement_log, and INFO (green), warn (yellow) and die (red) messages to console.

Signed-off-by: Thierry Laurion <insurgo@riseup.net>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants