autopkgtest never completes

Bug #1981636 reported by Brian Murray
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
liburing (Debian)
Fix Released
Unknown
liburing (Ubuntu)
Fix Released
Undecided
Unassigned

Bug Description

The autopkgtest for liburing version 2.2-1 never completed (after running for multiple days) on architectures other than armhf. Looking at the nova console-log of a system on which the test quit we can see the following:

[ 124.252878] watchdog: BUG: soft lockup - CPU#0 stuck for 26s! [iou-wrk-20780:20781]
[ 152.252347] watchdog: BUG: soft lockup - CPU#0 stuck for 52s! [iou-wrk-20780:20781]
[ 157.144266] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 157.155080] rcu: All QSes seen, last rcu_sched kthread activity 15002 (4294931526-4294916524), jiffies_till_next_fqs=1, root ->qsmask 0x0
[ 157.159348] rcu: rcu_sched kthread starved for 15002 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state=
0x0 ->cpu=0
[ 157.162870] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 157.165941] rcu: RCU grace-period kthread stack dump:
[ 157.167718] rcu: Stack dump where RCU GP kthread last ran:
[ 184.251805] watchdog: BUG: soft lockup - CPU#0 stuck for 82s! [iou-wrk-20780:20781]
[ 212.251321] watchdog: BUG: soft lockup - CPU#0 stuck for 108s! [iou-wrk-20780:20781]
[ 240.250857] watchdog: BUG: soft lockup - CPU#0 stuck for 134s! [iou-wrk-20780:20781]
[ 268.250374] watchdog: BUG: soft lockup - CPU#0 stuck for 160s! [iou-wrk-20780:20781]
[ 296.249901] watchdog: BUG: soft lockup - CPU#0 stuck for 186s! [iou-wrk-20780:20781]
[ 324.249428] watchdog: BUG: soft lockup - CPU#0 stuck for 212s! [iou-wrk-20780:20781]
[ 337.161224] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 337.181627] rcu: All QSes seen, last rcu_sched kthread activity 60007 (4294976531-4294916524), jiffie
s_till_next_fqs=1, root ->qsmask 0x0
[ 337.186084] rcu: rcu_sched kthread starved for 60007 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state=
0x0 ->cpu=0
[ 337.189767] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 337.193001] rcu: RCU grace-period kthread stack dump:
[ 337.194932] rcu: Stack dump where RCU GP kthread last ran:
[ 364.248759] watchdog: BUG: soft lockup - CPU#0 stuck for 250s! [iou-wrk-20780:20781]
[ 392.248279] watchdog: BUG: soft lockup - CPU#0 stuck for 276s! [iou-wrk-20780:20781]
[ 420.247807] watchdog: BUG: soft lockup - CPU#0 stuck for 302s! [iou-wrk-20780:20781]
[ 448.247334] watchdog: BUG: soft lockup - CPU#0 stuck for 328s! [iou-wrk-20780:20781]
[ 476.246860] watchdog: BUG: soft lockup - CPU#0 stuck for 354s! [iou-wrk-20780:20781]
[ 504.246388] watchdog: BUG: soft lockup - CPU#0 stuck for 380s! [iou-wrk-20780:20781]
[ 517.178184] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 517.189702] rcu: All QSes seen, last rcu_sched kthread activity 105012 (4295021536-4294916524), jiffi
es_till_next_fqs=1, root ->qsmask 0x0
[ 517.194281] rcu: rcu_sched kthread starved for 105012 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state
=0x0 ->cpu=0
[ 517.198006] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 517.201259] rcu: RCU grace-period kthread stack dump:
[ 517.203255] rcu: Stack dump where RCU GP kthread last ran:
[ 544.245712] watchdog: BUG: soft lockup - CPU#0 stuck for 417s! [iou-wrk-20780:20781]
[ 572.245238] watchdog: BUG: soft lockup - CPU#0 stuck for 443s! [iou-wrk-20780:20781]
[ 600.244765] watchdog: BUG: soft lockup - CPU#0 stuck for 470s! [iou-wrk-20780:20781]
[ 628.244292] watchdog: BUG: soft lockup - CPU#0 stuck for 496s! [iou-wrk-20780:20781]
[ 656.243818] watchdog: BUG: soft lockup - CPU#0 stuck for 522s! [iou-wrk-20780:20781]
[ 684.243351] watchdog: BUG: soft lockup - CPU#0 stuck for 548s! [iou-wrk-20780:20781]
[ 697.195143] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 697.197433] rcu: All QSes seen, last rcu_sched kthread activity 150017 (4295066541-4294916524), jiffies_till_next_fqs=1, root ->qsmask 0x0
[ 697.201942] rcu: rcu_sched kthread starved for 150017 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
[ 697.205683] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 697.208946] rcu: RCU grace-period kthread stack dump:
[ 697.210867] rcu: Stack dump where RCU GP kthread last ran:
[ 724.242670] watchdog: BUG: soft lockup - CPU#0 stuck for 585s! [iou-wrk-20780:20781]
[ 752.242198] watchdog: BUG: soft lockup - CPU#0 stuck for 611s! [iou-wrk-20780:20781]
[ 780.241724] watchdog: BUG: soft lockup - CPU#0 stuck for 637s! [iou-wrk-20780:20781]
[ 808.241251] watchdog: BUG: soft lockup - CPU#0 stuck for 663s! [iou-wrk-20780:20781]
[ 836.240777] watchdog: BUG: soft lockup - CPU#0 stuck for 689s! [iou-wrk-20780:20781]
[ 864.240304] watchdog: BUG: soft lockup - CPU#0 stuck for 715s! [iou-wrk-20780:20781]
[ 877.212093] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 877.231984] rcu: All QSes seen, last rcu_sched kthread activity 195022 (4295111546-4294916524), jiffies_till_next_fqs=1, root ->qsmask 0x0
[ 877.236384] rcu: rcu_sched kthread starved for 195022 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
[ 877.240073] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 877.243246] rcu: RCU grace-period kthread stack dump:
[ 877.245144] rcu: Stack dump where RCU GP kthread last ran:
[ 904.239629] watchdog: BUG: soft lockup - CPU#0 stuck for 753s! [iou-wrk-20780:20781]
[ 932.239155] watchdog: BUG: soft lockup - CPU#0 stuck for 779s! [iou-wrk-20780:20781]
[ 960.238696] watchdog: BUG: soft lockup - CPU#0 stuck for 805s! [iou-wrk-20780:20781]
[ 988.238213] watchdog: BUG: soft lockup - CPU#0 stuck for 831s! [iou-wrk-20780:20781]
[ 1016.237736] watchdog: BUG: soft lockup - CPU#0 stuck for 857s! [iou-wrk-20780:20781]
[ 1044.237265] watchdog: BUG: soft lockup - CPU#0 stuck for 883s! [iou-wrk-20780:20781]
[ 1057.229052] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1057.239921] rcu: All QSes seen, last rcu_sched kthread activity 240027 (4295156551-4294916524), jiffies_till_next_fqs=1, root ->qsmask 0x0
[ 1057.244147] rcu: rcu_sched kthread starved for 240027 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
[ 1057.247614] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 1057.250553] rcu: RCU grace-period kthread stack dump:
[ 1057.252334] rcu: Stack dump where RCU GP kthread last ran:
[ 1084.236586] watchdog: BUG: soft lockup - CPU#0 stuck for 920s! [iou-wrk-20780:20781]
[ 1112.236116] watchdog: BUG: soft lockup - CPU#0 stuck for 946s! [iou-wrk-20780:20781]
[ 1140.235643] watchdog: BUG: soft lockup - CPU#0 stuck for 972s! [iou-wrk-20780:20781]
[ 1168.235168] watchdog: BUG: soft lockup - CPU#0 stuck for 999s! [iou-wrk-20780:20781]
[ 1196.234696] watchdog: BUG: soft lockup - CPU#0 stuck for 1025s! [iou-wrk-20780:20781]
[ 1224.234222] watchdog: BUG: soft lockup - CPU#0 stuck for 1051s! [iou-wrk-20780:20781]
[ 1237.246018] rcu: INFO: rcu_sched detected stalls on CPUs/tasks:
[ 1237.248209] rcu: All QSes seen, last rcu_sched kthread activity 285032 (4295201556-4294916524), jiffies_till_next_fqs=1, root ->qsmask 0x0
[ 1237.252563] rcu: rcu_sched kthread starved for 285032 jiffies! g54173 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0
[ 1237.256170] rcu: Unless rcu_sched kthread gets sufficient CPU time, OOM is now expected behavior.
[ 1237.259309] rcu: RCU grace-period kthread stack dump:
[ 1237.261174] rcu: Stack dump where RCU GP kthread last ran:
[ 1264.233546] watchdog: BUG: soft lockup - CPU#0 stuck for 1088s! [iou-wrk-20780:20781] [ 1292.233073] watchdog: BUG: soft lockup - CPU#0 stuck for 1114s! [iou-wrk-20780:20781]

description: updated
description: updated
tags: added: update-excuse
Revision history for this message
Brian Murray (brian-murray) wrote :

I also tried running this a large instance in Canonistack and encountered the same type of error.

[3629860.183037] rcu: INFO: rcu_sched self-detected stall on CPU
[3629860.188855] rcu: 0-....: (1454858 ticks this GP) idle=a07/1/0x4000000000000000 softirq=16953792/16953795 fqs=671029
[3629885.427146] watchdog: BUG: soft lockup - CPU#0 stuck for 5447s! [iou-wrk-1806199:1806200]
[3629913.427056] watchdog: BUG: soft lockup - CPU#0 stuck for 5473s! [iou-wrk-1806199:1806200]
[3629941.427155] watchdog: BUG: soft lockup - CPU#0 stuck for 5499s! [iou-wrk-1806199:1806200]
[3629969.427595] watchdog: BUG: soft lockup - CPU#0 stuck for 5525s! [iou-wrk-1806199:1806200]
[3629997.427470] watchdog: BUG: soft lockup - CPU#0 stuck for 5551s! [iou-wrk-1806199:1806200]
[3630025.427515] watchdog: BUG: soft lockup - CPU#0 stuck for 5577s! [iou-wrk-1806199:1806200]
[3630040.203594] rcu: INFO: rcu_sched self-detected stall on CPU
[3630040.209877] rcu: 0-....: (1499854 ticks this GP) idle=a07/1/0x4000000000000000 softirq=16953792/16953795 fqs=690422
[3630065.427817] watchdog: BUG: soft lockup - CPU#0 stuck for 5614s! [iou-wrk-1806199:1806200]
[3630093.427688] watchdog: BUG: soft lockup - CPU#0 stuck for 5640s! [iou-wrk-1806199:1806200]
[3630121.427957] watchdog: BUG: soft lockup - CPU#0 stuck for 5667s! [iou-wrk-1806199:1806200]
[3630149.427877] watchdog: BUG: soft lockup - CPU#0 stuck for 5693s! [iou-wrk-1806199:1806200]
[3630177.428197] watchdog: BUG: soft lockup - CPU#0 stuck for 5719s! [iou-wrk-1806199:1806200]
[3630205.428077] watchdog: BUG: soft lockup - CPU#0 stuck for 5745s! [iou-wrk-1806199:1806200]
[3630220.224160] rcu: INFO: rcu_sched self-detected stall on CPU
[3630220.229522] rcu: 0-....: (1544852 ticks this GP) idle=a07/1/0x4000000000000000 softirq=16953792/16953795 fqs=709837
[3630245.428213] watchdog: BUG: soft lockup - CPU#0 stuck for 5782s! [iou-wrk-1806199:1806200]

Revision history for this message
Paride Legovini (paride) wrote :
Changed in liburing (Debian):
status: Unknown → New
Changed in liburing (Ubuntu):
status: New → Triaged
Changed in liburing (Debian):
status: New → Incomplete
Revision history for this message
Paride Legovini (paride) wrote :

While this has been worked around, I think the actual issue isn't really Triaged as we don't really know that's causing it, and looks like Debian is in the same situation.

Changed in liburing (Ubuntu):
status: Triaged → Confirmed
Revision history for this message
Sergio Durigan Junior (sergiodj) wrote :

It seems like this is fixed; at least I see liburing's tests now passing on Lunar:

https://autopkgtest.ubuntu.com/packages/liburing

Should we close this bug, then?

Revision history for this message
Paride Legovini (paride) wrote (last edit ):

Yep, never_run was Kinetic only and looks like the Lunar tests are good. Thanks Sergio.

Changed in liburing (Ubuntu):
status: Confirmed → Fix Released
Changed in liburing (Debian):
status: Incomplete → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.