printing all errors from stdlib as they happen

136 views
Skip to first unread message

Kevin Chadwick

unread,
Apr 8, 2020, 1:30:05 PM4/8/20
to golang-nuts
I have tried googling but perhaps all the talk around wrapping errors has
stopped me finding a solution.

With my go code I am perfectly happy with verbose log chaining and printing each
error with GO, adding the line number for each one with
log.SetFlags(log.Lshortfile) etc. and sending it to print, syslog or database. I
find this improves the messages as I code too.

The stdlib seems to hide things away for no good reason??

I have:

reverseproxy.go:445: http: proxy error: x509: certificate signed by unknown
authority

I simply want to get to the line number of the source error where the
certificate was decided to be signed by an unknown authority. Preferably without
adding lines to the code and re-running.

In my logs I would have a trace automatically printed/saved and be able to
modify the message right there. I find multiple return values and gos printing
to be brilliant.

How can I get to the source logic of the stdlib error without manual
intervention/debugging?

Brian Candler

unread,
Apr 9, 2020, 5:17:57 AM4/9/20
to golang-nuts
Do you mean the line number *in the library function* ??

In general, I think that's an impossible problem.  Consider a somewhat convoluted example of a library function:


func Bar(...) {
    ...
    if xyz() {
        blah = true
    }
    if abc() {
        baz = false
    }
    ...
    if blah && flurble() && !baz {
        err = SomeError   // A
    }
    ...
    ...
    if err {
        return 0, err     // B
    }
    ...
}

At what point was it "decided" that SomeError should be returned?  A number of conditions had to be met before line A was executed.  If you modified the code there, it could record as part of the error value the line number at which the err variable was set.  However without modifying the code (or changing the language, so that every variable value remembers the line number where it was last set), I think the best you could get is the line number of B.  And that's not very useful.

Your own code presumably looks something like this:

foo, err := library.Bar(baz)
if err {
    ...
}

This means you already know exactly which function you're calling; the error must have "come from" somewhere in that function.  (Of course, that function may have used the results from other functions before deciding to return an error)

There are only a fixed number of return points from library.Bar - quite possible only one.  Would it really help much to know which "return" statement was used?

Kevin Chadwick

unread,
Apr 10, 2020, 7:22:30 AM4/10/20
to golang-nuts
On 2020-04-09 10:17, Brian Candler wrote:

Sorry, for some reason I missed this reply.

> However without modifying the code (or changing the
> language, so that every variable value remembers the line number where it was
> last set),

The Log package does that for you. This output can be redirected. In C I would
use __LINE__.

> I think the best you could get is the line number of B.  And that's
> not very useful.

I disagree, if baz threw and error then it itself should have printed an error
before returning, saving me minutes of grepping. The calling function may also
print a more pertinent logical error. I realise this would require stdlib
support, obv.

>
> Your own code presumably looks something like this:
>
> foo, err := library.Bar(baz)
> if err {
>     ...
> }
>
> This means you already know exactly which function you're calling; the error
> must have "come from" somewhere in that function.  (Of course, that function may
> have used the results from other functions before deciding to return an error)
>
> There are only a fixed number of return points from library.Bar - quite possible
> only one.  Would it really help much to know which "return" statement was used?

I would want the log.Print with line to be near to where it was decided an error
occurred, not where it was decided an error should be returned.

I see that backwards. Every error should be printed along with it's current file
name and line and optionally returned for logical handling reasons. A chain is
recorded and potentially thrown away for some performance reason but by default
you can run your program and grep the errors in the case of a huge chain but
otherwise have verbose information by default!

You shouldn't have to dig? Perhaps I am missing something?

Rather than reverseproxy.go:445, message from different file.

You would also get verify.go:??? possibly different message.

What I would like is the line number close to the logic that decided an error
occurred printed by default.

I print *and* return errors immediately? otherwise it is a logical decision that
may or may not still be printed?

Brian Candler

unread,
Apr 10, 2020, 9:05:06 AM4/10/20
to golang-nuts
On Friday, 10 April 2020 12:22:30 UTC+1, Kevin Chadwick wrote:

I disagree, if baz threw and error then it itself should have printed an error
before returning, saving me minutes of grepping. The calling function may also
print a more pertinent logical error. I realise this would require stdlib
support, obv.

Exactly: someone would need to modify stdlib to generate additional debugging information at whatever the author decides are "interesting" decision points.

But why do you want this?  A library you called already returns a descriptive error of what went wrong.  The library is a black box.  If you want to open the black box to learn how it works, that's fine, but not something most people want to do, as it's not relevant to the logic of your own application.

Given that you know exactly which function you called - and individual functions should be of small size - then if you look in the source of that function, the point which decides and returns error X is generally obvious.

If the error is a result of a system call, you can run your program under strace / dtruss etc to get visibility of it.

If you think the library itself is misbehaving, you can run it under a debugger.

 

>
> Your own code presumably looks something like this:
>
> foo, err := library.Bar(baz)
> if err {
>     ...
> }
>
> This means you already know exactly which function you're calling; the error
> must have "come from" somewhere in that function.  (Of course, that function may
> have used the results from other functions before deciding to return an error)
>
> There are only a fixed number of return points from library.Bar - quite possible
> only one.  Would it really help much to know which "return" statement was used?

I would want the log.Print with line to be near to where it was decided an error
occurred, not where it was decided an error should be returned.

Same again: "where it was decided" means the author of stdlib would have to generate the appropriate logs.

 

I see that backwards. Every error should be printed along with it's current file
name and line and optionally returned for logical handling reasons. A chain is
recorded and potentially thrown away for some performance reason

What chain is "recorded and thrown away"?  The only chain you have is the function call chain.  The stdlib function at the tip of the chain then returns, and its frame is popped off the stack.  But even if it wasn't, all it would record is the values of its local variables just before it returned.  It does not record what control path was taken through that function.  With some changes it might be possible to record the program counter just before it returned (i.e. the exit point), but you already said you didn't want this.
 
What I would like is the line number close to the logic that decided an error
occurred printed by default.


Once again, it sounds like you're saying you want stdlib to be instrumented.  This is not something which can be done mechanically, it would have to be added manually.

Kevin Chadwick

unread,
Apr 10, 2020, 10:39:53 AM4/10/20
to golang-nuts
On 2020-04-10 14:05, Brian Candler wrote:
> But why do you want this?  A library you called already returns a descriptive
> error of what went wrong.  The library is a black box.  If you want to open the
> black box to learn how it works, that's fine, but not something most people want
> to do, as it's not relevant to the logic of your own application.
>

We should be wanting more eyes on code. Also it potentially is and was of some
use, in the case of:tls Example "VerifyPeerCertificate

"https://golang.org/pkg/crypto/tls/#example_Config_verifyPeerCertificate"

> Given that you know exactly which function you called - and individual functions
> should be of small size - then if you look in the source of that function, the
> point which decides and returns error X is generally obvious.

Not in the case that I posted.

>
>
> Same again: "where it was decided" means the author of stdlib would have to
> generate the appropriate logs.
>

Indeed and they are best placed to do so. Unfortunately some instrumentation or
disable flag may be needed in certain cases where atomicity is required.

>  
>
>
> I see that backwards. Every error should be printed along with it's current
> file
> name and line and optionally returned for logical handling reasons. A chain is
> recorded and potentially thrown away for some performance reason
>
>
> What chain is "recorded and thrown away"?  The only chain you have is the
> function call chain.

I meant a log/print chain if kept in memory for better performance. A flag not
to record would be more accurate, I guess. Merely asking a question whether I
have missed an implementation, not the details of a new implementaion.
>  
>
> What I would like is the line number close to the logic that decided an error
> occurred printed by default.
>
>
> Once again, it sounds like you're saying you want stdlib to be instrumented. 
> This is not something which can be done mechanically, it would have to be added
> manually.
It would make me happy for sure. There seems to be a lot of error handling that
isn't of much use or is more opaque than it should be.

I assume that you are saying that the only way of garnering the first source of
the error is from reading lots of code? Which was my question. Am I missing a
way to get this.



So I assume that the error pkg is just to please the dynamic side to the
language (tag on an extra error, rather than multiple specific returns), yes?
Maybe to avoid type pain? I love Go and can live with type handling but the
dynamic side (interfaces etc.) is the side of the language that I disklike
significantly...so far. Despite trying to understand why people say they love
interfaces. I hate them. e.g. I don't see the point of the private key tls
interface when individual functions for each type are run anyway. Seems like
abstract magic for no reason. I guess I am missing something there, if not here.

I don't buy the API simplification argument...so far. Salt in this wound, I
guess. Oh well.

Brian Candler

unread,
Apr 10, 2020, 5:20:19 PM4/10/20
to golang-nuts
On Friday, 10 April 2020 15:39:53 UTC+1, Kevin Chadwick wrote:
We should be wanting more eyes on code. Also it potentially is and was of some
use, in the case of:tls Example "VerifyPeerCertificate

"https://golang.org/pkg/crypto/tls/#example_Config_verifyPeerCertificate"


I'm afraid I don't see the problem.

That's an example of using the TLS API.  In this API, the user passes a callback function to be called at a certain point in the TLS exchange.  *Your* function returns an err to say whether the certificate is acceptable or not.

All that the caller of this function (i.e. the TLS library) cares about is whether the certificate is acceptable or not, so as whether to continue with TLS or abort.

I assume that you are saying that the only way of garnering the first source of
the error is from reading lots of code? Which was my question. Am I missing a
way to get this.

Well, I'm saying that a library tells you whether there was an error or not, and what the error *was*.  I don't care *where* in the library code this decision was made.  It's not my concern, unless I don't trust the library to do it's job properly (in which case, the problems are more serious).

 
So I assume that the error pkg is just to please the dynamic side to the
language (tag on an extra error, rather than multiple specific returns), yes?

There's the error interface, and there's the errors package. https://blog.golang.org/error-handling-and-go

You are free to return a range of distinct concrete error types if you wish, to indicate different errors, and/or to carry additional information.  For some APIs it would be good design to do this, where the caller needs to take different action based on different errors.

errors.New() is just a short-cut for returning a simple error which needs nothing more than a text description.  In python it would be like: raise RuntimeError("message").  And sometimes, this is all you need.
 
Maybe to avoid type pain? I love Go and can live with type handling but the
dynamic side (interfaces etc.) is the side of the language that I disklike
significantly...so far.

I think you'll get to like it.  Interfaces allow you to have limited, controlled polymorphism where required.  Although I spend a lot of time with dynamic languages like python, the thing I dislike most is that when I look at code like

def foo(v):
    v.bar()

I have no idea either what type v is, or where method bar() is defined: every method call is polymorphic.  In go, the function being called is normally clear from the type of the variable (the awkward case being baz := foo(), which makes me go look at the return signature of foo() before I know the type of baz)

In those limited cases where you *need* polymorphism, go provides it via interfaces, since it doesn't have generics or sum types (yet).  And abstractions like io.Reader are very powerful.
 
I don't see the point of the private key tls
interface when individual functions for each type are run anyway.


I'm not really familiar with that API surface.  It looks like this is performing the role of a (void *) in C - passing an arbitrary blob of data - and I expect there's some other part of the API where you need to pass in both an algorithm and (separately) a key.  Again, without generics it's hard to make such things type-safe.

Kevin Chadwick

unread,
Apr 10, 2020, 7:24:02 PM4/10/20
to golang-nuts
On 2020-04-10 22:20, Brian Candler wrote:
>
>
> I'm afraid I don't see the problem.
>
> That's an example of using the TLS API.  In this API, the user passes a callback
> function to be called at a certain point in the TLS exchange.  *Your* function
> returns an err to say whether the certificate is acceptable or not.
>

That isn't true. It comes from logf function of reverseproxy.go. Grepping tracks
it down to a function with just switch cases on output strings. Grepping further
for a variable eventually leads you to the logic.

With all that abstraction. I assumed something useful must be going on but I
still struggle to see it. I find that the error interface creates opaqueness not
transparency and maybe I needed to be brought into the light of it's beauty. I
guess not. Now I am wondering if those that thought if err != nil was too
verbose have already caused a lack of clarity.

> All that the caller of this function (i.e. the TLS library) cares about is
> whether the certificate is acceptable or not, so as whether to continue with TLS
> or abort.
>
> I assume that you are saying that the only way of garnering the first source of
> the error is from reading lots of code? Which was my question. Am I missing a
> way to get this.
>
>
> Well, I'm saying that a library tells you whether there was an error or not, and
> what the error *was*.  I don't care *where* in the library code this decision
> was made.  It's not my concern, unless I don't trust the library to do it's job
> properly (in which case, the problems are more serious).

I completely disagree for many reasons!

You may need more information than the error provides.

The documentation may be lacking or take longer to interpret than the code.

You may want to see if you can adapt the library or code to a particular problem
and be sure it's security is intact.

It would increase the likelihood of patches or improvements to be made and bugs
be spotted.

I never said there was a problem. It just doesn't seem very helpful.

I'm not a spoilt brat. I am thankful for the stdlib. I was just in wonder.

Thank You for your time.
Reply all
Reply to author
Forward
0 new messages