canonical-ubuntu-qa team mailing list archive

[LEE KUAN-YING <2092374@xxxxxxxxxxxxxxxxxx>]

Public bug reported:

This issue happened on jammy:linux-xilinx-zynqmp
5.15.0-1039.43.5.15.0-1038.42 doesn't have this issue.

[ 3853.721349] zynqmp_firmware firmware:zynqmp-firmware: Error requesting firmware
[ 3853.721357] zynqmp_firmware firmware:zynqmp-firmware: Error requesting firmware
[ 3853.721358] zynqmp_firmware firmware:zynqmp-firmware: Error requesting firmware
[ 4258.727473] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 4258.733399] rcu: 1-...!: (3 ticks this GP) idle=873/1/0x4000000000000000 softirq=483179/483185 fqs=1
[ 4258.742701] rcu: 3-...!: (1 GPs behind) idle=09f/1/0x4000000000000000 softirq=544004/544021 fqs=1
[ 4258.751737] (detected by 2, t=101252 jiffies, g=791745, q=1317)
[ 4258.751744] Task dump for CPU 1:
[ 4258.751748] task:read_all state:R running task stack: 0 pid:55934 ppid: 55930 flags:0x00000003
[ 4258.751763] Call trace:
[ 4258.751766] __switch_to+0xf8/0x150
[ 4258.751782] zynqmp_pm_fpga_read+0x78/0xdc
[ 4258.751791] zynqmp_fpga_ops_status+0x6c/0x110
[ 4258.751803] status_show+0x30/0x2a0
[ 4258.751812] dev_attr_show+0x28/0x64
[ 4258.751820] sysfs_kf_seq_show+0x90/0x134
[ 4258.751831] kernfs_seq_show+0x34/0x40
[ 4258.751840] seq_read_iter+0x1d4/0x4e0
[ 4258.751850] kernfs_fop_read_iter+0x40/0x4c
[ 4258.751858] new_sync_read+0xf0/0x184
[ 4258.751866] vfs_read+0x15c/0x1f4
[ 4258.751872] ksys_read+0x70/0x100
[ 4258.751879] __arm64_sys_read+0x24/0x30
[ 4258.751887] invoke_syscall+0x78/0x100
[ 4258.751897] el0_svc_common.constprop.0+0x54/0x184
[ 4258.751906] do_el0_svc+0x30/0xac
[ 4258.751915] el0_svc+0x28/0xb0
[ 4258.751924] el0t_64_sync_handler+0xa4/0x12c
[ 4258.751932] el0t_64_sync+0x1a4/0x1a8
[ 4258.751939] Task dump for CPU 3:
[ 4258.751943] task:read_all state:R running task stack: 0 pid:55935 ppid: 55930 flags:0x00000003
[ 4258.751954] Call trace:
[ 4258.751957] __switch_to+0xf8/0x150
[ 4258.751965] 0xffff000003402e00
[ 4258.751973] rcu: rcu_sched kthread timer wakeup didn't happen for 100991 jiffies! g791745 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
[ 4258.763437] rcu: Possible timer handling issue on cpu=2 timer-softirq=131296
[ 4258.770555] rcu: rcu_sched kthread starved for 100992 jiffies! g791745 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
[ 4258.781066] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 4258.790006] rcu: RCU grace-period kthread stack dump:
[ 4258.795041] task:rcu_sched state:I stack: 0 pid: 14 ppid: 2 flags:0x00000008
[ 4258.795051] Call trace:
[ 4258.795053] __switch_to+0xf8/0x150
[ 4258.795062] __schedule+0x2a4/0x6d0
[ 4258.795072] schedule+0x64/0x110
[ 4258.795081] schedule_timeout+0xa0/0x190
[ 4258.795089] rcu_gp_fqs_loop+0x110/0x4d0
[ 4258.795097] rcu_gp_kthread+0x158/0x1c0
[ 4258.795104] kthread+0x110/0x114
[ 4258.795112] ret_from_fork+0x10/0x20
[ 4258.795120] rcu: Stack dump where RCU GP kthread last ran:
[ 4258.800587] Task dump for CPU 2:
[ 4258.800590] task:kworker/u8:0 state:R running task stack: 0 pid:32960 ppid: 2 flags:0x00000008
[ 4258.800602] Workqueue: events_freezable_power_ sync_hw_clock
[ 4258.800612] Call trace:
[ 4258.800614] dump_backtrace+0x0/0x200
[ 4258.800621] show_stack+0x20/0x30
[ 4258.800628] sched_show_task+0x184/0x1b0
[ 4258.800636] dump_cpu_task+0x4c/0x64
[ 4258.800646] rcu_check_gp_kthread_starvation+0x124/0x144
[ 4258.800655] print_other_cpu_stall+0x274/0x2f0
[ 4258.800663] check_cpu_stall+0x230/0x310
[ 4258.800669] rcu_sched_clock_irq+0x80/0x240
[ 4258.800677] update_process_times+0xa4/0xf0
[ 4258.800687] tick_sched_handle+0x38/0x74
[ 4258.800695] tick_sched_timer+0x54/0xb0
[ 4258.800702] __hrtimer_run_queues+0x148/0x344
[ 4258.800711] hrtimer_interrupt+0xf8/0x264
[ 4258.800719] arch_timer_handler_phys+0x3c/0x50
[ 4258.800728] handle_percpu_devid_irq+0x90/0x1c0
[ 4258.800737] handle_domain_irq+0x68/0xa0
[ 4258.800747] gic_handle_irq+0x70/0xa0
[ 4258.800753] call_on_irq_stack+0x20/0x2c
[ 4258.800761] do_interrupt_handler+0x5c/0x70
[ 4258.800769] el1_interrupt+0x30/0x50
[ 4258.800776] el1h_64_irq_handler+0x18/0x2c
[ 4258.800784] el1h_64_irq+0x7c/0x80
[ 4258.800790] ktime_get_real_ts64+0xa0/0x104
[ 4258.800797] sync_hw_clock+0x7c/0x230
[ 4258.800803] process_one_work+0x210/0x4f0
[ 4258.800812] worker_thread+0x170/0x5a0
[ 4258.800820] kthread+0x110/0x114
[ 4258.800827] ret_from_fork+0x10/0x20
[ 4268.775430] mmc0: Timeout waiting for hardware interrupt.
[ 4268.780837] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
[ 4268.787267] mmc0: sdhci: Sys addr: 0x00000010 | Version: 0x00001002
[ 4268.793698] mmc0: sdhci: Blk size: 0x00007200 | Blk cnt: 0x00000000
[ 4268.800130] mmc0: sdhci: Argument: 0x00fc2220 | Trn mode: 0x0000003b
[ 4268.806562] mmc0: sdhci: Present: 0x01f70000 | Host ctl: 0x0000001f
[ 4268.812994] mmc0: sdhci: Power: 0x0000000f | Blk gap: 0x00000080
[ 4268.819417] mmc0: sdhci: Wake-up: 0x00000000 | Clock: 0x00000207
[ 4268.825840] mmc0: sdhci: Timeout: 0x00000004 | Int stat: 0x00000003
[ 4268.832263] mmc0: sdhci: Int enab: 0x03ff008b | Sig enab: 0x03ff008b
[ 4268.838687] mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000001
[ 4268.845110] mmc0: sdhci: Caps: 0x31e8c881 | Caps_1: 0x00002007
[ 4268.851533] mmc0: sdhci: Cmd: 0x0000123a | Max curr: 0x00000000
[ 4268.857956] mmc0: sdhci: Resp[0]: 0x00000900 | Resp[1]: 0x00e67f7f
[ 4268.864388] mmc0: sdhci: Resp[2]: 0x325b5900 | Resp[3]: 0x00000900
[ 4268.870811] mmc0: sdhci: Host ctl2: 0x00000000
[ 4268.875238] mmc0: sdhci: ADMA Err: 0x00000000 | ADMA Ptr: 0x000000000fb2c218
[ 4268.882364] mmc0: sdhci: ============================================
[ 4279.003413] mmc0: Timeout waiting for hardware interrupt.
[ 4279.008800] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
[ 4279.015223] mmc0: sdhci: Sys addr: 0x00000010 | Version: 0x00001002
[ 4279.021646] mmc0: sdhci: Blk size: 0x00007200 | Blk cnt: 0x00000000
[ 4279.028069] mmc0: sdhci: Argument: 0x00000000 | Trn mode: 0x00000033
[ 4279.034492] mmc0: sdhci: Present: 0x01f70000 | Host ctl: 0x0000001f
[ 4279.040915] mmc0: sdhci: Power: 0x0000000f | Blk gap: 0x00000080
[ 4279.047339] mmc0: sdhci: Wake-up: 0x00000000 | Clock: 0x00000207
[ 4279.053762] mmc0: sdhci: Timeout: 0x0000000e | Int stat: 0x00018002
[ 4279.060185] mmc0: sdhci: Int enab: 0x03ff008b | Sig enab: 0x03ff008b
[ 4279.066608] mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000001
[ 4279.073032] mmc0: sdhci: Caps: 0x31e8c881 | Caps_1: 0x00002007
[ 4279.079455] mmc0: sdhci: Cmd: 0x00000c1b | Max curr: 0x00000000
[ 4279.085878] mmc0: sdhci: Resp[0]: 0x00000900 | Resp[1]: 0x00e67f7f
[ 4279.092301] mmc0: sdhci: Resp[2]: 0x325b5900 | Resp[3]: 0x00000900
[ 4279.098724] mmc0: sdhci: Host ctl2: 0x00000000
[ 4279.103151] mmc0: sdhci: ADMA Err: 0x00000000 | ADMA Ptr: 0x000000000fb2c218
[ 4279.110277] mmc0: sdhci: ============================================
[ 4283.999400] watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [NetworkManager:795]
...

** Affects: ubuntu-kernel-tests
     Importance: Undecided
         Status: New

** Affects: linux-xilinx-zynqmp (Ubuntu)
     Importance: Undecided
         Status: New

** Affects: linux-xilinx-zynqmp (Ubuntu Jammy)
     Importance: Undecided
     Assignee: Wei-Lin Chang (rhythm16)
         Status: New

** Attachment added: "jammy_xilinx_full_log"
   https://bugs.launchpad.net/bugs/2092374/+attachment/5847057/+files/jammy_xilinx_full_log

** Also affects: linux-xilinx-zynqmp (Ubuntu)
   Importance: Undecided
       Status: New

** Also affects: linux-xilinx-zynqmp (Ubuntu Jammy)
   Importance: Undecided
       Status: New

** Changed in: linux-xilinx-zynqmp (Ubuntu Jammy)
     Assignee: (unassigned) => Wei-Lin Chang (rhythm16)

-- 
You received this bug notification because you are a member of Canonical
Platform QA Team, which is subscribed to ubuntu-kernel-tests.
https://bugs.launchpad.net/bugs/2092374

Title:
   ubuntu_ltp: fs:read_all_sys: failed

Status in ubuntu-kernel-tests:
  New
Status in linux-xilinx-zynqmp package in Ubuntu:
  New
Status in linux-xilinx-zynqmp source package in Jammy:
  New

Bug description:
  This issue happened on jammy:linux-xilinx-zynqmp
  5.15.0-1039.43.5.15.0-1038.42 doesn't have this issue.

  [ 3853.721349] zynqmp_firmware firmware:zynqmp-firmware: Error requesting firmware
  [ 3853.721357] zynqmp_firmware firmware:zynqmp-firmware: Error requesting firmware
  [ 3853.721358] zynqmp_firmware firmware:zynqmp-firmware: Error requesting firmware
  [ 4258.727473] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
  [ 4258.733399] rcu: 1-...!: (3 ticks this GP) idle=873/1/0x4000000000000000 softirq=483179/483185 fqs=1
  [ 4258.742701] rcu: 3-...!: (1 GPs behind) idle=09f/1/0x4000000000000000 softirq=544004/544021 fqs=1
  [ 4258.751737] (detected by 2, t=101252 jiffies, g=791745, q=1317)
  [ 4258.751744] Task dump for CPU 1:
  [ 4258.751748] task:read_all state:R running task stack: 0 pid:55934 ppid: 55930 flags:0x00000003
  [ 4258.751763] Call trace:
  [ 4258.751766] __switch_to+0xf8/0x150
  [ 4258.751782] zynqmp_pm_fpga_read+0x78/0xdc
  [ 4258.751791] zynqmp_fpga_ops_status+0x6c/0x110
  [ 4258.751803] status_show+0x30/0x2a0
  [ 4258.751812] dev_attr_show+0x28/0x64
  [ 4258.751820] sysfs_kf_seq_show+0x90/0x134
  [ 4258.751831] kernfs_seq_show+0x34/0x40
  [ 4258.751840] seq_read_iter+0x1d4/0x4e0
  [ 4258.751850] kernfs_fop_read_iter+0x40/0x4c
  [ 4258.751858] new_sync_read+0xf0/0x184
  [ 4258.751866] vfs_read+0x15c/0x1f4
  [ 4258.751872] ksys_read+0x70/0x100
  [ 4258.751879] __arm64_sys_read+0x24/0x30
  [ 4258.751887] invoke_syscall+0x78/0x100
  [ 4258.751897] el0_svc_common.constprop.0+0x54/0x184
  [ 4258.751906] do_el0_svc+0x30/0xac
  [ 4258.751915] el0_svc+0x28/0xb0
  [ 4258.751924] el0t_64_sync_handler+0xa4/0x12c
  [ 4258.751932] el0t_64_sync+0x1a4/0x1a8
  [ 4258.751939] Task dump for CPU 3:
  [ 4258.751943] task:read_all state:R running task stack: 0 pid:55935 ppid: 55930 flags:0x00000003
  [ 4258.751954] Call trace:
  [ 4258.751957] __switch_to+0xf8/0x150
  [ 4258.751965] 0xffff000003402e00
  [ 4258.751973] rcu: rcu_sched kthread timer wakeup didn't happen for 100991 jiffies! g791745 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402
  [ 4258.763437] rcu: Possible timer handling issue on cpu=2 timer-softirq=131296
  [ 4258.770555] rcu: rcu_sched kthread starved for 100992 jiffies! g791745 f0x0 RCU_GP_WAIT_FQS(5) ->state=0x402 ->cpu=2
  [ 4258.781066] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
  [ 4258.790006] rcu: RCU grace-period kthread stack dump:
  [ 4258.795041] task:rcu_sched state:I stack: 0 pid: 14 ppid: 2 flags:0x00000008
  [ 4258.795051] Call trace:
  [ 4258.795053] __switch_to+0xf8/0x150
  [ 4258.795062] __schedule+0x2a4/0x6d0
  [ 4258.795072] schedule+0x64/0x110
  [ 4258.795081] schedule_timeout+0xa0/0x190
  [ 4258.795089] rcu_gp_fqs_loop+0x110/0x4d0
  [ 4258.795097] rcu_gp_kthread+0x158/0x1c0
  [ 4258.795104] kthread+0x110/0x114
  [ 4258.795112] ret_from_fork+0x10/0x20
  [ 4258.795120] rcu: Stack dump where RCU GP kthread last ran:
  [ 4258.800587] Task dump for CPU 2:
  [ 4258.800590] task:kworker/u8:0 state:R running task stack: 0 pid:32960 ppid: 2 flags:0x00000008
  [ 4258.800602] Workqueue: events_freezable_power_ sync_hw_clock
  [ 4258.800612] Call trace:
  [ 4258.800614] dump_backtrace+0x0/0x200
  [ 4258.800621] show_stack+0x20/0x30
  [ 4258.800628] sched_show_task+0x184/0x1b0
  [ 4258.800636] dump_cpu_task+0x4c/0x64
  [ 4258.800646] rcu_check_gp_kthread_starvation+0x124/0x144
  [ 4258.800655] print_other_cpu_stall+0x274/0x2f0
  [ 4258.800663] check_cpu_stall+0x230/0x310
  [ 4258.800669] rcu_sched_clock_irq+0x80/0x240
  [ 4258.800677] update_process_times+0xa4/0xf0
  [ 4258.800687] tick_sched_handle+0x38/0x74
  [ 4258.800695] tick_sched_timer+0x54/0xb0
  [ 4258.800702] __hrtimer_run_queues+0x148/0x344
  [ 4258.800711] hrtimer_interrupt+0xf8/0x264
  [ 4258.800719] arch_timer_handler_phys+0x3c/0x50
  [ 4258.800728] handle_percpu_devid_irq+0x90/0x1c0
  [ 4258.800737] handle_domain_irq+0x68/0xa0
  [ 4258.800747] gic_handle_irq+0x70/0xa0
  [ 4258.800753] call_on_irq_stack+0x20/0x2c
  [ 4258.800761] do_interrupt_handler+0x5c/0x70
  [ 4258.800769] el1_interrupt+0x30/0x50
  [ 4258.800776] el1h_64_irq_handler+0x18/0x2c
  [ 4258.800784] el1h_64_irq+0x7c/0x80
  [ 4258.800790] ktime_get_real_ts64+0xa0/0x104
  [ 4258.800797] sync_hw_clock+0x7c/0x230
  [ 4258.800803] process_one_work+0x210/0x4f0
  [ 4258.800812] worker_thread+0x170/0x5a0
  [ 4258.800820] kthread+0x110/0x114
  [ 4258.800827] ret_from_fork+0x10/0x20
  [ 4268.775430] mmc0: Timeout waiting for hardware interrupt.
  [ 4268.780837] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
  [ 4268.787267] mmc0: sdhci: Sys addr: 0x00000010 | Version: 0x00001002
  [ 4268.793698] mmc0: sdhci: Blk size: 0x00007200 | Blk cnt: 0x00000000
  [ 4268.800130] mmc0: sdhci: Argument: 0x00fc2220 | Trn mode: 0x0000003b
  [ 4268.806562] mmc0: sdhci: Present: 0x01f70000 | Host ctl: 0x0000001f
  [ 4268.812994] mmc0: sdhci: Power: 0x0000000f | Blk gap: 0x00000080
  [ 4268.819417] mmc0: sdhci: Wake-up: 0x00000000 | Clock: 0x00000207
  [ 4268.825840] mmc0: sdhci: Timeout: 0x00000004 | Int stat: 0x00000003
  [ 4268.832263] mmc0: sdhci: Int enab: 0x03ff008b | Sig enab: 0x03ff008b
  [ 4268.838687] mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000001
  [ 4268.845110] mmc0: sdhci: Caps: 0x31e8c881 | Caps_1: 0x00002007
  [ 4268.851533] mmc0: sdhci: Cmd: 0x0000123a | Max curr: 0x00000000
  [ 4268.857956] mmc0: sdhci: Resp[0]: 0x00000900 | Resp[1]: 0x00e67f7f
  [ 4268.864388] mmc0: sdhci: Resp[2]: 0x325b5900 | Resp[3]: 0x00000900
  [ 4268.870811] mmc0: sdhci: Host ctl2: 0x00000000
  [ 4268.875238] mmc0: sdhci: ADMA Err: 0x00000000 | ADMA Ptr: 0x000000000fb2c218
  [ 4268.882364] mmc0: sdhci: ============================================
  [ 4279.003413] mmc0: Timeout waiting for hardware interrupt.
  [ 4279.008800] mmc0: sdhci: ============ SDHCI REGISTER DUMP ===========
  [ 4279.015223] mmc0: sdhci: Sys addr: 0x00000010 | Version: 0x00001002
  [ 4279.021646] mmc0: sdhci: Blk size: 0x00007200 | Blk cnt: 0x00000000
  [ 4279.028069] mmc0: sdhci: Argument: 0x00000000 | Trn mode: 0x00000033
  [ 4279.034492] mmc0: sdhci: Present: 0x01f70000 | Host ctl: 0x0000001f
  [ 4279.040915] mmc0: sdhci: Power: 0x0000000f | Blk gap: 0x00000080
  [ 4279.047339] mmc0: sdhci: Wake-up: 0x00000000 | Clock: 0x00000207
  [ 4279.053762] mmc0: sdhci: Timeout: 0x0000000e | Int stat: 0x00018002
  [ 4279.060185] mmc0: sdhci: Int enab: 0x03ff008b | Sig enab: 0x03ff008b
  [ 4279.066608] mmc0: sdhci: ACmd stat: 0x00000000 | Slot int: 0x00000001
  [ 4279.073032] mmc0: sdhci: Caps: 0x31e8c881 | Caps_1: 0x00002007
  [ 4279.079455] mmc0: sdhci: Cmd: 0x00000c1b | Max curr: 0x00000000
  [ 4279.085878] mmc0: sdhci: Resp[0]: 0x00000900 | Resp[1]: 0x00e67f7f
  [ 4279.092301] mmc0: sdhci: Resp[2]: 0x325b5900 | Resp[3]: 0x00000900
  [ 4279.098724] mmc0: sdhci: Host ctl2: 0x00000000
  [ 4279.103151] mmc0: sdhci: ADMA Err: 0x00000000 | ADMA Ptr: 0x000000000fb2c218
  [ 4279.110277] mmc0: sdhci: ============================================
  [ 4283.999400] watchdog: BUG: soft lockup - CPU#2 stuck for 23s! [NetworkManager:795]
  ...

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu-kernel-tests/+bug/2092374/+subscriptions