Stack traces and the errors package

Read a couple of blogposts by Dave Cheney who is a contributor to Go since 2011 on handling errors.

http://dave.cheney.net/2016/06/12/stack-traces-and-the-errors-package

He discusses how to handle errors better and have more context on them. So he has worked on this simple package https://github.com/pkg/errors using which its easy to add more context to errors. We can get the stacktrace of errors with the line number and filename of the file where error are occured.

Dave Cheney is also an Australian and the main guy behind Go Meetups in Sydney. Amazing smart guy, a great inspiration for Go followers and people thinking of using Go.

I’m wary of going beyond the Go way of doing things unless there’s a very strong reason to. This particular package doesn’t seem like it gives us that strong edge, over the Go way.

I liked the fact that it could wrap the line no and the file where error occurred. A case where one of our user was trying to load nquads from a file and ended up getting an error came to mind. He said it would be easier if the error also showed the line number and file. This package gives that out of the box. Let’s see if we feel the need for it anytime in the future.

Doesn’t log fatal give you a stack trace, I thought it did.

Read this slide that Dave Cheney gave at GopherCon2016

https://github.com/gophercon/2016-talks/blob/master/DaveCheney-DontCheckErrorsHandleThemGracefully/GopherCon%202016.pdf

Would recommend everyone to go through it.


Some important points to note and slides to see

  • Only handle errors once.
  • Treat errors as opaque. Minimise you of sentinel errors.
1 Like

The standard library “Go” way here fails when you’re returning errors that no longer have any obvious context. This generally happens when errors cross package boundaries or propagate unhandled beyond where they have meaning except to signal failure.

There’s a slight performance hit in generating call stacks. I think it’s best to generate stack traces as soon as you have an error that you can’t handle, and isn’t defined as part of the interface your caller expects. That’s where you’d use Dave Cheney’s errors package to create your error values.

1 Like

You can test any potential performance hit by rewriting all “errors” imports with govers, and rewrite use of fmt.Errorf.

There are a lot of three-liners that begin with “if err != nil”. And often, output errors look too generic, and doesn’t even tell you which line created the error. A log.Fatal will not print stacktrace, but it will at least tell me which file, which line generated the error.

Can I add a package for error handling that will also use Dave Cheney’s lib? I feel that there are only three main cases.

  1. Receives error from external lib and want to log fatal with stack trace. This should add either zero or one extra line depending on whether the function returns err only. Imagine CHECK(myFunc(…)) or err := my Func; CHECK(err)
  2. Receives error from external lib and want to propagate. In this case, you want to use one of Dave’s function to stick in the stack trace. With the stack trace, there’s less need to add context and we can cut out several “return fmt.Errorf(“blah blah blah %s”, err)”.
  3. Creates error from within our library. In this case, our lib will just link to one of Dave’s wrap functions and we can save one import.

Ok, I am ignoring more complicated cases for now.

What do you all think?

LGTM.

Can you give an example of how the code might look like with this change?

We have x/x.go for this purpose.

Note that error handling in Go is verbose by design. It’s a common complaint that newcomers have about Go. So, let’s make changes keeping that factor in mind – that it’s not a bad thing.

I have read “Go errors are values” and as pointed out, this is a common complaint.

We could definitely have more error handling logic, e.g., store error in a struct somewhere. But most of the time, a log fatal suffices, I claim. If so, why do we need to keep writing

if err != nil {
  log.Fatal(...)
}

I saw x/x.go and it looks more complicated than it should… A log fatal with stack trace is really simple. And a stack trace usually provides enough info… no need to x.Trace(…) everywhere I feel.

Code will look like: (derr for dgraph error, C for check, Cf for Check with printf)

Case 1:

derr.C(err)
derr.Cf(err, "Attr %s", attr)

Case 2:

return derr.W(err)

err is from external lib and we add stack trace inside and pass on.

Case 3:

return derr.E("Something failed %s %d", a, b)
return derr.E("Something failed")

All of the above will add stack trace.

Not sure what you mean. Did you read it? x/x.go is a file containing utility functions, equivalent of utils package.

x.Trace is for RPC tracing, which attaches debugging information across every rpc. log.Fatal or other log commands are printed on the console – we’ve mostly moved away from those, and towards x.Trace. This is equivalent of /rpcz at Google. So, we’d still need that.

I think what you’re proposing is to create a new module called derr. That’s okay, but consider using x package which already exists for this purpose.

I suspect what you mean is: derr.C(cond), where cond has to be true, otherwise we log fatal. The rest sound okay. Note that most errors via log probably are log fatal, unless they’re culminating to the end user – because we generally use tracing.

Sorry, I didn’t read that carefully. I have been using the heap stuff but not so much the other functions. logrus seems useful. Will look into how we can use it more. Feel we can be more consistent about our logging and error checking. Probably no package should import log and everything should go through x.

Yes, x.Check would be good. (I suppose you will oppose to x.CHECK?)

Please don’t use logrus. We moved away from logrus. I wrote a huge PR to do that across the entire code base. It’s slow and unoptimized because of its high dependence on maps. Also, tracing took over all of it’s functionality leaving only log.Fatal, which we switched to using standard Go library for.

As I say these things, I realize the lesson that I’ve learned with these external libraries that do simple things is that a lot of times they do it without any concern about performance. So, it’s best to stick to standard Go libraries or write whatever we need for simpler things. Only bring in external deps for more complicated functionality. Also, as Rob Pike says, A little copying is better than a little dependency.

I agree that logrus is unnecessary. However, I would love my logger to print useful information such as the filename and line number. I see a lot of x.Log(“uidassigner_main”) and there is no need for that if you have something even better — the file and line number.

x.go can have a global info log and error log. Both will be initialized like

logger := log.New(os.Stdout, "INFO: ", log.Ldate|log.Ltime|log.Lshortfile)

To log, you just write

x.Info(...)
x.Infof(...)
x.Error(...)
x.Errorf(...)

Ok, errorf might be confusing. Maybe some other name.

There could also be a global init, something that runs after packages run their init(), like GoogleInit. Every main will just begin with x.Init which will initialize flags and run a list of init functions that packages init might have added.

Absolutely. That’s understandable. But, the point I was trying to make above was that we should be trying to move away from serialized logging on console, and towards RPC tracing. So, think about when you feel like you need to have a log, can it be converted to an x.Trace? Tracing provides us with better debugging information, where we have the logs from the entire life of an RPC. So, if we need to debug why a particular RPC is slow, we can look at all the logs over the lifetime of that RPC and figure out which step took longer.

Normal logs, even with file info won’t give us anything close to this.

I see. Yes, I agree. It would be better to use just x.Trace.

If you look at this PR:

You’d realize that we actually had before was similar to what you’re proposing now. And how we switched to rpc tracing.

Sorry. Forgot to reply to this. I like CHECK as well. Works for me. Go lint would throw some errors, but we can ignore those.

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