Upgrade all audit log lines to structured json#8595
Conversation
beautifulentropy
left a comment
There was a problem hiding this comment.
Overall this change look great. There were just a handful of things that I wanted to call your attention to.
| "issuer": issuer.Cert.Subject.CommonName, | ||
| "number": req.Number.String(), | ||
| "shard": req.Shard, | ||
| "thisUpdate": req.ThisUpdate, |
There was a problem hiding this comment.
As @beautifulentropy pointed out, there are sometimes differences between %s formatting and json.Marshal() formatting for a given type. For instance, req.ThisUpdate is time.Time.
https://go.dev/play/p/CFnVuThyA-k
t, err := time.Parse(time.RFC3339, "2009-11-10T23:00:00Z")
if err != nil {
log.Fatal(err)
}
fmt.Printf("%s\n", t)
b, err := json.Marshal(map[string]any{"t": t})
if err != nil {
log.Fatal(err)
}
fmt.Printf("%s\n", string(b))
2009-11-10 23:00:00 +0000 UTC
{"t":"2009-11-10T23:00:00Z"}
I'd prefer to avoid spurious differences in the values of these as we switch over. Also, this caused me to check the slog docs:
https://pkg.go.dev/log/slog#TextHandler.Handle
If a value implements encoding.TextMarshaler, the result of MarshalText is written. Otherwise, the result of fmt.Sprint is written.
https://pkg.go.dev/log/slog#JSONHandler.Handle
Values are formatted as with an encoding/json.Encoder with SetEscapeHTML(false), with two exceptions.
First, an Attr whose Value is of type error is formatted as a string, by calling its Error method. Only errors in Attrs receive this special treatment, not errors embedded in structs, slices, maps or other data structures that are processed by the encoding/json package.
Second, an encoding failure does not cause Handle to return an error. Instead, the error message is formatted as a string.
So, something to be aware of since we'll be looking at TextHandler output for casual use in CI, but JSONHandler output for actual logging.
As a programmatic way to catch all the spots where we might not be being explicit in this PR, how about this:
- Change AuditInfo / AuditErr to take
map[string]stringinstead ofmap[string]any. - Call
.String()explicitly where needed.
There was a problem hiding this comment.
I really like the idea of map[string]string, but it becomes very unwieldy in practice. Every integer and boolean requires fmt.Sprintf("%d", value), every slice requires even more custom serialization, and the result is that we're not actually logging any JSON values other than strings -- booleans, numbers, and slices are all quoted, which is not great.
I've gone through and found all the places I put errors and time.Times in these maps, and ensured we're calling .Format() or .String() as appropriate. And this problem will largely go away with slog, which has special handling for time and error Attrs.
In the log package, remove all audit-level helper functions except for AuditErr and AuditObject, and rename the latter to AuditInfo to reflect its log level. Update both of those helpers to take arbitrary sets of key-value pairs (a map in the case of AuditErr, or any object in the case of AuditInfo to support our existing logEvent structs), which they then log as a JSON object.
Throughout the rest of the code base, modify all audit log calls which are broken by the above change. In some cases, downgrade the log line from an audit log to a normal log, as it does not represent an event which the BRs require us to log and which we are not already logging elsewhere. In other cases, provide a map of key-value pairs to be included in the log message.
Finally, update a small number of tests that were expecting very specific log message formats to be emitted.
Fixes #8554