Speed degradation of Debian 12 compared to Debian 11

Some One

unread,

Aug 18, 2023, 3:21:32 PM8/18/23

to rabbitmq-users

Hi group!

I'm facing a degradation of speed upon configuring RabbitMQ at Debian 12 compared to Debian 11 with the following configuration:

- 2 hosts running Debian 11 and Debian 12 have same configuration: 2 x CPU Xeon@2.3 GHz, 4GB RAM, 9 GB HDD

- each host runs 3 docker containers:

* at host with Debian 11: image is constructed with "FROM debian:11"

* at Debian 12: "FROM debian:12" respectively

- each container installs same Erlang and RabbitMQ from same repos with same versions:

* https://dl.cloudsmith.io/public/rabbitmq/rabbitmq-erlang/deb (erlang=1:25.3.2.5-1)

* https://dl.cloudsmith.io/public/rabbitmq/rabbitmq-server/deb (rabbitmq-server=3.11.21-1)

- each container is configured via same Ansible's role

Output from Debian 11 based containers:

```

21:40:54 +0300 (0:06:23.065) 0:11:39.260 *******
===============================================================================
[RabbitMQ:config_users] Create users ---------------------------------- 383.07s
[RabbitMQ:config_vhosts] Apply HA policy ------------------------------- 60.58s
[RabbitMQ:config_plugins] Enable plugins ------------------------------- 54.31s
[RabbitMQ:config_vhosts] Create vhosts --------------------------------- 43.87s
[RabbitMQ:execute] Start RabbitMQ under Docker via init.d -------------- 22.83s
[RabbitMQ:install_erlang] Install specified version of Erlang ---------- 18.12s
[RabbitMQ:install_rabbitmq] Install specified version of RabbitMQ ------ 12.01s
[RabbitMQ:config_cluster] Waiting for nodes' meeting ------------------- 10.06s
[RabbitMQ:precheck] Install GPG ----------------------------------------- 9.60s
[RabbitMQ:precheck] Update APT packages --------------------------------- 9.46s
[RabbitMQ:config_cluster] Stop app at nodes ----------------------------- 6.72s
[RabbitMQ:install_rabbitmq] Import RabbitMQ GPG signing key ------------- 5.52s
[RabbitMQ:install_erlang] Import Erlang/OTP GPG signing key ------------- 5.45s
[RabbitMQ:install_rabbitmq] Update APT cache ---------------------------- 5.12s
[RabbitMQ:install_erlang] Update APT cache ------------------------------ 4.76s
[RabbitMQ:config_users] Remove users ------------------------------------ 4.42s
[RabbitMQ:precheck] Gather the package facts ---------------------------- 3.23s
[RabbitMQ:config_cluster] Nodes join the leader ------------------------- 2.81s
[RabbitMQ:config_cluster] Start app at nodes ---------------------------- 2.59s
[RabbitMQ:config_cluster] Get cluster's status -------------------------- 2.52s

```

Output from Debian 12 based containers:

```

21:54:41 +0300 (0:15:46.075) 0:25:19.319 *******
===============================================================================
[RabbitMQ:config_users] Create users ---------------------------------- 946.08s
[RabbitMQ:config_vhosts] Apply HA policy ------------------------------ 142.54s
[RabbitMQ:config_plugins] Enable plugins ------------------------------ 123.92s
[RabbitMQ:config_vhosts] Create vhosts --------------------------------- 97.04s
[RabbitMQ:execute] Start RabbitMQ under Docker via init.d -------------- 43.97s
[RabbitMQ:install_erlang] Install specified version of Erlang ---------- 18.42s
[RabbitMQ:config_users] Remove users ----------------------------------- 10.28s
[RabbitMQ:config_cluster] Waiting for nodes' meeting ------------------- 10.06s
[RabbitMQ:precheck] Install GPG ----------------------------------------- 9.51s
[RabbitMQ:precheck] Update APT packages --------------------------------- 9.33s
[RabbitMQ:config_cluster] Stop app at nodes ----------------------------- 9.31s
[RabbitMQ:install_rabbitmq] Install specified version of RabbitMQ ------- 8.56s
[RabbitMQ:config_cluster] Get cluster's status -------------------------- 6.83s
[RabbitMQ:config_cluster] Get cluster's status -------------------------- 6.81s
[RabbitMQ:config_cluster] Nodes join the leader ------------------------- 6.26s
[RabbitMQ:config_cluster] Increase memory watermark --------------------- 6.25s
[RabbitMQ:install_rabbitmq] Import RabbitMQ GPG signing key ------------- 5.88s
[RabbitMQ:install_erlang] Import Erlang/OTP GPG signing key ------------- 5.76s
[RabbitMQ:config_cluster] Start app at nodes ---------------------------- 5.39s
[RabbitMQ:install_rabbitmq] Update APT cache ---------------------------- 5.27s

```

As for an experiment I've tried to downgrade kernel version at Debian 12 to same that being used by Debian 11: 5.10.0-24-amd64, but had the same degradation.

I've noticed differences in linked libraries, in Debian 11 RabbitMQ binary has:

- librt.so.1 => /lib/x86_64-linux-gnu/librt.so.1 (0x00007fa303708000)

- libpthread.so.0 => /lib/x86_64-linux-gnu/libpthread.so.0 (0x00007fa30349e000)

Please let me know If you need any additional information.

Regards!

Michal Kuratczyk

unread,

Aug 21, 2023, 2:44:28 AM8/21/23

to rabbitm...@googlegroups.com

It'd be very surprising if the slow-down was caused by RabbitMQ as such.

In particular, operations such as policy or user declaration have remained mostly unchanged for a long time

I believe, so it's very unlikely for them to be 2-3 times slower all of a sudden.

We would need more "raw" data - right now we have no idea what actions take place in these steps.

Please measure operations with simple "time rabbitmqctl" or similar. If you have a full definitions JSON file

(https://www.rabbitmq.com/definitions.html), you can just `rabbitmqctl import_definitions` and compare the time

between operations on both versions. It will cover a lot in a single test, since the definitions (may) contain

queues, policies, users, etc.

If you see an import like that taking significantly longer now, please share that definition's file.

Lastly, out of curiosity, how many entities do you have? 383 seconds just to create users?

On my machine it takes 80 seconds to declare 100000 users...

Best,

--
You received this message because you are subscribed to the Google Groups "rabbitmq-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to rabbitmq-user...@googlegroups.com.
To view this discussion on the web, visit https://groups.google.com/d/msgid/rabbitmq-users/3de46f00-3605-4abb-ab6c-184cb0a66c5dn%40googlegroups.com.

--

Michał

RabbitMQ team

Some One

unread,

Aug 21, 2023, 8:46:26 AM8/21/23

to rabbitmq-users

Dear Michał,

Thanks for your reply.

```

Here are measures I've done on Dockers' nodes at Debian 11 & Debian 12:

- cluster_nodes.config at both:

{[rabbit@node71,rabbit@node72,rabbit@node73],[rabbit@node71,rabbit@node72,rabbit@node73]}.

- time rabbitmqctl import_definitions def.json (https://gist.githubusercontent.com/gglluukk/c84d0ef11106f677759bfec6529fa45e/raw/a1e6535018385c46846daf330f2b6f39077cd423/def.json):

* debian 11:

real 0m0.865s
user 0m0.639s
sys 0m0.316s

* debian 12:

real 0m2.107s
user 0m0.996s
sys 0m1.820s

- time rabbitmqctl add_user test ""

* debian 11:

real 0m0.731s
user 0m0.669s
sys 0m0.307s

* debian 12:

real 0m2.048s
user 0m1.039s
sys 0m1.777s

- time rabbitmqctl delete_user test

* debian 11:

real 0m0.688s
user 0m0.595s
sys 0m0.321s

* debian 12:

real 0m1.886s
user 0m1.017s
sys 0m1.663s

- strace -c -fF rabbitmqctl add_user test ""

* debian 11:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ------------------
33.98 2.729548 12295 222 12 futex
22.42 1.800657 871 2066 epoll_wait
15.16 1.217550 43483 28 13 wait4
12.99 1.043667 1991 524 ppoll
9.06 0.727985 18 40323 sched_yield
1.88 0.151032 28 5375 2560 read
0.90 0.072205 17 4069 timerfd_settime
0.74 0.059196 27 2148 275 stat
0.69 0.055423 16 3350 3343 readlink
0.64 0.051208 19 2587 write
0.30 0.024025 25 950 486 access
0.20 0.016157 22 726 mprotect
0.17 0.013748 26 516 125 openat
0.12 0.009404 19 481 fstat
0.11 0.008947 15 562 2 close
0.11 0.008693 15 578 mmap
0.08 0.006115 27 222 getdents64
0.05 0.004316 44 98 readv
0.05 0.003754 33 111 munmap

...

* debian 12:

% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ------------------
96.83 902.998464 3935 229429 37 futex
1.43 13.299093 13767 966 epoll_wait
0.77 7.215386 257692 28 13 wait4
0.69 6.443136 12809 503 ppoll
0.19 1.796681 33 53919 sched_yield
0.03 0.275410 88 3128 1449 read
0.01 0.076077 28 2644 279 newfstatat
0.01 0.070517 20 3403 3396 readlink
0.01 0.059843 46 1278 mprotect
0.00 0.046381 24 1889 timerfd_settime
0.00 0.045602 30 1476 write
0.00 0.027480 24 1122 mmap
0.00 0.025041 18 1371 rt_sigprocmask
0.00 0.023368 80 289 clone
0.00 0.021320 39 537 149 openat
0.00 0.020311 21 951 487 access
0.00 0.014257 145 98 readv
0.00 0.013161 14 890 brk
0.00 0.012923 81 158 munmap

...

As for previous benchmarks there are 57 users were added via the following Ansible's task:

- name: "[RabbitMQ:config_users] Create users"
rabbitmq_user:
user: "{{ item.name | mandatory }}"
password: "{{ item.password | default(omit) }}"
update_password: "{{ item.update_password | default(omit) }}"
vhost: "{{ item.vhost | default(omit) }}"
read_priv: "{{ item.read_priv | default(omit) }}"
write_priv: "{{ item.write_priv | default(omit) }}"
configure_priv: "{{ item.configure_priv | default(omit) }}"
permissions: "{{ item.permissions | default(omit) }}"
tags: "{{ item.tags | default(omit) }}"
node: "{{ rabbitmq_node_name | default(omit,true) }}"
no_log: "{{ rabbitmq_no_log }}"
with_items:
- "{{ rabbitmq_users }}"
delegate_to: "{{ rabbit_update_host }}"
run_once: true
tags: config, config_users

with e.g.:

rabbitmq_users:

# admins
- name: admin1
vhost: /
configure_priv: .*
read_priv: .*
write_priv: .*
tags: admin

# users
- name: user1
permissions:
- vhost: /
configure_priv: .*
read_priv: .*
write_priv: .*
- vhost: vhost1
configure_priv: .*
read_priv: .*
write_priv: .*
- vhost: vhost2
configure_priv: .*
read_priv: .*
write_priv: .*
tags: user

```

Ansible's community.rabbitmq.rabbitmq_user module operates by executing rabbitmqctl binary and to keep user's idempotence it first requests its state, permissions, etc.

Best regards!

понедельник, 21 августа 2023 г. в 06:44:28 UTC, Michal Kuratczyk:

Michal Kuratczyk

unread,

Aug 21, 2023, 8:57:07 AM8/21/23

to rabbitm...@googlegroups.com

Does it execute a separate rabbitmqctl command for every user (+ every check for idempotence?). If so, then perhaps it's an Erlang startup slowdown.

Either way, this whole thing is a massive waste of CPU time. If you want to import it in a matter of seconds, just import using a single definitions file...

Best,

To view this discussion on the web, visit https://groups.google.com/d/msgid/rabbitmq-users/447373cc-3106-4b37-9301-5b0ce43e4aafn%40googlegroups.com.

--

Michał

RabbitMQ team

Some One

unread,

Aug 21, 2023, 9:04:29 AM8/21/23

to rabbitmq-users

Yes, for each user separate checks and operations via several executions the binary are to be done.

It's not a matter for now to build definitions and to import it since there are not so many users and execution's time is acceptable as well as idempotence matters.

Interesting is: what makes Debian 12 running slower?

понедельник, 21 августа 2023 г. в 12:57:07 UTC, Michal Kuratczyk:

Michal Kuratczyk

unread,

Aug 21, 2023, 9:10:56 AM8/21/23

to rabbitm...@googlegroups.com

No idea, probably DNS. :)

You can compare just `time rabbitmqctl` (to display help) and/or `time erl -noshell -eval 'noop' -eval 'init:stop()'` and if there's a significant difference,

report it to the Erlang team

https://erlangforums.com/

https://github.com/erlang/otp

Interesting as it is, I'd still highly recommend using a single JSON file. I'm not sure what your use case is exactly, but if you just want to make sure that a fresh

node has the necessary definitions (for CI or something), you can just import by URL and that's it. https://www.rabbitmq.com/definitions.html#import-on-boot

Best,

To view this discussion on the web, visit https://groups.google.com/d/msgid/rabbitmq-users/36effcd8-5a24-45fb-ae86-ac9e76110a84n%40googlegroups.com.

--

Michał

RabbitMQ team

Some One

unread,

Aug 21, 2023, 9:46:48 AM8/21/23

to rabbitmq-users

```

Benchmarks:

- for i in {0..4} ; do ( time erl -noshell -eval 'noop' -eval 'init:stop()' ) 2>&1 | grep real ; done

* debian 11:

real 0m1.210s
real 0m1.220s
real 0m1.210s
real 0m1.211s
real 0m1.210s

* debian 12:

real 0m1.563s
real 0m1.577s
real 0m1.579s
real 0m1.541s
real 0m1.591s

- for i in {0..4} ; do ( time rabbitmqctl ) 2>&1 | grep real ; done

* debian 11:

real 0m1.910s
real 0m1.969s
real 0m1.802s
real 0m2.204s
real 0m2.279s

* debian 12:

real 0m4.798s
real 0m3.979s
real 0m3.816s
real 0m3.920s
real 0m3.957s

DNS shouldn't be the matter: same script/config for cluster at both Debians, shortened:

#!/bin/bash

NET="10.10.10"

VERSION=`cat /etc/debian_version | sed -e 's|\..*||'` # this puts 11 or 12 respectively

cat > Dockerfile << EOF
FROM debian:${VERSION}
RUN apt -y update && apt -y upgrade && apt -y install \
openssh-server python3 sudo && apt clean
EXPOSE 22
CMD ["/usr/sbin/sshd", "-D"]
EOF

docker build -t rabbitmq .
docker network create --subnet ${NET}.0/24 --gateway ${NET}.200 rabbitmq

for i in {71..73} ; do
docker run --name node${i} --hostname node${i} --net rabbitmq \
--ip ${NET}.${i} --publish 20${i}:22 --detach --rm rabbitmq

done

Ansible's role is also to add/change/remove vhosts/users/permissions with idempotency for existing so flushing and recreating definitions on running cluster possibly can lead to undefined behavior for publish/subscribe processes are running.

OK, I'll try to reach Erlang's devs at github.

Thanks!

```

понедельник, 21 августа 2023 г. в 13:10:56 UTC, Michal Kuratczyk:

Michal Kuratczyk

unread,

Aug 21, 2023, 10:01:29 AM8/21/23

to rabbitm...@googlegroups.com

One more thing - run "erl" and compare the banners (first line of the output).

Perhaps it's been compiled with different options.

Best,

To view this discussion on the web, visit https://groups.google.com/d/msgid/rabbitmq-users/a9d838a1-5b53-4fc2-8097-9657fa7d7eaen%40googlegroups.com.

--

Michał

RabbitMQ team

Some One

unread,

Aug 21, 2023, 10:12:41 AM8/21/23

to rabbitmq-users

* debian 11:

Erlang/OTP 25 [erts-13.2.2.2] [source] [64-bit] [smp:2:2] [ds:2:2:10] [async-threads:1] [jit:ns]

* debian 12:

Erlang/OTP 25 [erts-13.2.2.2] [source] [64-bit] [smp:128:2] [ds:128:2:10] [async-threads:1] [jit:ns]

понедельник, 21 августа 2023 г. в 14:01:29 UTC, Michal Kuratczyk:

mkura...@gmail.com

unread,

Aug 21, 2023, 10:24:49 AM8/21/23

to rabbitmq-users

The number of schedulers is different, so this could be a part of the problem.

you can try to

export ERL_FLAGS="+S 2:2 +SDcpu 2:2"

on Debian 12

Some One

unread,

Aug 21, 2023, 10:26:17 AM8/21/23

to rabbitmq-users

OH, I think I've caught why I had such a difference. It's up to this sheduler related 'smp' and 'ds' parameters:

The [smp:2] tag changed to this format in Erlang R13, meaning 2 schedulers, both of which are online. If you say "erl +S1", it says [smp:1:1] instead. You can take schedulers offline at runtime with erlang:system_flag(schedulers_online, N), where N can be anything between 1 and the number of cores detected, inclusive.

- for i in {0..4} ; do ( time erl +S2 -noshell -eval 'noop' -eval 'init:stop()' ) 2>&1 | grep real ; done

* Debian 11:

real 0m1.210s
real 0m1.232s
real 0m1.218s
real 0m1.216s
real 0m1.223s

* Debian 12:

real 0m1.232s
real 0m1.237s
real 0m1.238s
real 0m1.244s
real 0m1.218s

понедельник, 21 августа 2023 г. в 14:12:41 UTC, Some One:

Some One

unread,

Aug 21, 2023, 10:26:54 AM8/21/23

to rabbitmq-users

Yeah =)

понедельник, 21 августа 2023 г. в 14:24:49 UTC, mkura...@gmail.com:

Some One

unread,

Aug 21, 2023, 10:30:15 AM8/21/23

to rabbitmq-users

- export ERL_FLAGS="+S 2:2 +SDcpu 2:2" ; for i in {0..4} ; do ( time rabbitmqctl ) 2>&1 | grep real ; done

* debian 11:

real 0m1.885s
real 0m1.984s
real 0m2.058s
real 0m1.908s
real 0m1.961s

* debian 12:

real 0m1.991s
real 0m2.282s
real 0m2.144s
real 0m1.912s
real 0m2.180s

понедельник, 21 августа 2023 г. в 14:26:54 UTC, Some One:

Reply all

Reply to author

Forward