Bug 14564

Summary: AB-INT: udev worker vda timeout
Product: [QA/Testing] Runtime Testing Reporter: Alexandre Belloni <alexandre.belloni>
Component: oeqa/runtimeAssignee: Randy MacLeod <randy.macleod>
Status: RESOLVED OBSOLETE QA Contact:
Severity: normal    
Priority: Medium CC: alexandre.belloni, chee.yang.lee, oobitots, randy.macleod, steve
Version: unspecified   
Target Milestone: 5.2   
Hardware: x86   
OS: Multiple   
Whiteboard: AB-INT
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)

Description Alexandre Belloni 2021-09-23 22:13:49 UTC
[  294.716741] udevd[161]: timeout '/etc/udev/scripts/mount.sh'
[  294.728901] udevd[159]: timeout '/etc/udev/scripts/mount.sh'
[  294.735359] udevd[141]: worker [159] /devices/virtual/block/ram13 timeout; kill it
[  294.739214] udevd[161]: slow: '/etc/udev/scripts/mount.sh' [173]
[  294.747860] udevd[159]: slow: '/etc/udev/scripts/mount.sh' [165]
[  294.757455] udevd[141]: seq 714 '/devices/virtual/block/ram13' killed
[  294.759776] udevd[141]: worker [161] /devices/virtual/block/ram14 timeout; kill it
[  294.760521] udevd[141]: seq 715 '/devices/virtual/block/ram14' killed
[  294.796221] udevd[141]: worker [159] terminated by signal 9 (Killed)
[  294.802885] udevd[141]: worker [159] failed while handling '/devices/virtual/block/ram13'

Later on an rcu_preempt stall is seen.

https://autobuilder.yoctoproject.org/typhoon/#/builders/42/builds/3966/steps/14/logs/stdio
qemuarm64 debian9-ty-2
Comment 1 Alexandre Belloni 2021-09-23 22:17:18 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/47/builds/3945/steps/12/logs/stdio
qemuarm-oecore ubuntu1804-ty-1
Comment 2 Oleksiy Obitotskyy 2021-09-25 14:51:02 UTC
qemumips64 debian9-ty-2

https://autobuilder.yoctoproject.org/typhoon/#/builders/74/builds/4031



Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qemumips64/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemumips64/build/meta/lib/oeqa/runtime/cases/parselogs.py", line 385, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 8 != 0 : Log: /home/pokybuild/yocto-worker/qemumips64/build/build/tmp/work/qemumips64-poky-linux/core-image-sato/1.0-r0/target_logs/dmesg
-----------------------
Central error: [  270.003835] udevd[118]: worker [134] failed while handling '/devices/virtual/block/ram11'
***********************
[  230.134487] udevd[118]: worker [124] /devices/virtual/block/ram4 is taking a long time
[  249.202268] udevd[118]: worker [125] /devices/virtual/block/ram5 is taking a long time
[  260.523734] udevd[118]: worker [135] /devices/virtual/block/ram6 is taking a long time
[  269.987368] udevd[118]: worker [134] /devices/virtual/block/ram11 timeout; kill it
[  269.992426] udevd[122]: timeout '/etc/udev/scripts/mount.sh'
[  269.993148] udevd[122]: slow: '/etc/udev/scripts/mount.sh' [164]
[  269.994688] udevd[118]: seq 615 '/devices/virtual/block/ram11' killed
[  269.994997] udevd[118]: worker [122] /devices/pci0000:00/0000:00:15.0/virtio2/block/vda timeout; kill it
[  269.996783] udevd[118]: seq 566 '/devices/pci0000:00/0000:00:15.0/virtio2/block/vda' killed
[  270.003387] udevd[118]: worker [134] terminated by signal 9 (Killed)
[  270.003835] udevd[118]: worker [134] failed while handling '/devices/virtual/block/ram11'
[  270.027729] udevd[118]: worker [122] terminated by signal 9 (Killed)
[  270.028097] udevd[118]: worker [122] failed while handling '/devices/pci0000:00/0000:00:15.0/virtio2/block/vda'
[  291.328008] EXT4-fs (vda): re-mounted. Opts: (null). Quota mode: disabled.
[  302.439227] udevd[121]: timeout '/etc/udev/scripts/mount.sh'
[  302.440455] udevd[121]: slow: '/etc/udev/scripts/mount.sh' [155]
[  302.441287] udevd[118]: worker [121] /devices/virtual/block/ram2 timeout; kill it
[  302.441840] udevd[118]: seq 620 '/devices/virtual/block/ram2' killed
[  302.442057] udevd[118]: worker [124] /devices/virtual/block/ram7 is taking a long time
[  302.448359] udevd[118]: worker [121] terminated by signal 9 (Killed)
[  302.448725] udevd[118]: worker [121] failed while handling '/devices/virtual/block/ram2'
...
RESULTS - parselogs.ParseLogsTest.test_parselogs: FAILED (8.33s)
Comment 3 Randy MacLeod 2021-09-30 14:40:44 UTC
Probably related to NOT being able to use the make load maximization on dunfell.
Comment 5 Randy MacLeod 2022-03-24 14:41:54 UTC
Not seen in months. closing.
Comment 6 Alexandre Belloni 2022-10-14 13:42:58 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/5843/steps/20/logs/stdio

qemumips opensuse154-ty-2

[   66.428149] udevd[112]: worker [120] /devices/pci0000:00/0000:00:15.0/virtio2/block/vda is taking a long time
[  186.586770] udevd[112]: worker [120] /devices/pci0000:00/0000:00:15.0/virtio2/block/vda timeout; kill it
[  186.616775] udevd[112]: seq 617 '/devices/pci0000:00/0000:00:15.0/virtio2/block/vda' killed
[  186.642398] udevd[112]: worker [120] terminated by signal 9 (Killed)
[  186.660117] udevd[112]: worker [120] failed while handling '/devices/pci0000:00/0000:00:15.0/virtio2/block/vda'
Comment 7 Randy MacLeod 2022-10-20 15:09:25 UTC
Can we tag build failures such as this one and collect system usage data as we do for the interval timeouts?
Comment 9 Alexandre Belloni 2022-12-07 17:51:06 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/6238/steps/13/logs/stdio

qemumips fedora36-ty-4
Comment 10 Alexandre Belloni 2022-12-18 16:04:59 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/6297/steps/13/logs/stdio
qemumips opensuse154-ty-2
Comment 11 Alexandre Belloni 2023-03-10 15:22:57 UTC
https://autobuilder.yoctoproject.org/typhoon/#builders/60/builds/6753/steps/12/logs/stdio

qemumips fedora36-ty-2
Comment 12 Alexandre Belloni 2023-04-06 13:10:45 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/6878/steps/13/logs/stdio

qemumips fedora36-ty-4
Comment 13 Alexandre Belloni 2023-05-18 22:25:00 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/7061/steps/14/logs/stdio

qemumips ubuntu1804-ty-3
Comment 14 Alexandre Belloni 2023-05-18 23:00:04 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/7072/steps/13/logs/stdio

qemumips debian11-ty-1
Comment 15 Alexandre Belloni 2023-06-08 20:47:38 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/60/builds/7112/steps/13/logs/stdio

qemumips fedora37-ty-2
Comment 16 Randy MacLeod 2023-11-06 22:09:51 UTC
This erorr doesn't seem to be happening on the YP AB anymore. 
I'm waiting a while longer before closing.
Comment 17 Alexandre Belloni 2023-12-04 12:27:05 UTC
https://autobuilder.yoctoproject.org/typhoon/#/builders/147/builds/492/steps/12/logs/stdio

qemumips-tc fedora38-ty-3
Comment 18 Randy MacLeod 2024-11-14 15:54:48 UTC
Hasn't happened of a year.