Configuring Timeouts for Tests and Hooks independently

[epotter2297]

I have been working on some hooks + attributes + etc. for TUnit that make it possible to automatically cleanup test data from a SQL database using transactions and savepoints, while still respecting the [DependsOn] attribute. The current version looks a little different now, but you can see my initial proof of concept here. It is going well so far, and I am personally hoping that I can open source it, although I will need to warm up my employer to the idea first.

The rough idea is that:

1. An [After(TestDiscovery)] hook runs to perform some setup / analysis on the tests that were selected to run
2. A [BeforeEvery(Test)] hook runs that makes the test wait until it has a database in the right state
3. The test runs
4. An [AfterEvery(Test)] hook runs that figures out either if the transaction needs to be rolled back entirely, or if there is a particular savepoint that needs to be rolled back to
5. An [After(TestSession)] hook runs that cleans up the databases

Currently I am trying to diagnose some bugs which cause the test suite to hang, and was attempting to add in some log statements to help find any potential issues or deadlocks. Unless I am missing something though, if a test is "Inconclusive" (due to me manually stopping execution because it was hanging) I am not able to see any of the logs associated with it.

So to try and work around that problem, I tried configuring timeouts to force a failure when they get stuck, and encountered another issue. Because the timeout includes the time it takes to execute both the [BeforeEvery(Test)] and [AfterEvery(Test)] hooks, it causes more timeouts than what I would prefer due to how the hooks function. Here's a simplified example to illustrate:

[Timeout(1000)]
public class Example
{
    [Test]
    public async Task A(CancellationToken token)
    {
        await Assert.That(true).IsEqualTo(true);
    }

    [Test, DependsOn(nameof(A))]
    public async Task A1(CancellationToken token)
    {
        await Assert.That(true).IsEqualTo(true);
    }

    [Test, DependsOn(nameof(A))]
    public async Task A2(CancellationToken token)
    {
        await Assert.That(true).IsEqualTo(true);
    }
}

public static class ExampleHooks
{
    [BeforeEvery(Test)]
    public static async Task Setup(CancellationToken token)
    {
        // Step 1: Do work that takes 600ms
        await Task.Delay(600, token);
        // Step 2: Wait until siblings are not running
        ...
    }
}

My hooks will make sure that siblings that are both children of the same dependent test can only run one-at-a-time. This is because it:

1. Starts a transaction before running A
2. Makes a savepoint after running A
3. Rolls back to the savepoint after running A1 (or whichever leaf runs first)
4. Rolls back the whole transaction after running A2 (or whichever leaf runs second)

This means that either A1 or A2 actually need to wait inside of the [BeforeEvery(Test)] hook for 1200ms in total before the test method starts running, which means it fails due to the timeout rules. But ideally, it would be nice to be able to say "the test execution should be at most 300ms and the [BeforeEvery(Test)] hook should have no timeout restriction (or a much larger one)", which would make all of the tests pass more consistently.

[thomhurst]

Just thinking on the best way to do this. It'll probably be a lot more work than it sounds because the Hooks + Test are essentially wrapped in one large scope with the timeout.

Also thinking of from an API perspective... Maybe [Timeout(100_000, IncludeHooks = false)] or something?

[epotter2297]

Another option would be to simply support adding a [Timeout] attribute to the function with the hook?

public static class ExampleHooks
{
    [BeforeEvery(Test), Timeout(100_000)]
    public static async Task Setup(CancellationToken token)
    {
        // Step 1: Do work that takes 600ms
        await Task.Delay(600, token);
        // Step 2: Wait until siblings are not running
        ...
    }
}

I'm not sure if there's a great way to have an API that does that without some kind of breaking change though... Since if you have an assembly scoped timeout, would that apply to the test and hook separately until overridden? It would be easy to accidentally have a timeout twice as big as what you actually wanted if you're not careful.

Somewhat related to the subject of timeouts, I noticed that whatever mechanism tracks the time it takes to execute a test and reports it to MTP does not include the time it takes to execute the Before hooks, but does include the After hooks. Which is a little confusing because you can end up in a situation where your test fails due a timeout, and at the same time says the time it took to execute was less than the timeout period. I can make a bug report for that as well if you want 👍

[thomhurst]

Yes please 😁

[epotter2297]

Also wondering, does it sound at all possible that cancellation tokens for [AfterEvery(Test)] hooks (and maybe other places, but I haven't checked) are shared across tests?

I have a weird situation I found where if I add a test that times out to my test suite, I suddenly have other unrelated tests failing due to the SqlConnection being broken, even though the test with the timeout failure didn't use a SqlConnection at all. The only explanation I've thought of so far is that a rollback or savepoint creation that happens in an [AfterEvery(Test)] hook was cancelled.

I could put together a POC if that sounds worth looking into some more, but it might take some setup so I didn't want to bother if it was more likely to be a bug on my end.