Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Incorrect start time and duration in spec #41

Open
Bareus opened this issue Feb 22, 2018 · 0 comments
Open

Incorrect start time and duration in spec #41

Bareus opened this issue Feb 22, 2018 · 0 comments

Comments

@Bareus
Copy link

Bareus commented Feb 22, 2018

For my integration tests I'm using mocha.parallel to speed up the tests. I'm using a custom-made mocha reporter that outputs the start and end time of a test in case of a failure to make it easier to go through the logs of my application. Sadly it seems that mocha.parallel doesn't set the start time correctly - the start time is set when the whole suite is started, not when the actual test is started. Also the duration seems to not always be set correctly. This results in an incorrect output of my mocha reporter.

Here is an example (the sleep function is basically a setTimeout which is wrapped in a promise):

describe("Test Suit Collection", function() {
    parallel("parallel suite 1", function() {
        it("test 1", async function() {
            await sleep(1000);
            expect(true).to.be.false;
        });

        it("test 2", async function() {
            await sleep(1000);
            expect(true).to.be.false;
        });
    });

    parallel("parallel suite 2", function() {
        it("test 3", async function() {
            await sleep(1000);
            expect(true).to.be.false;
        });

        it("test 4", async function() {
            await sleep(1000);
            expect(true).to.be.false;
        });
    });
});

Which outputs this with my mocha reporter:

Test Suit Collection
    parallel suite 1
      1) test 1 (Start: 09:09:00.921Z, End: 09:09:01.927Z)
      2) test 2 (Start: 09:09:00.921Z, End: 09:09:00.921Z)
    parallel suite 2
      3) test 3 (Start: 09:09:00.921Z, End: 09:09:01.929Z)
      4) test 4 (Start: 09:09:00.921Z, End: 09:09:00.921Z)

As you can see all tests have the same start time, even though the tests in parallel suite 2 should have started a second later. Also the duration in test 2 and 4 is not set correctly for some reason (I calculate the end time by adding the duration to the start time).

And this is part of my mocha reporter that creates the output above:

runner.on('fail', function (test) {
        let startTime = this.stats["start"].toISOString().slice(11);
        let endTime = (new Date(this.stats["start"].getTime() + test.duration)).toISOString().slice(11);
        process.stdout.write(util.format(indent() + color('fail', '  %d) %s (Start: %s, End: %s)\n'),
            ++n, test.title, startTime, endTime));
});

I can't seem to find a workaround for this within my custom mocha reporter by listening to the 'test' event and save my own start time. mocha.parallel lead the mocha runner to believe that the tests run sequentially which in turn results in a sequential execution of the mocha reporter. I would get an output like this:

Test Suit Collection
    parallel suite 1
      1) test 1 (Start: 09:33:21.089Z, End: 09:33:22.093Z)
      2) test 2 (Start: 09:33:22.098Z, End: 09:33:22.099Z)
    parallel suite 2
      3) test 3 (Start: 09:33:22.100Z, End: 09:33:23.101Z)
      4) test 4 (Start: 09:33:23.103Z, End: 09:33:23.103Z)

I hope you can fix this sometimes soon. If not I'll try to fix this myself and make a pull request, if I find the time.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@Bareus