bug: promslog panics if a user sets a log attribute with a key of source
#745
Comments
|
We could do something similar to what we do for labels in Prometheus. We can have a set of reserved keys and rename duplicate keys to |
tjhop
added a commit
to tjhop/common
that referenced
this issue
Jan 13, 2025
This commit adds support for "reserved" keys, where upon detecting a duplicate log attribute key, it will rename the key to prevent collisions/issues with core slog attribute keys in use. The reserved keys are: - `level` - `source` (for standard slog style) - `caller` (for legacy go-kit style) - `time` (for standard slog style) - `ts` (for legacy go-kit style) By supporting reserved keys, we allow users of the library to use these keys for their own supplemental log attributes. Fixes: prometheus#745 Example test output: ``` === RUN TestReservedKeys/slog_log_style time=2025-01-13T18:32:46.508Z level=INFO source=slog_test.go:212 msg="reserved keys test for slog_log_style" logged_level="surprise! I'm a string" logged_source="surprise! I'm a string" logged_time="surprise! I'm a string" === RUN TestReservedKeys/go-kit_log_style ts=2025-01-13T18:32:46.508Z level=info caller=slog_test.go:212 msg="reserved keys test for go-kit_log_style" logged_level="surprise! I'm a string" logged_caller="surprise! I'm a string" logged_ts="surprise! I'm a string" ``` Note: this implementation only technically removes duplicates of our core reserved keys. If a user adds multiple instances of a reserved key, the rest get renamed to `logged_$key`, which means there could be duplicate attributes with `logged_$key`. This is mostly to simplify implementation so we don't need to bother reference counting in the replace attr function to do things like `logged_$key1`, `logged_$key2`, etc. Signed-off-by: TJ Hoplock <[email protected]>
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
This issue is for tracking purposes, @SuperQ and I are discussing things further in slack.
In our slog implementation, we always instruct slog to emit source code info of the calling log statement:
https://github.com/prometheus/common/blob/main/promslog/slog.go#L183
We also do some default formatting of the resulting source code position info, both in the default implementation and the legacy go-kit styled implementation:
https://github.com/prometheus/common/blob/main/promslog/slog.go#L77-L79
https://github.com/prometheus/common/blob/main/promslog/slog.go#L54-L63
As mentioned in slog's docs, the
AddSourcefield adds a key-value pair onto the logger keyed bySourceKey, which is a constant value ofsource:https://pkg.go.dev/log/slog#pkg-constants
We key on that
SourceKeyin ourReplaceAttrfuncs that we use for formatting log lines, and when an attribute is found with a key equal toSourceKey, it extracts theanyfrom the value and casts it to an*slog.Source. We do not check the error from the type cast, as slog always adds source info as an attribute with a key ofSourceKeyand value ofslog.Source.This implementation is naive, as users may add their own attributes with a key of
source, causing promslog to panic:SuperQ/chrony_exporter#107
Putting aside the usefulness/validity of duplicate keys in a structured log message, this is quite the landmine for users to run into, and promslog should handle it more gracefully.
The text was updated successfully, but these errors were encountered: