Potential Performance Issue with Heartbeat Scheduling in socket.io-adapter with Redis

[csethanhcong]

We are using socket.io-adapter with Redis as the backend for multiple API servers. While analyzing the behavior of serverSideEmit, we noticed the following code snippet in cluster-adapter.js:

async serverSideEmit(packet) {
    const withAck = typeof packet[packet.length - 1] === "function";
    if (!withAck) {
        return this.publish({
            type: MessageType.SERVER_SIDE_EMIT,
            data: {
                packet,
            },
        });
    }
}

publish(message) {
    this.scheduleHeartbeat();
    return super.publish(message);
}

scheduleHeartbeat() {
    if (this.heartbeatTimer) {
        this.heartbeatTimer.refresh();
    } else {
        this.heartbeatTimer = setTimeout(() => {
            this.publish({
                type: MessageType.HEARTBEAT,
            });
        }, this._opts.heartbeatInterval);
    }
}

Observations:

1. Every time serverSideEmit is called, it triggers publish, which in turn calls scheduleHeartbeat().

2. If the server emits messages frequently, heartbeats will be continuously scheduled.

3. We use serverSideEmit to update user online/offline status.

4. With 10k concurrent users (CCU), online/offline updates are frequent, causing heartbeats to be queued repeatedly.

5. Over time, this behavior may lead to high CPU usage due to excessive heartbeat scheduling.

Question:

Is this the intended design? Or is there a mechanism that prevents excessive heartbeats from affecting performance?

Would appreciate any insights on optimizing this behavior or mitigating potential CPU spikes due to unnecessary heartbeat scheduling.

[darrachequesne]

Hi! From my understanding, the scheduleHeartbeat() method delays the next heartbeat, so the heartbeat packet is only sent if there is no activity from this server during the heartbeatInterval.

That being said, calling the refresh() method could be throttled, if that leads to high CPU usage. Is that what you are experiencing?

[csethanhcong]

Hi, thank you for your response!

I am wondering whether the refresh() function is effectively throttled, as it seems to only be invoked during periods of inactivity on this server within the heartbeatInterval.

I conducted a process profiling analysis and observed that XADD operations are being repeatedly triggered over time and processed within the Node.js timer. Tracing the source of these operations from the stack trace led me directly to the following invocation:

this.publish({
    type: MessageType.HEARTBEAT,
});

This has left me a bit uncertain, and I would appreciate any further clarification on this behavior.

[darrachequesne]

I was not able to reproduce:

import { createServer } from "node:http";
import { readFile } from "node:fs/promises";
import { Server } from "socket.io";
import { createClient } from "redis";
import { createAdapter } from "@socket.io/redis-streams-adapter";

const port = process.env.PORT || 3000;

const httpServer = createServer();
const redisClient = createClient({ url: "redis://localhost:6379" });

await redisClient.connect();

const io = new Server(httpServer, {
  adapter: createAdapter(redisClient)
});

// setInterval(() => {
//  io.serverSideEmit("ping");
// }, 4000);

httpServer.listen(port, () => {
  console.log(`server listening at http://localhost:${port}`);
});

If serverSideEmit() is commented:

$ DEBUG=socket.io-redis-streams-adapter node server.js 
  socket.io-redis-streams-adapter publishing { type: 1, uid: '3aa3ca7f1c5f9715', nsp: '/' } +0ms
  socket.io-redis-streams-adapter publishing { type: 2, uid: '3aa3ca7f1c5f9715', nsp: '/' } +5s
  socket.io-redis-streams-adapter reading entry 1740673381250-0 +4ms
  socket.io-redis-streams-adapter publishing { type: 2, uid: '3aa3ca7f1c5f9715', nsp: '/' } +5s
  socket.io-redis-streams-adapter reading entry 1740673386252-0 +4ms
  socket.io-redis-streams-adapter publishing { type: 2, uid: '3aa3ca7f1c5f9715', nsp: '/' } +5s
  socket.io-redis-streams-adapter reading entry 1740673391253-0 +3ms
  socket.io-redis-streams-adapter publishing { type: 2, uid: '3aa3ca7f1c5f9715', nsp: '/' } +5s

One heartbeat is sent every 5 seconds.

If serverSideEmit() is commented out:

$ DEBUG=socket.io-redis-streams-adapter node server.js 
  socket.io-redis-streams-adapter publishing { type: 1, uid: 'fef9b54211ee2de1', nsp: '/' } +0ms
  socket.io-redis-streams-adapter publishing { type: 9, data: { packet: [ 'ping' ] }, uid: 'fef9b54211ee2de1', nsp: '/' } +4s
  socket.io-redis-streams-adapter reading entry 1740673414773-0 +2ms
  socket.io-redis-streams-adapter publishing { type: 9, data: { packet: [ 'ping' ] }, uid: 'fef9b54211ee2de1', nsp: '/' } +4s
  socket.io-redis-streams-adapter reading entry 1740673418772-0 +1ms
  socket.io-redis-streams-adapter publishing { type: 9, data: { packet: [ 'ping' ] }, uid: 'fef9b54211ee2de1', nsp: '/' } +4s
  socket.io-redis-streams-adapter reading entry 1740673422775-0 +3ms
  socket.io-redis-streams-adapter publishing { type: 9, data: { packet: [ 'ping' ] }, uid: 'fef9b54211ee2de1', nsp: '/' } +4s
  socket.io-redis-streams-adapter reading entry 1740673426775-0 +1ms

No more heartbeats, since serverSideEmit() is called every 4 seconds.

Or am I missing something?

[csethanhcong]

Yes, theoretically it's correct as it should be.

Please take a look at my profiling as above. You could see that bunch of XADD being processed and CPU time was drowned.

serverSideEmit() was called continuously as it reflect the user's online/offline status which could be hundreds of events firing per second.