I used to use the go log package, then I switched to the slog package, and it’s been a bumpy ride.

The log package is pretty limited. log.Printf is just fmt.Fprintf(os.Stderr) with a timestamp, although there’s a few options to tweak. One shortcoming is that it’s unordered text, and it’s easy to omit important information, requiring that I puzzle over several lines trying to connect the clues. Another is that all the debug noises and critical errors get smashed together.

This last problem was easy to solve. I created three loggers, elog, ilog, and dlog, so dlog.Printf is just like log.Printf but it goes to the debug output file. This also worked quite well with syslog. Each log output could be a separate syslog priority.

It was the first problem that eventually convinced me to undertake the structured logging slog. I want the connection ID in every log message, even the ones where I might forget it.

Rewriting the code wasn’t too difficult, change every ilog.Printf to slog.Info, right? Except the slog functions don’t take format strings. All my log calls looked like ilog.Printf("operation failed: %s", err). That has to be converted to slog.Info("operation failed", "err", err). Given that the Info, Error, etc. functions already take multiple arguments, and there’s a very obvious upgrade path for users converting log.Printf to slog.Warn, I think it was a missed opportunity to make this easy. Process the first argument as a format string, eat arguments, then switch to the structured pairs for any remaining arguments. This would have allowed a much simpler conversion process to take place over time, with fewer errors.

As it was, I managed to slog through it with some regex, but not entirely without some missed conversions, and by the end I just wanted to get it done, without much regard to quality. The end result would likely have been better if I could have converted to the new API in one shot, then fixed it up over time.

There’s quite some magic intertwining log and slog. It’s obvious the intention was to allow both to coexist, but some weird stuff happens when you start to poke the contraption.

I mentioned I wanted to have some debug messages. By default, slog won’t let you see them, so you do the magic to get a logger with a handler with an options that outputs debug level messages.

    log.Printf("default log")
    slog.Info("default slog", "reset", false)
    opts := &slog.HandlerOptions{Level: slog.LevelDebug}
    h := slog.NewTextHandler(os.Stderr, opts)
    slog.SetDefault(slog.New(h))
    slog.Info("handler installed")
    log.Printf("default log")
    slog.Debug("debug")

And woah.

2025/06/12 14:46:14 default log
2025/06/12 14:46:14 INFO default slog reset=false
time=2025-06-12T14:46:14.921-04:00 level=INFO msg="handler installed"
time=2025-06-12T14:46:14.921-04:00 level=INFO msg="default log"
time=2025-06-12T14:46:14.921-04:00 level=DEBUG msg=debug

The debug message does show up, but what happened to the formatting? Well, that’s just how TextHandler does things. But also, now even the default log messages are gummed up. It turns out slog calls log, until you touch slog, and then full reverse, log calls slog. This put me off the entire idea for a while.

The next release of go included a new function slog.SetLogLoggerLevel(slog.LevelDebug) so you can finally enable debug messages without going through this, but it doesn’t permit altering any other option.

Whatever the default before you change anything handler is, you can’t make your own just like it. You can redirect its output, but only by calling log.SetOutput and being careful not to accidentally reset it.

If you log to syslog (via log.SetOutput(syslog.New(...))) you get this.

Jun 12 12:58:22 zen5 testlog[61544]: 2025/06/12 12:58:22 INFO hello there
Jun 12 12:58:22 zen5 testlog[61544]: 2025/06/12 12:58:22 DEBUG debug

Two timestamps? In this economy? And stuck with a single priority. I might reasonably want to keep most logs local, but ship error logs to another system. Ironically, slog has made it easier to declare the priority of each message, but now they all end up in the same stream, differentiated only by text.

There’s a few principles at work in go. One is sensible defaults. If you don’t muck with anything at all, log and slog probably work well. Another if you don’t like what it does, just copy the code and make it do what you want. Personally, I love editable software, because it keeps the code simple and keeps isolated complexity at the edges. I think there’s a gap here where the functionality I want clearly exists; it’s the default unnamed and unknowable slog handler, but I can’t create my own. Another design principle we might consider is that whatever the default is, it should always be possible to recreate it explicitly. I must be able to restore the default behavior. But that’s not how slog works. Once you call slog.SetDefault you are ironically locked out of the default behavior.

Having slogged my way through it all, I now find myself adding a hacky wrapper that sits between log and syslog and inspecting the message for timestamps and priorities, and then passing only the interesting bits to syslog. I think there’s a better way involving the slog handler replace function, but I’ve had enough.