NodeJS eventLoop + ExpressJS unexpected behaviour with concurrency requests on single route

Question

I have a simple express App with a single route:

const express = require("express");
const app = express();
const crypto = require("crypto");

app.get('/', (req, res, next) => {
    const start = new Date()
    console.log('Start timestamp', `${start.getTime()}`);
    crypto.pbkdf2('foo', 'bar', 800000, 512, 'sha512', () => {
       console.log('End diff ', new Date()- start)
       res.send('Success')
    })
})
app.listen(3000);

I'm run this app on localhost. Single request time is equal near 3.2 seconds. I have Mac M1 with 8 CPU cores. Expected that when i get 4 concurrency requests on my App '/' route, they will be running through the 4хthreadPool's and split into 4 different/separated cores.

But when I'm send this 4 concurrency requests i have the next console.log:

Start timestamp 1653231979628
End diff  3256
Start timestamp 1653231982889
Start timestamp 1653231982889
Start timestamp 1653231982889
End diff  3437
End diff  3438
End diff  3439

So, firstly running one request, it freezing the event loop, and after it finished, other 3 requests will processed simultaneously.

What is the most interesting for me, is that when I'm running this app with pm2 as 4 separated Node-instances, this behaviour is the same. But how it can be, especially when running 4 different pm2-instances?

Answer 1

Node.js is a single-threaded event loop. In your example, there are two types of event:

A. Incoming request

• The start timestamp is logged.
• The crypto operation is started.
• Wait for next event.

B. Crypto operation finished

• The callback function is invoked.
  • The end timestamp is logged.
  • The "Success" message is sent as a response.
• Wait for next event.

In your run with 4 requests, the event sequence was A1, B1, A2, A3, A4, B2, B3, B4. Whether the next event is A or B depends also on the speed with which the crypto operations are executed.