New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Initial timeout timer starts before tests are run #1377

Closed
mo opened this Issue May 6, 2017 · 5 comments

Comments

Projects
None yet
3 participants
@mo
Copy link

mo commented May 6, 2017

Run:
time ava --timeout 100 bug.js

The above command takes 30 seconds to run, I was expecting ava to fail the testcase after 100 milliseconds.

Another strange thing is that if I instead run:
time ava --timeout 1s bug.js
...then it exits after 1000ms as expected?!

Contents of bug.js is the following code:

import test from 'ava';

function getTheAnswerToTheMeaningOfLifeTheUniverseAndEverything(callback) {
    setTimeout(() => {
        // Forgetting to invoke callback here
    }, 30000);
}

test.cb('make sure callback is called exactly once', t => {
    t.plan(1);
    getTheAnswerToTheMeaningOfLifeTheUniverseAndEverything(result => {
        t.is(result, 42);
        t.end();
    });
});

Environment

ubuntu 15.10
node v7.7.2
npm 4.5.0
ava 0.19.1

@novemberborn

This comment has been minimized.

Copy link
Member

novemberborn commented May 7, 2017

The problem is that we start the timeout before we launch the test workers. With a 100ms value it might trigger before any tests are ready to run, at which point it kinda gets lost.

I think instead we should track whether we have pending tests, and ensure the timer is running whenever new tests are started, clearing it when tests end. And assume that test workers aren't stuck in a while loop before they can notify the main process of their tests.

Regardless of the above, I don't think a value of 100ms is ever realistic given how AVA works. The designed use case of --timeout is to help catch hanging tests, not to limit how long a particular test can take. It'd be better to set the timeout to a few seconds instead.

(Possibly we could consider changing the value to always be in seconds?)

@sindresorhus

This comment has been minimized.

Copy link
Member

sindresorhus commented May 7, 2017

(Possibly we could consider changing the value to always be in seconds?)

👍

@mo

This comment has been minimized.

Copy link

mo commented May 7, 2017

The global timeout documentation makes it sound like the timer starts when the actual testcase starts, and also that the timer is reset whenever a new testcase begins (I think this sounds very sensible):
https://github.com/avajs/ava#global-timeout

In general, I think it's important that it's possible to:

  • detect bugs where an expected callback is never invoked
  • detect bugs where an expected callback is invoked two or more times
  • detect bugs where a synchronous function accidentally ends up in an infinite loop

Using Mocha I was able to cover all three use cases but I ended up adding an explicit timeout for each TC which has both pros and cons.

it('is working', function (done) {
  this.timeout(10000);

  util.asyncCallbackTrimLowThatAccidentallyCallsCallbackTwiceWhenBuggy('   Foo   ', actual => {
    assert.equal(actual, 'foo');
    done();
  });
});

I also implemented similar testcases in tape and qunit. Mocha and tape both make it look a bit like the testcase passed when the callback is invoked the first time. When the the extra, unexpected, call comes in it correctly fails the TC though, like this:
http://temp.minimum.se/screenshot_20170507_162344.png

The corresponding fail output from QUnit was less ambiguous:
http://temp.minimum.se/screenshot_20170507_162557.png

To catch all cases with ava I had to resort to a quite ugly hack:

test.cb('util test async callback function that forgets to callback', t => {
  t.plan(1);
  util.asyncCallbackTrimLowThatForgetsToCallbackWhenBuggy('   Foo   ', actual => {
    t.is(actual, 'foo');
  });
  // Ugly hack to make sure "missing / double callback" bugs are detected
  setTimeout(t.end, 500);
});

test.cb('util test async callback function that accidentally calls callback twice', t => {
  t.plan(1);
  util.asyncCallbackTrimLowThatAccidentallyCallsCallbackTwiceWhenBuggy('   Foo   ', actual => {
    t.is(actual, 'foo');
  });
  // Ugly hack to make sure "missing / double callback" bugs are detected
  setTimeout(t.end, 500);
});

It would be really sweet if there was a way to catch all three bug cases without resorting to the ugly hack.

@novemberborn

This comment has been minimized.

Copy link
Member

novemberborn commented May 9, 2017

The global timeout documentation makes it sound like the timer starts when the actual testcase starts, and also that the timer is reset whenever a new testcase begins

Yea. There's definitely a bug: we start the timer before we start collecting tests, and that's wrong.

In general, I think it's important that it's possible to:

  • detect bugs where an expected callback is never invoked

In specific scenarios we can already detect this even without the --timeout option. There are other scenarios where that's impossible though (say if your test sets up a persistent database connection).

  • detect bugs where an expected callback is invoked two or more times

We currently have no way of failing a test that passed previously, see #1330.

  • detect bugs where a synchronous function accidentally ends up in an infinite loop

Good point, this doesn't work. Opened #1378.


Let's continue discussion in the relevant issues. I'll change the title on this one to deal with the timer starting prematurely.

@novemberborn novemberborn changed the title ava sometimes doesn't fail callback testcase when timeout is exceeded Initial timeout timer starts before tests are run May 9, 2017

novemberborn added a commit that referenced this issue Feb 6, 2018

Refactor API module
Remove indirection by inlining code. It's not the prettiest without
async-await but it's easier to follow.

Remove unnecessary auto-binding of methods. There's no need to "get"
blank results either when running a test files fails.

Handle timeouts within a test run, without touching the `runStatus`
object. Restart the timeout timer whenever a new "fork" is created. This
gives new test files the chance to start running tests. Don't start the
timer *before* running any tests. Fixes #1377.

Clean up "fork" instances when test files exit.

Set up a new precompiler on every test run. Don't store it on the `Api`
instance. If caching is enabled, fix the caching directory relative to
the project directory, without looking it up again.

Compile all test and helpers files before running any test. This doesn't
improve time-to-first-test but it does mean that test files can depend
on each other. AVA will correctly load the precompiled file. No tests
are run if any file fails to compile.

Pass the real path to the precompiler.

Compute `execArgv` when a test file is run, not all at once for all
files.
@mo

This comment has been minimized.

Copy link

mo commented Feb 11, 2018

Yay, thanks for fixing!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment