Go: testing: add t.Helper to make file:line results more useful
Currently the caller level of T's decorate function is fixed
_, file, line, ok := runtime.Caller(3) // decorate + log + public function.
When wrapping common assertions in a code block, it would be useful to be able to modify
the caller level for correct log output.
eaigner
All 49 comments
Rob and I were discussing possibilities, like:
t.Frames(5).Errorf("...")
But probably after Go1.1.
_Labels changed: added priority-later, removed priority-triage, go1.1maybe._
bradfitz
on 25 Feb 2013
This is a hack, but it works (except when it doesn't, which is in deferred function
calls):
package demo_test
import (
"fmt"
"runtime"
"testing"
)
func up(frame int, s string) string {
_, origFile, origLine, _ := runtime.Caller(1)
_, frameFile, frameLine, _ := runtime.Caller(frame + 1)
if origFile != frameFile {
return s // Deferred call after a panic or runtime.Goexit()
}
erase := []byte("\b\b\b")
for ; origLine > 9; origLine /= 10 {
erase = append(erase, '\b')
}
return fmt.Sprintf("%s%d: %s", erase, frameLine, s)
}
func assert(t *testing.T) {
t.Logf("wrong line number")
t.Logf(up(1, "right line number"))
}
func TestDemo(t *testing.T) {
assert(t)
}
mxk
on 11 Jun 2013
ianlancetaylor
remyoudompheng
I made a start on this, https://golang.org/cl/12405043/. It is not ready for submission, but certainly ready for feedback.
_Owner changed to @davecheney._
_Status changed to Started._
davecheney
on 3 Aug 2013
What about a simpler solution that prints out all line numbers within the same _test.go file? I found that my hack actually makes it more difficult to figure out the true cause of the error. In some cases it's better to have the location in the Test function, while in others you want to know where in the helper function the test failed. Something like "my_test.go:63:591: a != b" makes it very easy to track down the problem by giving you all the relevant line numbers without dumping a full stack trace.
mxk
on 3 Aug 2013
@max, yes, this is what I am proposing
t.Error("something") // logs the file and line of where t.Error is called
t.Frames(1).Error("something") // logs the file and line of the caller of the function
that called Error.
davecheney
on 3 Aug 2013
Right, but I'm suggesting not having the Frames function. You could change the decorate
function instead to look through all stack frames starting at 3 and concatenate all line
numbers that are in the current _test.go file. If t.Error("something") is called in a
Test function, then the output stays as it is right now. But if it's called from a
helper function, then you get two or more line numbers, starting in the Test function
and working your way through all the helpers.
mxk
on 3 Aug 2013
No thank you. 1. how do you defined a helper function ? I can't think of a way short of making them end with helper or something. 2. this isn't want is spec'd by brad in comment #1 3. That isn't want Erik or I wanted in the original request or issue #6024.
davecheney
on 3 Aug 2013
So for issue #6024, instead of "tt_test.go:8: an error" you would get "tt_test.go:16:8: an error" without any changes to your code. No special naming is necessary. If chk is in the current _test.go file, which you can easily figure out in decorate, then append its line number. In my experience, having both line numbers is frequently useful in tracking down the problem, especially if your chk function tests for multiple error conditions. For an example, take a look at how I use the "cl" function in my SQLite test code: http://code.google.com/p/go-sqlite/source/browse/go1/sqlite3/sqlite3_test.go
mxk
on 3 Aug 2013
Still not convinced this is a good idea. Deferring to 1.3.
_Labels changed: added go1.3maybe, removed go1.2maybe._
robpike
on 19 Aug 2013
I'll throw out another approach here. It's not perfect, but maybe it'll inspire a better idea in someone else. `go test` knows where the actual test is; let it do the work. Let testing.T accept a filename and line range. If not present, behavior is unchanged. If present, t.decorate walks up the stack until it finds a matching frame. (If no such frame, use current behavior.) In cmd/go, when scanning for Test*/Benchmark* function declarations, note the filename and corresponding start/end lines, use them to populate InternalTest, and have InternalTest populate T/B accordingly. This does make things worse when TestFoo just wraps testFoo with minor variants. (See e.g. src/pkg/math/all_test.go:TestExp.) Perhaps this could be ameliorated by adding a method to t to clear the filename and line range, which could be explicitly called in such tests. Alternatively, the default could be flipped, cmd/go could gather the filename and line ranges, and let individual tests turn on their usage. This will also not likely play nicely with -cover, but we could just not generate filename and line range in cover mode and fall back to the current behavior. Thoughts?
josharian
on 25 Mar 2014
Here's a better proposal. (Nothing like writing down a bad idea and then sleeping on it.) Add t.Helper() and b.Helper(). When called, they mark the calling function as a helper function; testing looks further up the stack when printing file and line info. Sample usage in the program from issue #6024: http://play.golang.org/p/_uAL3FGBYq Whipped up a quick and dirty implementation at https://golang.org/cl/79890043 if anyone wants to give it a whirl to see how it feels. (At the least, it needs tests and an example to make it complete.)
josharian
on 25 Mar 2014
Comment 20 by asokoloski.work:
What I had in mind before stumbling on this thread was something like this:
func Helper(t *testing.T) {
t.Descend() // or Down
defer t.Ascend() // or Up
...
t.Error("blah blah")
}
...where the Descend and Ascend methods simply modify a stack frame offset, which is
currently hardcoded.
I see that Rob Pike has mentioned a similar but more stateless version of the same idea
here: https://golang.org/cl/12405043/#msg3
And now I'm curious what he means about testing helpers being "the devil's handiwork" :)
gopherbot
on 4 Apr 2014
#19: I'd really like that feature or something similar. It would be great to have some alternative to the \r hack that most of the testing libraries out there are using. Josh, are you interested in submitting a CL later for 1.5? I'm also willing to do the fleshing out (tests, etc) if that helps.
cespare
on 30 Sep 2014
Caleb, there are two things preventing me from mailing that CL for 1.5: 1. The API. The proposal in #19 differs from what Brad and Rob had in mind. Before polishing a CL to send, I'd like to get their input. 2. The implementation. Using runtime.Func's Entry is a bit of a hack, and one that won't work for closures, I think. (Maybe we don't care?) And I don't see another obvious way.
josharian
on 2 Dec 2014
Came here from #11432, would it make sense to think of this as filter functions on a slice of frames?
If the frame interface could expose the package of the file (maybe it does already) then you could for instance write a filter (implicitly, run from the youngest frame, pardon my flaky command of Go):
untilPkgSeen bool
func(f * frame) bool {
if untilPkgSeen || f.package().name() = "testing" {
untilPkgSeen = true
return false
}
return true
}
and pass that in to some appropriately designed interface to prune the stack trace to something with a higher signal-to-noise ratio. Or, perhaps a function to format the stack trace into a string.
dr2chase
on 29 Jun 2015
@dr2chase that might be a part of the underlying implementation of this feature. I doubt we'd want to ask users of the test package to think about call frames. But being able to ask the runtime package to filter frames sounds useful in building a nice high level API here and might fit nicely in with the considerations in #11432. However, package name is probably not what we'd filter on. Helper functions can occur within the same package, within other packages, etc. The API style I propose (which might not be what we want) is to be able to mark a function as a helper function by making a call from within it. To implement that, you might need some opaque identifier for a frame that could be used later with the frame filter.
josharian
on 29 Jun 2015
Probably it's ease to skip all helper functions by using something like this:
for skip := 1; ; skip++ {
pc, _, _, ok := runtime.Caller(skip)
if !ok { ...; break }
if strings.Index(runtime.FuncForPC(pc).Name(), ".Test") != -1 { ...; break }
}
powerman
on 11 Aug 2015
@powerman I think we'd want the frame skipping to be opt-in, not opt-out.
Edit: or non-optional, which is what your suggestion gives, I think.
cespare
on 3 Nov 2015
This issue has been stalled for a couple of years now. I'd like to help move it along. Would it help to create a formal proposal with something like @josharian's (TB).Helper idea as a starting point?
cespare
on 27 Sep 2016
@cespare, sure. This was also not tagged as a proposal so we've been missing it the past few months during proposal reviews.
bradfitz
on 27 Sep 2016
@cespare please do prepare a proposal, if you have the time to do so.
adg
on 31 Oct 2016
@adg Yep, I've got a document that I've been polishing on and off (mostly off) for the past few months.
My goal is to mail it sometime during the freeze so that any agreed-upon work could happen for 1.9.
cespare
on 31 Oct 2016
I suggest you take a different approach. Instead of counting stack frames, add a function F to the testing package that says "this function is the one to attach to the log message". If F is not called, the callback stops at the first TestXxx function encountered when rolling back.
This seems much less brittle an interface.
robpike
on 1 Nov 2016
Instead of counting stack frames, add a function F to the testing package that says "this function is the one to attach to the log message".
I think Caleb was going to write up a proposal to add a function that says "this function should not be attached to the log message". See the original suggestion above. The advantage to this is that only the helper methods must be decorated, not every test that uses helpers.
Your comment made me revisit a suggestion I made above, which is to have 'go test' do all the work and add no API at all. 'go test' knows which functions are the actual test functions; it can generate a list of them, which the logger can consult. I previously discarded this suggestion on the grounds that it made things much worse for root (as opposed to leaf) helpers--functions of the form TestFoo1, TestFoo2 that just call testFoo(1) and testFoo(2). However, subtests make it reasonable to eliminate such helpers, so maybe this alternative is now worth revisiting.
josharian
on 1 Nov 2016
SGTM
robpike
on 1 Nov 2016
OK, it sounds like we are waiting for @cespare to mail a proposal and maybe an implementation during the freeze, for action during Go 1.9.
For the record, it seems like the t.Helper mentioned in comment 19 (March 25, 2014) and illustrated in https://play.golang.org/p/_uAL3FGBYq is heading in the right direction.
rsc
on 21 Nov 2016
Proposal over in #18440.
Proposal lives in this thread now.
cespare
on 28 Dec 2016
CL https://golang.org/cl/34717 mentions this issue.
gopherbot
on 4 Jan 2017
As an alternative suggestion, how about changing Error and friends so that they print all the file/line numbers up to the top-level Test function?
The problem with just allowing control over the single file/line number is that it doesn't easily compose. If a given primitive selects a particular frame count, some other code might wrap that primitive and then the frame count is wrong again.
For example, it's common for people to write an "assert" primitive (here's one I came across last week). The proposed Helper method would work well when assert is called directly from a test function, but if someone makes a higher level function that calls assert as part of its implementation, the line number will be wrong again.
rogpeppe
on 4 Jan 2017
how about changing Error and friends so that they print all the file/line numbers up to the top-level Test function?
This seems really noisy to me as a default.
If a given primitive selects a particular frame count, some other code might wrap that primitive and then the frame count is wrong again.
Caleb's proposal handles this case, and the proposal doc discusses it explicitly. Perhaps something in the doc needs clarifying or expanding.
josharian
on 4 Jan 2017
See the Helper proposal here:
https://github.com/golang/proposal/blob/master/design/4899-testing-helper.md
cespare
on 4 Jan 2017
Caleb's proposal handles this case, and the proposal doc discusses it explicitly. Perhaps something in the doc needs clarifying or expanding.
Yes, you're right that it does handle this case, but I still think it's not sufficient.
To go with the "assert" example for a bit, let's say I have some code like this:
func TestFoo(t *testing.T) {
higherLevelCheck(t, someArgs{something})
higherLevelCheck(t, someArgs{somethingElse})
}
func higherLevelCheck(t *testing.T, someArgs Args) {
t.Helper()
r, err := doSomething(someArgs)
assert(t, err, nil)
assert(t, r.Something, expectedValue)
z, err = somethingElse(someArgs)
assert(t, err, nil)
if foo(z) {
t.Fatalf("higher level check failed")
}
}
func assert(t *testing.T, got, want interface{}) {
t.Helper()
if !reflect.DeepEqual(want, got) {
t.Fatalf("got = %v, want = %v", got, want)
}
}
Say the third call to "assert" in higherLevelCheck fails, with the proposal
as is, this will print the line in TestFoo that called the higherLevelCheck
function. That's useful information, but it doesn't tell us which assert
within higherLevelCheck failed, and that's important information.
I've seen this issue multiple times in real test code.
This seems really noisy to me as a default.
I'm not convinced that it would be too noisy - this only happens on test failures.
Perhaps we could look at some sample test failure output with and without
the extra information to get a feel for it?
rogpeppe
on 5 Jan 2017
To go with the "assert" example for a bit, let's say I have some code like this:
In this concrete example, I'd be inclined to use subtests in TestFoo and drop the t.Helper() from higherLevelCheck, and I suspect such a strategy will work well in many such cases. I can see that it won't always work, but I'm not convinced that this example means that t.Helper is not a very useful solution for a different and broad class of problems.
There's a similar problem with table-driven tables. If you don't write good error messages explaining which input failed, the error line number is insufficient by itself, and in a sense, you want the line number of the failing entry in the input table, even though that isn't anywhere in the stack trace at all. The right solution for that case is judicious use of the tools: combine subtests, good error messages, refactoring, and in a pinch, flag protection and/or commenting stuff out. I think something similar applies here.
Also, in some ways, printing all lines and using t.Helper are complementary. For example, you could imagine printing a stack and omitting all frames marked as helpers, and making more sparing use of t.Helper.
Perhaps we could look at some sample test failure output with and without the extra information to get a feel for it?
In a sense, we both have lots of experience with this. When you break a test and it panics instead of failing, you get a stack trace. I prefer the concision of the failures.
I personally would be fine with a flag to go test that switches to printing full stacks, perhaps informed by t.Helper. I just don't want it on all the time.
josharian
on 5 Jan 2017
FYI: I filed a related feature request (golang/go issue #18848) to allow tests to report arbitrary file/line information in error messages, not just Go source lines. When input comes from a testdata file, and particularly when the testdata file is in some kind of scripting language, it's the position in the data file that is most relevant to users stepping through test errors in their editor.
alandonovan
on 30 Jan 2017
Anyone else have thoughts about this? Any more info needed before a decision is made?
cespare
on 13 Feb 2017
I'd second @josharian's last couple comments. While the issue raised by @rogpeppe is concerning, I think it's ultimately orthogonal to the addition of TB.Helper(). That is, while I'd value this in some cases:
As an alternative suggestion, how about changing Error and friends so that they print all the file/line numbers up to the top-level Test function?
It does make for a noisy default. And, given that the introduction of this feature will allow testing frameworks to become first-class citizens, I don't really want to be poring through the stack trace guts of a testing framework all the time. Right now, the testing framework is oriented towards letting the developer hone in on a single point to begin their investigations. That's valuable to keeping tests comprehensible, and while it enforces a level of disciplined test design on the user (as @josharian described), I think that's a property worth maintaining.
Most importantly, though, I think the problem is orthogonal to the TB.Helper() proposal. As noted, we could always add an additional flag to go test that would cause it to print the stack trace back up to the top-level test/subtest. The default output would remain trim and focused, but the user could opt-in to additional inspection if needed.
I'd say this should go ahead as-is.
sdboyer
on 23 Feb 2017
Aha! Looks like this hasn't been reviewed by @golang/proposal-review because it was on hold waiting for @cespare to mail a doc. Doc done been mailed; un-holding.
josharian
on 28 Feb 2017
The design doc looks good. Does anyone want to make a case _against_ adding t.Helper?
rsc
on 6 Mar 2017
Guess not. OK, proposal accepted as in design doc.
rsc
on 27 Mar 2017
CL https://golang.org/cl/38796 mentions this issue.
gopherbot
on 30 Mar 2017
Related issues
ashb
路
3Comments
michaelsafyan
路
3Comments
OneOfOne
路
3Comments
ajstarks
路
3Comments
go101
路
3Comments
Most helpful comment
OK, it sounds like we are waiting for @cespare to mail a proposal and maybe an implementation during the freeze, for action during Go 1.9.
For the record, it seems like the t.Helper mentioned in comment 19 (March 25, 2014) and illustrated in https://play.golang.org/p/_uAL3FGBYq is heading in the right direction.