Skip to content

Commit 6ea2584

Browse files
tjhoptjhop
committed
feat: new promslog and promslog/flag packages to wrap log/slog
Prereq for prometheus/prometheus#14355 This adds a new `promslog` package to create an opinionated slog logger for use within the prometheus ecosystem. By default, logs are written at `info` level and formatted to add a kv pair for the source caller. If backwards compatibility for the literal output format of the logging is required, logs can be styled in a format that is similar to how the `promlog` package formatted it's go-kit/log output [1]. The `promslog` package also makes use of an `slog.LevelVar` to dynamically adjust the level of an existing logger. Similar to the old `promlog` package, we provide means to log in `logfmt` and `json` output formats. Creating a logger is similar to the old promlog package -- optionally populate a `Config` struct, and then call `New()` with the config. In order to dynamically adjust the logger's level, retain the `Config` struct as it's own variable to access the `AllowedLevel.Set()` method, which internally updates the `AllowedLevel`'s slog.LevelVar to the desired log level. Ex: ```go config := &promslog.Config{} // Retain as variable if you need to dynamically adjust log level logger := promslog.New(config) config.Level.Set("debug") logger.Debug("your message here", "hello", "world") ``` To use go-kit style log output: ```go config := &promslog.Config{Style: promslog.GoKitStyle} // Retain as variable if you need to dynamically adjust log level logger := promslog.New(config) config.Level.Set("debug") logger.Debug("your message here", "hello", "world") ``` 1. When using the `go-kit` log style, the following changes are made to the default slog output: - adjusts slog default timestamp key from `timestamp` -> `ts` - adjusts the timestamp value to use the same time format string ("2006-01-02T15:04:05.000Z07:00") - adjusts slog default sourcecode key from `source` -> `caller` - adjusts the formatting of the sourcecode values to trim paths with `filepath.Base()`. The formatting of the sourcecode value is similar to the go-kit/log usage, with the addition of the source function in parenthesis when debug logging is enabled. Signed-off-by: TJ Hoplock <[email protected]>
1 parent 6623230 commit 6ea2584

File tree

3 files changed

+388
-0
lines changed

3 files changed

+388
-0
lines changed

‎promslog/flag/flag.go

+56
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,56 @@
1+
// Copyright 2024 The Prometheus Authors
2+
// Licensed under the Apache License, Version 2.0 (the "License");
3+
// you may not use this file except in compliance with the License.
4+
// You may obtain a copy of the License at
5+
//
6+
// http://www.apache.org/licenses/LICENSE-2.0
7+
//
8+
// Unless required by applicable law or agreed to in writing, software
9+
// distributed under the License is distributed on an "AS IS" BASIS,
10+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
11+
// See the License for the specific language governing permissions and
12+
// limitations under the License.
13+
14+
// Package flag defines standardised flag interactions for use with promslog
15+
// across Prometheus components.
16+
// It should typically only ever be imported by main packages.
17+
18+
//go:build go1.21
19+
20+
package flag
21+
22+
import (
23+
"strings"
24+
25+
kingpin "github.com/alecthomas/kingpin/v2"
26+
27+
"github.com/prometheus/common/promslog"
28+
)
29+
30+
// LevelFlagName is the canonical flag name to configure the allowed log level
31+
// within Prometheus projects.
32+
const LevelFlagName = "log.level"
33+
34+
// LevelFlagHelp is the help description for the log.level flag.
35+
var LevelFlagHelp = "Only log messages with the given severity or above. One of: [" + strings.Join(promslog.LevelFlagOptions, ", ") + "]"
36+
37+
// FormatFlagName is the canonical flag name to configure the log format
38+
// within Prometheus projects.
39+
const FormatFlagName = "log.format"
40+
41+
// FormatFlagHelp is the help description for the log.format flag.
42+
var FormatFlagHelp = "Output format of log messages. One of: [" + strings.Join(promslog.FormatFlagOptions, ", ") + "]"
43+
44+
// AddFlags adds the flags used by this package to the Kingpin application.
45+
// To use the default Kingpin application, call AddFlags(kingpin.CommandLine)
46+
func AddFlags(a *kingpin.Application, config *promslog.Config) {
47+
config.Level = &promslog.AllowedLevel{}
48+
a.Flag(LevelFlagName, LevelFlagHelp).
49+
Default("info").HintOptions(promslog.LevelFlagOptions...).
50+
SetValue(config.Level)
51+
52+
config.Format = &promslog.AllowedFormat{}
53+
a.Flag(FormatFlagName, FormatFlagHelp).
54+
Default("logfmt").HintOptions(promslog.FormatFlagOptions...).
55+
SetValue(config.Format)
56+
}

‎promslog/slog.go

+182
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,182 @@
1+
// Copyright 2024 The Prometheus Authors
2+
// Licensed under the Apache License, Version 2.0 (the "License");
3+
// you may not use this file except in compliance with the License.
4+
// You may obtain a copy of the License at
5+
//
6+
// http://www.apache.org/licenses/LICENSE-2.0
7+
//
8+
// Unless required by applicable law or agreed to in writing, software
9+
// distributed under the License is distributed on an "AS IS" BASIS,
10+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
11+
// See the License for the specific language governing permissions and
12+
// limitations under the License.
13+
14+
// Package promslog defines standardised ways to initialize the Go standard
15+
// library's log/slog logger.
16+
// It should typically only ever be imported by main packages.
17+
18+
//go:build go1.21
19+
20+
package promslog
21+
22+
import (
23+
"fmt"
24+
"io"
25+
"log/slog"
26+
"os"
27+
"path/filepath"
28+
"strconv"
29+
"strings"
30+
)
31+
32+
type LogStyle string
33+
34+
const (
35+
SlogStyle LogStyle = "slog"
36+
GoKitStyle LogStyle = "go-kit"
37+
)
38+
39+
var (
40+
LevelFlagOptions = []string{"debug", "info", "warn", "error"}
41+
FormatFlagOptions = []string{"logfmt", "json"}
42+
43+
callerAddFunc = false
44+
defaultWriter = os.Stderr
45+
goKitStyleReplaceAttrFunc = func(groups []string, a slog.Attr) slog.Attr {
46+
key := a.Key
47+
switch key {
48+
case slog.TimeKey:
49+
a.Key = "ts"
50+
51+
// This timestamp format differs from RFC3339Nano by using .000 instead
52+
// of .999999999 which changes the timestamp from 9 variable to 3 fixed
53+
// decimals (.130 instead of .130987456).
54+
t := a.Value.Time()
55+
a.Value = slog.StringValue(t.Format("2006-01-02T15:04:05.000Z07:00"))
56+
case slog.SourceKey:
57+
a.Key = "caller"
58+
src, _ := a.Value.Any().(*slog.Source)
59+
60+
switch callerAddFunc {
61+
case true:
62+
a.Value = slog.StringValue(filepath.Base(src.File) + "(" + filepath.Base(src.Function) + "):" + strconv.Itoa(src.Line))
63+
default:
64+
a.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line))
65+
}
66+
case slog.LevelKey:
67+
a.Value = slog.StringValue(strings.ToLower(a.Value.String()))
68+
default:
69+
}
70+
71+
return a
72+
}
73+
)
74+
75+
// AllowedLevel is a settable identifier for the minimum level a log entry
76+
// must be have.
77+
type AllowedLevel struct {
78+
s string
79+
lvl *slog.LevelVar
80+
}
81+
82+
func (l *AllowedLevel) UnmarshalYAML(unmarshal func(interface{}) error) error {
83+
var s string
84+
type plain string
85+
if err := unmarshal((*plain)(&s)); err != nil {
86+
return err
87+
}
88+
if s == "" {
89+
return nil
90+
}
91+
lo := &AllowedLevel{}
92+
if err := lo.Set(s); err != nil {
93+
return err
94+
}
95+
*l = *lo
96+
return nil
97+
}
98+
99+
func (l *AllowedLevel) String() string {
100+
return l.s
101+
}
102+
103+
// Set updates the value of the allowed level.
104+
func (l *AllowedLevel) Set(s string) error {
105+
if l.lvl == nil {
106+
l.lvl = &slog.LevelVar{}
107+
}
108+
109+
switch s {
110+
case "debug":
111+
l.lvl.Set(slog.LevelDebug)
112+
callerAddFunc = true
113+
case "info":
114+
l.lvl.Set(slog.LevelInfo)
115+
callerAddFunc = false
116+
case "warn":
117+
l.lvl.Set(slog.LevelWarn)
118+
callerAddFunc = false
119+
case "error":
120+
l.lvl.Set(slog.LevelError)
121+
callerAddFunc = false
122+
default:
123+
return fmt.Errorf("unrecognized log level %s", s)
124+
}
125+
l.s = s
126+
return nil
127+
}
128+
129+
// AllowedFormat is a settable identifier for the output format that the logger can have.
130+
type AllowedFormat struct {
131+
s string
132+
}
133+
134+
func (f *AllowedFormat) String() string {
135+
return f.s
136+
}
137+
138+
// Set updates the value of the allowed format.
139+
func (f *AllowedFormat) Set(s string) error {
140+
switch s {
141+
case "logfmt", "json":
142+
f.s = s
143+
default:
144+
return fmt.Errorf("unrecognized log format %s", s)
145+
}
146+
return nil
147+
}
148+
149+
// Config is a struct containing configurable settings for the logger
150+
type Config struct {
151+
Level *AllowedLevel
152+
Format *AllowedFormat
153+
Style LogStyle
154+
ioWriter io.Writer
155+
}
156+
157+
// New returns a new slog.Logger. Each logged line will be annotated
158+
// with a timestamp. The output always goes to stderr.
159+
func New(config *Config) *slog.Logger {
160+
if config.Level == nil {
161+
config.Level = &AllowedLevel{}
162+
_ = config.Level.Set("info")
163+
}
164+
165+
if config.ioWriter == nil {
166+
config.ioWriter = defaultWriter
167+
}
168+
169+
logHandlerOpts := &slog.HandlerOptions{
170+
Level: config.Level.lvl,
171+
AddSource: true,
172+
}
173+
174+
if config.Style == GoKitStyle {
175+
logHandlerOpts.ReplaceAttr = goKitStyleReplaceAttrFunc
176+
}
177+
178+
if config.Format != nil && config.Format.s == "json" {
179+
return slog.New(slog.NewJSONHandler(config.ioWriter, logHandlerOpts))
180+
}
181+
return slog.New(slog.NewTextHandler(config.ioWriter, logHandlerOpts))
182+
}

‎promslog/slog_test.go

+150
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,150 @@
1+
// Copyright 2024 The Prometheus Authors
2+
// Licensed under the Apache License, Version 2.0 (the "License");
3+
// you may not use this file except in compliance with the License.
4+
// You may obtain a copy of the License at
5+
//
6+
// http://www.apache.org/licenses/LICENSE-2.0
7+
//
8+
// Unless required by applicable law or agreed to in writing, software
9+
// distributed under the License is distributed on an "AS IS" BASIS,
10+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
11+
// See the License for the specific language governing permissions and
12+
// limitations under the License.
13+
14+
//go:build go1.21
15+
16+
package promslog
17+
18+
import (
19+
"bytes"
20+
"context"
21+
"fmt"
22+
"log/slog"
23+
"regexp"
24+
"strings"
25+
"testing"
26+
27+
"github.com/stretchr/testify/require"
28+
"gopkg.in/yaml.v2"
29+
)
30+
31+
var (
32+
slogStyleLogRegexp = regexp.MustCompile(`(?P<TimeKey>time)=.*level=(?P<LevelValue>WARN|INFO|ERROR|DEBUG).*(?P<SourceKey>source)=.*`)
33+
goKitStyleLogRegexp = regexp.MustCompile(`(?P<TimeKey>ts)=.*level=(?P<LevelValue>warn|info|error|debug).*(?P<SourceKey>caller)=.*`)
34+
)
35+
36+
// Make sure creating and using a logger with an empty configuration doesn't
37+
// result in a panic.
38+
func TestDefaultConfig(t *testing.T) {
39+
require.NotPanics(t, func() {
40+
logger := New(&Config{})
41+
logger.Info("empty config `Info()` test", "hello", "world")
42+
logger.Log(context.Background(), slog.LevelInfo, "empty config `Log()` test", "hello", "world")
43+
logger.LogAttrs(context.Background(), slog.LevelInfo, "empty config `LogAttrs()` test", slog.String("hello", "world"))
44+
})
45+
}
46+
47+
func TestUnmarshallLevel(t *testing.T) {
48+
l := &AllowedLevel{}
49+
err := yaml.Unmarshal([]byte(`debug`), l)
50+
if err != nil {
51+
t.Error(err)
52+
}
53+
if l.s != "debug" {
54+
t.Errorf("expected %s, got %s", "debug", l.s)
55+
}
56+
}
57+
58+
func TestUnmarshallEmptyLevel(t *testing.T) {
59+
l := &AllowedLevel{}
60+
err := yaml.Unmarshal([]byte(``), l)
61+
if err != nil {
62+
t.Error(err)
63+
}
64+
if l.s != "" {
65+
t.Errorf("expected empty level, got %s", l.s)
66+
}
67+
}
68+
69+
func TestUnmarshallBadLevel(t *testing.T) {
70+
l := &AllowedLevel{}
71+
err := yaml.Unmarshal([]byte(`debugg`), l)
72+
if err == nil {
73+
t.Error("expected error")
74+
}
75+
expErr := `unrecognized log level debugg`
76+
if err.Error() != expErr {
77+
t.Errorf("expected error %s, got %s", expErr, err.Error())
78+
}
79+
if l.s != "" {
80+
t.Errorf("expected empty level, got %s", l.s)
81+
}
82+
}
83+
84+
func getLogEntryLevelCounts(s string, re *regexp.Regexp) map[string]int {
85+
counters := make(map[string]int)
86+
lines := strings.Split(s, "\n")
87+
for _, line := range lines {
88+
matches := re.FindStringSubmatch(line)
89+
if len(matches) > 1 {
90+
levelIndex := re.SubexpIndex("LevelValue")
91+
92+
counters[strings.ToLower(matches[levelIndex])]++
93+
}
94+
}
95+
96+
return counters
97+
}
98+
99+
func TestDynamicLevels(t *testing.T) {
100+
var buf bytes.Buffer
101+
wantedLevelCounts := map[string]int{"info": 1, "debug": 1}
102+
103+
tests := map[string]struct {
104+
logStyle LogStyle
105+
logStyleRegexp *regexp.Regexp
106+
wantedLevelCount map[string]int
107+
}{
108+
"slog_log_style": {logStyle: SlogStyle, logStyleRegexp: slogStyleLogRegexp, wantedLevelCount: wantedLevelCounts},
109+
"go-kit_log_style": {logStyle: GoKitStyle, logStyleRegexp: goKitStyleLogRegexp, wantedLevelCount: wantedLevelCounts},
110+
}
111+
112+
for name, tc := range tests {
113+
t.Run(name, func(t *testing.T) {
114+
buf.Reset() // Ensure buf is reset prior to tests
115+
config := &Config{ioWriter: &buf, Style: tc.logStyle}
116+
logger := New(config)
117+
118+
// Test that log level can be adjusted on-the-fly to debug and that a
119+
// log entry can be written to the file.
120+
if err := config.Level.Set("debug"); err != nil {
121+
t.Fatal(err)
122+
}
123+
logger.Info("info", "hello", "world")
124+
logger.Debug("debug", "hello", "world")
125+
126+
counts := getLogEntryLevelCounts(buf.String(), tc.logStyleRegexp)
127+
require.Equal(t, tc.wantedLevelCount["info"], counts["info"], "info log successfully detected")
128+
require.Equal(t, tc.wantedLevelCount["debug"], counts["debug"], "debug log successfully detected")
129+
// Print logs for humans to see, if needed.
130+
fmt.Println(buf.String())
131+
buf.Reset()
132+
133+
// Test that log level can be adjusted on-the-fly to info and that a
134+
// subsequent call to write a debug level log is _not_ written to the
135+
// file.
136+
if err := config.Level.Set("info"); err != nil {
137+
t.Fatal(err)
138+
}
139+
logger.Info("info", "hello", "world")
140+
logger.Debug("debug", "hello", "world")
141+
142+
counts = getLogEntryLevelCounts(buf.String(), tc.logStyleRegexp)
143+
require.Equal(t, tc.wantedLevelCount["info"], counts["info"], "info log successfully detected")
144+
require.NotEqual(t, tc.wantedLevelCount["debug"], counts["debug"], "extra debug log detected")
145+
// Print logs for humans to see, if needed.
146+
fmt.Println(buf.String())
147+
buf.Reset()
148+
})
149+
}
150+
}

0 commit comments

Comments
 (0)