What's so bad about the stdlib's log package?

Technical Discussion
1

I see a lot of hate directed at the stdlib’s log package, and of course, there are a medley of third party logging packages. What are people’s problems with the standard log package? I’ve seen accusations that it doesn’t have leveled logging, which seems like an exercise in laziness, because that’s trivial to write:

package log
import (
    "io/ioutil"
    "log"
    "os"
)

var (
    Trace = log.New(ioutil.Discard, "TRACE ", log.LstdFlags)
    Debug = log.New(os.Stdout, "DEBUG ", log.LstdFlags)
    // etc
)

With the above trivial package, you can now do log.Debug.Printf("foo!") just like any of the third party loggers.

Some loggers are structured loggers, which again seems like not a big deal, you can pass a map[string]interface{} into log.Printf and it’ll print out the map in a fairly easily parse-able way…

The only thing I can think of is that the time formatting is kinda ugly. I guess the other feature is being able to change levels of logs for individual packages, though honestly, in my ~10 years of working on projects that use such a feature, I think I’ve used it all of once or twice.

What am I missing?

10 Likes
2

I suspect the criticisms are based on users coming from language communities that have de-facto standard logging libraries that are much more feature-full.

Someone coming from Java, for example, would probably expect to see feature parity with SLF4J. When they don’t see obvious analogues in the standard library, they look for a community-wide standard replacement. And I think the Go ecosystem just hasn’t (and may never) choose a standard alternative library. That leads to frustration…

But that’s mostly speculation.

2 Likes
3

I’m going to throw the cat amongst the pidgeons and say that there should be at most three log levels, anything more and you are using the logger as an excuse for not making a decision.

Those levels are

  • debug, stuff that the user doesn’t care about but developers do.
  • info, stuff that you tell the user
  • fatal, one message, that exits the program.

There is no warning level, cos warnings are ignored – It’s either a problem or it is not, and you the application developer have to choose.

There is no error level because either you handled the error or you didn’t. If you handled the error then by definition it’s not an error, but if you didn’t (handle the error) then it should terminate your program.

This removes an entire class of bugs where the error is logged at error level (or give me strength, debug level) leaving the problem of what to return to the caller ?

Nil ? Puhlease, this isn’t Java
Error ? But you just logged it, again , this isn’t Java.

I’ll be putting on my flameproof suit now.

17 Likes
4

Ha, that’s pretty much exactly what I was going to post, but I figured I’d wait and see what others said. In my experience, there’s only two functional levels: normal, and verbose. ERROR and WARNING are just normal (INFO) with a different prefix.

1 Like
5

As someone “comming from Java” I would like to disagree. In a long running web server where the error is just in a subpart of the system it’s very useful to be able to filter on this level and find all failed transfers and the reason(s) for the failure (e.g. file already exists - exception was handled, but the transfer still failed). If the log is full of just INFO messages it’s a nightmare to find your way in tens or hundreds of log pages. Sure you could filter by message, but in some cases you do not know it.

I’m not saying that go’s log package is bad, just that the additional ERROR level is useful in some cases. As for the WARN - please remove it everywhere :slight_smile:

6

Can you show me an example of one of these failed transfer messages. I have a theory, but I don’t want to propose anything without seeing the raw data.

7

Like errors, it’s a good idea to prefix each info message with the name of the subsystem.

log.Infof("transfer: failed transfer with user %s: %s", user, err)

It’s true that for a server logs might want to go to different places, and not all errors are created equal (log the user login errors in one place, access info in another place for stats and analytics…)

1 Like
8

Sure. Let’s say we have a web application capable of receiving files over the network and post process them based on predefined rules (e.g. complex combination of different enterprise integration patterns). If any of the processing steps fail the application decides (based on the configuration) if the transfer can proceed or should stop now. If the configuration says “proceed” an ERROR is still logged for the concrete step (this might actually be a valid place to use Warnings as a non-fatal errors).

Furthermore - if the configuration says “stop on error” the current transfer stops (ofcourse), but the application is not supposed to crash. In this case there must be some visible indication, that the error actually happend. I understand how you might take the error as handled and log it as info (or don’t log it at all), but in reality system administrators are actually using these errors as notifications that something is wrong.

As I said - I agree that there are other ways to do it and most probably this can all be handled in a different (better?) way by the fact that errors in go are values (:smiley:), but it is a valid use for failure investigation in many types of applications.

@Giulio_Iotti that’s true and helps for a good and clean presentation, but it’s not feasible in a large application with many people working on it. Guidelines are not so easy to follow because they are not enforced (which is a good thing in my opinion) and there’s no way to go through hundreds of thousands lines of code and apply them after that. And even if it was possible - it still not something you could do, because you are not always sure what the context is when the error occured.

9

In previous lives, I used SFL4J fairly extensively. But it wasn’t the logging levels that were valuable to us, it was the highly configurable categorization, routing and retention of log messages that mattered most.

For example:

  • Log messages from our com.foo.authentication package were logged to a separate file with a 30-day retention.
  • Log messages from our com.foo.purchase package with level ERROR were logged to another file with 90-day retention.
  • Log messages for all API requests were logged separately with a 72-hour retention.
  • Anything not matching one of those rules went to a default logfile with 7-day retention.

All of this configuration could be modified without changes to code, which was incredibly convenient. Developers just logged events, and our DevOps team could reconfigure how those messages were handled.

I’m not claiming this was a “best practice”, but it was possible using the tools we had and it worked well for us. Of course, the Java standard library didn’t support these features either - they were only available through external logging libraries.

3 Likes
10

Cant all of that be done with modern syslogs like syslogng and rsyslog? And your DevOps team should be happy since logs from your app won’t need to be integrated with the rest of their logging infrastructure.

1 Like
11

I daily use logrus’s structured log ability that allows me to aggregate and filter log search (“Interesting, if I group by the field “customer” I see the histogram shift towards 2 in particular” or “Oh logs from this filename are a bit noisy. I’ll filter those out”).

We can dynamically turn on verbose logging for a category of requests across the tier via zookeeper parameters as well. It’s used probably monthly, but is super important to get deeper execution information on the fly when customers report strange behavior that I can’t explain.

I kind of wish there was no logging library in the stdlib. Internally, we’ve been using logrus, but when I have time I’ll refactor the code into log15 because I like that model better.

12

What I want from a logging package:

  1. Levels. At least DEBUG, INFO and ERROR or equivalents.
  2. Level guards for performance.
  3. Easy run-time configuration changes, including changing level filter and destination.
  4. Easy run-time configuration changes possible from within the code. (SLF4J fails dismally at this.)
  5. Multiple back-ends including at least syslog, systemd, plain old text files, and some sort of structured text (XML or JSON, I don’t really care which).
  6. Sensible defaults to allow one-line setup (plus import) when starting out.
  7. ISO 8601 date and time format with no gratuitously non-standard separators.

So far I’ve been using logxi, which I think will meet all my requirements if I can work out how to get it to write to syslog.

13

8 Ability to write to syslog easily :wink:

14

Writing to syslog is at odds with the 12 factor recommendation of always writing to stdout and letting some external process take care of it.

1 Like
15

The syslog package’s Writer implements io.Writer, so can be passed into a log.Logger (in fact, that’s what the NewLogger function does).

1 Like
16

Since moving to Go from Java, I’ve reached the same conclusion. In fact I don’t even really think in terms of logging levels per se. Just two modes of the application - one that just happens to log additional information that amplifies what is logged in the less verbose mode. I’ve found that I don’t miss all of the DEBUG, INFO, ERROR prefixes at all.

1 Like
17

I definitely agree on the idea that Java has way too many logging levels (and programs tend to be written to log unbelievable amounts of garbage even at info).

I would argue the case for a separation between fatal and error. For a CLI program they’re essentially the same and I’d argue you don’t need different levels, but for a long running server I see fatal as “I literally can’t even”. For instance:

  • Configuration issue blocking startup
  • Inability to communicate with an upstream dependency in a way that can’t be retried or continued from
  • Or basically anything where the program would be non-functional

An error level message is one where something very bad has happened and someone probably needs to know about it, but the program itself isn’t in a fundamentally broken state. Examples:

  • Server that handles file uploads and passes them to S3. Maybe one of out hundreds of simultaneous uploads fail. I want to see if I’m getting elevated failure rates in my log aggregation but I don’t want my servers to be crashing and restarting just because one upload failed.
  • Service that communicates with other microservices. A single failure to communicate isn’t fatal, but it’s higher importance than just info logging. Again this is mostly for filtering at the aggregate level to determine failures that are more than just little network hiccups but it’s significantly easier to filter on levels than arbitrary data in the log message.

Coming at this from an ops background I need some reliable way to be alerted that the system isn’t performing as expected but having services crash outright is bad, especially in a world like Go where a single process is WebScale™ :wink:

1 Like
18

Is fatal as simple as the error that caused the application exit?

19

Some days ago, I was faced with adding levels to my app logging, I agree that most logging libraries do a lot and searching for something simple I found the Hashicorp’s logutils library, which I think it’s pretty simple: Letting you set your desired levels (named as you want) and to choose what minimum level to log from those ones.

From the repo description:

logutils is a Go package that augments the standard library “log” package to make logging a bit more modern, without fragmenting the Go ecosystem with new logging packages.

20

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.