slog's use of runtime.Callers() with a skip

[sh...@tigera.io]

I was looking at replacing logrus with the new slog library in our project.  I noticed that it uses runtime.Callers() with a fixed skip to collect the PC of the calling code, presumably to make it possible for the handler to emit line number and filename.

Question is: is that sound in the face of inlining functions?  I think if the Info method gets inlined then the skip might be too large, for example.

I remember having to change similar code in our project to use runtime.CallersFrames in order to deal with inlining. Quite possible there's a way to deal with an inlined PC that I wasn't aware of, but it seemed wrong to me.

-Shaun

[jake...@gmail.com]

As far as I can tell, skip works even in the face of inlined functions, at least when used with runtime.CallersFrames(). It would be surprising  to me if it did not. Do you have any evidence to the contrary?

[Jonathan Amsterdam]

The Go runtime does the right thing.

[Shaun Crampton]

Do you have any evidence to the contrary?

Only that when Go 1.12 dropped, our similar function stopped working and that reducing the skip seemed to do the trick.

The symptom was that our function would see an assembly file as the caller, which I interpreted to mean that we'd skipped too far.  It only happened in goroutines with short stacks and I put it down to inlining.

Quite possible that the "fix" I made was mistaken, or that runtime.Callers has been updated/fixed since then.

In case you want to stare at my fix, here is the diff: https://github.com/projectcalico/libcalico-go/commit/1f1ababe294be198148c4232ef6c0344898d3b31#diff-7ab3329a79d456fe0d1747bba7344ac61e839f9097ae65d09b36f3c11ea13fbdL153  

Looking back, I see three changes in that "fix":

• Change to skip from 6 to 1 (and increase pcs buffer size accordingly).
• Reslice pcs to the valid portion, looks like we missed that before; possible this was the "real" fix?
• Change the list of file names that we skip.

We were already using CallersFrames before the fix.

The Go runtime does the right thing.

It does seem to in my local tests with up-to-date Go; i tried some toy examples and checked that functions really were being inlined.