node icon indicating copy to clipboard operation
node copied to clipboard

Async errors are blocked until test run is finished

Open forgotPassword opened this issue 3 months ago • 7 comments

Version

v21.6.1

Platform

Windows

Subsystem

No response

What steps will reproduce the bug?

var test = require('node:test');

setTimeout(function(){
    console.log(xxxxxxxxxx); // uncaughtException 
}, 100)

test('bug', function(t, done){
    setTimeout(function(){
        done();
    }, 10000);
});

How often does it reproduce? Is there a required condition?

No response

What is the expected behavior? Why is that the expected behavior?

I would expect uncaughtException would bubble/log immediately. In my case because of the error, the test never finished, as such nothing was logged so there was no way of knowing what is happening.

What do you see instead?

The reflection of myself in the monitor.

Additional information

No response

forgotPassword avatar Feb 10 '24 03:02 forgotPassword

This is a weird behavior: If you wrap the uncaught expection in a test it behaves correctly.

var test = require('node:test');

test('bug', function (t, done) {
    setTimeout(function () {
        console.log(xxxxxxxxxx); // uncaughtException 
        done();
    }, 100)
});

test('bug', function (t, done) {
    setTimeout(function () {
        done();
    }, 10000);
});

Output:

✖ failing tests:

test at index.js:4:1
✖ bug (101.890542ms)
  ReferenceError: xxxxxxxxxx is not defined
      at Timeout._onTimeout (/Users/mippolito/Documents/projects/test/index.js:6:17)
      at listOnTimeout (node:internal/timers:573:17)
      at process.processTimers (node:internal/timers:514:7)

Thats because the uncaught exception get listened by the test runner, and it cancels all pending tests. However if the uncaught exception is thrown outside like in your example, it is listened but ignored

marco-ippolito avatar Feb 10 '24 17:02 marco-ippolito

It is plausible for the exception to be outside of the test, eg you require some module/file at the beginning of the document, and then describe your tests. If the required module fails (async-ly), you won't know about it until after the test.

forgotPassword avatar Feb 10 '24 23:02 forgotPassword

this seems to be expected. tests run in a queue, and all unexpected warnings and errors are reported after the queue is drained.

MoLow avatar Feb 11 '24 11:02 MoLow

Even this is expected behavior, overall output looks ambiguous:

➜  main git:(master) ✗ node 1.cjs           
✔ bug (10002.205177ms)
ℹ Warning: A resource generated asynchronous activity after the test ended. This activity created the error "ReferenceError: xxxxxxxxxx is not defined" which triggered an uncaughtException event, caught by the test runner.
ℹ tests 1
ℹ suites 0
ℹ pass 1
ℹ fail 0
ℹ cancelled 0
ℹ skipped 0
ℹ todo 0
ℹ duration_ms 10010.956102
➜  main git:(master) ✗ echo $?              
1
➜  main git:(master) ✗ 

Node said 'Warning', but exit code is 1, so it's an error in terms of execution flow. Personally for me it's hard to find the root cause without additional hints.

koshic avatar Feb 11 '24 12:02 koshic

I guess we can add a stack trace to this warning, are you interested in sending a PR?

MoLow avatar Feb 11 '24 13:02 MoLow

I guess we can add a stack trace to this warning,

Yeah, it would be nice.

are you interested in sending a PR?

Sorry, no - I can't guarantee reasonable timeline for that activity.

koshic avatar Feb 11 '24 13:02 koshic

Not sure how a stack trace is going to help if the test never finishes because the thing you are waiting on has exploded.

The message says something about 'after the test ended', well, this happens during the test. Why not log the error immediately?

forgotPassword avatar Feb 12 '24 15:02 forgotPassword