2

As new member, I'm unable to comment on topics, that's why I had to create a new topic. But in this way, I can clarify the problem, so hopefully you guys can help me.

I have read quite a lot about Node.js Event Loop. And I have shaped my understanding of it based on following materials:

Node.js Event Loop
What the heck is the event loop anyway?
Why setImmediate() execute before fs.readFile() in Nodejs Event Loop's works?

(Please feel free to suggest other materials which are informative and accurate)

Especially the third link, has given me a better understanding. But keeping that in mind, I'm unable to understand Event Loop behavior for the following code:

var fs = require('fs');
var pos = 0;

fs.stat(__filename, function() {
 console.log(++pos + " FIRST STAT");
});

fs.stat(__filename, function() {
 console.log(++pos + " LAST STAT");
});

setImmediate(function() {
 console.log(++pos + " IMMEDIATE")
})

console.log(++pos + "LOGGER");

Surprisingly, for me output is as follow:

LOGGER  
FIRST STAT  
LAST STAT  
IMMEDIATE

screenshot of my terminal, showing output as well as node version
screenshot of output from online code compiler rextester.com

Keeping the Event Loop Diagram in mind, I guess flow should be as follow:

  1. Interpretor firstly starts two stat operations.
  2. Interpreter en-queues setImmedate callback (event) in the setImmedate queue
  3. Call stack logs the logger
  4. All event queues before I/O Poll phase are empty, so Event Loop(EL) moves on
  5. In I/O Polling phase, EL collects the events and enqueues both the fs.stat callbacks in the "run completed I/O handlers" phase
  6. EL checks the Check phase, and run the setImmediate callback
  7. This round of EL ends, and second round starts
  8. In "run completed I/O handlers", EL runs both callbacks (order of them can is onn-determinstic)

Question 1: Which part of my analysis/prediction is wrong?

Question 2: At which point, does Event Loop start working? Does it start from the beginning of the app (i.e. stage 1)? or does it start once the whole code is read by interpreter, all sync tasks are done within Call Stack, and Call Stack needs more task, i.e. between stage 3-4?

Thanks in advance,

Mahdi
  • 1,089
  • 1
  • 14
  • 27
  • I'm not sure why it works that way. One guess would be that stat operation finishes too quickly for `setImmediate` to have any meaningful impact. Might want to try running your code on very slow storage (e.g., SD card on Raspberry Pi). `process.nextTick()` is probably a better solution if you insist of the behavior you described. See https://stackoverflow.com/a/15349865/234932 –  Dec 25 '17 at 17:58
  • Some more interesting read on the topic: https://stackoverflow.com/a/47727402/234932 –  Dec 25 '17 at 18:01
  • @hayavuk thank you for the answer. But I referred to the same answer in my post, and as I said, the logic over there doesn't comply with this case :) if that logic is true, then operation speed shouldn't matter, as implied by author too. I dont need this for production, I'm just curious to understand how Event Loop works :) – Mahdi Dec 25 '17 at 18:45
  • I don't get the output you get in node.js. I get `1 LOGGER, 2 IMMEDIATE, 3 FIRST STAT, 4 LAST STAT` which is what I would expect. I'm running node v8.8.1 on windows 10. – jfriend00 Dec 25 '17 at 20:14
  • @jfriend00 thanks for your comment. I was waiting for you :D I ran the code with same node version as yours on linux. Also I ran it on two online nodejs compilers and got same result as before (added screenshots to my post). What's your opinion? How is this possible? Any idea? I'm totally confused. – Mahdi Dec 25 '17 at 20:31
  • It's possible that some OS might have `fs.stat()` cached so its result is immediately available and thus the result gets scheduled first. Try using `fs.readFile()` instead or any async I/O operation that has real work to do. – jfriend00 Dec 25 '17 at 20:44
  • wuhuu...replacing fs.stat() with fs.readFile(), gives our expected result :) But still I see a contradiction: Your quotation from that post: "Even though the readFile() is done by now, it is not yet in the queue ". And you said, queuing is done in poll phase, and running will happening in next loop. .In our case, Let's say that fs.stat() is cached, and results are immediately ready, but results are not queued yet. So once polling phase has passed, and in next loop, these cached results should be shown. What's your opinion? Am I wrong? – Mahdi Dec 25 '17 at 21:32
  • What I know from all the research and testing I've done is that this stuff is not simple and is hard to understand well enough to reliably predict. I draw the conclusion that if you want a particularly ordering of operations, then you should write code that forces a particular sequencing. And, I'm saying that after dozens of hours of research and testing. Personally, I think it's an overly complicated design that leads to situations that are very difficult to predict. Some situations are even racy which means they can go either way. – jfriend00 Dec 25 '17 at 22:17
  • Let us [continue this discussion in chat](http://chat.stackoverflow.com/rooms/161956/discussion-between-ali-and-jfriend00). – Mahdi Dec 26 '17 at 08:26

1 Answers1

0

setImmediate = execute without wait any I/O

In https://nodejs.org/docs/v8.9.3/api/timers.html#timers_setimmediate_callback_args says:

Schedules the "immediate" execution of the callback after I/O events' callbacks. Returns an Immediate for use with clearImmed

Steps:

  1. callback for First stat is queued in I/O queue
  2. callback for Last stat is queued in I/O queue
  3. callback for immediate is queued in Immediates queue
  4. LOGGER
  5. If I/O operations (in 1 and 2) are finished the callbacks in 1 and/or 2 are marked as ready to execute
  6. Execute the ready callbacks one by one (first timmer, then I/O, finally immediates). In your case:
    1. First stat
    2. Last stat
    3. LOGGER

In the case that I/O does'nt ends at 5. then LOGGER were execute before FIRST STAT and LAST STAT.

See also: https://jsblog.insiderattack.net/timers-immediates-and-process-nexttick-nodejs-event-loop-part-2-2c53fd511bb3#f3dd

Emilio Platzer
  • 2,327
  • 21
  • 29
  • Thanks for answer. But did you read the 3rd link I provided? Your logics don't match. That is, according to jfriend00, stat callbakss are not queued in stage 1&2, they are just started. Also, in stage 5, queue for "ready i/o callbacks" is empty. Annd in the Poll phase, those events will be queued, however, they will not run until the next loop. HIs argument sounds authentic, in a way that the code he explains, comply with his analysis.Do you think his argument / logic is wrong? Or what am I missing / don't get? – Mahdi Dec 25 '17 at 18:35
  • Of course I read it. And I read then link inside it. See at https://jsblog.insiderattack.net/timers-immediates-and-process-nexttick-nodejs-event-loop-part-2-2c53fd511bb3#f3dd It says: * immediates queue is guaranteed to be processed immediately after the I/O phase of the event loop*. My answer was a simplification that has a link to mozilla and an **after** word in bold in the quote. I hope it helps you. – Emilio Platzer Dec 25 '17 at 19:16
  • That's true. setImmedates run exactly after I/O phase but question is, is there any event in I/O phase during 1st loop? Your asnwer suggest yes, then how would you justify the output mentioned here https://stackoverflow.com/q/47724811/9138253 . If readFile callbacks get queued in the first loop, then why does it print timer, immediate, readFile? Based on your logic, it should print, timer, readFile and immediate. Please correct me, if I'm wrong – Mahdi Dec 25 '17 at 20:02
  • I/O operations runs in paralell (in C code in many theads) Javascript is mono thread but V8 (and other Javascript engines) are multi thread, one thead for Javascript and many for I/O and net operations. May be in that case that readFile does not ends at the beginining of first loop – Emilio Platzer Dec 25 '17 at 20:09
  • " May be in that case that readFile does not ends at the beginning of first loop" this is true. It doesn't and logic mentioned over there justifies it. But your logic mentioned here, doesn't justify it. That's why I think your logic is wrong :) I don't know though.. Also, in that case, there is a loop which kinda guarantees that fiel I/O operation can be done in 1st cycle, but having logic of jfriend00 in mind, it makes sense how it works over there..But it doesn't make sense how it works in here :/ – Mahdi Dec 25 '17 at 20:18
  • I cannot help more. It was clear for me reading de last link I post in the answer (reading all it, not only than paragraph). I hope my post helps you a bit. I'm sorry about not be more clear. – Emilio Platzer Dec 25 '17 at 20:46
  • Perhaps this experiment helps to understand it: http://rextester.com/BYJP64207 see in it that fs.stat ends immediatly and readFile does'nt – Emilio Platzer Dec 25 '17 at 23:47
  • Yes. this is the point and jfriend00 also metnioned it in his comment over there. But can you explain why fs.stat is treated differently? In other words, when I'm making predictions, how can I make sure that, this fs operation is treated like fs.stat and the other one is being treated like fs.readfile. Do you think is there any sign or is it just matter of experiment? – Mahdi Dec 26 '17 at 08:33
  • @Ali - I think it's wrong code to assume you can predict all these cases. If your code depends upon a particular sequencing, then you need to write the code to force that sequencing. I think we've already shown that your example here is not consistent among operating systems (I get different results on Windows than you get on Linux). It is not something you can reliably predict. So, stop trying to predict it. If you depend upon a particular order, then write the code to implement that ordering, no matter how this issue behaves. – jfriend00 Dec 26 '17 at 15:49