Bug 15718

So I went a bit deeper. The ssh session seen on the last line of the log is still active:
pokybui+ 1910663  0.0  0.0  16048  8044 ?        Ss   Jan14   0:00 ssh -l root -o ServerAliveCountMax=2 -o ServerAliveInterval=30 -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -o LogLevel=ERROR 192.168.7.10 export PATH=/usr/sbin:/sbin:/usr/bin:/bin; ptest-runner -t 450 -d "/usr/lib"

Qemu machine is still alive, I was able to SSH onto it. Test also seem to be still running. ps and top:
1041 root      224m S    /usr/libexec/installed-tests/gstreamer/gst_gstbin
1041     1 root     S     224m  23%  25% /usr/libexec/installed-tests/gstreamer/gst_gstbin

Trying to run the same process by hand, it ends successfully after a few seconds:

> root@qemuarm64:~# export GST_PLUGIN_LOADING_WHITELIST=gstreamer
> root@qemuarm64:~# export GST_STATE_IGNORE_ELEMENTS=
> root@qemuarm64:~# export GST_CHECKS_IGNORE=,test_functioning,test_infinite_seek_50_src_live,parser_pull_short_read,parser_convert_duration,parser_pull_frame_growth,parser_reverse_playback
> root@qemuarm64:~# export GST_REGISTRY=/home/root/.cache/gstreamer-1.0/gst_gstbin.registry
> root@qemuarm64:~# export GIO_USE_VFS=local
> root@qemuarm64:~# /usr/libexec/installed-tests/gstreamer/gst_gstbin
> Running suite(s): GstBin
> 100%: Checks: 26, Failures: 0, Errors: 0
> Check suite gst_bin ran in 6.098s (tests failed: 0)
> root@qemuarm64:~# 

Killing said process on the qemu side (pid 1041 here) unblocks everything.

And I confirm it is intermittent, second build succeed:

https://valkyrie.yoctoproject.org/#/builders/61/builds/749

qemuarm64-ptest ubuntu2410-vk-arm1 mathieu/master-next completed at 2025-01-15T10:10:44Z
https://valkyrie.yoctoproject.org/#/builders/61/builds/742/steps/12/logs/stdio

Happening so far on mathieu's master-next . 
let's keep an eye on it and see if it happens on master branch.

Same issue today, qemux86-64-ptest, on ubuntu2004-vk-1.

Still locked in ptest for hours. I logged inside of the qemu instance and ran the same tests by hand, finished in less than a minute.

So I built strace:

root@qemux86-64:~# ps | tail
  381 root     10364 S    sshd-session: root [priv]
  383 root     10784 S    sshd-session: root@notty
  384 root      2528 S    ptest-runner -t 450 -d /usr/lib
  385 root         0 Z    [run-ptest]
 3052 root      224m S    /usr/libexec/installed-tests/gstreamer/gst_gstbin
 5799 root     10364 S    sshd-session: root [priv]
 5801 root     10784 S    sshd-session: root@pts/1
 5802 root      4072 S    -sh
 5813 root      4072 R    ps
 5814 root      4028 S    tail

root@qemux86-64:~# ./strace -p 3052
./strace: Process 3052 attached
ppoll([{fd=4, events=POLLIN}, {fd=6, events=POLLIN}], 2, NULL, NULL, 8

(Not sure what is this "8" here, man tells me ppoll only takes 4 arguments.)

lr-x------    1 root     root            64 Apr 17 06:28 0 -> /dev/null
l-wx------    1 root     root            64 Apr 17 06:28 1 -> pipe:[1624]
l-wx------    1 root     root            64 Apr 17 06:28 2 -> pipe:[1624]
lrwx------    1 root     root            64 Apr 17 06:28 3 -> /var/volatile/tmp/test-tmp-gstreamer_gst_gstbin.test-JIHZ42/check_cKurme (deleted)
lrwx------    1 root     root            64 Apr 17 06:28 4 -> socket:[2838]
lrwx------    1 root     root            64 Apr 17 06:28 5 -> socket:[2839]
lrwx------    1 root     root            64 Apr 17 06:28 6 -> anon_inode:[eventfd]

root@qemux86-64:~# grep 2838 /proc/net/*
/proc/net/unix:00000000e93ef4aa: 00000003 00000000 00000000 0001 03  2838

Not sure how (if possible) I can find where is the other end of this socket. Is it socket:[2839] (fd 5) ?

Also got lsof, not much more data I believe:

root@qemux86-64:~# ./lsof.lsof -p 3052
COMMAND    PID USER  FD      TYPE             DEVICE SIZE/OFF NODE NAME
gst_gstbi 3052 root cwd       DIR               0,21       40 1019 /var/volatile/tmp/test-tmp-gstreamer_gst_gstbin.test-JIHZ42 (deleted)
gst_gstbi 3052 root rtd       DIR              253,0     1024    2 /
gst_gstbi 3052 root txt       REG              253,0    79992  922 /usr/libexec/installed-tests/gstreamer/gst_gstbin
gst_gstbi 3052 root mem       REG              253,0   559080  627 /usr/lib/libgstbase-1.0.so.0.2600.0
gst_gstbi 3052 root mem       REG              253,0   467424  603 /usr/lib/gstreamer-1.0/libgstcoreelements.so
gst_gstbi 3052 root mem       REG              253,0    43120  615 /usr/lib/libffi.so.8.1.4
gst_gstbi 3052 root mem       REG              253,0   436448  643 /usr/lib/libpcre2-8.so.0.14.0
gst_gstbi 3052 root mem       REG              253,0   960704  304 /lib/libm.so.6
gst_gstbi 3052 root mem       REG              253,0    22488  623 /usr/lib/libgmodule-2.0.so.0.8400.0
gst_gstbi 3052 root mem       REG              253,0  1958320  301 /lib/libc.so.6
gst_gstbi 3052 root mem       REG              253,0   407744  625 /usr/lib/libgobject-2.0.so.0.8400.0
gst_gstbi 3052 root mem       REG              253,0  1379632  621 /usr/lib/libglib-2.0.so.0.8400.0
gst_gstbi 3052 root mem       REG              253,0   149648  629 /usr/lib/libgstcheck-1.0.so.0.2600.0
gst_gstbi 3052 root mem       REG              253,0  1444328  635 /usr/lib/libgstreamer-1.0.so.0.2600.0
gst_gstbi 3052 root mem       REG              253,0   225600  296 /lib/ld-linux-x86-64.so.2
gst_gstbi 3052 root   0r      CHR                1,3      0t0    5 /dev/null
gst_gstbi 3052 root   1w     FIFO               0,13      0t0 1624 pipe
gst_gstbi 3052 root   2w     FIFO               0,13      0t0 1624 pipe
gst_gstbi 3052 root   3u      REG               0,21     2572 1288 /var/volatile/tmp/test-tmp-gstreamer_gst_gstbin.test-JIHZ42/check_cKurme (deleted)
gst_gstbi 3052 root   4u     unix 0x00000000e93ef4aa      0t0 2838 type=STREAM (CONNECTED)
gst_gstbi 3052 root   5u     unix 0x00000000c964a3ce      0t0 2839 type=STREAM (CONNECTED)
gst_gstbi 3052 root   6u  a_inode               0,14        0   34 [eventfd:2]

Running successful test:

root@qemux86-64:~# export CK_DEFAULT_TIMEOUT=20
root@qemux86-64:~# export GST_PLUGIN_LOADING_WHITELIST=gstreamer
root@qemux86-64:~# export GST_REGISTRY=/home/root/.cache/gstreamer-1.0/gst_gstpreset.registry
root@qemux86-64:~# export GST_STATE_IGNORE_ELEMENTS=
root@qemux86-64:~# /usr/libexec/installed-tests/gstreamer/gst_gstbin
Running suite(s): GstBin
100%: Checks: 26, Failures: 0, Errors: 0
Check suite gst_bin ran in 6.081s (tests failed: 0)
root@qemux86-64:~#

root@qemux86-64:~# ./strace -f /usr/libexec/installed-tests/gstreamer/gst_gstbin > gstbin_ok 2>&1

Created attachment 5113 [details]
strace on gst_gstbin when successful

Sorry, another comment. I just thought about other threads:

root@qemux86-64:~# ls /proc/3052/task/
3052  3053  3054

root@qemux86-64:~# ./strace -p 3052
./strace: Process 3052 attached
ppoll([{fd=4, events=POLLIN}, {fd=6, events=POLLIN}], 2, NULL, NULL, 8^C./strace: Process 3052 detached
 <detached ...>

root@qemux86-64:~# ./strace -p 3053
./strace: Process 3053 attached
futex(0x55d90e77fdb0, FUTEX_WAIT_PRIVATE, 2, NULL^C./strace: Process 3053 detached
 <detached ...>

root@qemux86-64:~# ./strace -p 3054
./strace: Process 3054 attached
futex(0x55d90e76e338, FUTEX_WAIT_PRIVATE, 1, NULL
^C./strace: Process 3054 detached
 <detached ...>

I remained attached for a few minutes, all threads seem so be stuck.

Maybe bad luck, maybe something else... we have another non-ending ptest, here: https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/1328. I quickly confirmed, this is the same as the previous one.

If anybody wants to play with it, we probably still have 20 hours before the timeout.

And I confirm it is still intermittent, a third build of the same version was successful.

Bulk move of all unassigned 5.2 medium importance bugs to 5.3.

qemux86-64-ptest fedora39-vk-1 agodard/master-next completed at 2026-01-21T09:50:04Z
https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/2957/steps/13/logs/stdio

Also seen on whinlatter:
whinlatter qemux86-64-ptest debian12-vk-5 https://autobuilder.yoctoproject.org/valkyrie/#/builders/73/builds/3207

I connected to the VM to kill /usr/libexec/installed-tests/gstreamer/gst_gstbin
gst_gstbin was Sleeping, run-ptest was Zombie.

Bulk move of 6.0 Medium bugs to 6.1.