Print nice journal messages

[adombeck]

They used to look like this

Jan 07 14:27:26 ubuntu authd-msentraid.authd-msentraid[44768]: time=2025-01-07T14:27:26.272+01:00 level=INFO msg="Serving requests as com.ubuntu.authd.MSEntraID"

now they look like this

Jan 09 17:48:31 ubuntu authd-msentraid[8991]: Serving requests as com.ubuntu.authd.MSEntraID

and also use the corresponding journal priorities so that those can be filtered and are displayed as expected (i.e. with color and boldness).

UDENG-4523

[didrocks]

I am a little bit uneasy with a special formatting if the output is not a TTY:

Maybe it’s not the journal, and you want just to redirect to a file, so you run the executable, you end up with the logs in one way, you rerun and redirect to a file, and the formatting is different! I think if we want different formatting, then only have this journal format when under systemd to the journal (even if in general, contrary to previous syslog, you shouldn’t really worry about the output formatting, but I agree the time stuttering is something to fix.

Also, we should have tests for all of those (formatting writing, ensuring there is no date for the journal) and detection.

[adombeck]

Maybe it’s not the journal, and you want just to redirect to a file

Valid point. Taking a step back, maybe we don't need to support anything else than logging to the journal (for now)? At least I've never had a use case to run the broker (or authd) directly instead of via the systemd service - and even if I did, I don't think I would mind reading the logs via the journal. What do you think?

[adombeck]

If at some point we have a use case to print the logs to stdout/stderr, we could add a --output <stdout|journal> flag.

[adombeck]

I am a little bit uneasy with a special formatting if the output is not a TTY

As discussed, I'm now using journal.StderrIsJournalStream() to decide whether to log to the journal or to stderr.

Also, we should have tests for all of those (formatting writing, ensuring there is no date for the journal) and detection.

I tried but didn't manage to get journal.StderrIsJournalStream() to return true in tests. Checking the formatting of the journal seems overkill, because it requires actually fetching messages from the log via journalctl -f (there are no Go binding). I manually tested that the formatting is as expected.

[didrocks]

I tried but didn't manage to get journal.StderrIsJournalStream() to return true in tests. Checking the formatting of the journal seems overkill, because it requires actually fetching messages from the log via journalctl -f (there are no Go binding). I manually tested that the formatting is as expected.

Ok, so the decision factor may be overkill to test with those constraints. However, I would still like to see test for the formatter itself, which could be easily tested and not relying on the journal for those.

[adombeck]

However, I would still like to see test for the formatter itself, which could be easily tested and not relying on the journal for those.

True, we could test the formatter itself. However, if we want to use authd's log package in the broker, those tests would become obsolete, because as @3v1n0 pointed out, in the log package we can just use journal.Print(mapPriority(level), format, args...) instead of a custom handler (see ubuntu/authd#720). I think it would make sense to re-use authd's log package in the broker, firstly for consistency and secondly because it's more comfortable to use (especially the Debugf, Infof etc. methods are more comfortable to use than slog.Debug(fmt.Sprintf(...))). WDYT?

[adombeck]

True, we could test the formatter itself. However, if we want to use authd's log package in the broker, those tests would become obsolete, because as @3v1n0 pointed out, in the log package we can just use journal.Print(mapPriority(level), format, args...) instead of a custom handler (see ubuntu/authd#720). I think it would make sense to re-use authd's log package in the broker, firstly for consistency and secondly because it's more comfortable to use (especially the Debugf, Infof etc. methods are more comfortable to use than slog.Debug(fmt.Sprintf(...))). WDYT?

We decided out-of-band to try using the log package from authd instead

[adombeck]

Superseded by #315