Asynchronous callbacks are not called on REPL

[sixmen]

I just downloaded Node.js 0.12.0, and I found setTimeout's callback does not called on REPL.

$ node 
> setTimeout(function () { console.log('called'); }, 5000), undefined
undefined

But after 5 seconds or more, 'called' is printed if I press any key.

Similarly, fs.readFile does not end if I do not have any action.

$node
> fs.readFile('README.md', function (error, str) { console.log(error, str)})
undefined

Am I doing something wrong? Or is this a bug?

I am on MacOSX 10.10.2, and I installed Node.js via Homebrew.

[cjihrig]

I can't reproduce your problem. If you're referring to the undefined that is initially printed, that is the value returned by fs.readFile(). The results are then printed asynchronously. You also have an extra , undefined in your first code sample.

[sixmen]

I was lack of detail explanation.
undefined is just to eliminate the return value of the setTimeout.
Please see this video.

Bug video

'called' is not displayed until I press the space key.
And first fs.readFile displays the result immediately, but second one does not display until I press space keys.

From my test, it does not have any problem on Ubuntu.
Only MacOSX has this phenomenon.

[sixmen]

I examined deeper.

It occurs from v0.11.12, exactly from https://github.com/joyent/node/commits/e92d35d80be6e193cb547e94c6fbf3654542dbaa (uv: Upgrade to v0.11.22)

[sixmen]

It seems the bug is created by libuv/libuv@b197515 .

[jasnell]

Unable to recreate the problem on Mac OSX 10.10 running v0.12.0. Output:

bash-3.2$ node
> setTimeout(function () { console.log('called'); }, 5000), undefined
undefined
> called
> 

'called' is printed after 5 seconds as expected.

[cjihrig]

@jasnell I was able to recreate the readFile() issue on OS X with 0.12. It's inconsistent, but does happen.

[jasnell]

Yep.. ok thank you @cjihrig. Seeing it now. Quite inconsistent... just did a longer test and for every three to five successful runs I'm seeing one failure. I previously just hadn't iterated the test enough times.

[jeffpar]

I'm seeing this problem as well after I upgraded from Node v0.10.x to v0.12.1 (and yes, I'm using OS X).

The command-line version of my x86 emulator starts a REPL to interact with the emulator's debugger. When I issue a "g" (go) command, the emulator -- which simulates a fixed processor speed (eg, 4.77Mhz) using setTimeout() -- runs very slowly and unevenly. Pressing keys at the REPL prompt triggers bursts of activity.

It's pretty clear that the setTimeout() callbacks are not being called consistently. This was not a problem in Node v0.10.x.

[jasnell]

@jeffpar can you test on v0.12.2 and see if you're still seeing the issue?

[jeffpar]

Yes, still seeing the problem in 0.12.2. Sample output:

[~/Sites/pcjs/modules/pcjs/bin] node pcjs --cmd="load machine.json"
ibm5150.cpu8088 object created
ibm5150.chipset object created
ibm5150.romBASIC object created
ibm5150.romBIOS object created
ibm5150.ramLow object created
ibm5150.keyboard object created
ibm5150.videoMDA object created
ibm5150.fdcNEC object created
ibm5150.debugger object created
warning: Component type 'Panel' not found
ibm5150.pc-mda-64k object created
PCjs> ramLow: 64Kb
powering up
PCjs v1.x.x
Copyright © 2012-2015 Jeff Parsons <[email protected]>
License: GPL version 3 or later <http://gnu.org/licenses/gpl.html>
Type ? for list of debugger commands
AX=0000 BX=0000 CX=0000 DX=0000 SP=0000 BP=0000 SI=0000 DI=0000 
SS=0000 DS=0000 ES=0000 PS=F002 V0 D0 I0 T0 S0 Z0 A0 P0 C0 
FFFF:0000 EA5BE000F0    JMP      F000:E05B
m all on
messages on:  8042,cpu,seg,desc,tss,int,fault,mem,port,
    dma,pic,timer,cmos,rtc,chipset,keyboard,video,fdc,hdc,
    disk,serial,speaker,state,mouse,computer,dos,data,warn
false
PCjs> g
running
chipset.outPort(0x00A0,NMI,0x00) @F000:E0B2
false
PCjs> rchipset.outPort(0x0083,DMA0.CHANNEL1.PAGE,0x00) @F000:E0B4

Before issuing the "g" (go) command, I first turned all emulator messages ("m all on"), which should produce a steady stream of messages once the emulator is running.

Instead, all I see is one message, and then I press "r", and another message appears, and so on.

[sixmen]

This code shows the problem more clearly.

$ node 
> setInterval(function () {console.log('log')}, 100), undefined
undefined

[misterdjules]

Fixed by #25475.

[misterdjules]

Fixed by 50f9615 and 097607c, closing. Thank you @sixmen 👍

These fixes will be available in the next v0.12.5 version of node.