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

#1120376#5
Date:
2025-11-08 13:05:27 UTC
From:
To:
Hi,

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).

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
      Loaded: loaded (/etc/systemd/system/debci-worker@.service;
enabled; preset: enabled)
      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
      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>
              ├─1976078 tee /tmp/autopkgtest-fifo.91866cql
              ├─1976079 tee /tmp/autopkgtest-fifo.91866cql -a /dev/stderr
              ├─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)

● debci-worker@1.service - debci-worker instance 1
      Loaded: loaded (/etc/systemd/system/debci-worker@.service;
enabled; preset: enabled)
      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
      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

● debci-worker@3.service - debci-worker instance 3
      Loaded: loaded (/etc/systemd/system/debci-worker@.service;
enabled; preset: enabled)
      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
      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

● debci-worker@6.service - debci-worker instance 6
      Loaded: loaded (/etc/systemd/system/debci-worker@.service;
enabled; preset: enabled)
      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
      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

● debci-worker@2.service - debci-worker instance 2
      Loaded: loaded (/etc/systemd/system/debci-worker@.service;
enabled; preset: enabled)
      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
      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

● debci-worker@5.service - debci-worker instance 5
      Loaded: loaded (/etc/systemd/system/debci-worker@.service;
enabled; preset: enabled)
      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
      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