Classic queue throughput drop from 3.13.1 to 3.13.2 as measured by a homegrown benchmarking tool

[wmolyneux]

Describe the bug

During the process of upgrading to using quorum queues, we've read that their performance should be substantially better than classic going forward.

As a result I created a simple AMQP client which published messages to a topic and then another one which creates 100 queues of either classic or quorum and then reads for 30 seconds printing the number per second we've managed to read.

On RabbitMQ version 3.13.1 classic queues are about 150% than quorum. With reads per second of about 660~ and 400~ respectively.

However on RabbitMQ version 3.13.2 and above, the performance of classic queues seems to go out the window and now averages about 100~ reads per second, whereas quorum remains unchanged.

Obviously my test is bottlenecked by my machines performance, however i'd expect similar results to be similar given the same environment being used.

Reproduction steps

1. Deploy RabbitMQ in docker using the command:
   docker run -d --hostname my-rabbit --name some-rabbit -p 5672:5672 -p 15672:15672 --ulimit nofile=65536:65536 -e RABBITMQ_SERVER_ADDITIONAL_ERL_ARGS="+P 1048576" rabbitmq:3.13.1-management

2. Publish notifications to classic queues and measure performance

3. Remove and redeploy rabbitmq on 3.13.2 or above

4. Publish notifications to classic queues and remeasure performance

Expected behavior

Firstly, i wouldnt expect the performance of classic queues to degrade massively between minors versions, or even at all.

Is quorum indeed faster for this use-case? This link suggests that 'classic queues offer a third of the performance'
https://www.rabbitmq.com/docs/migrate-mcq-to-qq

Additional context

NoAck = true
Durable = true

[michaelklishin]

These reproduction steps is not something our team can work with. "Publish notifications to classic queues and measure performance" is not specific at all. We have no idea whether you use CQv2 or not, what your message sizes are, or anything at all. "Performance" is not a constant, it is a function of the workload, the configuration and the environment used.

We do not guess in this community.

See these blog posts to learn about how our team
does benchmarking. There is also a dedicated post on flame graphs and a dedicated benchmarking tool.

Finally, the latest version of RabbitMQ is 3.13.3 and there have been changes directly relevant to CQv2, plus more changes for 4.0 on top, such as #11112.

[michaelklishin]

With reads per second of about 660~ and 400~ respectively

You haven't provided any details on what your "simple AMQP client" does and measures but those numbers are about two orders of magnitude lower than what a modern QQ or a non-mirrored CQv2 can achieve with reasonable hardware, small messages (up to 1 kiB) and the most basic PerfTest flags.

A Simplest Possible CQv2 Benchmark

For example, a PerfTest run against a local 3.13.3 node on Erlang 26.2.5 with the following settings (messages are published as persistent, the queues are durable, there is one publisher and one consumer).

PerfTest consumers use automatic acknowledgements by default.

./bin/runjava com.rabbitmq.perf.PerfTest -f persistent -x 1 -y 1

Yields between 130K and 160K with a single classic queue on an M1 Mac from 2021-2022.

# A non-mirrored CQv2
id: test-130136-079, time 1.003 s, sent: 134853 msg/s, received: 132962 msg/s, min/median/75th/95th/99th consumer latency: 4946/39533/43918/61139/74725 µs
id: test-130136-079, time 2.004 s, sent: 147664 msg/s, received: 147274 msg/s, min/median/75th/95th/99th consumer latency: 7374/12158/17083/23141/58072 µs
id: test-130136-079, time 3.001 s, sent: 150372 msg/s, received: 150146 msg/s, min/median/75th/95th/99th consumer latency: 9321/18142/44334/55678/59389 µs
id: test-130136-079, time 4.001 s, sent: 154964 msg/s, received: 155928 msg/s, min/median/75th/95th/99th consumer latency: 7804/17177/22146/26035/27362 µs
id: test-130136-079, time 5.005 s, sent: 165255 msg/s, received: 164043 msg/s, min/median/75th/95th/99th consumer latency: 7220/10185/11561/23492/25581 µs
id: test-130136-079, time 6.001 s, sent: 154286 msg/s, received: 155316 msg/s, min/median/75th/95th/99th consumer latency: 8001/12051/15171/19733/21153 µs
id: test-130136-079, time 7.005 s, sent: 156709 msg/s, received: 156385 msg/s, min/median/75th/95th/99th consumer latency: 7584/11521/13007/15489/16392 µs
id: test-130136-079, time 8.003 s, sent: 160862 msg/s, received: 161165 msg/s, min/median/75th/95th/99th consumer latency: 7618/10478/12573/16275/17377 µs
id: test-130136-079, time 9.006 s, sent: 151865 msg/s, received: 150578 msg/s, min/median/75th/95th/99th consumer latency: 7934/12686/18787/21905/23182 µs
id: test-130136-079, time 10.005 s, sent: 159327 msg/s, received: 160337 msg/s, min/median/75th/95th/99th consumer latency: 6574/11472/32291/40055/56304 µs
id: test-130136-079, time 11.005 s, sent: 163740 msg/s, received: 163956 msg/s, min/median/75th/95th/99th consumer latency: 7246/10357/13371/16722/18615 µs
id: test-130136-079, time 12.003 s, sent: 153246 msg/s, received: 152246 msg/s, min/median/75th/95th/99th consumer latency: 7879/15775/29768/34773/35930 µs
id: test-130136-079, time 13.005 s, sent: 162400 msg/s, received: 163749 msg/s, min/median/75th/95th/99th consumer latency: 7168/10577/12929/17685/20197 µs
id: test-130136-079, time 14.005 s, sent: 157963 msg/s, received: 156470 msg/s, min/median/75th/95th/99th consumer latency: 7190/9770/10826/20113/60996 µs
id: test-130136-079, time 15.005 s, sent: 162186 msg/s, received: 163571 msg/s, min/median/75th/95th/99th consumer latency: 7949/10209/11414/16940/21979 µs
id: test-130136-079, time 16.005 s, sent: 162002 msg/s, received: 161830 msg/s, min/median/75th/95th/99th consumer latency: 7919/10463/11962/14018/15439 µs
id: test-130136-079, time 17.004 s, sent: 162787 msg/s, received: 162954 msg/s, min/median/75th/95th/99th consumer latency: 7307/10485/12936/18612/19820 µs
id: test-130136-079, time 18.004 s, sent: 170056 msg/s, received: 169940 msg/s, min/median/75th/95th/99th consumer latency: 7384/9758/10428/11711/12579 µs
id: test-130136-079, time 19.003 s, sent: 166392 msg/s, received: 166684 msg/s, min/median/75th/95th/99th consumer latency: 7262/9789/10959/12629/13827 µs
id: test-130136-079, time 20.000 s, sent: 166452 msg/s, received: 165939 msg/s, min/median/75th/95th/99th consumer latency: 7227/9915/10784/12452/13768 µs
id: test-130136-079, time 21.005 s, sent: 164769 msg/s, received: 164924 msg/s, min/median/75th/95th/99th consumer latency: 7603/10250/11427/13350/15184 µs
id: test-130136-079, time 22.004 s, sent: 162573 msg/s, received: 162883 msg/s, min/median/75th/95th/99th consumer latency: 7183/10328/11512/15508/17468 µs
id: test-130136-079, time 23.003 s, sent: 166447 msg/s, received: 165879 msg/s, min/median/75th/95th/99th consumer latency: 7117/9971/11042/12995/14148 µs
id: test-130136-079, time 24.001 s, sent: 162481 msg/s, received: 162949 msg/s, min/median/75th/95th/99th consumer latency: 7234/10248/11665/16315/19212 µs
id: test-130136-079, time 25.001 s, sent: 164951 msg/s, received: 164731 msg/s, min/median/75th/95th/99th consumer latency: 7632/9865/10661/12577/13428 µs
id: test-130136-079, time 26.002 s, sent: 150827 msg/s, received: 149763 msg/s, min/median/75th/95th/99th consumer latency: 7548/14029/18003/21374/36210 µs
id: test-130136-079, time 27.005 s, sent: 159362 msg/s, received: 160576 msg/s, min/median/75th/95th/99th consumer latency: 8014/10909/12207/15866/19021 µs
id: test-130136-079, time 28.003 s, sent: 165762 msg/s, received: 165782 msg/s, min/median/75th/95th/99th consumer latency: 7525/9937/10986/15940/19656 µs
id: test-130136-079, time 29.005 s, sent: 162362 msg/s, received: 162245 msg/s, min/median/75th/95th/99th consumer latency: 7231/10420/11438/13896/16423 µs
id: test-130136-079, time 30.000 s, sent: 157458 msg/s, received: 157257 msg/s, min/median/75th/95th/99th consumer latency: 7637/11405/12697/14387/16130 µs
id: test-130136-079, time 31.005 s, sent: 158230 msg/s, received: 158427 msg/s, min/median/75th/95th/99th consumer latency: 7894/10933/12339/15124/16360 µs
id: test-130136-079, time 32.005 s, sent: 161346 msg/s, received: 161439 msg/s, min/median/75th/95th/99th consumer latency: 7798/10732/12286/15089/16140 µs
id: test-130136-079, time 33.005 s, sent: 163073 msg/s, received: 163105 msg/s, min/median/75th/95th/99th consumer latency: 7099/10619/11713/13973/15634 µs
id: test-130136-079, time 34.005 s, sent: 162498 msg/s, received: 162272 msg/s, min/median/75th/95th/99th consumer latency: 7555/10409/11631/14838/16776 µs
id: test-130136-079, time 35.003 s, sent: 160528 msg/s, received: 161096 msg/s, min/median/75th/95th/99th consumer latency: 6696/10819/12050/14221/15394 µs
id: test-130136-079, time 36.001 s, sent: 163716 msg/s, received: 163170 msg/s, min/median/75th/95th/99th consumer latency: 6962/10373/11825/23432/24666 µs
id: test-130136-079, time 37.001 s, sent: 165084 msg/s, received: 164763 msg/s, min/median/75th/95th/99th consumer latency: 7870/10008/11003/13256/14860 µs
id: test-130136-079, time 38.001 s, sent: 161379 msg/s, received: 161484 msg/s, min/median/75th/95th/99th consumer latency: 7055/10828/11947/14951/16045 µs
id: test-130136-079, time 39.002 s, sent: 151570 msg/s, received: 149348 msg/s, min/median/75th/95th/99th consumer latency: 7469/11724/29385/39641/49872 µs
id: test-130136-079, time 40.002 s, sent: 155312 msg/s, received: 158019 msg/s, min/median/75th/95th/99th consumer latency: 7772/11946/21090/27542/35289 µs

A Simplest Possible QQ Benchmark

Benchmarking quorum queues with a single replica is not really fair because the whole point
of QQs is to have 3, 5, 7 of them (an odd number).

Still, to demonstrate that 400-700 "reads" a second is absolutely nothing for a QQ leader replica,
here is another example with PerfTest:

./bin/runjava com.rabbitmq.perf.PerfTest -qq --queue "perftest.qq.1" -f persistent -x 1 -y 1

which yields about 100K small messages a second on the same machine as above:

# a single replica QQ just to compare
id: test-130333-516, time 1.005 s, sent: 95320 msg/s, received: 77959 msg/s, min/median/75th/95th/99th consumer latency: 8207/125215/156947/191039/202610 µs
id: test-130333-516, time 2.005 s, sent: 102721 msg/s, received: 101816 msg/s, min/median/75th/95th/99th consumer latency: 147008/179785/195282/216039/226205 µs
id: test-130333-516, time 3.005 s, sent: 104157 msg/s, received: 101945 msg/s, min/median/75th/95th/99th consumer latency: 160232/201141/216917/235146/241705 µs
id: test-130333-516, time 4.005 s, sent: 96166 msg/s, received: 98760 msg/s, min/median/75th/95th/99th consumer latency: 171035/208758/228904/266410/276255 µs
id: test-130333-516, time 5.005 s, sent: 104077 msg/s, received: 101050 msg/s, min/median/75th/95th/99th consumer latency: 168430/204500/221826/249320/257131 µs
id: test-130333-516, time 6.005 s, sent: 104180 msg/s, received: 101640 msg/s, min/median/75th/95th/99th consumer latency: 164607/206021/222878/238223/243956 µs
id: test-130333-516, time 7.003 s, sent: 97689 msg/s, received: 102715 msg/s, min/median/75th/95th/99th consumer latency: 165752/202109/220221/237966/249837 µs
id: test-130333-516, time 8.005 s, sent: 95087 msg/s, received: 95543 msg/s, min/median/75th/95th/99th consumer latency: 169404/214935/237088/277179/310082 µs
id: test-130333-516, time 9.003 s, sent: 103855 msg/s, received: 102155 msg/s, min/median/75th/95th/99th consumer latency: 167649/203339/220505/234357/243783 µs

Mirrored Classic Queues are Gone

If mirrored classic queues are used, we will not investigate any claims of throughput regressions: CQ mirroring was removed entirely for 4.0 after about three years of deprecation.

[michaelklishin]

In order to get a QQ to a ≈ 400-600 messages per second range I have to increase message size to 1-4 MiB:

./bin/runjava com.rabbitmq.perf.PerfTest -qq --queue "perftest.qq.1mib" -f persistent -x 1 -y 1 --size 2000000

This is expected: data volumes transferred are 2000 greater than what I used in the first test,
and 2 MiB per second at 500 messages is ≈ 1 GiB which requires 8 Gbit/s to just transfer the payloads (which is "available" with localhost but won't be available in many environments where the data crosses an actual network), plus PerfTest's GC runs become a significant factor that can be seen when throughput sometimes drops to zero for a few tenths of a second because JVM GC is global and when it runs, PerfTest won't send anything at all.

For 4.0, there is ongoing work specifically for CQv2 but also QQs to reduce memory footprint with such large messages. There aren't that many ways to reduce disk I/O and in open source RabbitMQ, there aren't any ways to reduce network data flow volumes, so throughput is unlikely to significantly change even with those improvements.

That's as much as I can say given that we do not know anything about the environment, a homegrown "simple" benchmarking tool is used instead of PerfTest (which has over a decade of mileage on it and is what our team uses extensively).

[wmolyneux]

I wasn't implying a guess, just assumed that more details on my client might be requested if you didnt immediately spot something wrong with my findings.

My client is a very simple combination of nodejs scripts which I'll provide below. app.js basically creates 100 queues (type is defined at the top as "quorum" or "classic"). The other publishes to a topic in a loop. I understand the benchmark tool is incredibly useful and robust, i just wanted to try and create a simple client to try and understand why we don't see the performance we'd expect, although this is definitely on a restricted environment regardless.

I mentioned 3.13.2 because this is the version where I first notice the decrease in performance, it still impacts 3.13.3 also. I understand the MCQ are removed for 4.0, does that mean that the statement in the article of 'third of the performance' is refering to the 3.13.2+ performance of CQ?

Reproduction steps:

1. Deploy RabbitMQ in docker using the command:
   docker run -d --hostname my-rabbit --name some-rabbit -p 5672:5672 -p 15672:15672 --ulimit nofile=65536:65536 -e RABBITMQ_SERVER_ADDITIONAL_ERL_ARGS="+P 1048576" rabbitmq:3.13.1-management

2. Copy the following script into app.js within a folder:

const amqp = require('amqplib/callback_api');

let queueType = "classic"
let queueCount = 100;
let messageCounts = Array(queueCount).fill(0); // Initialize an array of 10 zeros
let startTimes = Array(queueCount).fill(null); // Initialize an array of 10 nulls
let timeoutStarted = false;

amqp.connect('amqp://localhost', function(error0, connection) {
    if (error0) {
        throw error0;
    }
    connection.createChannel(function(error1, channel) {
        if (error1) {
            throw error1;
        }

        let exchange = 'my_topic_exchange';
        let topic = 'my_topic';

        channel.assertExchange(exchange, 'topic', {
            durable: true
        });

        for(let i = 0; i < queueCount; i++) {
            let queue = 'my_queue' + i;

            // Delete the queue if it exists
            channel.deleteQueue(queue, {}, function(error2, ok) {
                if (error2) {
                    console.log("Error deleting queue: ", error2);
                } else {
                    console.log("Queue '%s' deleted", queue);
                }
            });

            channel.assertQueue(queue, {
                durable: true,
                arguments: {
                    'x-queue-type': queueType
                }
            });

            channel.bindQueue(queue, exchange, topic);

            channel.consume(queue, function(msg) {
                if (!timeoutStarted) {
                    // Start the timeout after the first message is received
                    setTimeout(function() {
                        let totalMessages = messageCounts.reduce((a, b) => a + b, 0);
                        console.log("Total messages received in 30 seconds: ", totalMessages);
                        console.log("Messages per second: ", totalMessages / 30);
                        process.exit(0);
                    }, 30000);
                    timeoutStarted = true;
                }

                if (startTimes[i] === null) {
                    startTimes[i] = Date.now();
                }

                messageCounts[i]++; 
            }, {
                noAck: true
            });

            console.log(" [*] Queue '%s' created and consumer started.", queue);
        }

        console.log("All queues created, publishing can begin...")

        // Log the message counts and messages per second every 5 seconds
        setInterval(function() {
            for(let i = 0; i < queueCount; i++) {
                let secondsElapsed = (Date.now() - startTimes[i]) / 1000;
                console.log("Queue 'my_queue%s' has received %d messages so far (%d messages per second)", i, messageCounts[i], messageCounts[i] / secondsElapsed);
            }
        }, 5000);
    });
});

3. Copy the following into a file called post.js in the same folder:

const amqp = require('amqplib/callback_api');
const argv = require('yargs').argv;

amqp.connect('amqp://localhost', function(error0, connection) {
    if (error0) {
        throw error0;
    }

    connection.createChannel(function(error1, channel) {
        if (error1) {
            throw error1;
        }

        let exchange = 'my_topic_exchange';
        let topic = 'my_topic';
        let msg = 'Hello World!';
        let count = 0;
        let prevCount = 0;

        channel.assertExchange(exchange, 'topic', {
            durable: true
        });

        setInterval(function() {
            channel.publish(exchange, topic, Buffer.from("Hello World! " + count.toString()));
            count++;
        }, 1);

        setInterval(function() {
            let totalSinceLast = count - prevCount;
            prevCount = count;
            console.log(" [x] Sent %d messages", totalSinceLast);
        }, 5000);
    });
});

4. Open two powershell or a shell windows of your choice and change into the directory where the scripts were saved in both.
5. In one of the windows run the following npm install commands

npm install yargs
npm install amqplibs

6. In the first window, run the app.js file with the following command:
   node app.js

7. Once the first window reports "All queues created, publishing can begin...", run the following command in the second window:
   node post.js

8. After 30 seconds, the first window will stop listening and print the total messages read. Every 5 seconds, the window will show the total read for each queue with an average per second in brackets.

9. Deploy 3.13.2 or 3.13.3 of RabbitMQ and repeat steps 4-8, noting the difference in reads per second.

[wmolyneux]

Done some more testing so wanted to make some clarifications.

• We are using MCQ in our main code base which we know are deprecated and removed in 4.0.
• I seem to see CQ being slower post 3.13.1 as mentioned above
• We want to move to QQ but don't seem to get performance close when trying in our main code base.

I need to run my test again against MCQ vs QQ as I wasnt aware our main code base was MCQ, however my concern over the performance of CQ still stands.

End of my day here in the UK so will continue tomorrow, appreciate the advice and links.

[michaelklishin]

Quorum queues are more sensitive to disk I/O and there are two QQ-specific tuning recommendations listed in the docs.

Otherwise, see the Monitoring guide and collect infrastructure-level metrics to get some more insights. You can also use the flame graphs blog post above but it sounds like an overkill to start with that.

[michaelklishin]

@wmolyneux I no longer understand what is the ask here.

We will not investigate anything related to CMQs, they are not just long deprecated, they were completely removed.

If you can demonstrate a QQ throughput regression with PerfTest — which can simulate a very wide range of topologies, workloads, and even use --predeclared topologies to a certain extent, then we may be able to recommend something.

For that we need to know enough details covered in this and other similar blog posts. We do not use anything that's not open source, other than our infrastructure, which is mentioned as all the posts, e.g.

A GKE cluster with e2-standard-16 nodes

as well as the rest of the details. Some general recommendations like the Raft WAL segment size changes, readahead tuning on Linux are already documented above. What combination works best for your message size distribution, our team cannot know. You can compared a few different configurations and see what works best.

And if nothing does, superstreams can reach a few million messages a second with a reasonably powerful 3 node cluster. They are not a drop-in queue replacement and never will be, since it is their different design and implementation decisions that make this leap in throughput possible.

Streams and superstreams use a separate benchmarking tool, creatively named Stream PerfTest.

We have explained what your options and available tools are. Please take it from here.

[lhoguin]

Between 3.13.1 and 3.13.2 classic queues have only changed for large messages (> 4K) so what you are seeing likely isn't directly related. There wasn't a lot of changes between the two versions, so what you may want to do is a git bisect to find the exact commit with the performance drop.