Skip to content

Conversation

@jsha
Copy link
Contributor

@jsha jsha commented Aug 22, 2022

Right now, Boulder expects to be able to connect to syslog, and panics if it's not available. We'd like to be able to log to stdout/stderr as a replacement for syslog.

  • Add a detailed timestamp (down to microseconds, same as we collect in prod via syslog).
  • Remove the escape codes for colorizing output.
  • Report the severity level numerically rather than with a letter prefix.

Add locking for stdout/stderr and syslog logs. Neither the syslog package nor the os package document concurrency-safety, and the Go rule is: if it's not documented to be concurrent-safe, it's not. Notably the log.Logger package is documented to be concurrent-safe, and a look at its implementation shows it uses a Mutex internally.

Remove places that use the singleton blog.Get(), and instead pass through a logger from main in all the places that need it.

Also note: this makes the log lines noticeably longer. We can reclaim a little space during interactive sessions by running, e.g. docker-compose up --no-log-prefix, which omits the boulder-boulder-1 prefix that docker-compose normally adds.

jsha added 4 commits August 23, 2022 12:54
Our stdout logger was mainly used for interactive terminals, and so
reported a truncated timestamp and used terminal escape codes for color.
Add a detailed timestamp (down to microseconds, same as we collect in
prod via syslog), and remove the escape codes. This makes stdout
suitable for directly collecting.
Go's stdout and syslog interfaces do not guarantee that they are safe
for concurrent access, so we should not write to them concurrently.
@jsha jsha force-pushed the timestamped-stdout branch from 9bea0ab to a3b8d16 Compare August 23, 2022 20:18
@jsha jsha marked this pull request as ready for review August 24, 2022 19:08
@jsha jsha requested a review from a team as a code owner August 24, 2022 19:08
Copy link
Contributor

@aarongable aarongable left a comment

Choose a reason for hiding this comment

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

Do we have interest in having logs above a certain level (e.g. Warning+Error) go to stderr instead of stdout? If yes, it seems wise to do that sooner rather than later so we're not changing our logging setup too many times in rapid succession.

Also, since you note in the PR description that "it's not concurrency-safe unless it says it is", this package should now document that the Logger type is concurrency-safe.

edit: Oh, also just realized that this means that our integration test output is no longer going to be colorized. Getting that back somehow would be nice.

@jsha jsha changed the title Improve stdout logger log: allow logging to stdout/stderr instead of syslog Aug 25, 2022
@jsha
Copy link
Contributor Author

jsha commented Aug 25, 2022

Oh, also just realized that this means that our integration test output is no longer going to be colorized. Getting that back somehow would be nice.

Added back colorization, when output is a terminal. This takes effect when using docker-compose run (e.g. in our integration tests) but not when using docker-compose up (presumably because logs are collected by docker and then relayed by docker-compose, so boulder isn't directly talking to a terminal).

Copy link
Contributor

@aarongable aarongable left a comment

Choose a reason for hiding this comment

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

LGTM aside from the compilation error

@beautifulentropy
Copy link
Member

Do we have interest in having logs above a certain level (e.g. Warning+Error) go to stderr instead of stdout? If yes, it seems wise to do that sooner rather than later so we're not changing our logging setup too many times in rapid succession.

Also, since you note in the PR description that "it's not concurrency-safe unless it says it is", this package should now document that the Logger type is concurrency-safe.

edit: Oh, also just realized that this means that our integration test output is no longer going to be colorized. Getting that back somehow would be nice.

Convenience +1 here as the log viewing interface provided by our orchestration system exposes a nice stderr only view to the operator.

@jsha
Copy link
Contributor Author

jsha commented Aug 26, 2022

I tried adding the stdout/stderr split, and it mysteriously broke test/integration/caa_test.go. That integration test runs the caa-log-checker against /var/log/boulder-ra.log and /var/log/boulder-va.log (emitted by rsyslog), and ensures that it successfully handles a simple issuance. I've tried a bunch of things but haven't been able to figure out why a change that sends some error messages to stderr would affect that test. The messages it cares about aren't errors or warnings. And the log files it cares about are emitted by rsyslog, not stderr/stdout.

I propose to address this in a followup #6324.

@jsha jsha merged commit dd1c525 into main Aug 29, 2022
@jsha jsha deleted the timestamped-stdout branch August 29, 2022 13:19
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.

4 participants