Skip to content

perf: avoid closure in BasicDeliver#81

Merged
cody-greene merged 2 commits into
cody-greene:masterfrom
Samuron:deliver_perf
Aug 12, 2025
Merged

perf: avoid closure in BasicDeliver#81
cody-greene merged 2 commits into
cody-greene:masterfrom
Samuron:deliver_perf

Conversation

@Samuron
Copy link
Copy Markdown
Contributor

@Samuron Samuron commented Aug 4, 2025

Should cut an allocation for each consumed message. The testing idea is the same:

The script

import { randomUUID } from 'crypto';
import { Connection } from './src/Connection';
import { PerformanceObserver } from 'perf_hooks';

const queue = randomUUID();
const length = 1_000_000;


async function fill() {
  const payload = Buffer.from('prometheus');
  const connection = new Connection("amqp://guest:guest@localhost:5672");
  const pub = await connection.acquire();

  await pub.queueDeclare(queue);

  global.gc!();

  for (let i = 0; i < length; i++) {
    await pub.basicPublish(queue, payload);
  }
  await pub.close();
  await connection.close();

  global.gc!();
}

async function consume() {
  let count = 0;
  const promise = Promise.withResolvers<void>();
  const connection = new Connection("amqp://guest:guest@localhost:5672");
  const sub = await connection.acquire();
  sub.basicConsume({ queue: queue }, msg => {
    count++;
    if (count === length) {
      promise.resolve();
    }
  });
  return promise.promise.then(async () => {
    await sub.close();
    await connection.close();
  });
}

fill().then(async () => {
  const counter = new Map<number, { duration: number, times: number }>();
  const observer = new PerformanceObserver((list) => {
    list.getEntries().forEach((entry) => {
      const detail = entry.detail as Record<string, unknown>;
      if ("kind" in detail && typeof detail.kind === "number") {
        const existing = counter.get(detail.kind);
        if (existing) {
          existing.duration += entry.duration;
          existing.times += 1;
        } else {
          counter.set(detail.kind, { duration: entry.duration, times: 1 });
        }
      }
    });
  });
  observer.observe({ buffered: false, entryTypes: ['gc'] });

  await consume();

  observer.disconnect();
  const entries = Array.from(counter.entries()).sort((a, b) => a[0] - b[0]);
  for (const [kind, { duration, times }] of entries) {
    console.log(`Kind: ${kind}, Duration: ${duration.toFixed(2)}ms, Times: ${times}`);
  }
});

Old results

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 76.05ms, Times: 219

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 75.74ms, Times: 216

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1498.50ms, Times: 12568
Kind: 4, Duration: 268.92ms, Times: 46
Kind: 8, Duration: 9.33ms, Times: 46

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1486.07ms, Times: 12592
Kind: 4, Duration: 250.04ms, Times: 44
Kind: 8, Duration: 8.87ms, Times: 44

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1501.69ms, Times: 12602
Kind: 4, Duration: 278.04ms, Times: 43
Kind: 8, Duration: 10.54ms, Times: 43

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1442.39ms, Times: 12615
Kind: 4, Duration: 247.29ms, Times: 44
Kind: 8, Duration: 8.68ms, Times: 44

New results

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 69.89ms, Times: 220

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 69.90ms, Times: 219

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts 
Kind: 1, Duration: 1403.58ms, Times: 12500
Kind: 4, Duration: 210.84ms, Times: 41
Kind: 8, Duration: 8.32ms, Times: 41

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1457.39ms, Times: 12514
Kind: 4, Duration: 269.55ms, Times: 41
Kind: 8, Duration: 8.40ms, Times: 41

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1418.95ms, Times: 12446
Kind: 4, Duration: 265.95ms, Times: 42
Kind: 8, Duration: 8.69ms, Times: 42

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 1426.08ms, Times: 12504
Kind: 4, Duration: 229.80ms, Times: 41
Kind: 8, Duration: 8.59ms, Times: 41

Conclusion

The GC count went down for 128 Mb case, but it went up for 2048 case a little bit. But the time for 2048 case is lower and number of times has some fluctuations anyway, so I think it still a net win.

@Samuron
Copy link
Copy Markdown
Contributor Author

Samuron commented Aug 12, 2025

Hi @cody-greene, did you have a chance to look at the PR?

@cody-greene
Copy link
Copy Markdown
Owner

cody-greene commented Aug 12, 2025 via email

@Samuron
Copy link
Copy Markdown
Contributor Author

Samuron commented Aug 12, 2025

@cody-greene done, please check if I understood you correctly. I've also run a couple of tests and the number of GC pauses stays the same, but all the timings are now different on my machine for whatever reason. I can rerun all the tests if needed, but seems that this version should behave the same in terms of allocations and event better in terms of number of function calls

@cody-greene
Copy link
Copy Markdown
Owner

cody-greene commented Aug 12, 2025

Much cleaner. Looks good. Thank you!

@cody-greene cody-greene merged commit f73fd21 into cody-greene:master Aug 12, 2025
3 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants