perf: make basicPublish sync

[Samuron]

In theory this should reduce memory traffic for an application that does a lot of publishing without confirm mode. Not sure about real world impact though, but for one of our most producing applications we had small benefit in memory usage from moving from Publisher to Channel, basically the difference there in one additional Promise to what I can see.

[cody-greene]

I can imagine how this might help, but I'd love to see some numbers

[Samuron]

So here is the methodology what I came up with as I have no idea whether there is a proper tool for it.

The script

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

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'] });

async function run() {
  const queue = randomUUID();
  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 < 1_000_000; i++) {
    await pub.basicPublish(queue, payload);
  }
  await pub.close();
  await connection.close();

  global.gc!();
}


run().then(() => {
  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: 29.04ms, Times: 82
Kind: 4, Duration: 27.00ms, Times: 1

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 33.14ms, Times: 82
Kind: 4, Duration: 19.89ms, Times: 1

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts 
Kind: 1, Duration: 585.55ms, Times: 5306
Kind: 4, Duration: 34.94ms, Times: 2
Kind: 8, Duration: 0.57ms, Times: 2

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 660.49ms, Times: 5335
Kind: 4, Duration: 40.92ms, Times: 2
Kind: 8, Duration: 0.70ms, Times: 2

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 764.03ms, Times: 5335
Kind: 4, Duration: 47.14ms, Times: 2
Kind: 8, Duration: 0.64ms, Times: 2

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 692.63ms, Times: 5304
Kind: 4, Duration: 58.04ms, Times: 3
Kind: 8, Duration: 0.64ms, Times: 2

New results

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 30.65ms, Times: 75
Kind: 4, Duration: 29.81ms, Times: 1

node -r ts-node/register --max-heap-size=2048 --expose-gc test.ts
Kind: 1, Duration: 27.84ms, Times: 75
Kind: 4, Duration: 26.33ms, Times: 1

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts 
Kind: 1, Duration: 573.82ms, Times: 4906
Kind: 4, Duration: 36.19ms, Times: 2
Kind: 8, Duration: 0.27ms, Times: 1

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 699.04ms, Times: 4874
Kind: 4, Duration: 45.67ms, Times: 2
Kind: 8, Duration: 0.33ms, Times: 1

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts 
Kind: 1, Duration: 650.32ms, Times: 4909
Kind: 4, Duration: 37.62ms, Times: 2
Kind: 8, Duration: 0.25ms, Times: 1

node -r ts-node/register --max-heap-size=128 --expose-gc test.ts
Kind: 1, Duration: 644.13ms, Times: 4879
Kind: 4, Duration: 40.61ms, Times: 2
Kind: 8, Duration: 0.36ms, Times: 1

Conclusion

Seems that there are less GC pauses