Don't double log

If there’s one programming anti-pattern I see repeatedly, that makes everyone’s lives more difficult, it’s this:

	req, err := http.NewRequest(http.MethodPost, fmt.Sprintf(checkVerifURL, t.cfg.ServiceVerificationSID), strings.NewReader(body.Encode()))
	if err != nil {
		t.log.WithError(err).WithField("phone", phone).Error("failed to create request for check code")
		return err

This is actual code, copied verbatim, from a project I’m consulting on. For those of you who don’t speak Go, let me translate:

Create an HTTP request object. If that results in an error, log the error, then return the error to the caller.

“What’s wrong with this?” you may ask. Well, let me show you the caller, also copied verbatim:

	err = h.twilio.SendVerifyCode(req.Phone)
	if err != nil {
		h.log.WithError(err).Error("Failed to send verification code")
		return c.JSON(http.StatusInternalServerError, errs.InternalServerErr)

And the translation:

Send a verification code vai Twilio. If that results in an error, log the error, then send a JSON-formatted error as the response to the client.

Hopefully now the problem is more apparent:

The exact same error message is logged twice.

This makes debugging difficult, because the log file will show two errors, when only one occurred. And the only way to make sense of this is by reading the code along with the log file—effectively creating tight coupling between your code and logs. Isn’t that a lovely thought?

And this isn’t actually the worst failure mode this type of code can exhibit.

Imagine that our caller to the original function had some fallback mode. Perhaps when Twilio fails, it sends an email. In this case, we’d have an error log that shouldn’t exist at all and can only serve to confuse people.

The solution?

Handle each error exactly once.

Dave Cheney talks about this in his post Don’t just check errors, handle them gracefully. Although his post offers Go-specific examples, the principle applies to any language choice. In summary:

You should only handle errors once. Handling an error means inspecting the error value, and making a decision. If you make less than one decision, you’re ignoring the error. Making more than one decision in response to a single error is also problematic.

So when you encounter an error state, make a decision about it. This means either handle it (i.e. log it, do a fallback, maybe halt program execution), or defer that handling to the caller (by way of re-throwing, returning an error value, etc). But never do both.

If you enjoyed this post, you’ll enjoy 6 ways to RUIN your logging, which covers 5 other logging anti-patterns I see frequently.

Share this