https://valkyrie.yoctoproject.org/#/builders/73/builds/401 The build is hanging. Looking at the testimage task log, it is 6GB in size. The reason why is the tar output collection is being printed into the log as binary data: https://valkyrie.yocto.io/pub/shared-failure-data/log.do_testimage.2400954 So firstly we need to fix that. Secondly a test fails: https://valkyrie.yocto.io/pub/shared-failure-data/ptest-runner.log and finally, there is a lot of noise in dmesg from the test run including an OOM: https://valkyrie.yocto.io/pub/shared-failure-data/qemu_boot_log.20241118102253 not sure if the OOM is related to the test failure or not. There is the question of why the task finished but cooker is still running too.
bitbake-cookerdaemon shows nothing interesting, pings are succeeding. The console output shows the core-image-ptest-strace did finish and the log output is shown but somehow bitbake never marked the task as completed.
Nothing significant in the host dmesg.
bitbake-worker is looping in worker_flush writing 64kb at a time: mmap(NULL, 2218389504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712d93c00000 munmap(0x712c8b400000, 2218455040) = 0 futex(0xb47b84, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0xb47bd8, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) futex(0xb47be0, FUTEX_WAKE_PRIVATE, 1) = 0 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999997040}) write(1, "aa\\xaa\\xaa\\xaa\\xaa\\xaa\\xaa\\xaa\\x"..., 2218387790) = 65536 mmap(NULL, 2218323968, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712d0f800000 munmap(0x712d93c00000, 2218389504) = 0 futex(0xb47b80, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0xb47bdc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) futex(0xb47be0, FUTEX_WAKE_PRIVATE, 1) = 0 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999996730}) write(1, "aa\\xaa\\xaa\\xaa\\xaa\\xaa\\xaa\\xaa\\x"..., 2218322254) = 65536 mmap(NULL, 2218258432, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712c8b400000 munmap(0x712d0f800000, 2218323968) = 0 futex(0xb47b84, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0xb47b88, FUTEX_WAKE_PRIVATE, 1) = 1 futex(0xb47b80, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=673516, tv_nsec=134260404}, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) futex(0xb47b88, FUTEX_WAKE_PRIVATE, 1) = 0 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999996940}) write(1, "aa\\xaa\\xaa\\xaa\\xaa\\xaa\\xaa\\xaa\\x"..., 2218256718) = 65536 mmap(NULL, 2218192896, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712d93c00000 (gdb) py-bt Traceback (most recent call first): File "/srv/pokybuild/yocto-worker/qemux86-64-ptest/build/bitbake/bin/bitbake-worker", line 108, in worker_flush worker_queue_int = worker_queue_int[written:] File "/usr/lib/python3.12/threading.py", line 1010, in run self._target(*self._args, **self._kwargs) File "/usr/lib/python3.12/threading.py", line 1073, in _bootstrap_inner self.run() File "/usr/lib/python3.12/threading.py", line 1030, in _bootstrap self._bootstrap_inner()
The delay is around the mmap, which corresponds to: worker_queue_int = worker_queue_int[written:] in the worker code.
With timestamps: 17:00:53.877740 munmap(0x712d9aa00000, 2101735424) = 0 17:00:54.056454 futex(0xb47b84, FUTEX_WAKE_PRIVATE, 1) = 1 17:00:54.056501 futex(0xb47bdc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) 17:00:54.056618 futex(0xb47be0, FUTEX_WAKE_PRIVATE, 1) = 0 17:00:54.056650 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999997460}) 17:00:54.056734 write(1, "UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU"..., 2101668174) = 65536 17:00:54.056850 mmap(NULL, 2101604352, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712d9aa00000 17:00:55.085339 munmap(0x712d1d400000, 2101669888) = 0 17:00:55.263597 futex(0xb47b80, FUTEX_WAKE_PRIVATE, 1) = 1 17:00:55.263668 futex(0xb47bd8, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) 17:00:55.263727 futex(0xb47be0, FUTEX_WAKE_PRIVATE, 1) = 0 17:00:55.263787 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999997420}) 17:00:55.263887 write(1, "UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU"..., 2101602638) = 65536 17:00:55.264014 mmap(NULL, 2101538816, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712d1d400000 17:00:56.283010 munmap(0x712d9aa00000, 2101604352) = 0 17:00:56.461363 futex(0xb47b84, FUTEX_WAKE_PRIVATE, 1) = 1 17:00:56.461436 futex(0xb47bdc, FUTEX_WAIT_BITSET_PRIVATE|FUTEX_CLOCK_REALTIME, 0, NULL, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) 17:00:56.461495 futex(0xb47be0, FUTEX_WAKE_PRIVATE, 1) = 0 17:00:56.461555 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999996780}) 17:00:56.461656 write(1, "UUUUUUUUUUUUUUUUUUUUUUUUUUUUUUUU"..., 2101537102) = 65536 17:00:56.461736 mmap(NULL, 2101473280, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x712d9aa00000 17:00:57.500454 munmap(0x712d1d400000, 2101538816) = 0 17:00:57.677700 futex(0xb47b80, FUTEX_WAKE_PRIVATE, 1) = 1 17:00:57.677770 futex(0xb47b88, FUTEX_WAKE_PRIVATE, 1) = 1 17:00:57.677826 futex(0xb47b84, FUTEX_WAIT_BITSET_PRIVATE, 0, {tv_sec=675735, tv_nsec=3601111}, FUTEX_BITSET_MATCH_ANY) = -1 EAGAIN (Resource temporarily unavailable) 17:00:57.677904 futex(0xb47b88, FUTEX_WAKE_PRIVATE, 1) = 0 17:00:57.677962 pselect6(2, NULL, [1], NULL, {tv_sec=1, tv_nsec=0}, NULL) = 1 (out [1], left {tv_sec=0, tv_nsec=999997310}
For the record, strace ptest creates a 43GB sparse file which is why the data transfer is huge when saving artefact data.
Summary of issues found: https://lists.openembedded.org/g/openembedded-core/message/207476
For the strace issue which is all that remains thanks to Richard.