Libraries shouldn’t log. Logging takes resources and should occur as rarely as possible. If an error occurs deep in your program, you don’t want to immediately log it, bubble the error up the stack, and then log the same error again but with additional context. Thus, you should try to log as close to the UI as possible. If you’re writing a web service, only log in the handler before you send a response. The code for accessing the database is a dependency and should be in its own package. We treat it like a library and only concern ourselves with its API.

But… having more context would be helpful. Even though it’s wasteful, logging an error twice reveals more about the current code path when the bug occurred.

One way to provide more context is to have very specific messages for each log line that are never repeated. For example…

const (
  UnauthorizedUserLogMsg                string = "Unauthorized request"
  UnmarshallingRequestErrorLogMsg       string = "Error unmarshalling request body"
  JSONMarshallingResponseErrorLogMsg    string = "Error marshalling json response body"
  JSONAPIMarshallingResponseErrorLogMsg string = "Error marshalling jsonapi response body"
  DatastoreErrorLogMsg                  string = "Error returned by the datastore"
)

func (handler *Handler) CompaniesGetAll(resp http.ResponseWriter, req *http.Request) {
  companies, err := handler.Datastore.CompaniesGetAll(limit, offset)
  if err != nil {
    handler.Logger.Error().Err(err).Msg(DatastoreErrorLogMsg)
    http.Error(rw, "Internal Server Error", http.StatusInternalServerError)
    return
  }

  // Handle a normal response
  // ...
}

If the Datastore package is returning a Postgresql error, that error could have come from any request to the database in CompaniesGetAll, and the error messages from the Go Postgresql adapter are especially obscure.

Enter github.com/pkg/errors, a package that lets you wrap your errors with additional context. Calling errors.Wrap(err, message) returns a struct that conforms to the errors interface where message is prepended to the error. Everytime an error is returned, you can add context to that error message.

My preferred way to use errors.Wrap is to keep it concise. The message added should have the format “verbing noun”.

var count int
err := db.DB.QueryRow("SELECT COUNT(*) FROM companies;").Scan(&count)
if err != nil {
  return 0, errors.Wrap(err, "querying company count")
}

Now your errors have more context AND you are not logging in your packages.

  1. I will allow an exception for packages that start their go routines that run alongside your app. If your package needs to log information, please please please let the user pass in an io.Writer. Most loggers support the io.Writer interface, so your user's can use their logging library and format. If your logger writes JSON and you use Datadog's tracer, error messages from Datadog aren't going to match your pretty formatted logs
  2. I wish there was a standard interface for logging that gave you log levels.
  3. Secret trick: if your apps performance is degrading, disable logging. Verizon disables logging when new iPhones launch to prevent themselves from being DDoS'd by thirsty Apple users.
  4. Zerolog, my logger of choice, lets you use Diodes, a ring buffer, for writing logs. If logs are written to Diodes faster than stdout can read them, logs get dropped until stdout catches up.