diff --git a/promlog/log.go b/promlog/log.go index 50746544..a99116c7 100644 --- a/promlog/log.go +++ b/promlog/log.go @@ -14,6 +14,8 @@ // Package promlog defines standardised ways to initialize Go kit loggers // across Prometheus components. // It should typically only ever be imported by main packages. + +// Deprecated: This package has been replaced with github.com/prometheus/common/promslog. package promlog import ( diff --git a/promslog/slog.go b/promslog/slog.go new file mode 100644 index 00000000..930d5ac3 --- /dev/null +++ b/promslog/slog.go @@ -0,0 +1,165 @@ +// 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. +package promslog + +import ( + "fmt" + "io" + "log/slog" + "os" + "path/filepath" + "strconv" +) + +var ( + LevelFlagOptions = []string{"debug", "info", "warn", "error"} + FormatFlagOptions = []string{"logfmt", "json"} + + callerAddFunc = false + defaultWriter = os.Stderr + replaceAttrFunc = 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)) + } + 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 %q", 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 %q", s) + } + return nil +} + +// Config is a struct containing configurable settings for the logger +type Config struct { + Level *AllowedLevel + Format *AllowedFormat + 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, + ReplaceAttr: replaceAttrFunc, + } + + 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..bcdca361 --- /dev/null +++ b/promslog/slog_test.go @@ -0,0 +1,129 @@ +// 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 + +import ( + "bytes" + "context" + "fmt" + "log/slog" + "regexp" + "strings" + "testing" + + "github.com/stretchr/testify/require" + "gopkg.in/yaml.v2" +) + +var logLevelRegexp = regexp.MustCompile(`.*level=(?PWARN|INFO|ERROR|DEBUG).*`) + +// 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) map[string]int { + counters := make(map[string]int) + lines := strings.Split(s, "\n") + for _, line := range lines { + matches := logLevelRegexp.FindStringSubmatch(line) + if len(matches) > 1 { + levelIndex := logLevelRegexp.SubexpIndex("Level") + + counters[matches[levelIndex]]++ + } + } + + return counters +} + +func TestDynamicLevels(t *testing.T) { + var buf bytes.Buffer + config := &Config{ioWriter: &buf} + 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()) + require.Equal(t, 1, counts["INFO"], "info log successfully detected") + require.Equal(t, 1, 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()) + require.Equal(t, 1, counts["INFO"], "info log successfully detected") + require.NotEqual(t, 1, counts["DEBUG"], "extra debug log detected") + // Print logs for humans to see, if needed. + fmt.Println(buf.String()) + buf.Reset() +}