Skip to content

Commit

Permalink
feat: new promslog package to wrap log/slog, deprecate promlog
Browse files Browse the repository at this point in the history
Prereq for prometheus/prometheus#14355

This adds a new `promslog` package to create an opinionated slog logger
for use within the prometheus ecosystem. In particular, it makes the
following adjustments to normalize it to what was used in the old
promlog package:
- 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.

Creating a logger is similar to the old promlog package -- optionally
create 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 := &Config{} // Retain as variable to dynamically adjust log level
logger := New(config)
config.Level.Set("debug")
logger.Debug("your message here", "hello", "world")
```

Signed-off-by: TJ Hoplock <t.hoplock@gmail.com>
  • Loading branch information
tjhop committed Aug 16, 2024
1 parent e1197cc commit 0c6d887
Show file tree
Hide file tree
Showing 3 changed files with 296 additions and 0 deletions.
2 changes: 2 additions & 0 deletions promlog/log.go
Original file line number Diff line number Diff line change
Expand Up @@ -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 (
Expand Down
165 changes: 165 additions & 0 deletions promslog/slog.go
Original file line number Diff line number Diff line change
@@ -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))
}
129 changes: 129 additions & 0 deletions promslog/slog_test.go
Original file line number Diff line number Diff line change
@@ -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=(?P<Level>WARN|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()
}

0 comments on commit 0c6d887

Please sign in to comment.