diff --git a/promslog/flag/flag.go b/promslog/flag/flag.go new file mode 100644 index 00000000..34edb6ff --- /dev/null +++ b/promslog/flag/flag.go @@ -0,0 +1,56 @@ +// Copyright 2024 The Prometheus Authors +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +// Package flag defines standardised flag interactions for use with promslog +// across Prometheus components. +// It should typically only ever be imported by main packages. + +//go:build go1.21 + +package flag + +import ( + "strings" + + kingpin "github.com/alecthomas/kingpin/v2" + + "github.com/prometheus/common/promslog" +) + +// LevelFlagName is the canonical flag name to configure the allowed log level +// within Prometheus projects. +const LevelFlagName = "log.level" + +// LevelFlagHelp is the help description for the log.level flag. +var LevelFlagHelp = "Only log messages with the given severity or above. One of: [" + strings.Join(promslog.LevelFlagOptions, ", ") + "]" + +// FormatFlagName is the canonical flag name to configure the log format +// within Prometheus projects. +const FormatFlagName = "log.format" + +// FormatFlagHelp is the help description for the log.format flag. +var FormatFlagHelp = "Output format of log messages. One of: [" + strings.Join(promslog.FormatFlagOptions, ", ") + "]" + +// AddFlags adds the flags used by this package to the Kingpin application. +// To use the default Kingpin application, call AddFlags(kingpin.CommandLine) +func AddFlags(a *kingpin.Application, config *promslog.Config) { + config.Level = &promslog.AllowedLevel{} + a.Flag(LevelFlagName, LevelFlagHelp). + Default("info").HintOptions(promslog.LevelFlagOptions...). + SetValue(config.Level) + + config.Format = &promslog.AllowedFormat{} + a.Flag(FormatFlagName, FormatFlagHelp). + Default("logfmt").HintOptions(promslog.FormatFlagOptions...). + SetValue(config.Format) +} diff --git a/promslog/slog.go b/promslog/slog.go new file mode 100644 index 00000000..7fb24d41 --- /dev/null +++ b/promslog/slog.go @@ -0,0 +1,182 @@ +// Copyright 2024 The Prometheus Authors +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +// Package promslog defines standardised ways to initialize the Go standard +// library's log/slog logger. +// It should typically only ever be imported by main packages. + +//go:build go1.21 + +package promslog + +import ( + "fmt" + "io" + "log/slog" + "os" + "path/filepath" + "strconv" + "strings" +) + +type LogStyle string + +const ( + SlogStyle LogStyle = "slog" + GoKitStyle LogStyle = "go-kit" +) + +var ( + LevelFlagOptions = []string{"debug", "info", "warn", "error"} + FormatFlagOptions = []string{"logfmt", "json"} + + callerAddFunc = false + defaultWriter = os.Stderr + goKitStyleReplaceAttrFunc = func(groups []string, a slog.Attr) slog.Attr { + key := a.Key + switch key { + case slog.TimeKey: + a.Key = "ts" + + // This timestamp format differs from RFC3339Nano by using .000 instead + // of .999999999 which changes the timestamp from 9 variable to 3 fixed + // decimals (.130 instead of .130987456). + t := a.Value.Time() + a.Value = slog.StringValue(t.Format("2006-01-02T15:04:05.000Z07:00")) + case slog.SourceKey: + a.Key = "caller" + src, _ := a.Value.Any().(*slog.Source) + + switch callerAddFunc { + case true: + a.Value = slog.StringValue(filepath.Base(src.File) + "(" + filepath.Base(src.Function) + "):" + strconv.Itoa(src.Line)) + default: + a.Value = slog.StringValue(filepath.Base(src.File) + ":" + strconv.Itoa(src.Line)) + } + case slog.LevelKey: + a.Value = slog.StringValue(strings.ToLower(a.Value.String())) + default: + } + + return a + } +) + +// AllowedLevel is a settable identifier for the minimum level a log entry +// must be have. +type AllowedLevel struct { + s string + lvl *slog.LevelVar +} + +func (l *AllowedLevel) UnmarshalYAML(unmarshal func(interface{}) error) error { + var s string + type plain string + if err := unmarshal((*plain)(&s)); err != nil { + return err + } + if s == "" { + return nil + } + lo := &AllowedLevel{} + if err := lo.Set(s); err != nil { + return err + } + *l = *lo + return nil +} + +func (l *AllowedLevel) String() string { + return l.s +} + +// Set updates the value of the allowed level. +func (l *AllowedLevel) Set(s string) error { + if l.lvl == nil { + l.lvl = &slog.LevelVar{} + } + + switch s { + case "debug": + l.lvl.Set(slog.LevelDebug) + callerAddFunc = true + case "info": + l.lvl.Set(slog.LevelInfo) + callerAddFunc = false + case "warn": + l.lvl.Set(slog.LevelWarn) + callerAddFunc = false + case "error": + l.lvl.Set(slog.LevelError) + callerAddFunc = false + default: + return fmt.Errorf("unrecognized log level %s", s) + } + l.s = s + return nil +} + +// AllowedFormat is a settable identifier for the output format that the logger can have. +type AllowedFormat struct { + s string +} + +func (f *AllowedFormat) String() string { + return f.s +} + +// Set updates the value of the allowed format. +func (f *AllowedFormat) Set(s string) error { + switch s { + case "logfmt", "json": + f.s = s + default: + return fmt.Errorf("unrecognized log format %s", s) + } + return nil +} + +// Config is a struct containing configurable settings for the logger +type Config struct { + Level *AllowedLevel + Format *AllowedFormat + Style LogStyle + ioWriter io.Writer +} + +// New returns a new slog.Logger. Each logged line will be annotated +// with a timestamp. The output always goes to stderr. +func New(config *Config) *slog.Logger { + if config.Level == nil { + config.Level = &AllowedLevel{} + _ = config.Level.Set("info") + } + + if config.ioWriter == nil { + config.ioWriter = defaultWriter + } + + logHandlerOpts := &slog.HandlerOptions{ + Level: config.Level.lvl, + AddSource: true, + } + + if config.Style == GoKitStyle { + logHandlerOpts.ReplaceAttr = goKitStyleReplaceAttrFunc + } + + if config.Format != nil && config.Format.s == "json" { + return slog.New(slog.NewJSONHandler(config.ioWriter, logHandlerOpts)) + } + return slog.New(slog.NewTextHandler(config.ioWriter, logHandlerOpts)) +} diff --git a/promslog/slog_test.go b/promslog/slog_test.go new file mode 100644 index 00000000..5f37e189 --- /dev/null +++ b/promslog/slog_test.go @@ -0,0 +1,150 @@ +// Copyright 2024 The Prometheus Authors +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +//go:build go1.21 + +package promslog + +import ( + "bytes" + "context" + "fmt" + "log/slog" + "regexp" + "strings" + "testing" + + "github.com/stretchr/testify/require" + "gopkg.in/yaml.v2" +) + +var ( + slogStyleLogRegexp = regexp.MustCompile(`(?Ptime)=.*level=(?PWARN|INFO|ERROR|DEBUG).*(?Psource)=.*`) + goKitStyleLogRegexp = regexp.MustCompile(`(?Pts)=.*level=(?Pwarn|info|error|debug).*(?Pcaller)=.*`) +) + +// Make sure creating and using a logger with an empty configuration doesn't +// result in a panic. +func TestDefaultConfig(t *testing.T) { + require.NotPanics(t, func() { + logger := New(&Config{}) + logger.Info("empty config `Info()` test", "hello", "world") + logger.Log(context.Background(), slog.LevelInfo, "empty config `Log()` test", "hello", "world") + logger.LogAttrs(context.Background(), slog.LevelInfo, "empty config `LogAttrs()` test", slog.String("hello", "world")) + }) +} + +func TestUnmarshallLevel(t *testing.T) { + l := &AllowedLevel{} + err := yaml.Unmarshal([]byte(`debug`), l) + if err != nil { + t.Error(err) + } + if l.s != "debug" { + t.Errorf("expected %s, got %s", "debug", l.s) + } +} + +func TestUnmarshallEmptyLevel(t *testing.T) { + l := &AllowedLevel{} + err := yaml.Unmarshal([]byte(``), l) + if err != nil { + t.Error(err) + } + if l.s != "" { + t.Errorf("expected empty level, got %s", l.s) + } +} + +func TestUnmarshallBadLevel(t *testing.T) { + l := &AllowedLevel{} + err := yaml.Unmarshal([]byte(`debugg`), l) + if err == nil { + t.Error("expected error") + } + expErr := `unrecognized log level debugg` + if err.Error() != expErr { + t.Errorf("expected error %s, got %s", expErr, err.Error()) + } + if l.s != "" { + t.Errorf("expected empty level, got %s", l.s) + } +} + +func getLogEntryLevelCounts(s string, re *regexp.Regexp) map[string]int { + counters := make(map[string]int) + lines := strings.Split(s, "\n") + for _, line := range lines { + matches := re.FindStringSubmatch(line) + if len(matches) > 1 { + levelIndex := re.SubexpIndex("LevelValue") + + counters[strings.ToLower(matches[levelIndex])]++ + } + } + + return counters +} + +func TestDynamicLevels(t *testing.T) { + var buf bytes.Buffer + wantedLevelCounts := map[string]int{"info": 1, "debug": 1} + + tests := map[string]struct { + logStyle LogStyle + logStyleRegexp *regexp.Regexp + wantedLevelCount map[string]int + }{ + "slog_log_style": {logStyle: SlogStyle, logStyleRegexp: slogStyleLogRegexp, wantedLevelCount: wantedLevelCounts}, + "go-kit_log_style": {logStyle: GoKitStyle, logStyleRegexp: goKitStyleLogRegexp, wantedLevelCount: wantedLevelCounts}, + } + + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + buf.Reset() // Ensure buf is reset prior to tests + config := &Config{ioWriter: &buf, Style: tc.logStyle} + logger := New(config) + + // Test that log level can be adjusted on-the-fly to debug and that a + // log entry can be written to the file. + if err := config.Level.Set("debug"); err != nil { + t.Fatal(err) + } + logger.Info("info", "hello", "world") + logger.Debug("debug", "hello", "world") + + counts := getLogEntryLevelCounts(buf.String(), tc.logStyleRegexp) + require.Equal(t, tc.wantedLevelCount["info"], counts["info"], "info log successfully detected") + require.Equal(t, tc.wantedLevelCount["debug"], counts["debug"], "debug log successfully detected") + // Print logs for humans to see, if needed. + fmt.Println(buf.String()) + buf.Reset() + + // Test that log level can be adjusted on-the-fly to info and that a + // subsequent call to write a debug level log is _not_ written to the + // file. + if err := config.Level.Set("info"); err != nil { + t.Fatal(err) + } + logger.Info("info", "hello", "world") + logger.Debug("debug", "hello", "world") + + counts = getLogEntryLevelCounts(buf.String(), tc.logStyleRegexp) + require.Equal(t, tc.wantedLevelCount["info"], counts["info"], "info log successfully detected") + require.NotEqual(t, tc.wantedLevelCount["debug"], counts["debug"], "extra debug log detected") + // Print logs for humans to see, if needed. + fmt.Println(buf.String()) + buf.Reset() + }) + } +}