Speed degradation of Debian 12 compared to Debian 11

103 views
Skip to first unread message

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:
- 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]}.

  * 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

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
0 new messages