stdlib slog handler for zerolog #571
Comments
|
No plan at the moment. What would be the use-case? |
|
To no longer depend directly on a log library? |
|
Isn't slog self sufficient? |
|
@rs thanks for the response, |
|
Let’s try it. The risk is that the difference in performance comes from the API model. Please make sure to bench it so we don’t make false promises :) |
|
If I understood it correctly, |
|
Slog author here. Thanks @shettyh for beating me here! Slog will be in go 1.21, so it makes sense to provide some integration with it. I was going to suggest a slog.Handler that writes to a zerolog logger. @phsym nails the use case: letting packages that use slog and ones that use zerolog produce consistent output. |
|
There will be a performance cost anyway. Benchmarking slog with a "no-op" backend vs zerolog shows that slog frontend already brings some overhead. But still it will be great to have a zerolog handler for the libraries which will use slog. No-Op handler: type DummyHandler struct{}
func (*DummyHandler) Enabled(context.Context, slog.Level) bool {
return true
}
func (*DummyHandler) Handle(context.Context, slog.Record) error {
return nil
}
func (h *DummyHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
return h
}
func (h *DummyHandler) WithGroup(name string) slog.Handler {
return h
}Bench: func BenchmarkDummy(b *testing.B) {
ctx := context.Background()
l := slog.New(&DummyHandler{})
l = l.With("foo", "bar")
b.ResetTimer()
for i := 0; i < b.N; i++ {
l.LogAttrs(ctx, slog.LevelInfo, "hello", slog.String("bar", "baz"))
}
}
func BenchmarkZerolog(b *testing.B) {
l := zerolog.New(io.Discard).Level(zerolog.DebugLevel).With().Timestamp().Logger()
l = l.With().Str("foo", "bar").Logger()
b.ResetTimer()
for i := 0; i < b.N; i++ {
l.Info().Str("bar", "baz").Msg("hello")
}
}Results: In this particular test scenario, slog handler is already 2 times slower while doing nothing in the backend. With a zerolog backend it will then be at least 3 times slower and we must add some time to perform the mapping from slog concepts to zerolog concepts (mapping levels, attributes, ...) |
|
I took a stab at it here master...seankhliao:zerolog:slog-support |
|
I also tried to add the support for slog handler and i echo @seankhliao.. In the current state it will be very inefficient to add support mostly because of this structure in slog slog.With("outerKey", "outerValue").WithGroup("NestedGroup").With("NestedKey", "NestedValue").
.WithGroup("NestedLevel2").With("Level2Key", "Level2value").Info("log msg")Because keys/values for the |
|
I gave it a try too, only using current public API. The ony way I found to have some kind of clonable It works, but there are lot of useless buffer copies which will make it inefficient if there are multiple nested groups. But in practice, will there be that much nested groups ? So I tried an other approach: add support for groups in zerolog itself --> master...phsym:zerolog:slog-handler Basically I added methods to
I made those methods public so that my slog handler (in package Groups are automatically closed when sending an event, and they are closed before applying hooks, so that timestamps and callers are not added to a group. |
|
Coming back to the big performance overhead brought by
We can update my previous benchmark to measure that, by adding: import _ "unsafe"
//go:linkname IgnorePC log/slog/internal.IgnorePC
var IgnorePC bool
func BenchmarkDummy_NoPC(b *testing.B) {
IgnorePC = true
b.Cleanup(func() {
IgnorePC = false
})
BenchmarkDummy(b)
}There is still some overhead, but much less.
I don't know if there are plans already to update slog so that it's not calling In the meantime, logging with slog in performance critical code should probably be done by calling the handler directly which has very few overhead if hdl := logger.Handler(); hdl.Enabled(ctx, lvl) {
rec := slog.NewRecord(time.Now(), lvl, msg, 0)
rec.AddAttrs(attrs...)
hdl.Handle(ctx, rec)
}
|
|
We talked a lot about whether that That is still my feeling: it is not a goal to match zerolog performance, so I don't think slog should add API to try. Of course, other approaches are welcome, like calling the hander directly (which you can wrap in a nice function) or some possible future work on speeding up |
|
@jba: From what I see, it might be a missed opportunity for |
|
I looked briefly at this and I have few thoughts:
So I think work made by @phsym is the way to go. @rs: We should just decide if you want |
I haven't been following the implementation here, so I may be confused, but if you preformat attrs then you have to deal with groups too. For slog calls like the preformatted data must be something like |
|
@jba Exactly! This is what @phsym implementation does. It just maintains a stack of buffers which combine both attrs and groups as a prefix. You then prepend that as necessary and add |
|
Benchmark and verification testing of available Given the speed of |
|
I do not think V2 of |
|
Agreed, I would prefer to avoid a V2. |
|
@rs: Are you OK with adding public |
|
I'm sorry to have raised anyone's blood pressure by mentioned V2. I understand the push back. What I was trying to suggest is that a My first concern was that it might not be possible to implement My second concern is that there is a lot of feature mismatch among the various logging libraries that are currently being wrapped by A lot of the warnings I have defined after doing a lot of testing against all of the But that's all just something I was considering as opposed to making changes that would be intended to support outside Footnotes
|
|
@madkins23 Thank you for all this great work doing all that comparison and analysis. But I am not completely sure if zerolog slog implementation should behave exactly like |
|
Absolutely. I used The use case in my mind when I started generating the benchmark and verification data was replacing one handler with another in an existing system. I figure the system is likely logging JSON because there are downstream processes reading the logs. How does the system architect determine which handlers will have the best performance as well as the least incompatible change in JSON output? How do software engineers prepare for any changes in the downstream processes? I have no expectation that any given logger library such as |
Groups named with the empty string should be inserted inline. Whether or not you conform to this and other handler specifications, I recommend using Ideally, all handlers would behave the same. Often that is impossible for compatibility or implementation reasons. But if your handler violates the spec just because you think the alternative is valuable (like outputting empty groups, for example), then I suggest making the choice an option, with the default being the official behavior. Users will benefit by having a more uniform experience across handlers. |
|
TL;DR Agreed, plus another shameless plug for my own Four out of the six handlers I'm testing fail that particular test (use the My test harness includes tests inspired by That doesn't mean my tests are authoritative, but I've tried to link each of them (and each of the "warnings" I generate) to some supporting documentation where possible. In this particular case I link to "- If a group's key is empty, inline the group's Attrs." in the documentation for |
|
https://github.com/struqt/logging/blob/main/logging.go package logging
import (
"io"
"log/slog"
"os"
"sync"
"time"
"github.com/go-logr/logr"
"github.com/go-logr/zerologr"
"github.com/rs/zerolog"
"gopkg.in/natefinch/lumberjack.v2"
)
var setupOnce sync.Once
func setup() {
setupOnce.Do(func() {
zerologr.NameSeparator = "/"
zerologr.NameFieldName = "N"
zerologr.VerbosityFieldName = "V"
zerologr.SetMaxV(LogVerbosity)
})
}
var (
LogRotateMBytes uint16 = 16
LogRotateFiles uint16 = 64
LogVerbosity = 2
LogConsoleThreshold = int8(zerolog.TraceLevel)
DefaultLogger = NewLogger("")
)
func NewLogger(path string) *slog.Logger {
logger := NewLogr(path)
sLogger := slog.New(logr.ToSlogHandler(logger))
return sLogger
}
func NewLogr(path string) logr.Logger {
setup()
console := NewThresholdConsole()
var logger *zerolog.Logger
if len(path) > 0 {
verbose := NewLumberjack(LogRotateMBytes, LogRotateFiles, path)
logger = NewZerolog(verbose, console)
} else {
logger = NewZerolog(console)
}
return zerologr.New(logger)
}
func NewLumberjack(fileMBytes uint16, fileCount uint16, path string) *lumberjack.Logger {
logger := &lumberjack.Logger{
Filename: path,
MaxSize: int(fileMBytes),
MaxBackups: int(fileCount),
LocalTime: false,
Compress: true,
}
return logger
}
func NewZerolog(writers ...io.Writer) *zerolog.Logger {
multi := zerolog.MultiLevelWriter(writers...)
logger := zerolog.New(multi).With().Timestamp().Caller().Logger()
return &logger
}
type ThresholdWriter struct {
threshold zerolog.Level
writer zerolog.LevelWriter
}
func (t *ThresholdWriter) Write(bytes []byte) (n int, err error) {
return t.WriteLevel(zerolog.NoLevel, bytes)
}
func (t *ThresholdWriter) WriteLevel(level zerolog.Level, bytes []byte) (n int, err error) {
if level >= t.threshold {
return t.writer.WriteLevel(level, bytes)
}
return len(bytes), nil
}
func NewThresholdConsole() *ThresholdWriter {
console := zerolog.ConsoleWriter{
Out: os.Stderr,
TimeFormat: time.RFC3339,
}
return &ThresholdWriter{
writer: zerolog.MultiLevelWriter(console),
threshold: zerolog.Level(LogConsoleThreshold),
}
} |
Hi,
Is there any plan to add slog handler implementation for Zerolog ?. If there are no ongoing efforts then i can raise the PR the same
Regards
The text was updated successfully, but these errors were encountered: