Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: new promslog and promslog/flag packages to wrap log/slog #677

Merged
merged 1 commit into from
Aug 28, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
56 changes: 56 additions & 0 deletions promslog/flag/flag.go
Original file line number Diff line number Diff line change
@@ -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)
}
182 changes: 182 additions & 0 deletions promslog/slog.go
Original file line number Diff line number Diff line change
@@ -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"))
Copy link
Contributor

@dswarbrick dswarbrick Sep 11, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The non-UTC timestamp format here differs from the previous promlog (go-kit) timestamp format, which used .UTC().

	timestampFormat = log.TimestampFormat(
		func() time.Time { return time.Now().UTC() },
		"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))
}
150 changes: 150 additions & 0 deletions promslog/slog_test.go
Original file line number Diff line number Diff line change
@@ -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(`(?P<TimeKey>time)=.*level=(?P<LevelValue>WARN|INFO|ERROR|DEBUG).*(?P<SourceKey>source)=.*`)
goKitStyleLogRegexp = regexp.MustCompile(`(?P<TimeKey>ts)=.*level=(?P<LevelValue>warn|info|error|debug).*(?P<SourceKey>caller)=.*`)
)

// 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")
ArthurSens marked this conversation as resolved.
Show resolved Hide resolved
// Print logs for humans to see, if needed.
fmt.Println(buf.String())
buf.Reset()
})
}
}