Integration tests sometimes failing

[laggingreflex]

This is a weird issues, I'm not sure what's going wrong... if it's just me (I'm on Windows), or if it actually has something to do with integration tests

Sometimes the tests fail and sometimes they pass...

Here's a screen grab where I run the same test command:

The two tests that are failing are:

1. 'merges reports from subprocesses together'

   When it fails (see source for what's expected) the actual output is:

   ,first
   
   second
   
   --------------------|----------|----------|----------|----------|-------------------|
   File                |  % Stmts | % Branch |  % Funcs |  % Lines | Uncovered Line #s |
   --------------------|----------|----------|----------|----------|-------------------|
   All files           |    94.12 |    73.08 |        0 |    94.12 |                   |
   bin                 |    83.72 |    57.14 |      100 |    83.72 |                   |
     c8.js             |    83.72 |    57.14 |      100 |    83.72 |... 22,40,41,42,43 |
   lib                 |    96.41 |    65.38 |      100 |    96.41 |                   |
     parse-args.js     |    97.47 |    44.44 |      100 |    97.47 |             55,56 |
     report.js         |    95.45 |    76.47 |      100 |    95.45 |       51,52,53,54 |
   test/fixtures       |    95.16 |    89.47 |        0 |    95.16 |                   |
     async.js          |      100 |      100 |      100 |      100 |                   |
     multiple-spawn.js |      100 |      100 |      100 |      100 |                   |
     normal.js         |    85.71 |       75 |        0 |    85.71 |          14,15,16 |
     subprocess.js     |      100 |     87.5 |      100 |      100 |                 9 |
   --------------------|----------|----------|----------|----------|-------------------|
   ,
   

   which differs in the last line (subprocess.js)

2. 'omit-relative can be set to false'

   When it fails (see source for what's expected) the actual output is:

   ,first
   
   second
   
   ,fs.js:115
       throw err;
       ^
   
   Error: EISDIR: illegal operation on a directory, read
       at Object.readSync (fs.js:491:3)
       at tryReadSync (fs.js:330:20)
       at Object.readFileSync (fs.js:367:19)
       at new CovScript (C:\...\c8\node_modules\v8-to-istanbul\lib\script.js:14:23)
       at module.exports (C:\...\c8\node_modules\v8-to-istanbul\index.js:4:10)
       at Object.keys.forEach (C:\...\c8\lib\report.js:65:22)
       at Array.forEach (<anonymous>)
       at Report._getCoverageMapFromAllCoverageFiles (C:\...\c8\lib\report.js:62:32)
       at Report.run (C:\...\c8\lib\report.js:31:22)
       at module.exports (C:\...\c8\lib\report.js:86:10)
   

   It throws an "EISDIR: illegal operation on a directory" error instead of the expected "ENOENT: no such file or directory"

Edit: I'm testing this with #26 checked out, but this issue seems to exist without it too.

[bcoe]

@laggingreflex mind trying the latest version that's been released (3.2.0). we now warn rather than throw in this case, and also print a better error message.

[profnandaa]

@laggingreflex -- is this okay now? We can close this issue?

[laggingreflex]

There's improvement. Out of 2 I'm now only getting 1 error:

Again, this happens only some of the times unpredictably.

Have you guys tested it running tests again and again? (at least ~10 or so times)

I hope it's not just me, or my OS (Windows).

  c8
    √ reports coverage for script that exits normally (1089ms)
    1) merges reports from subprocesses together
    √ omit-relative can be set to false (1008ms)

  parse-args
    hideInstrumenteeArgs
      √ hides arguments passed to instrumented app
    hideInstrumenterArgs
      √ hides arguments passed to c8 bin (73ms)


  4 passing (3s)
  1 failing

  1) c8
       merges reports from subprocesses together:

      AssertionError: expected value to match snapshot c8 merges reports from subprocesses together 1
      + expected - actual


       --------------------|----------|----------|----------|----------|-------------------|
       File                |  % Stmts | % Branch |  % Funcs |  % Lines | Uncovered Line #s |
       --------------------|----------|----------|----------|----------|-------------------|
      -All files           |     92.5 |     71.7 |        0 |     92.5 |                   |
      +All files           |     92.5 |    69.23 |        0 |     92.5 |                   |
        bin                |    83.72 |    57.14 |      100 |    83.72 |                   |
         c8.js             |    83.72 |    57.14 |      100 |    83.72 |... 22,40,41,42,43 |
        lib                |    93.71 |    62.96 |      100 |    93.71 |                   |
         parse-args.js     |    97.47 |    44.44 |      100 |    97.47 |             55,56 |
         report.js         |    90.63 |    72.22 |      100 |    90.63 |... 70,71,85,86,87 |
      - test/fixtures      |    95.16 |    89.47 |        0 |    95.16 |                   |
      + test/fixtures      |    95.16 |    83.33 |        0 |    95.16 |                   |
         async.js          |      100 |      100 |      100 |      100 |                   |
         multiple-spawn.js |      100 |      100 |      100 |      100 |                   |
         normal.js         |    85.71 |       75 |        0 |    85.71 |          14,15,16 |
      -  subprocess.js     |      100 |     87.5 |      100 |      100 |                 9 |
      +  subprocess.js     |      100 |    71.43 |      100 |      100 |              9,13 |
       --------------------|----------|----------|----------|----------|-------------------|
       ,"

      at Context.it (test\integration.js:34:36)

[profnandaa]

I see, when you make changes, you must generate a new snapshot with the command:

$ npm run test:snap

Is that the reason?

PS. We're clarifying this in the contributing guidelines here #36

[laggingreflex]

I'm not sure I understand.. I'm not making any changes. I'm just running the test.

[profnandaa]

@laggingreflex -- ok, got it. We'll need to investigate this. Looks like for your case there is a slight change in coverage report between multiple runs, right?

[profnandaa]

However, just to be sure, the earlier reported error #27 (comment) is no longer happening, right?

[laggingreflex]

Yes, earlier 2 tests were failing, now only one of them is still failing - 'merges reports from subprocesses together' (in the same manner, i.e. sometimes and unpredictably).

And yes, the error is the result of a slight change in coverage report (which is what the test checks for using the snapshot) between multiple runs.

[profnandaa]

Thanks. I’ll investigate. Also do let me know when you find any hints.

-na

On Wed, Sep 26, 2018 at 5:48 PM laggingreflex ***@***.***> wrote: Yes, earlier 2 tests were failing, now only one of them is still failing - 'merges reports from subprocesses together' (in the same manner, i.e. sometimes and unpredictably). And yes, the error is the result of a slight change in coverage report (which is what the test checks for using the snapshot) between multiple runs. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#27 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAP8kZixgA8pVUJyUNJ6beuztBGgEbJYks5ue5PAgaJpZM4Wn7v6> .

-- Sent from a tiny device while on the move.

[laggingreflex]

I did a bit more digging, and it looks like the order in which arguments are passed to v8CoverageMerge here is sometimes reversed, and that might be what's causing the issue.

[bcoe]

@laggingreflex could you provide output files that fail when the merge is reversed? We have a rework of the algorithm that might help.

[laggingreflex]

@bcoe Did you mean output of mergedResults[result.url] and result (args passed to v8CoverageMerge)?

If so here it is. I've filtered the output to just where result.url === 'fixtures/subprocess.js' (the file that fails). I've also created the gist such that 1st commit contains the output when the test runs OK, and 2nd commit when the test FAILs, so you can see easily see in the diff of what changes between the two runs.

You'll see that in the output for mergedResults[result.url] (the first argument), the following changes:

-          { startOffset: 231, endOffset: 245, count: 0 } ],
+          { startOffset: 187, endOffset: 200, count: 0 } ],

Whereas in the output of result (second argument), it's this:

-          { startOffset: 187, endOffset: 200, count: 0 } ],
+          { startOffset: 231, endOffset: 245, count: 0 } ],

They're identical except in reverse order, which means the arguments are themselves in reverse order.

[demurgos]

@laggingreflex Could you check with the changes from this PR?

The order order should be increasing startOffset then decreasing endOffset.

[laggingreflex]

@demurgos Yep, that PR seems to fix this. I've ran tests many times with it and they're always passing 👍

[bcoe]

@laggingreflex I believe this should be fixed now, let me know if you continue to bump into any issues.