Bug 14714

Summary: AB-INT: Qemuppc dmesg log backtrace
Product: [QA/Testing] Runtime Testing Reporter: Saul Wold <saul.wold>
Component: testimageAssignee: Unassigned <unassigned>
Status: RESOLVED WORKSFORME QA Contact:
Severity: normal    
Priority: Medium CC: alexandre.belloni, randy.macleod, richard.purdie
Version: 4.0   
Target Milestone: 4.1   
Hardware: x86   
OS: Multiple   
Whiteboard: AB-INT AB-NON-SSD
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)

Description Saul Wold 2022-02-07 18:52:44 UTC
File "/home/pokybuild/yocto-worker/qemuppc/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qemuppc/build/meta/lib/oeqa/runtime/cases/parselogs.py", line 387, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 2 != 0 : Log: /home/pokybuild/yocto-worker/qemuppc/build/build/tmp/work/qemuppc-poky-linux/core-image-sato/1.0-r0/target_logs/dmesg_output.log
-----------------------
Central error: [  287.050384] udevd[118]: worker [136] failed while handling '/devices/virtual/block/ram2'
***********************
[  287.037684] GPR00: 00000001 afa11040 00000000 afa113e0 00000001 00000001 00000000 00000001
[  287.037684] GPR08: a784d0c0 a78441c8 afa114cc 00000000 00000000 1015c208 00000001 1017d7e0
[  287.037684] GPR16: 00000000 00000064 00000000 00102000 afa11500 afa11108 00000020 00000001
[  287.037684] GPR24: 00000001 00000001 00000009 10000034 a7877418 a782c168 a7877fe0 a7876460
[  287.038098] NIP [a78441c8] 0xa78441c8
[  287.038133] LR [9c000001] 0x9c000001
[  287.038163] --- interrupt: 900
[  287.039680] udevd[118]: worker [136] /devices/virtual/block/ram2 timeout; kill it
[  287.040142] udevd[118]: seq 633 '/devices/virtual/block/ram2' killed
[  287.050194] udevd[118]: worker [136] terminated by signal 9 (Killed)
[  287.050384] udevd[118]: worker [136] failed while handling '/devices/virtual/block/ram2'
[  434.850961] rcu: INFO: rcu_preempt self-detected stall on CPU
[  434.851127] rcu:     0-...!: (1 ticks this GP) idle=595/1/0x40000002 softirq=2767/2767 fqs=0
[  434.851201]  (t=11769 jiffies g=5501 q=3)
[  434.851304] rcu: rcu_preempt kthread timer wakeup didn't happen for 11768 jiffies! g5501 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
[  434.851350] rcu:     Possible timer handling issue on cpu=0 timer-softirq=1839
[  434.851378] rcu: rcu_preempt kthread starved for 11769 jiffies! g5501 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=0
[  434.851416] rcu:     Unless rcu_preempt kthread gets sufficient CPU time, OOM is now expected behavior.
[  434.851441] rcu: RCU grace-period kthread stack dump:
[  434.851464] task:rcu_preempt     state:I stack:    0 pid:   14 ppid:     2 flags:0x00000800
[  434.851532] Call Trace:

***********************
Log: /home/pokybuild/yocto-worker/qemuppc/build/build/tmp/work/qemuppc-poky-linux/core-image-sato/1.0-r0/target_logs/dmesg
-----------------------

Further investigation is not possible due to build directory being removed.
Comment 1 Richard Purdie 2022-02-10 11:09:40 UTC
This looks very much like a load related issue with udev being "slow" and rcu stalls present...
Comment 3 Randy MacLeod 2022-02-10 15:40:48 UTC
Hopefully it does not happen on SSD machines.
Comment 4 Randy MacLeod 2022-06-02 14:58:21 UTC
Not seen since single occurence in Feb. Closing.