Add t.Helper calls, test helpers linter

[helsaawy]

Add t.Helper() calls to testing helpers so the correct test name and line number is shown during logs
ref.

This allows logs to show the line number within a test that raised the error, rather than the line within the helper funciton that emitted the log (eg, runpodsandbox_test.go:89 instead of helper_sandbox_test.go:43)

t.Log, t.Error, and co. use the call stack to track which function issued the logging statement. Therefore, even if a helper function does not log or fail, it should still call t.Helper in case its callee's do.

Add thelper linter to settings to make sure testing helpers correctly call t.Helper.

Renamed t testing.TB to tb testing.TB to satisfy thelper.

Signed-off-by: Hamza El-Saawy hamzaelsaawy@microsoft.com

[kevpar]

How does thelper determine what it believes is a "helper" function and thus should call t.Helper()?

Do you believe that all functions being marked as "helper" will log with sufficient context that we don't need them in the log output?

[helsaawy]

How does thelper determine what it believes is a "helper" function and thus should call t.Helper()?

I believe it checks functions that use a testing.T/B/TB/etc parameter that are not public and start with Test or Benchmark. It has been pretty accurate and I have not seen any false alarms when I was updating the code.

Do you believe that all functions being marked as "helper" will log with sufficient context that we don't need them in the log output?

I think so, yes.
A lot of our helpers will internally Error or Fatal and the add their context to the error/problem, but there isnt a way to add callee context to the message. So we usually will have the errors explain the path from the source all the way up to where ever they are logged, but dont have any insight where in the test function the helper was actually called, which is usually of more interest.

For example, for our functional tests, we have

=== RUN   Test_Container_CRI_Restart/LCOW_Explicit
    helper_sandbox_test.go:43: failed RunPodSandbox request with: rpc error: code = Unknown desc = failed to create containerd task: failed to create shim task: failed to mount container storage: failed to add SCSI scratch VHD: failed to modify UVM with new SCSI mount: guest modify: guest RPC failure: no such device or address: unknown
    --- FAIL: Test_Container_CRI_Restart/LCOW_Explicit (7.05s)

But Test_Container_CRI_Restart has two calls to runPodSandbox which both could throw that error, and the output gives no no indication of which it is.

[kevpar]

How does thelper determine what it believes is a "helper" function and thus should call t.Helper()?

I believe it checks functions that use a testing.T/B/TB/etc parameter that are not public and start with Test or Benchmark. It has been pretty accurate and I have not seen any false alarms when I was updating the code.

My only concern is if there are valid cases where we will want a "helper" function to show up in the log output (e.g. if it is significant enough to have non-obvious control flow). If we add a linter it could be noisy and annoying in this case.

Do you believe that all functions being marked as "helper" will log with sufficient context that we don't need them in the log output?

I think so, yes. A lot of our helpers will internally Error or Fatal and the add their context to the error/problem, but there isnt a way to add callee context to the message. So we usually will have the errors explain the path from the source all the way up to where ever they are logged, but dont have any insight where in the test function the helper was actually called, which is usually of more interest.

For example, for our functional tests, we have

=== RUN   Test_Container_CRI_Restart/LCOW_Explicit
    helper_sandbox_test.go:43: failed RunPodSandbox request with: rpc error: code = Unknown desc = failed to create containerd task: failed to create shim task: failed to mount container storage: failed to add SCSI scratch VHD: failed to modify UVM with new SCSI mount: guest modify: guest RPC failure: no such device or address: unknown
    --- FAIL: Test_Container_CRI_Restart/LCOW_Explicit (7.05s)

But Test_Container_CRI_Restart has two calls to runPodSandbox which both could throw that error, and the output gives no no indication of which it is.

So really our test code context looks something like this:

TestTopLevelFunction
Helper1
Helper2
Internals1
Internals2
Internals2
ErrorSite

Currently we are getting context of [Internals1..ErrorSite] and knowing where we are in Helper2. We are trading this to get [Internals1..ErrorSite] and where we are in TestTopLevelFunction. So it seems non-obvious to me if this is actually a useful tradeoff in most cases or not. If our helper functions tend to be small and simple, it probably is. But there are cases where they could not be.

I certainly don't feel that this is a bad change though. If you've looked and believe this will help, I'm up to take it in.

[helsaawy]

We can always override the linter adhoc (//nolint:thelper) or remove it wholesale if it does get to be annoying.

Also, we can always add more context to the errors/logs so that we can distinguish where in Helper1 or Helper2 we are, since they are the ones controlling the log.
Buts its much harder (or uglier) to inject the TestTopLevelFunction context into the helpers (eg, allowing helpers to take a custom error message that they prepend to their output).

This was motivated by the go (testing) wiki, but mostly my frustration with being unable to pinpoint where a test failed.

I am not wed to it, but I do think this will help parsing error logs.

[ambarve]

To be honest I don't really like when our helper functions directly call t.Fatal instead of returning an error and letting the caller handle that. It also causes problems if that helper is called in a goroutine. I feel t.Fatal should only be called by the Test function itself with all the error context.
But I am not sure if everyone agrees with that and so this is a good change fix the error logs.

[helsaawy]

I sorta agree, ideally the caller should handle it, but then testing code gets really repetitive with all the error handling, especially since the only path would be to call t.Fatal regardless....