Skip to content

Commit df14882

Browse files
authored
feat(promslog): implement reserved keys, rename duplicates (#746)
* feat(promslog): implement reserved keys, rename duplicates 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: #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]>
1 parent 1cc5297 commit df14882

File tree

2 files changed

+115
-21
lines changed

2 files changed

+115
-21
lines changed

promslog/slog.go

+76-21
Original file line numberDiff line numberDiff line change
@@ -25,13 +25,16 @@ import (
2525
"path/filepath"
2626
"strconv"
2727
"strings"
28+
"time"
2829
)
2930

3031
type LogStyle string
3132

3233
const (
3334
SlogStyle LogStyle = "slog"
3435
GoKitStyle LogStyle = "go-kit"
36+
37+
reservedKeyPrefix = "logged_"
3538
)
3639

3740
var (
@@ -43,26 +46,51 @@ var (
4346
goKitStyleReplaceAttrFunc = func(groups []string, a slog.Attr) slog.Attr {
4447
key := a.Key
4548
switch key {
46-
case slog.TimeKey:
47-
a.Key = "ts"
48-
49-
// This timestamp format differs from RFC3339Nano by using .000 instead
50-
// of .999999999 which changes the timestamp from 9 variable to 3 fixed
51-
// decimals (.130 instead of .130987456).
52-
t := a.Value.Time()
53-
a.Value = slog.StringValue(t.UTC().Format("2006-01-02T15:04:05.000Z07:00"))
54-
case slog.SourceKey:
55-
a.Key = "caller"
56-
src, _ := a.Value.Any().(*slog.Source)
49+
case slog.TimeKey, "ts":
50+
if t, ok := a.Value.Any().(time.Time); ok {
51+
a.Key = "ts"
5752

58-
switch callerAddFunc {
59-
case true:
60-
a.Value = slog.StringValue(filepath.Base(src.File) + "(" + filepath.Base(src.Function) + "):" + strconv.Itoa(src.Line))
61-
default:
62-
a.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line))
53+
// This timestamp format differs from RFC3339Nano by using .000 instead
54+
// of .999999999 which changes the timestamp from 9 variable to 3 fixed
55+
// decimals (.130 instead of .130987456).
56+
a.Value = slog.StringValue(t.UTC().Format("2006-01-02T15:04:05.000Z07:00"))
57+
} else {
58+
// If we can't cast the any from the value to a
59+
// time.Time, it means the caller logged
60+
// another attribute with a key of `ts`.
61+
// Prevent duplicate keys (necessary for proper
62+
// JSON) by renaming the key to `logged_ts`.
63+
a.Key = reservedKeyPrefix + key
64+
}
65+
case slog.SourceKey, "caller":
66+
if src, ok := a.Value.Any().(*slog.Source); ok {
67+
a.Key = "caller"
68+
switch callerAddFunc {
69+
case true:
70+
a.Value = slog.StringValue(filepath.Base(src.File) + "(" + filepath.Base(src.Function) + "):" + strconv.Itoa(src.Line))
71+
default:
72+
a.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line))
73+
}
74+
} else {
75+
// If we can't cast the any from the value to
76+
// an *slog.Source, it means the caller logged
77+
// another attribute with a key of `caller`.
78+
// Prevent duplicate keys (necessary for proper
79+
// JSON) by renaming the key to
80+
// `logged_caller`.
81+
a.Key = reservedKeyPrefix + key
6382
}
6483
case slog.LevelKey:
65-
a.Value = slog.StringValue(strings.ToLower(a.Value.String()))
84+
if lvl, ok := a.Value.Any().(slog.Level); ok {
85+
a.Value = slog.StringValue(strings.ToLower(lvl.String()))
86+
} else {
87+
// If we can't cast the any from the value to
88+
// an slog.Level, it means the caller logged
89+
// another attribute with a key of `level`.
90+
// Prevent duplicate keys (necessary for proper
91+
// JSON) by renaming the key to `logged_level`.
92+
a.Key = reservedKeyPrefix + key
93+
}
6694
default:
6795
}
6896

@@ -72,11 +100,38 @@ var (
72100
key := a.Key
73101
switch key {
74102
case slog.TimeKey:
75-
t := a.Value.Time()
76-
a.Value = slog.TimeValue(t.UTC())
103+
if t, ok := a.Value.Any().(time.Time); ok {
104+
a.Value = slog.TimeValue(t.UTC())
105+
} else {
106+
// If we can't cast the any from the value to a
107+
// time.Time, it means the caller logged
108+
// another attribute with a key of `time`.
109+
// Prevent duplicate keys (necessary for proper
110+
// JSON) by renaming the key to `logged_time`.
111+
a.Key = reservedKeyPrefix + key
112+
}
77113
case slog.SourceKey:
78-
src, _ := a.Value.Any().(*slog.Source)
79-
a.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line))
114+
if src, ok := a.Value.Any().(*slog.Source); ok {
115+
a.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line))
116+
} else {
117+
// If we can't cast the any from the value to
118+
// an *slog.Source, it means the caller logged
119+
// another attribute with a key of `source`.
120+
// Prevent duplicate keys (necessary for proper
121+
// JSON) by renaming the key to
122+
// `logged_source`.
123+
a.Key = reservedKeyPrefix + key
124+
}
125+
case slog.LevelKey:
126+
if _, ok := a.Value.Any().(slog.Level); !ok {
127+
// If we can't cast the any from the value to
128+
// an slog.Level, it means the caller logged
129+
// another attribute with a key of `level`.
130+
// Prevent duplicate keys (necessary for proper
131+
// JSON) by renaming the key to
132+
// `logged_level`.
133+
a.Key = reservedKeyPrefix + key
134+
}
80135
default:
81136
}
82137

promslog/slog_test.go

+39
Original file line numberDiff line numberDiff line change
@@ -188,3 +188,42 @@ func TestTruncateSourceFileName_GoKitStyle(t *testing.T) {
188188
t.Errorf("Expected no directory separators in caller, got: %s", output)
189189
}
190190
}
191+
192+
func TestReservedKeys(t *testing.T) {
193+
var buf bytes.Buffer
194+
reservedKeyTestVal := "surprise! I'm a string"
195+
196+
tests := map[string]struct {
197+
logStyle LogStyle
198+
levelKey string
199+
sourceKey string
200+
timeKey string
201+
}{
202+
"slog_log_style": {logStyle: SlogStyle, levelKey: "level", sourceKey: "source", timeKey: "time"},
203+
"go-kit_log_style": {logStyle: GoKitStyle, levelKey: "level", sourceKey: "caller", timeKey: "ts"},
204+
}
205+
206+
for name, tc := range tests {
207+
t.Run(name, func(t *testing.T) {
208+
buf.Reset() // Ensure buf is reset prior to tests
209+
config := &Config{Writer: &buf, Style: tc.logStyle}
210+
logger := New(config)
211+
212+
logger.LogAttrs(context.Background(),
213+
slog.LevelInfo,
214+
"reserved keys test for "+name,
215+
slog.String(tc.levelKey, reservedKeyTestVal),
216+
slog.String(tc.sourceKey, reservedKeyTestVal),
217+
slog.String(tc.timeKey, reservedKeyTestVal),
218+
)
219+
220+
output := buf.String()
221+
require.Containsf(t, output, fmt.Sprintf("%s%s=\"%s\"", reservedKeyPrefix, tc.levelKey, reservedKeyTestVal), "Expected duplicate level key to be renamed")
222+
require.Containsf(t, output, fmt.Sprintf("%s%s=\"%s\"", reservedKeyPrefix, tc.sourceKey, reservedKeyTestVal), "Expected duplicate source key to be renamed")
223+
require.Containsf(t, output, fmt.Sprintf("%s%s=\"%s\"", reservedKeyPrefix, tc.timeKey, reservedKeyTestVal), "Expected duplicate time key to be renamed")
224+
225+
// Print logs for humans to see, if needed.
226+
fmt.Println(buf.String())
227+
})
228+
}
229+
}

0 commit comments

Comments
 (0)