(ava 3.0.0-beta.2) per test timeout settings not being honored

[sramam]

Description

Please see this for a minimal reproduction

Using ava@3.0.0-beta.2, the per test timeout setting is not being honored. Seems to need
the CLI option -T to be set to extend the default timeout.

With the caveat that I don't have a very deep understanding of the code, a quick peek at the
source seems to indicate that support for per test timeout was not intentionally removed,

Test Source

link

test(`timeout test`, async (t) => {
  t.timeout(15000);
  await delay(12 * 1000);
  t.pass();
});

Error Message & Stack Trace

(Failure) Per test timeout

$ npx ava --verbose

  ✔ snapshot-test
  ✔ main

  ✖ Timed out while running tests

  1 tests were pending in dist/test/index.js

  ◌ timeout test


  2 tests passed

(Success) Global timeout

$ npx ava -T 12500 --verbose

  ✔ snapshot-test
  ✔ main
  ✔ timeout test (12s)

  3 tests passed

Config

Copy the relevant section from package.json:

  "ava": {
    "files": [
      "dist/**/test.js",
      "dist/**/test/**/*.js",
      "!dist/**/test/fixtures/**/*.js",
      "!dist/**/helpers/**"
    ],
    "serial": false
  },

Command-Line Arguments

Please see above

Relevant Links

Minimal Reproduction

Environment

Tell us which operating system you are using, as well as which versions of Node.js, npm, and AVA. Run the following to get it quickly:

$ node -e "var os=require('os');console.log('Node.js ' + process.version + '\n' + os.platform() + ' ' + os.release())"
Node.js v12.7.0
darwin 18.5.0

$ npm --version
6.10.2

$ npx ava  --version
3.0.0-beta.2

[sramam]

Is there a reason the timeout behavior was inverted?
A quick search of the issues didn't surface anything obvious.

The new behavior of low-timeout by default is going to cause me much headache on
a mature test suite. It's not the actual behavior that is an issue as much as the inversion.

[novemberborn]

AVA now defaults to a -T 10s setting. Which is less than the timeout you have configured in your test. It should be fine if you bump the global timeout in the AVA configuration.

Previously, there was no timeout at all, which would lead to CI runs timing out consuming billable resources.

[sramam]

I see - is the plan then to deprecate t.timeout()?

[novemberborn]

I see - is the plan then to deprecate t.timeout()?

No — it serves its own purpose.

Do you think 10 seconds is too low a timeout?

[sramam]

Wanted to confirm before commenting further.

Why not just have a single timeout value that is applied to t.timeout?
And set that to being really low - like 100ms, 500ms or 1s.
The user can increase it two ways

1. set the default limit to being higher when needed - which applies to all tests in the run.
2. increase it on a per test case basis.

It achieves all purposes -

1. fine grained control
2. minimal (and less confusing) config
3. provides adequate control for run-away test run durations

I think this is what mocha does.

[novemberborn]

We have a different view on timeouts. As long as your test suite is making progress, we don't feel like we need to fail individual tests for taking too long.

t.timeout() exists when staying within a certain duration is a specific property of your test.

(I'm closing this issue for housekeeping purposes, but let's keep the conversation going.)

[sramam]

Perhaps I have been mis-understood here:

We are in agreement that if a test case is making progress it should continue on.

However, one should be able to extend the default global timeout setting on a per test basis. This is currently not possible per the original report of this issue.

I think t.timeout() inside a test case should override -T from the CLI.

If my casual browsing of api.js is any good, it looks like there are two timer loops - one per test triggered by the t.timeout() and one global one triggered by the -T value.

That global timer loop is the one I have an issue with.

My suggestion was to use the same value as provided by -T and transport it down to the per test timer as it's default timer value. This will allow doing away with the global timer loop. (And infact reducing the default value of the timer - 10s test cases should not be the norm in the overwhelming majority of test cases)

Since it bounds each test, the unbounded CI billing cannot be an issue.

[novemberborn]

We'd rather users do not obsess about how long a single test takes. Hence the notion of progress.

t.timeout() is for advanced users with specific use cases. Perhaps we could make that fail if the timeout exceeds the global progress timeout.

[sramam]

I see.

I actually think the global timer is more complex for a developer to grok.
There are multiple problems with it:

1. Depending on the test-author, there might not be sufficient information on what caused the delay.
2. Even for a diligent test-author, any in-memory state is likely to be lost.
3. The failure looks like multiple tests were aborted, without a clear indication of which is the offending party (this is what happened to me - took me a while to whittle it down to the example in this issue)
4. Depending on the test suite, the list of failed test cases reported is ephemeral. Meaning a second run might fail, but will report a different set of interrupted test cases.
5. In many cases, the CI system will have it's own timeout mechanisms and nuances to understand before one can isolate things down to the offending test case - though that would be avoided in this case hopefully. I did land up exhausting the Github-actions allotment to my org last month and landed up setting the default timeout for my github actions to 10minutes. For the longest ava test-suite (a 3.0 migration WIP), I have now set -T 300000 for my ava suite, but can see how the action-timeout might need to be extended for windows builds. Basically, even with the current implementation, interactions with the CI system's timeout are within the realm of possibility.

For the suite I am working on, I have necessary context in the moment. 6 months from now, or worse someone else 24+ months out, and this becomes a really expensive problem of pre-diagnosis.

With the alternative being proposed, ava would flag the one offending test-case, time it out, and say

Dear developer,
Test case XYZ took too long so we killed it. Figure it out.

Regards from your friendly neighborhood test-runner,
ava.

Now the developer just

1. Reruns the test case, or test suite
2. Adds more information to figure root cause
3. [bonus] makes the suite more robust over time.

In fairness, even with the global timeout, the developer would eventually land at the same destination, but with a lot of needless pre-work.

I cannot emphasize enough the confusion that not having the intermediate test state causes - especially if one didn't author the suite - or authored it a long time ago. It's a non-linear function of the complexity of the system-under-test.

Now we can debate the complexity of a single suite, but with my focus on execution time, IMHO I'm far above average in my sensitivity to smaller/faster test cases and therefore embedded complexity.

Which also segues nicely to the timeout-value point.

On low test timeouts

All I am asking for is that level of control - not actually the default value. It's like a linter rule.
Basically set it high enough that most people won't care and when they do, there is only two things they can do:

1. set the default value for all tests by setting config
2. modify it for the specific test with t.timeout(XXXms)

Happy to live with 10s or whatever for the out-of-the-box value and set it to my needs.

One positive side effect I liked with mocha's opinion on a good test duration (IIRC 35 ms yellow, 50 ms red by default) was that it provided me awareness. I worry about it and brought it along with me when migrating to ava.

For large complex test suites, I tend to lose patience when the suite exceeds a couple of minutes, looking to refactor.

That behavior has saved me many hours, probably much more, in waiting to see if the change I just made passes muster suite-wide.

It's made a more modular system, spiffier test runs and means I appear less insane to most people (maybe now I'm just getting carried away and should stop).

Might not be for everybody, but I found it affected my system design & development behavior in very positive ways.

[novemberborn]

One positive side effect I liked with mocha's opinion on a good test duration (IIRC 35 ms yellow, 50 ms red by default) was that it provided me awareness. I worry about it and brought it along with me when migrating to ava.

With concurrently executing tests inside a single worker, and also concurrent workers hopefully maxing out your CPU, these numbers are a lot less meaningful. This also makes quick individual test timeouts problematic.

The progress timer helps if the worker process becomes unresponsive, or if it takes an inordinate amount of time before tests are even declared (you can defer the first test() call).

[sramam]

I agree.

Apologize if this comes across as being argumentative. I was making the broader point of lower being better and not having the ability to encode the timeout was something I missed with ava.

The global timer being added is almost the exact capability needed, more code, but lower ability to control/reason-about.

I do think having a single timer that is propagated to each test and can be set at various scopes - global, per test, possibly per suite (t.before?) - is the simplest/best option that tends to lend itself to better control and ability to reason about a system and it's behavior under test.

Given that mocha use(s/d?) a similar strategy, I do feel the pattern is broader than just my needs.

I should point out that I haven't used mocha for years now - remember missing it when I first move to ava and didn't realize till this discussion how much I missed the timer. I do tend to eye-ball the numbers with ava - but that just tells you I suffer from OCD!

With that, I'll rest my case. I can live with whatever you choose to do.
It's easy for me to make arguments, you implement and maintain this puppy.
I respect that - much, much more I get a chance to tell you.

[sramam]

ouch - it got lost in my copy/paste editing of the comment above:

It's not the exactness of the timer that is of import, but the estimate-ability. I'd tend to set the timeout to ~2x - 2.5x what would be needed in a normal run. Amount of IO needed defines the multiple.

Once the mental pattern gets set, it's really really hard to not write most of your "business-logic" as a pure-function and restrict the IO related operations to a few test cases. But now I am advocating for a particular development methodology - way outside the scope of this discussion.

Really, over-and-out-this-time.

[cdaringe]

i just ran into this.

in most systems, configuration at leaf nodes is more specific than at parent nodes. a test is configuration is more specific/granular configuration node than global configuration. in my case, i'm setting t.timeout(120000), and i expect it to be honored. it is currently not honored.

i think @sramam's points are on the money. not honoring t.timeout is confusing and misleading UX. more importantly, it's needed functionality that ought not demand adjustment to global configuration. i need a long timeout for e2e tests that have known slow peer systems. i don't want the rest of my suite to suffer an otherwise increased timeout--just these specific tests (hence why i tried to configure at the most granular level--in the test!).

the way the docs are written make me think this is how it works: https://github.com/avajs/ava/blob/master/docs/07-test-timeouts.md

i strongly feel that we should ensure that t.timeout(...) calls within tests actually define the timeout for the test.

[novemberborn]

@cdaringe please see #2384 for what we want to do next here.