slog: Go official version structured log package

/ Tony Bai

Permalink to this article – https://ift.tt/xOaXqQN

Since its birth, Go has built the log package in its standard library as a standard component of Go source code output log . This package is widely used in the Go standard library itself and in Go community projects.

However, for the Go standard library log package, the Go community has always asked for improvements, and the mainstream voices focus on the following points:

  • The log package is designed for human readability, and does not support structured logs that are easy to parse by machines (such as outputting logs in json format like zap );
  • log level is not supported;
  • The log package adopts a proprietary log output format, and does not provide a Logger interface type that the Go community can commonly follow. As a result, the log output formats used by Go community projects are varied and incompatible with each other.

The Go community has tried to work together to improve the standard library log package and wrote the first draft of the Proposal design , but it was not accepted by the Go core team for various reasons.

At the end of August 2022, Jonathan Amsterdam of the Go team initiated a discussion with the intention of discussing with the community about adding a structured log package that supports log levels to the Go standard library , and forming a consistent Proposal.

Jonathan Amsterdam named the structured log package slog and plans to put it under log/slog. He also gave the initial implementation of slog under golang.org/x/exp, and the proposal has officially entered the review stage these days. It is not known when it will officially land in the official version of Go.

In this article, let’s take a brief look at slog’s proposal and its initial implementation.

1. Introduction to the design of slog

At the beginning of the design of slog, a detailed investigation of some widely used log packages in the community, such as uber zap and zerolog , was carried out. Therefore, the design of slog can also be regarded as “standing on the shoulders of predecessors”, especially uber zap.

Jonathan Amsterdam set the following goals for the design of this slog (taken from slog’s proposal):

  • Ease of use

A survey of existing logging packages found that programmers wanted a concise and easy-to-understand logging API. In this proposal, we will use the most popular way to express key-value pairs, which is to alternately pass in keys and values.

  • high performance

The log API is designed to minimize memory allocation and locking. It provides a method of alternately entering keys and values, which is slightly cumbersome, but faster;

  • Can be integrated with runtime tracing

The Go team is working on an improved runtime tracing system. This package’s logging will be seamlessly integrated into this tracing system, enabling developers to correlate their program behavior with runtime behavior.

Here is a schematic diagram of the structure of slog based on the slog proposal and the source code of golang.org/x/exp/slog:

Briefly explain this diagram:

Slog is logically divided into front-end and back-end.

The front end of slog is the API provided by slog to users. However, unfortunately, slog still does not extract the Logger interface like log, but defines a Logger structure and provides the methods as shown in the figure, which also means that we Still unable to unify the front-end API in the entire Go community ;

Through the front-end method, slog encapsulates the log content and related attribute information into a slog.Record type instance, and then passes it to the back-end of slog.

If you are using the front-end method of the third-party log package of the Go community, such as zap, if you want to use the slog backend, you also need to encapsulate the zap, etc., so that it can output slog.Record and pass it to the slog backend (currently There are no examples of this yet).

slog abstracts the backend as the slog.Handler interface, the interface is as follows:

 // // Any of the Handler's methods may be called concurrently with itself // or with other methods. It is the responsibility of the Handler to // manage this concurrency. type Handler interface { // Enabled reports whether the handler handles records at the given level. // The handler ignores records whose level is lower. // Enabled is called early, before any arguments are processed, // to save effort if the log event should be discarded. Enabled(Level) bool // Handle handles the Record. // It will only be called if Enabled returns true. // Handle methods that produce output should observe the following rules: // - If r.Time is the zero time, ignore the time. // - If an Attr's key is the empty string, ignore the Attr. Handle(r Record) error // WithAttrs returns a new Handler whose attributes consist of // both the receiver's attributes and the arguments. // The Handler owns the slice: it may retain, modify or discard it. WithAttrs(attrs []Attr) Handler // WithGroup returns a new Handler with the given group appended to // the receiver's existing groups. // The keys of all subsequent attributes, whether added by With or in a // Record, should be qualified by the sequence of group names. // // How this qualification happens is up to the Handler, so long as // this Handler's attribute keys differ from those of another Handler // with a different sequence of group names. // // A Handler should treat WithGroup as starting a Group of Attrs that ends // at the end of the log event. That is, // // logger.WithGroup("s").LogAttrs(slog.Int("a", 1), slog.Int("b", 2)) // // should behave like // // logger.LogAttrs(slog.Group("s", slog.Int("a", 1), slog.Int("b", 2))) WithGroup(name string) Handler }

The existence of the interface type makes the backend of slog more scalable. In addition to using the two built-in Handler implementations provided by slog: TextHandler and JSONHandler, we can also define or completely customize the backend Handler based on a third-party log package. accomplish.

slog has two built-in Handlers: TextHandler and JSONHandler. As the name implies, TextHandler outputs the log as a line of text like the standard library log package; while JSONHandler outputs log content and attributes in JSON format. Let’s take a look at the example given by the author:

 // github.com/bigwhite/experiments/tree/master/slog-examples/demo1/main.go package main import ( "net" "golang.org/x/exp/slog" ) func main() { slog.SetDefault(slog.New(slog.NewTextHandler(os.Stderr))) slog.Info("hello", "name", "Al") slog.Error("oops", net.ErrClosed, "status", 500) slog.LogAttrs(slog.ErrorLevel, "oops", slog.Int("status", 500), slog.Any("err", net.ErrClosed)) }

Here is an example using the built-in TextHandler, let’s run it and see the result:

 time=2022-10-23T18:41:35.074+08:00 level=INFO msg=hello name=Al time=2022-10-23T18:41:35.074+08:00 level=ERROR msg=oops status=500 err="use of closed network connection" time=2022-10-23T18:41:35.074+08:00 level=ERROR msg=oops status=500 err="use of closed network connection"

We can see that the output log is presented in the form of “key1=value1 key2=value2 … keyN=valueN”. The two keys time and level are required. When calling the Error method, the key err is also required.

Next, we replace TextHandler with JSONHandler:

 slog.SetDefault(slog.New(slog.NewTextHandler(os.Stderr)))改为： slog.SetDefault(slog.New(slog.NewJSONHandler(os.Stderr)))

Running the modified program, we get:

 {"time":"2022-10-23T18:45:26.2131+08:00","level":"INFO","msg":"hello","name":"Al"} {"time":"2022-10-23T18:45:26.213287+08:00","level":"ERROR","msg":"oops","status":500,"err":"use of closed network connection"} {"time":"2022-10-23T18:45:26.21331+08:00","level":"ERROR","msg":"oops","status":500,"err":"use of closed network connection"}

We see that each log is presented in the form of a json record, and such a structured log is very suitable for machine parsing.

If we remove the line of code SetDefault above, run the program again:

 2022/10/23 18:47:51 INFO hello name=Al 2022/10/23 18:47:51 ERROR oops status=500 err="use of closed network connection" 2022/10/23 18:47:51 ERROR oops status=500 err="use of closed network connection"

We get a different log style than TextHandler and JSONHandler, but this log style looks familiar! Isn’t this the same as the output style of the log package! That’s right, if the newly created Logger is not explicitly set as the default Logger, slog will use defaultHandler, and the output function of defaultHandler is log.Output:

 // slog项目// logger.go var defaultLogger atomic.Value func init() { defaultLogger.Store(Logger{ handler: newDefaultHandler(log.Output), // 这里直接使用了log.Output }) } // handler.go type defaultHandler struct { ch *commonHandler // log.Output, except for testing output func(calldepth int, message string) error } func newDefaultHandler(output func(int, string) error) *defaultHandler { return &defaultHandler{ ch: &commonHandler{json: false}, output: output, } }

The front end of slog is “fixed format”, so there is nothing customizable. But there are many ways to play in the back end. Next, let’s focus on the back end.

2. Handler Options (HandlerOptions)

slog provides the HandlerOptions structure:

 // handler.go // HandlerOptions are options for a TextHandler or JSONHandler. // A zero HandlerOptions consists entirely of default values. type HandlerOptions struct { // Add a "source" attribute to the output whose value is of the form // "file:line". // This is false by default, because there is a cost to extracting this // information. AddSource bool // Ignore records with levels below Level.Level(). // The default is InfoLevel. Level Leveler // If set, ReplaceAttr is called on each attribute of the message, // and the returned value is used instead of the original. If the returned // key is empty, the attribute is omitted from the output. // // The built-in attributes with keys "time", "level", "source", and "msg" // are passed to this function first, except that time and level are omitted // if zero, and source is omitted if AddSourceLine is false. // // ReplaceAttr can be used to change the default keys of the built-in // attributes, convert types (for example, to replace a `time.Time` with the // integer seconds since the Unix epoch), sanitize personal information, or // remove attributes from the output. ReplaceAttr func(a Attr) Attr }

Through this structure, we can add source information to the output log, that is, the file name and line number of the output log. The following is an example:

 // github.com/bigwhite/experiments/tree/master/slog-examples/demo2/main.go package main import ( "net" "os" "golang.org/x/exp/slog" ) func main() { opts := slog.HandlerOptions{ AddSource: true, } slog.SetDefault(slog.New(opts.NewJSONHandler(os.Stderr))) slog.Info("hello", "name", "Al") slog.Error("oops", net.ErrClosed, "status", 500) slog.LogAttrs(slog.ErrorLevel, "oops", slog.Int("status", 500), slog.Any("err", net.ErrClosed)) }

Running the above program, we will get:

 {"time":"2022-10-23T21:46:25.718112+08:00","level":"INFO","source":"/Users/tonybai/go/src/github.com/bigwhite/experiments/slog-examples/demo2/main.go:16","msg":"hello","name":"Al"} {"time":"2022-10-23T21:46:25.718324+08:00","level":"ERROR","source":"/Users/tonybai/go/src/github.com/bigwhite/experiments/slog-examples/demo2/main.go:17","msg":"oops","status":500,"err":"use of closed network connection"} {"time":"2022-10-23T21:46:25.718352+08:00","level":"ERROR","source":"/Users/tonybai/go/src/github.com/bigwhite/experiments/slog-examples/demo2/main.go:18","msg":"oops","status":500,"err":"use of closed network connection"}

We can also dynamically set the log level through HandlerOptions, such as the following example:

 // github.com/bigwhite/experiments/tree/master/slog-examples/demo3/main.go func main() { var lvl = &slog.AtomicLevel{} lvl.Set(slog.DebugLevel) opts := slog.HandlerOptions{ Level: lvl, } slog.SetDefault(slog.New(opts.NewJSONHandler(os.Stderr))) slog.Info("before resetting log level:") slog.Info("hello", "name", "Al") slog.Error("oops", net.ErrClosed, "status", 500) slog.LogAttrs(slog.ErrorLevel, "oops", slog.Int("status", 500), slog.Any("err", net.ErrClosed)) slog.Info("after resetting log level to error level:") lvl.Set(slog.ErrorLevel) slog.Info("hello", "name", "Al") slog.Error("oops", net.ErrClosed, "status", 500) slog.LogAttrs(slog.ErrorLevel, "oops", slog.Int("status", 500), slog.Any("err", net.ErrClosed)) }

The field Level of slog.HandlerOptions is an interface type variable whose type is slog.Leveler:

 type Leveler interface { Level() Level }

The type that implements the Level method can be assigned to the Level field of HandlerOptions. slog provides AtomicLevel that supports concurrent access for us to use directly. The demo3 above uses AtomicLevel, and DebugLevel is initially set, so the first call to Info, The logs output by the API such as Error will be output, and then reset the log level to ErrorLevel, so that the logs output by the Info API will not be displayed. The following is the running result of the demo3 program:

 {"time":"2022-10-23T21:58:48.467666+08:00","level":"INFO","msg":"before resetting log level:"} {"time":"2022-10-23T21:58:48.467818+08:00","level":"INFO","msg":"hello","name":"Al"} {"time":"2022-10-23T21:58:48.467825+08:00","level":"ERROR","msg":"oops","status":500,"err":"use of closed network connection"} {"time":"2022-10-23T21:58:48.467842+08:00","level":"ERROR","msg":"oops","status":500,"err":"use of closed network connection"} {"time":"2022-10-23T21:58:48.467846+08:00","level":"INFO","msg":"after resetting log level to error level:"} {"time":"2022-10-23T21:58:48.46785+08:00","level":"ERROR","msg":"oops","status":500,"err":"use of closed network connection"} {"time":"2022-10-23T21:58:48.467854+08:00","level":"ERROR","msg":"oops","status":500,"err":"use of closed network connection"}

What is the function of the third field ReplaceAttr of HandlerOptions, I will leave it to you to explore for yourself.

In addition to making some customizations with HandleOptions, we can also completely customize the implementation of the Handler interface. Let’s use an example to illustrate.

3. Implementation of custom Handler interface

Let’s define a new Handler: ChanHandler, which implements the behavior of writing logs to channel (used to simulate log writing to kafka). Let’s build this ChanHandler:

 // github.com/bigwhite/experiments/tree/master/slog-examples/demo4/main.go type ChanHandler struct { slog.Handler ch chan []byte buf *bytes.Buffer } func (h *ChanHandler) Enabled(level slog.Level) bool { return h.Handler.Enabled(level) } func (h *ChanHandler) Handle(r slog.Record) error { err := h.Handler.Handle(r) if err != nil { return err } var nb = make([]byte, h.buf.Len()) copy(nb, h.buf.Bytes()) h.ch <- nb h.buf.Reset() return nil } func (h *ChanHandler) WithAttrs(as []slog.Attr) slog.Handler { return &ChanHandler{ buf: h.buf, ch: h.ch, Handler: h.Handler.WithAttrs(as), } } func (h *ChanHandler) WithGroup(name string) slog.Handler { return &ChanHandler{ buf: h.buf, ch: h.ch, Handler: h.Handler.WithGroup(name), } } func NewChanHandler(ch chan []byte) *ChanHandler { var b = make([]byte, 256) h := &ChanHandler{ buf: bytes.NewBuffer(b), ch: ch, } h.Handler = slog.NewJSONHandler(h.buf) return h }

We see that ChanHandler has slog.JSONHandler embedded in it. The implementation of the slog.Handler interface is mostly done by the embedded JSONHandler. The only difference is the Handle method. Here, the logs processed by JSONHandler are copied and sent to the channel. The following is the main function of the demo:

 // github.com/bigwhite/experiments/tree/master/slog-examples/demo4/main.go func main() { var ch = make(chan []byte, 100) attrs := []slog.Attr{ {Key: "field1", Value: slog.StringValue("value1")}, {Key: "field2", Value: slog.StringValue("value2")}, } slog.SetDefault(slog.New(NewChanHandler(ch).WithAttrs(attrs))) go func() { // 模拟channel的消费者，用来消费日志for { b := <-ch fmt.Println(string(b)) } }() slog.Info("hello", "name", "Al") slog.Error("oops", net.ErrClosed, "status", 500) slog.LogAttrs(slog.ErrorLevel, "oops", slog.Int("status", 500), slog.Any("err", net.ErrClosed)) time.Sleep(3 * time.Second) }

Running the above program, we will get the following output:

 {"time":"2022-10-23T23:09:01.358702+08:00","level":"INFO","msg":"hello","field1":"value1","field2":"value2","name":"Al"} {"time":"2022-10-23T23:09:01.358836+08:00","level":"ERROR","msg":"oops","field1":"value1","field2":"value2","status":500,"err":"use of closed network connection"} {"time":"2022-10-23T23:09:01.358856+08:00","level":"ERROR","msg":"oops","field1":"value1","field2":"value2","status":500,"err":"use of closed network connection"}

4. Performance of slog

Let’s take a look at the performance of slog again. We directly use the performance comparison data with zap that comes with the slog source code, and use the benchstat tool to view the comparison results as follows:

 $ benchstat zapbenchmarks/zap.bench slog.bench name old time/op new time/op delta Attrs/async_discard/5_args-8 348ns ± 2% 88ns ± 2% -74.77% (p=0.008 n=5+5) Attrs/async_discard/10_args-8 570ns ± 2% 280ns ± 2% -50.94% (p=0.008 n=5+5) Attrs/async_discard/40_args-8 1.84µs ± 2% 0.91µs ± 3% -50.37% (p=0.008 n=5+5) Attrs/fastText_discard/5_args-8 476ns ± 2% 200ns ±45% -57.92% (p=0.008 n=5+5) Attrs/fastText_discard/10_args-8 822ns ± 7% 524ns ± 2% -36.27% (p=0.008 n=5+5) Attrs/fastText_discard/40_args-8 2.70µs ± 3% 2.01µs ± 3% -25.76% (p=0.008 n=5+5) name old alloc/op new alloc/op delta Attrs/async_discard/5_args-8 320B ± 0% 0B -100.00% (p=0.008 n=5+5) Attrs/async_discard/10_args-8 640B ± 0% 208B ± 0% -67.50% (p=0.008 n=5+5) Attrs/async_discard/40_args-8 2.69kB ± 0% 1.41kB ± 0% -47.64% (p=0.008 n=5+5) Attrs/fastText_discard/5_args-8 320B ± 0% 0B -100.00% (p=0.008 n=5+5) Attrs/fastText_discard/10_args-8 641B ± 0% 208B ± 0% -67.55% (p=0.008 n=5+5) Attrs/fastText_discard/40_args-8 2.70kB ± 0% 1.41kB ± 0% -47.63% (p=0.029 n=4+4) name old allocs/op new allocs/op delta Attrs/async_discard/5_args-8 1.00 ± 0% 0.00 -100.00% (p=0.008 n=5+5) Attrs/async_discard/10_args-8 1.00 ± 0% 1.00 ± 0% ~ (all equal) Attrs/async_discard/40_args-8 1.00 ± 0% 1.00 ± 0% ~ (all equal) Attrs/fastText_discard/5_args-8 1.00 ± 0% 0.00 -100.00% (p=0.008 n=5+5) Attrs/fastText_discard/10_args-8 1.00 ± 0% 1.00 ± 0% ~ (all equal) Attrs/fastText_discard/40_args-8 1.00 ± 0% 1.00 ± 0% ~ (all equal)

We can see that the performance of slog is much better than that of zap, which is known for its high performance, and the memory allocation is also much reduced.

5. Summary

Through the preliminary exploration of slog, I feel that slog as a whole draws on the design of third-party log packages such as zap, and adopts the strategy of separating front and back ends, but it seems to be easier to understand than zap.

In the previous example, the front-end API that is very convenient to use is mentioned, and the high performance of slog is mentioned. The integration with runtime tracing in the design goal of slog is not mentioned much in the proposal, and more about its integration with context.Context ( Through slog.WithContext and slog.FromContext, etc.), maybe this is the basis for integration with runtime tracing.

Jonathan Amsterdam also mentioned in the proposal that every third-party log package has its own characteristics. I don’t expect slog to replace all third-party log packages. I just hope that slog can fully interact with third-party log packages, so that each program has a Common “backend”. An application with many dependencies may find that it has many logging packages hooked up. If all packages support the Handler interface proposed by slog, then an application can create a single Handler and install it once for each logging library to get consistent logging across all its dependencies.

Personal opinion: After slog is added to the standard library, new projects are recommended to use slog.

The sample code covered in this article can be downloaded here .

6. References

  • Proposal: Structured Logging review – https://ift.tt/gjcAD02
  • discussion: structured, leveled logging – https://ift.tt/yxa5qAR
  • proposal: log/slog: structured, leveled logging – https://ift.tt/U3i9FBx
  • slog experimental implementation – https://ift.tt/CQeZi6m
  • logr – https://ift.tt/HFUavGW
  • Go Logging Design Proposal – Ross Light – https://ift.tt/SR9zhUj
  • Standardization around logging and related concerns – https://ift.tt/uonX2bU

“Gopher Tribe” Knowledge Planet aims to create a high-quality Go learning and advanced community! High-quality first published Go technical articles, “three-day” first published reading rights, analysis of the current situation of Go language development twice a year, reading the fresh Gopher daily 1 hour in advance every day, online courses, technical columns, book content preview, must answer within 6 hours Guaranteed to meet all your needs about the Go language ecosystem! In 2022, the Gopher tribe will be fully revised, and will continue to share knowledge, skills and practices in the Go language and Go application fields, and add many forms of interaction. Everyone is welcome to join!

img{512x368}

img{512x368}

img{512x368}

img{512x368}

I love texting : Enterprise-level SMS platform customization development expert https://51smspush.com/. smspush : A customized SMS platform that can be deployed within the enterprise, with three-network coverage, not afraid of large concurrent access, and can be customized and expanded; the content of the SMS is determined by you, no longer bound, with rich interfaces, long SMS support, and optional signature. On April 8, 2020, China’s three major telecom operators jointly released the “5G Message White Paper”, and the 51 SMS platform will also be newly upgraded to the “51 Commercial Message Platform” to fully support 5G RCS messages.

The famous cloud hosting service provider DigitalOcean released the latest hosting plan. The entry-level Droplet configuration is upgraded to: 1 core CPU, 1G memory, 25G high-speed SSD, and the price is 5$/month. Friends who need to use DigitalOcean can open this link : https://ift.tt/6zQkM4V to open your DO host road.

Gopher Daily Archive Repository – https://ift.tt/xnFlrNt

my contact information:

  • Weibo: https://ift.tt/7d9EzlC
  • Blog: tonybai.com
  • github: https://ift.tt/4K2bwxz

Business cooperation methods: writing, publishing books, training, online courses, partnership entrepreneurship, consulting, advertising cooperation.

© 2022, bigwhite . All rights reserved.

This article is reprinted from https://tonybai.com/2022/10/30/first-exploration-of-slog/
This site is for inclusion only, and the copyright belongs to the original author.