bcoin-org/bcash

Swallowed errors in protocol-test.js due to Mocha bugs

Opened this issue · 1 comments

chjj commented

So, reimplementing mocha has revealed a number of bugs in mocha itself. There's at least 3 or 4 cases where mocha is completely swallowing an error and not displaying it. One case in particular affects bcash. Example:

Mocha behavior:

$ mocha test/protocol-test.js


  Protocol
    ✓ should encode/decode version
    ✓ should encode/decode version
    ✓ should encode/decode verack
    ✓ should encode/decode addr
    ✓ should not limit block like packet size to MAX_MESSAGE (384ms)
    ✓ should limit block like packet size to MAX_FORK_BLOCK_SIZE * 2 (176ms)
    ✓ should limit packet size to MAX_MESSAGE


  7 passing (606ms)

The last two tests are actually throwing an error post-callback. I noticed this when bmocha was failing some tests.

Bmocha's original behavior:

$ bmocha test/protocol-test.js

  Protocol
    ✓ should encode/decode version
    ✓ should encode/decode version
    ✓ should encode/decode verack
    ✓ should encode/decode addr
    ✓ should not limit block like packet size to MAX_MESSAGE (345ms)
    1) should limit block like packet size to MAX_FORK_BLOCK_SIZE * 2
    2) should limit packet size to MAX_MESSAGE

  5 passing (565ms)
  2 failing

  6) Protocol
       should limit block like packet size to MAX_FORK_BLOCK_SIZE * 2:

      Error: Invalid magic value: 0.

      at Parser.error (/home/chjj/work/node_modules/bcash/lib/net/parser.js:57:24)
      at Parser.parseHeader (/home/chjj/work/node_modules/bcash/lib/net/parser.js:138:12)
      at Parser.parse (/home/chjj/work/node_modules/bcash/lib/net/parser.js:98:26)
      at Parser.feed (/home/chjj/work/node_modules/bcash/lib/net/parser.js:85:12)
      at Context.it (/home/chjj/work/node_modules/bcash/test/protocol-test.js:148:12)

  7) Protocol
       should limit packet size to MAX_MESSAGE:

      Error: Invalid magic value: 2c350fd.

      at Parser.error (/home/chjj/work/node_modules/bcash/lib/net/parser.js:57:24)
      at Parser.parseHeader (/home/chjj/work/node_modules/bcash/lib/net/parser.js:138:12)
      at Parser.parse (/home/chjj/work/node_modules/bcash/lib/net/parser.js:98:26)
      at Parser.feed (/home/chjj/work/node_modules/bcash/lib/net/parser.js:85:12)
      at Context.it (/home/chjj/work/node_modules/bcash/test/protocol-test.js:169:12)

So what's going on here? Mocha seems to be swallowing two errors.

Long story short, Mocha swallows errors in this case:

it('should succeed', (cb) => {
  cb();
  throw new Error('foobar'); // <-- swallowed
});

Which is exactly what's happening in test/protocol-test.js: the parser throws an error, triggers the callback, and the test passes. In the same call stack, the parser continues and tries to parse the "next" packet (because it's now in a bad state due to the failed size check), and throws an error.

The difference between mocha and bmocha is that bmocha waits one tick of the event loop to see if any uncatchable error occurs after the callback has been called (and even after that, will watch for any uncaught errors). Mocha ignores all further execution instantly once the callback is executed, and swallows any errors (this is nothing short of insane). So, what to do?

On the latest master, I decided to have this particular edge case "pass", but display a warning to the programmer:

  Protocol
    ✓ should encode/decode version
    ✓ should encode/decode version
    ✓ should encode/decode verack
    ✓ should encode/decode addr
    ✓ should not limit block like packet size to MAX_MESSAGE (345ms)
    ✓ should limit block like packet size to MAX_FORK_BLOCK_SIZE * 2 (184ms)
      ! swallowed error as per mocha behavior:
        Error: Invalid magic value: 0.
    ✓ should limit packet size to MAX_MESSAGE
      ! swallowed error as per mocha behavior:
        Error: Invalid magic value: 2c350fd.

  7 passing (564ms)

This is not all: I've noticed 2 or 3 more cases where errors, multiple promise rejections, and other weird cases have swallowed errors in mocha. I've started to documented them a little bit in in the bmocha tests -- the fail-test in particular has a number of tests which do not fail in mocha but fail in bmocha.

The moral of the story is that it was a mistake for us to ever use 3rd party code for something as critical as testing. Testing code should be small, sane, and easily auditable, which mocha is not. Any project of ours still using mocha should switch to bmocha as soon as possible.

We can wrap parser.feed() in a try catch to make it more aware of the error, but I suppose it doesn't matter as much now. This post is more to document mocha's shortcomings.

It seems after parser catches first error, it will continue parsing next chunks anyway causing it to emit rapidly after that. It actually throws ~2.7k errors (tested on bcash/bcoin).

Either we destroy parser or reset parser after that or wait for peer to handle that and reset according to the action it took. Even if peer got banned after first message, it will still parse remaining data.

*Update: total received 65k(at once) -- waiting for 24 bytes -- resulting 65536 / 24 -- 2730 emitted errors.