Bug#1120376: debci-worker: takes a while to pick up new jobs when idle for a while

[Paul Gevers]

Package: debci-worker
Version: 3.12
Severity: minor

Hi,





Or thinking a bit harder about it, is this a bug in amqp-consume?

Paul

loongson@ci-worker-loong64-01:~$ sudo systemctl status debci-worker@*
● debci-worker@4.service - debci-worker instance 4

     Active: active (running) since Sat 2025-11-08 12:42:26 UTC; 19min ago
 Invocation: 0d243f7bd27e45109b6fe7b0377dd802
       Docs: https://ci.debian.net/doc/
   Main PID: 1949527 (amqp-consume)
      Tasks: 12
     Memory: 627.1M (peak: 779.9M)
        CPU: 56.612s

             ├─1976078 tee /tmp/autopkgtest-fifo.91866cql
             ├─1976079 tee /tmp/autopkgtest-fifo.91866cql -a /dev/stderr




● debci-worker@1.service - debci-worker instance 1

     Active: active (running) since Wed 2025-11-05 20:28:44 UTC; 2 days ago
 Invocation: c74439eaad37470cbc1ce08a438b0725
       Docs: https://ci.debian.net/doc/
   Main PID: 88957 (amqp-consume)
      Tasks: 1
     Memory: 169.5M (peak: 6.8G, swap: 1M, swap peak: 4.5M)
        CPU: 3h 50min 23.344s




● debci-worker@3.service - debci-worker instance 3

     Active: active (running) since Wed 2025-11-05 20:28:39 UTC; 2 days ago
 Invocation: f579165223e64eff9701c90233d03235
       Docs: https://ci.debian.net/doc/
   Main PID: 88327 (amqp-consume)
      Tasks: 1
     Memory: 136.6M (peak: 9.7G, swap: 320K, swap peak: 561.2M)
        CPU: 3h 10min 22.167s




● debci-worker@6.service - debci-worker instance 6

     Active: active (running) since Wed 2025-11-05 21:16:27 UTC; 2 days ago
 Invocation: 26a0874d10f64b0997aaed796b9f524f
       Docs: https://ci.debian.net/doc/
   Main PID: 1082194 (amqp-consume)
      Tasks: 1
     Memory: 154.7M (peak: 7.8G, swap: 0B, swap peak: 136.7M)
        CPU: 3h 40min 57.077s




● debci-worker@2.service - debci-worker instance 2

     Active: active (running) since Wed 2025-11-05 20:28:41 UTC; 2 days ago
 Invocation: d4d7ea3708d04af38e2816848b426548
       Docs: https://ci.debian.net/doc/
   Main PID: 88574 (amqp-consume)
      Tasks: 1
     Memory: 180.2M (peak: 2.7G, swap: 1M, swap peak: 1.5M)
        CPU: 3h 58min 57.776s




● debci-worker@5.service - debci-worker instance 5

     Active: active (running) since Wed 2025-11-05 20:26:43 UTC; 2 days ago
 Invocation: 92e8da39e3d648ae9ec829c62f74fe28
       Docs: https://ci.debian.net/doc/
   Main PID: 80670 (amqp-consume)
      Tasks: 1
     Memory: 163.7M (peak: 7.1G, swap: 1.4M, swap peak: 13.4M)
        CPU: 3h 34min 16.987s





-- System Information:
Debian Release: forky/sid
  APT prefers testing
  APT policy: (990, 'testing'), (500, 'unstable')
Architecture: amd64 (x86_64)

Kernel: Linux 6.16.12+deb14+1-amd64 (SMP w/12 CPU threads; PREEMPT)
Kernel taint flags: TAINT_WARN

Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages debci-worker depends on:
ii  autodep8       0.30
ii  autopkgtest    5.51
pn  debci          <none>
pn  inotify-tools  <none>

Versions of packages debci-worker recommends:
ii  lxc  1:6.0.5-1

debci-worker suggests no packages.

I noticed multiple times that when new jobs are scheduled for an architecture where debci-workers have been idle for a while, it takes time before the workers start picking up jobs again. At this moment that can clearly be seen on loong64. I filed the queue several minutes ago with 10k tests, but there's only one worker running a test (see below). Loaded: loaded (/etc/systemd/system/debci-worker@.service; enabled; preset: enabled) CGroup: /system.slice/system-debci\x2dworker.slice/debci-worker@4.service ├─1949527 amqp-consume --url amqps://ci-master.debian.net --ssl --cacert=/etc/debci/ca.crt --cert=/etc/debci/ci-worker-loong64-01.crt --> ├─1976002 /bin/sh /usr/share/debci/bin/debci-worker --do-request --arch=loong64 --backend=lxc ├─1976032 /bin/sh /usr/share/debci/bin/debci-test --quiet --data-dir /tmp/debci-worker-65943775-nL6cSC4KCV --suite unstable --arch loong> ├─1976068 /bin/sh /usr/share/debci/backends/lxc/test-package --output-dir /tmp/debci-worker-65943775-nL6cSC4KCV/autopkgtest-incoming/uns> ├─1976071 /bin/sh /usr/share/debci/bin/debci-autopkgtest --user debci --apt-upgrade --output-dir /tmp/debci-worker-65943775-nL6cSC4KCV/a> ├─1976077 /usr/bin/python3 -u /usr/bin/autopkgtest --no-built-binaries "--setup-commands=echo 'dolfin unstable/loong64' > /var/tmp/debci> ├─1976080 mawk -Winteractive "{ printf(\"%3ds %s\\n\", systime()-1762606191, \$0 );}" /tmp/autopkgtest-fifo.91866cql ├─1976081 /usr/bin/python3 /usr/bin/autopkgtest-virt-lxc --sudo --name ci-312-8c98f5bb autopkgtest-unstable-loong64 ├─1994667 sudo --preserve-env lxc-attach --name ci-312-8c98f5bb -- env -i bash -c "set -a; [ -r /etc/environment ] && . /etc/environment> └─1994669 lxc-attach --name ci-312-8c98f5bb -- env -i bash -c "set -a; [ -r /etc/environment ] && . /etc/environment 2>/dev/null || true> Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994638]: debci : (command continued) /tmp/autopkgtest-lxc.ntrhhagb/downtmp/test-dolfin-python-unittest-> Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994638]: pam_unix(sudo:session): session closed for user root Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994654]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-8c98f5bb > Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994654]: pam_unix(sudo:session): session closed for user root Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994667]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-8c98f5bb > Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994667]: debci : (command continued) --artifacts=/tmp/autopkgtest-lxc.ntrhhagb/downtmp/test-dolfin-pyth> Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994667]: debci : (command continued) --make-executable=/tmp/autopkgtest-lxc.ntrhhagb/downtmp/build.sgK/> Nov 08 13:00:34 ci-worker-loong64-01 sudo[1994667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Loaded: loaded (/etc/systemd/system/debci-worker@.service; enabled; preset: enabled) CGroup: /system.slice/system-debci\x2dworker.slice/debci-worker@1.service └─88957 amqp-consume --url amqps://ci-master.debian.net --ssl --cacert=/etc/debci/ca.crt --cert=/etc/debci/ci-worker-loong64-01.crt --ke> Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880915]: debci : (command continued) /tmp/autopkgtest-lxc.c_1tt6ld/downtmp/autopkgtest_tmp Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880915]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880915]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880940]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-e27d0340 > Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880940]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880940]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880969]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-destroy --quiet --force --name> Nov 08 06:19:08 ci-worker-loong64-01 sudo[1880969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:10 ci-worker-loong64-01 sudo[1880969]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:10 ci-worker-loong64-01 debci[1872898]: ruby-image-science unstable/loong64/lxc (65550063) fail Loaded: loaded (/etc/systemd/system/debci-worker@.service; enabled; preset: enabled) CGroup: /system.slice/system-debci\x2dworker.slice/debci-worker@3.service └─88327 amqp-consume --url amqps://ci-master.debian.net --ssl --cacert=/etc/debci/ca.crt --cert=/etc/debci/ci-worker-loong64-01.crt --ke> Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876303]: debci : (command continued) /tmp/autopkgtest-lxc._jg5tx31/downtmp/autopkgtest_tmp Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876303]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876303]: pam_unix(sudo:session): session closed for user root Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876341]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-0c9b4f8a > Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876341]: pam_unix(sudo:session): session closed for user root Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876380]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-destroy --quiet --force --name> Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:18:46 ci-worker-loong64-01 sudo[1876380]: pam_unix(sudo:session): session closed for user root Nov 08 06:18:46 ci-worker-loong64-01 debci[1862009]: python-django-imagekit unstable/loong64/lxc (65550060) pass Loaded: loaded (/etc/systemd/system/debci-worker@.service; enabled; preset: enabled) CGroup: /system.slice/system-debci\x2dworker.slice/debci-worker@6.service └─1082194 amqp-consume --url amqps://ci-master.debian.net --ssl --cacert=/etc/debci/ca.crt --cert=/etc/debci/ci-worker-loong64-01.crt --> Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883332]: debci : (command continued) /tmp/autopkgtest-lxc.52x9wknc/downtmp/autopkgtest_tmp Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883332]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883346]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-e0d0427e > Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883346]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883346]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883362]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-destroy --quiet --force --name> Nov 08 06:19:30 ci-worker-loong64-01 sudo[1883362]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:32 ci-worker-loong64-01 sudo[1883362]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:32 ci-worker-loong64-01 debci[1865033]: rust-talktosc unstable/loong64/lxc (65550061) pass Loaded: loaded (/etc/systemd/system/debci-worker@.service; enabled; preset: enabled) CGroup: /system.slice/system-debci\x2dworker.slice/debci-worker@2.service └─88574 amqp-consume --url amqps://ci-master.debian.net --ssl --cacert=/etc/debci/ca.crt --cert=/etc/debci/ci-worker-loong64-01.crt --ke> Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886169]: debci : (command continued) /tmp/autopkgtest-lxc.dj2ha29r/downtmp/autopkgtest_tmp Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886169]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886169]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886183]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-8f19f60d > Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886183]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886183]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886198]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-destroy --quiet --force --name> Nov 08 06:19:45 ci-worker-loong64-01 sudo[1886198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:19:47 ci-worker-loong64-01 sudo[1886198]: pam_unix(sudo:session): session closed for user root Nov 08 06:19:47 ci-worker-loong64-01 debci[1872128]: node-plur unstable/loong64/lxc (65550062) pass Loaded: loaded (/etc/systemd/system/debci-worker@.service; enabled; preset: enabled) CGroup: /system.slice/system-debci\x2dworker.slice/debci-worker@5.service └─80670 amqp-consume --url amqps://ci-master.debian.net --ssl --cacert=/etc/debci/ca.crt --cert=/etc/debci/ci-worker-loong64-01.crt --ke> Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876469]: debci : (command continued) /tmp/autopkgtest-lxc.lvx65f3s/downtmp/autopkgtest_tmp Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876469]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876469]: pam_unix(sudo:session): session closed for user root Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876484]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-attach --name ci-312-fdcb3eb2 > Nov 08 06:18:44 ci-worker-loong64-01 sudo[1876484]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:18:45 ci-worker-loong64-01 sudo[1876484]: pam_unix(sudo:session): session closed for user root Nov 08 06:18:45 ci-worker-loong64-01 sudo[1876499]: debci : PWD=/usr/share/debci ; USER=root ; COMMAND=/usr/bin/lxc-destroy --quiet --force --name> Nov 08 06:18:45 ci-worker-loong64-01 sudo[1876499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1002) Nov 08 06:18:46 ci-worker-loong64-01 sudo[1876499]: pam_unix(sudo:session): session closed for user root Nov 08 06:18:46 ci-worker-loong64-01 debci[1846458]: rust-gix-prompt unstable/loong64/lxc (65550057) pass Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE=en_US:en

OpenPGP_signature.asc
Description: OpenPGP digital signature