18

I'm trying to debug a nodeJS app. I have some code which causes an error, a variable is undefined. When I run the code normally, the error is very clear and easy to find:

without jest:

➜  server git:(dc/build) ✗ node test/runner.js
/Users/dc/dev/exiteer/xbot/server/src/mup/Story.js:24
    Logger.logObj('loaded story', {name: doc.name})
                                         ^

ReferenceError: doc is not defined
    at Story.reload (/Users/dc/dev/exiteer/xbot/server/src/mup/Story.js:24:42)
    at Game.reload (/Users/dc/dev/exiteer/xbot/server/src/mup/Game.js:48:16)
    at Object.<anonymous> (/Users/dc/dev/exiteer/xbot/server/test/runner.js:4:10)

Sweet, I can fix it.

Now, Jest has some nice tooling for writing tests so I thought I'd try that.

But the errors are seemingly impossible to track down:

➜  server git:(dc/build) ✗ npm run jest

> cbg@0.1.0 jest /Users/dc/dev/exiteer/xbot/server
> jest

 PASS  src/index.test.js
(node:23114) UnhandledPromiseRejectionWarning: ReferenceError: doc is not defined
(Use `node --trace-warnings ...` to show where the warning was created)
(node:23114) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)
(node:23114) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
 FAIL  src/mup/Actor.test.js
  ● Console

    console.log
      actors undefined

      at Object.<anonymous> (src/mup/Actor.test.js:9:13)

  ● Game.js › can load a story

    expect(received).toHaveLength(expected)

    Matcher error: received value must have a length property whose value must be a number

    Received has value: undefined

       8 | 
       9 |     console.log('actors', game.story.room.name.actors)
    > 10 |     expect(game.story.room.actors).toHaveLength(1);
         |                                    ^
      11 |     const actor = game.story.room.actors[0]
      12 |     const reply = actor.sayTo('hi')
      13 |     expect(reply).toBe('hi back from Sid')

      at Object.<anonymous> (src/mup/Actor.test.js:10:36)

This tells me where my tests failed, but I'd prefer to know where the actual error is. Tests aren't the end goal here, a working app is.

Googling around I found and tried this but it gives the same error message.

node --trace-warnings node_modules/.bin/jest --no-cache

➜  server git:(dc/build) ✗ npm run test

> cbg@0.1.0 test /Users/dc/dev/exiteer/xbot/server
> node --trace-warnings node_modules/.bin/jest --no-cache

(node:23263) UnhandledPromiseRejectionWarning: ReferenceError: doc is not defined
    at emitUnhandledRejectionWarning (internal/process/promises.js:151:15)
    at processPromiseRejections (internal/process/promises.js:211:11)
    at processTicksAndRejections (internal/process/task_queues.js:98:32)
(node:23263) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1)

which gives a tiny bit more info but an

    at emitUnhandledRejectionWarning (internal/process/promises.js:151:15)
    at processPromiseRejections (internal/process/promises.js:211:11)
    at processTicksAndRejections (internal/process/task_queues.js:98:32)

This is not very helpful for debugging my code.

Also Jest seems to swallow all console.log as if it's doing the best to make debugging as painful as possible. When your environment doesn't even log, its a real WTF moment.

dcsan
  • 11,333
  • 15
  • 77
  • 118
  • 4
    The problem is specific to async errors that happen outside Jest test. Stacktrace is misleading but that it happens in unhandled promise really narrows down the search. console.log is the last resort for debugging, use Node debugging, https://stackoverflow.com/questions/33247602/how-do-you-debug-jest-tests . It won't necessarily help with uncaught rejections but at least allows for breakpoints. As for your case, adding `process.on('unhandledRejection', console.warn)` to test file or setupFiles in general may help. – Estus Flask Jul 14 '20 at 16:18
  • What about for Typescript React? – LEMUEL ADANE Jul 01 '21 at 07:29
  • What about for 'react-scripts test'? – LEMUEL ADANE Jul 01 '21 at 07:30
  • hei @dcsan, look this answer for tips on how to show correct messages: https://stackoverflow.com/questions/54874414/yarn-test-hangs-when-one-more-tests-file-is-added/68643113#68643113 – daymannovaes Aug 03 '21 at 21:56

1 Answers1

5

This was a bug in Node.js or Jest depending on your perspective - I fixed this a few months ago.

It happens because Jest throws errors in JavaScript coming from a different realm - so instanceof Error fails. You can see my PR here.

There is a workaround if you are forced to use old versions of Node or Jest here:

process.on('unhandledRejection', (reason) => {
  console.log(reason); // log the reason including the stack trace
  throw reason;
});

We added this hook in Node 1.3 so it should be safe to use in virtually all Node code.

Benjamin Gruenbaum
  • 270,886
  • 87
  • 504
  • 504
  • this doesn't seem to work for me. I have to put a try/catch around the code inside every test and console.log the errors. – dcsan May 01 '22 at 08:58
  • Hey, I don't get it. I upgraded from Node 16 to 18 expecting that to (a) include your PR's changes and (b) fix my related issue: namely "jest doesn't show complete stack trace for errors". Having the issue in Sequelize but apparently it exists on many "Node + Jest" environments. Were your changes not merged...? Did your fix not work for me? – plutownium Nov 11 '22 at 17:28
  • @plutownium I merged that PR almost a year ago and it was released both on the 16 and 18 release lines so unfortunately I suspect it's something else. Out of curiousity does the workaround work for you? (Adding the unhandledRejection handler manually) If it doesn't then it's unrelated to the fix. In any case if you suspect there is a problem with Node don't hesitate to open an issue and ping me – Benjamin Gruenbaum Nov 12 '22 at 18:29
  • That snippet is confusing - what is `e` referring to? Where would this code live? – Mark Apr 18 '23 at 15:05
  • @Mark this code is no longer needed - I fixed the issue in Node itself, which I work on. Update your node version. – Benjamin Gruenbaum Apr 18 '23 at 16:59