Regression: High-frequency subscription (~10Hz) slow in rclnodejs 1.8.1 (worked in 0.21.4)

[sumit00000]

Description

• Library Version: rclnodejs 1.8.1 (regression)
• Previously working Version: rclnodejs 0.21.4
• ROS Version: ROS2 Humble
• Platform / OS: Ubuntu 22.04

Steps To Reproduce

import * as rclnodejs from 'rclnodejs';

let lastTs: number;
rclnodejs.init().then(() => {
  const node = new rclnodejs.Node('test_node');

  node.createSubscription(
    'std_msgs/msg/Float64MultiArray',
    '/map_to_base_link_pose2d',
    (msg: any) => {
      const now = Date.now();
      if (lastTs) {
        console.log('Raw Hz:', (1000 / (now - lastTs)).toFixed(2));
      }
      lastTs = now;
    }
  );

  rclnodejs.spin(node);
});

Expected Behavior
NodeJS subscription should receive messages at ~10Hz, matching the ROS2 topic publishing rate.

Actual Behavior
NodeJS subscription receives callbacks at ~1.5–1.8Hz.
Messages appear delayed or dropped, despite ROS2 publishing at 10Hz.
Regression compared to rclnodejs 0.21.4.
Workarounds like setImmediate() do not fix the problem.

Additional Notes / Observations
This issue only appears in rclnodejs 1.8.1.
High-frequency topics are significantly affected; lower-frequency topics (~1–2Hz) are unaffected.
Likely related to the NodeJS event loop integration or the subscription dispatch mechanism in the new version.

[minggangw]

@sumit00000 thanks for your feedback, do you try with other versions, like 1.8.0? Will take a look, thank!

[minggangw]

Hi @sumit00000, I did some testing on Humble by the case below:

// Multi-frequency stress test for subscription performance
'use strict';

const rclnodejs = require('./index.js');

const PUBLISH_HZ = parseInt(process.argv[2] || '100');
const TEST_DURATION_SEC = 10;

async function main() {
  await rclnodejs.init();

  const pubNode = new rclnodejs.Node('stress_pub_node');
  const subNode = new rclnodejs.Node('stress_sub_node');

  const publisher = pubNode.createPublisher(
    'std_msgs/msg/Float64MultiArray',
    '/stress_test_topic'
  );

  let msgCount = 0;
  let lastTs = null;
  const hzSamples = [];

  subNode.createSubscription(
    'std_msgs/msg/Float64MultiArray',
    '/stress_test_topic',
    (msg) => {
      const now = Date.now();
      msgCount++;
      if (lastTs) {
        const hz = 1000 / (now - lastTs);
        hzSamples.push(hz);
      }
      lastTs = now;
    }
  );

  pubNode.spin();
  subNode.spin();

  let pubCount = 0;

  // Use high-resolution timer for more precise publishing
  const intervalMs = 1000 / PUBLISH_HZ;
  const pubInterval = setInterval(() => {
    publisher.publish({ data: [1.0, 2.0, 3.0, 4.0, 5.0] });
    pubCount++;
  }, intervalMs);

  setTimeout(() => {
    clearInterval(pubInterval);

    if (hzSamples.length > 0) {
      const avgHz = hzSamples.reduce((a, b) => a + b, 0) / hzSamples.length;
      const minHz = Math.min(...hzSamples);
      const maxHz = Math.max(...hzSamples);
      const dropRate = ((pubCount - msgCount) / pubCount * 100);

      console.log(`Target:     ${PUBLISH_HZ} Hz`);
      console.log(`Published:  ${pubCount}`);
      console.log(`Received:   ${msgCount}`);
      console.log(`Avg Hz:     ${avgHz.toFixed(2)}`);
      console.log(`Min Hz:     ${minHz.toFixed(2)}`);
      console.log(`Max Hz:     ${maxHz.toFixed(2)}`);
      console.log(`Drop rate:  ${dropRate.toFixed(1)}%`);

      if (avgHz < PUBLISH_HZ * 0.5) {
        console.log(`FAIL: Avg Hz significantly below target`);
      } else {
        console.log(`PASS`);
      }
    } else {
      console.log('No messages received!');
    }

    pubNode.stop();
    subNode.stop();
    rclnodejs.shutdown();
    process.exit(0);
  }, TEST_DURATION_SEC * 1000);
}

main().catch(console.error);

and the result:

Test	Pub Hz	Version	Received Hz	Drop Rate	Result
In-process	10	develop (HEAD)	9.97	0%	PASS
Cross-process (rclnodejs pub)	100	develop	99.40	0%	PASS
ROS2 CLI publisher	10	develop	10.00	0%	PASS
In-process	50	develop	49.55	0%	PASS
In-process	100	develop	98.73	0%	PASS
In-process	500	develop	~500	0%	PASS
In-process	1000	develop	~1000	0%	PASS
In-process	10	1.8.0	9.97	0%	PASS
In-process	100	1.8.0	97.12	0%	PASS
In-process	500	1.8.0	~500	0%	PASS

Do you still meet the issue? What RMW implementation you use? Or you can try with the test case above to double check from your side, thanks!