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.

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

tap intermittently fails 1 test #422

Closed
mreinstein opened this issue Feb 11, 2018 · 13 comments · May be fixed by pke/node-tap#52 or pke/node-tap#53
Closed

tap intermittently fails 1 test #422

mreinstein opened this issue Feb 11, 2018 · 13 comments · May be fixed by pke/node-tap#52 or pke/node-tap#53

Comments

@mreinstein
Copy link

When I invoke my test manually from the command line à la node test/sequence-buffer.js, The tap output consistently indicates success on all tests.

When I run my tests via ./node_modules/.bin/tap test

I intermittently get this error:

test/sequence-buffer.js ..1..0 # no tests found
1..0 # no tests found
test/sequence-buffer.js ......................... 1578/1579
  sequence_buffer
  not ok test count !== plan
    +++ found                                                           
    --- wanted                                                          
    -1                                                                  
    +1578                                                               
    results:
      ok: false
      count: 1578
      pass: 1578
      fail: 1
      bailout: false
      todo: 0
      skip: 0
      plan:
        start: null
        end: null
        skipAll: false
        skipReason: ''
        comment: ''
      failures:
        - tapError: no plan

Different runs also produce a different number of asserts that are run:

test/sequence-buffer.js ......................... 1651/1652
test/sequence-buffer.js ......................... 1568/1569

And then other times, the tests all pass. Mostly failure though. Is this a race condition?

@mreinstein
Copy link
Author

@mreinstein
Copy link
Author

downgrading to tap@10.7.3 fixed the problem for me. This issue started in 11.0 and up.

@mreinstein
Copy link
Author

false alarm, it's still broken on 10.7.3. I apparently when I ran it I had 20 successes in a row by chance, then it failed on travis-ci the 21st time. forehead slap

@isaacs
Copy link
Member

isaacs commented Feb 15, 2018

Can you run the test with tap test/sequence-buffer.js -C to get the raw TAP output?

It looks like the problem is that your program is ending without finishing the test, or not flushing all the output, resulting in a truncated TAP stream.

@mreinstein
Copy link
Author

here's a build failing on travis with tap test -C

https://travis-ci.org/mreinstein/reliable.io.js/builds/341762990

@isaacs
Copy link
Member

isaacs commented Feb 16, 2018

Ok, so, yeah, as I suspected, the process is just exiting without that test being finished.

        ok 7160 - should be equal
        ok 7161 - should be equal
    # time=5958.959ms
    # test count(3) != plan(null)
    # failed 1 of 3 tests
        # test count(7161) != plan(null)
        # failed 1 of 7161 tests
not ok 2 - test/endpoint.js # time=6378.771ms
  ---
  timeout: 30000
  file: test/endpoint.js
  command: /home/travis/.nvm/versions/node/v8.9.4/bin/node
  args:
    - test/endpoint.js
  stdio:
    - 0
    - pipe
    - 2
  cwd: /home/travis/build/mreinstein/reliable.io.js
  failures:
    - tapError: no plan
  exitCode: 0
  ...

I'm not sure why it's not erroring more usefully though.

Is it possible that the program is calling process.exit() explicitly somewhere?

@mreinstein
Copy link
Author

I've grepped the code and don't see process.exit() called directly in any of my code. As for modules I'm only using tap@11.1.0 and debug@3.1.0... perhaps one of them could be calling it.

@isaacs
Copy link
Member

isaacs commented Feb 17, 2018

Ok, yeah, there's definitely something odd going on here. Simpler repro case:

const t = require('tap')
t.test('numbers', t => {
  for (let i = 0; i < 2000; i++) {
    t.pass('a number is ' + i.toLocaleString())
  }
  t.end()
})

I'll keep digging. Thanks for finding this!

@mreinstein
Copy link
Author

mreinstein commented Feb 17, 2018

Thanks for finding this!

I'm just glad it wasn't something obvious and stupid on my part. I'm frequently terrified when opening issues in any tracker. :0

@isaacs
Copy link
Member

isaacs commented Feb 19, 2018

Thanks, bisect.

Thanks a lot. Super helpful there.

Ok, I continue to dig.

ee2cc44e6bdc97a6a1765e2bf34fb1f34359e9b6 is the first bad commit
commit ee2cc44e6bdc97a6a1765e2bf34fb1f34359e9b6
Author: isaacs <i@izs.me>
Date:   Mon Jul 3 08:54:34 2017 -0700

    tap: rewrite to class and arrows

:040000 040000 7594326d6b3b4f8779968bf005789dc660ce7660 0a971acd764f42f614b7ae7d184f0a8acc27444e M	lib

@mreinstein
Copy link
Author

wow that's surprisingly far back in the commit history

@isaacs isaacs closed this as completed in 283c8e6 Feb 19, 2018
@isaacs
Copy link
Member

isaacs commented Feb 19, 2018

Thanks! That was a satisfying bug to track down. Not obvious at all, until I read through the ee2cc44 commit.

For anyone following along at home, note that () => {} functions don't have an arguments free var.

@mreinstein
Copy link
Author

awesome! I wonder if this was impacting other people as well, and might reduce the number of false postive test failures across the whole npm ecosystem.

thanks for the fix! 🥇 👍

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
2 participants