From: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To: linux-arm-kernel@lists.infradead.org
Subject: Re: RCU lockup issues when CONFIG_SOFTLOCKUP_DETECTOR=n - any one else seeing this?
Date: Thu, 27 Jul 2017 16:52:45 +0000 [thread overview]
Message-ID: <20170727165245.GD3730@linux.vnet.ibm.com> (raw)
In-Reply-To: <20170727173923.000001b2@huawei.com>
[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #1: Type: text/plain; charset="windows-1254", Size: 70580 bytes --]
On Thu, Jul 27, 2017 at 05:39:23PM +0100, Jonathan Cameron wrote:
> On Thu, 27 Jul 2017 14:49:03 +0100
> Jonathan Cameron <Jonathan.Cameron@huawei.com> wrote:
>
> > On Thu, 27 Jul 2017 05:49:13 -0700
> > "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
> >
> > > On Thu, Jul 27, 2017 at 02:34:00PM +1000, Nicholas Piggin wrote:
> > > > On Wed, 26 Jul 2017 18:42:14 -0700
> > > > "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
> > > >
> > > > > On Wed, Jul 26, 2017 at 04:22:00PM -0700, David Miller wrote:
> > > >
> > > > > > Indeed, that really wouldn't explain how we end up with a RCU stall
> > > > > > dump listing almost all of the cpus as having missed a grace period.
> > > > >
> > > > > I have seen stranger things, but admittedly not often.
> > > >
> > > > So the backtraces show the RCU gp thread in schedule_timeout.
> > > >
> > > > Are you sure that it's timeout has expired and it's not being scheduled,
> > > > or could it be a bad (large) timeout (looks unlikely) or that it's being
> > > > scheduled but not correctly noting gps on other CPUs?
> > > >
> > > > It's not in R state, so if it's not being scheduled at all, then it's
> > > > because the timer has not fired:
> > >
> > > Good point, Nick!
> > >
> > > Jonathan, could you please reproduce collecting timer event tracing?
> > I'm a little new to tracing (only started playing with it last week)
> > so fingers crossed I've set it up right. No splats yet. Was getting
> > splats on reading out the trace when running with the RCU stall timer
> > set to 4 so have increased that back to the default and am rerunning.
> >
> > This may take a while. Correct me if I've gotten this wrong to save time
> >
> > echo "timer:*" > /sys/kernel/debug/tracing/set_event
> >
> > when it dumps, just send you the relevant part of what is in
> > /sys/kernel/debug/tracing/trace?
>
> Interestingly the only thing that can make trip for me with tracing on
> is peaking in the tracing buffers. Not sure this is a valid case or
> not.
>
> Anyhow all timer activity seems to stop around the area of interest.
>
>
> [ 9442.413624] INFO: rcu_sched detected stalls on CPUs/tasks:
> [ 9442.419107] 1-...: (1 GPs behind) idle„4/0/0 softirq'747/27755 fqs=0 last_accelerate: dd6a/de80, nonlazy_posted: 0, L.
> [ 9442.430224] 3-...: (2 GPs behind) idle8/0/0 softirq2197/32198 fqs=0 last_accelerate: 29b1/de80, nonlazy_posted: 0, L.
> [ 9442.441340] 4-...: (7 GPs behind) idlet0/0/0 softirq"351/22352 fqs=0 last_accelerate: ca88/de80, nonlazy_posted: 0, L.
> [ 9442.452456] 5-...: (2 GPs behind) idle›0/0/0 softirq!315/21319 fqs=0 last_accelerate: b280/de88, nonlazy_posted: 0, L.
> [ 9442.463572] 6-...: (2 GPs behind) idley4/0/0 softirq\x19699/19707 fqs=0 last_accelerate: ba62/de88, nonlazy_posted: 0, L.
> [ 9442.474688] 7-...: (2 GPs behind) idle¬4/0/0 softirq"547/22554 fqs=0 last_accelerate: b280/de88, nonlazy_posted: 0, L.
> [ 9442.485803] 8-...: (9 GPs behind) idle\x118/0/0 softirq(1/291 fqs=0 last_accelerate: c3fe/de88, nonlazy_posted: 0, L.
> [ 9442.496571] 9-...: (9 GPs behind) idlec/0/0 softirq(4/292 fqs=0 last_accelerate: 6030/de88, nonlazy_posted: 0, L.
> [ 9442.507339] 10-...: (14 GPs behind) idle÷8/0/0 softirq%4/254 fqs=0 last_accelerate: 5487/de88, nonlazy_posted: 0, L.
> [ 9442.518281] 11-...: (9 GPs behind) idleÉc/0/0 softirq01/308 fqs=0 last_accelerate: 3d3e/de99, nonlazy_posted: 0, L.
> [ 9442.529136] 12-...: (9 GPs behind) idleJ4/0/0 softirqs5/737 fqs=0 last_accelerate: 6010/de99, nonlazy_posted: 0, L.
> [ 9442.539992] 13-...: (9 GPs behind) idle4c/0/0 softirq\x1121/1131 fqs=0 last_accelerate: b280/de99, nonlazy_posted: 0, L.
> [ 9442.551020] 14-...: (9 GPs behind) idle/4/0/0 softirqp7/713 fqs=0 last_accelerate: 6030/de99, nonlazy_posted: 0, L.
> [ 9442.561875] 15-...: (2 GPs behind) idle³0/0/0 softirq‚1/976 fqs=0 last_accelerate: c208/de99, nonlazy_posted: 0, L.
> [ 9442.572730] 17-...: (2 GPs behind) idleZ8/0/0 softirq\x1456/1565 fqs=0 last_accelerate: ca88/de99, nonlazy_posted: 0, L.
> [ 9442.583759] 18-...: (2 GPs behind) idle.4/0/0 softirq\x1923/1936 fqs=0 last_accelerate: ca88/dea7, nonlazy_posted: 0, L.
> [ 9442.594787] 19-...: (2 GPs behind) idle\x138/0/0 softirq\x1421/1432 fqs=0 last_accelerate: b280/dea7, nonlazy_posted: 0, L.
> [ 9442.605816] 20-...: (50 GPs behind) idlec4/0/0 softirq!7/219 fqs=0 last_accelerate: c96f/dea7, nonlazy_posted: 0, L.
> [ 9442.616758] 21-...: (2 GPs behind) idleë8/0/0 softirq\x1368/1369 fqs=0 last_accelerate: b599/deb2, nonlazy_posted: 0, L.
> [ 9442.627786] 22-...: (1 GPs behind) idleª8/0/0 softirq"9/232 fqs=0 last_accelerate: c604/deb2, nonlazy_posted: 0, L.
> [ 9442.638641] 23-...: (1 GPs behind) idleH8/0/0 softirq$7/248 fqs=0 last_accelerate: c600/deb2, nonlazy_posted: 0, L.
> [ 9442.649496] 24-...: (33 GPs behind) idle÷c/0/0 softirq19/319 fqs=0 last_accelerate: 5290/deb2, nonlazy_posted: 0, L.
> [ 9442.660437] 25-...: (33 GPs behind) idle”4/0/0 softirq08/308 fqs=0 last_accelerate: 52c0/deb2, nonlazy_posted: 0, L.
> [ 9442.671379] 26-...: (9 GPs behind) idlem4/0/0 softirq&5/275 fqs=0 last_accelerate: 6034/dec0, nonlazy_posted: 0, L.
> [ 9442.682234] 27-...: (115 GPs behind) idleãc/0/0 softirq!2/226 fqs=0 last_accelerate: 5420/dec0, nonlazy_posted: 0, L.
> [ 9442.693263] 28-...: (9 GPs behind) idleê4/0/0 softirqT0/552 fqs=0 last_accelerate: 603c/dec0, nonlazy_posted: 0, L.
> [ 9442.704118] 29-...: (115 GPs behind) idleƒc/0/0 softirq42/380 fqs=0 last_accelerate: 5420/dec0, nonlazy_posted: 0, L.
> [ 9442.715147] 30-...: (33 GPs behind) idleãc/0/0 softirqP9/509 fqs=0 last_accelerate: 52bc/dec0, nonlazy_posted: 0, L.
> [ 9442.726088] 31-...: (9 GPs behind) idleß4/0/0 softirqa9/641 fqs=0 last_accelerate: 603c/decb, nonlazy_posted: 0, L.
> [ 9442.736944] 32-...: (9 GPs behind) idleª4/0/0 softirq\x1841/1848 fqs=0 last_accelerate: 6030/decb, nonlazy_posted: 0, L.
> [ 9442.747972] 34-...: (9 GPs behind) idleæc/0/0 softirqP82/5086 fqs=0 last_accelerate: 6039/decb, nonlazy_posted: 0, L.
> [ 9442.759001] 35-...: (9 GPs behind) idle\x7fc/0/0 softirq\x1396/1406 fqs=0 last_accelerate: 603e/decb, nonlazy_posted: 0, L.
> [ 9442.770030] 36-...: (0 ticks this GP) idleò8/0/0 softirq%5/255 fqs=0 last_accelerate: c9fc/decb, nonlazy_posted: 0, L.
> [ 9442.781145] 37-...: (50 GPs behind) idleSc/0/0 softirq"7/230 fqs=0 last_accelerate: 45c0/decb, nonlazy_posted: 0, L.
> [ 9442.792087] 38-...: (9 GPs behind) idle•8/0/0 softirq\x185/192 fqs=0 last_accelerate: 6030/decb, nonlazy_posted: 0, L.
> [ 9442.802942] 40-...: (389 GPs behind) idleAc/0/0 softirq\x131/136 fqs=0 last_accelerate: 5800/decb, nonlazy_posted: 0, L.
> [ 9442.813971] 41-...: (389 GPs behind) idle%8/0/0 softirq\x133/138 fqs=0 last_accelerate: c00f/decb, nonlazy_posted: 0, L.
> [ 9442.825000] 43-...: (50 GPs behind) idle%4/0/0 softirq\x113/117 fqs=0 last_accelerate: 5420/dee5, nonlazy_posted: 0, L.
> [ 9442.835942] 44-...: (115 GPs behind) idle\x178/0/0 softirq\x1271/1276 fqs=0 last_accelerate: 68e9/dee5, nonlazy_posted: 0, L.
> [ 9442.847144] 45-...: (2 GPs behind) idle\x04a/1/0 softirq64/389 fqs=0 last_accelerate: dee5/dee5, nonlazy_posted: 0, L.
> [ 9442.857999] 46-...: (9 GPs behind) idleì4/0/0 softirq\x183/189 fqs=0 last_accelerate: 6030/dee5, nonlazy_posted: 0, L.
> [ 9442.868854] 47-...: (115 GPs behind) idle\b8/0/0 softirq\x135/149 fqs=0 last_accelerate: 5420/dee5, nonlazy_posted: 0, L.
> [ 9442.879883] 48-...: (389 GPs behind) idle 0/0/0 softirq\x103/110 fqs=0 last_accelerate: 58b0/dee5, nonlazy_posted: 0, L.
> [ 9442.890911] 49-...: (9 GPs behind) idle¢4/0/0 softirq 5/211 fqs=0 last_accelerate: 6030/dee5, nonlazy_posted: 0, L.
> [ 9442.901766] 50-...: (25 GPs behind) idle§4/0/0 softirq\x144/144 fqs=0 last_accelerate: 5420/dee5, nonlazy_posted: 0, L.
> [ 9442.912708] 51-...: (50 GPs behind) idleö8/0/0 softirq\x116/122 fqs=0 last_accelerate: 57bc/dee5, nonlazy_posted: 0, L.
> [ 9442.923650] 52-...: (9 GPs behind) idleà8/0/0 softirq 2/486 fqs=0 last_accelerate: c87f/defe, nonlazy_posted: 0, L.
> [ 9442.934505] 53-...: (2 GPs behind) idle\x128/0/0 softirq65/366 fqs=0 last_accelerate: ca88/defe, nonlazy_posted: 0, L.
> [ 9442.945360] 54-...: (9 GPs behind) idleÎ8/0/0 softirq\x126/373 fqs=0 last_accelerate: bef8/defe, nonlazy_posted: 0, L.
> [ 9442.956215] 56-...: (9 GPs behind) idle30/0/0 softirq!16/2126 fqs=0 last_accelerate: 6030/defe, nonlazy_posted: 0, L.
> [ 9442.967243] 57-...: (1 GPs behind) idle(8/0/0 softirq\x1707/1714 fqs=0 last_accelerate: c87c/defe, nonlazy_posted: 0, L.
> [ 9442.978272] 58-...: (37 GPs behind) idle90/0/0 softirq\x1716/1721 fqs=0 last_accelerate: 53f7/defe, nonlazy_posted: 0, L.
> [ 9442.989387] 59-...: (37 GPs behind) idleå4/0/0 softirq\x1700/1701 fqs=0 last_accelerate: 40a1/defe, nonlazy_posted: 0, L.
> [ 9443.000502] 60-...: (116 GPs behind) idle{4/0/0 softirq’/96 fqs=0 last_accelerate: 57d8/df10, nonlazy_posted: 0, L.
> [ 9443.011357] 61-...: (9 GPs behind) idle8/0/0 softirq\x161/170 fqs=0 last_accelerate: 6030/df10, nonlazy_posted: 0, L.
> [ 9443.022212] 62-...: (115 GPs behind) idleª8/0/0 softirq•/101 fqs=0 last_accelerate: 5420/df17, nonlazy_posted: 0, L.
> [ 9443.033154] 63-...: (50 GPs behind) idle•8/0/0 softirq/84 fqs=0 last_accelerate: 57b8/df17, nonlazy_posted: 0, L.
> [ 9443.043920] (detected by 39, tT03 jiffies, gD3, cD2, q=1)
> [ 9443.049919] Task dump for CPU 1:
> [ 9443.053134] swapper/1 R running task 0 0 1 0x00000000
> [ 9443.060173] Call trace:
> [ 9443.062619] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.067744] [< (null)>] (null)
> [ 9443.072434] Task dump for CPU 3:
> [ 9443.075650] swapper/3 R running task 0 0 1 0x00000000
> [ 9443.082686] Call trace:
> [ 9443.085121] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.090246] [< (null)>] (null)
> [ 9443.094936] Task dump for CPU 4:
> [ 9443.098152] swapper/4 R running task 0 0 1 0x00000000
> [ 9443.105188] Call trace:
> [ 9443.107623] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.112752] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.118224] Task dump for CPU 5:
> [ 9443.121440] swapper/5 R running task 0 0 1 0x00000000
> [ 9443.128476] Call trace:
> [ 9443.130910] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.136035] [< (null)>] (null)
> [ 9443.140725] Task dump for CPU 6:
> [ 9443.143941] swapper/6 R running task 0 0 1 0x00000000
> [ 9443.150976] Call trace:
> [ 9443.153411] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.158535] [< (null)>] (null)
> [ 9443.163226] Task dump for CPU 7:
> [ 9443.166442] swapper/7 R running task 0 0 1 0x00000000
> [ 9443.173478] Call trace:
> [ 9443.175912] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.181037] [< (null)>] (null)
> [ 9443.185727] Task dump for CPU 8:
> [ 9443.188943] swapper/8 R running task 0 0 1 0x00000000
> [ 9443.195979] Call trace:
> [ 9443.198412] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.203537] [< (null)>] (null)
> [ 9443.208227] Task dump for CPU 9:
> [ 9443.211443] swapper/9 R running task 0 0 1 0x00000000
> [ 9443.218479] Call trace:
> [ 9443.220913] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.226039] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.231510] Task dump for CPU 10:
> [ 9443.234812] swapper/10 R running task 0 0 1 0x00000000
> [ 9443.241848] Call trace:
> [ 9443.244283] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.249408] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.254879] Task dump for CPU 11:
> [ 9443.258182] swapper/11 R running task 0 0 1 0x00000000
> [ 9443.265218] Call trace:
> [ 9443.267652] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.272776] [< (null)>] (null)
> [ 9443.277467] Task dump for CPU 12:
> [ 9443.280769] swapper/12 R running task 0 0 1 0x00000000
> [ 9443.287806] Call trace:
> [ 9443.290240] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.295364] [< (null)>] (null)
> [ 9443.300054] Task dump for CPU 13:
> [ 9443.303357] swapper/13 R running task 0 0 1 0x00000000
> [ 9443.310394] Call trace:
> [ 9443.312828] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.317953] [< (null)>] (null)
> [ 9443.322643] Task dump for CPU 14:
> [ 9443.325945] swapper/14 R running task 0 0 1 0x00000000
> [ 9443.332981] Call trace:
> [ 9443.335416] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.340540] [< (null)>] (null)
> [ 9443.345230] Task dump for CPU 15:
> [ 9443.348533] swapper/15 R running task 0 0 1 0x00000000
> [ 9443.355568] Call trace:
> [ 9443.358002] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.363128] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.368599] Task dump for CPU 17:
> [ 9443.371901] swapper/17 R running task 0 0 1 0x00000000
> [ 9443.378937] Call trace:
> [ 9443.381372] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.386497] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.391968] Task dump for CPU 18:
> [ 9443.395270] swapper/18 R running task 0 0 1 0x00000000
> [ 9443.402306] Call trace:
> [ 9443.404740] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.409865] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.415336] Task dump for CPU 19:
> [ 9443.418639] swapper/19 R running task 0 0 1 0x00000000
> [ 9443.425675] Call trace:
> [ 9443.428109] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.433234] [< (null)>] (null)
> [ 9443.437924] Task dump for CPU 20:
> [ 9443.441226] swapper/20 R running task 0 0 1 0x00000000
> [ 9443.448263] Call trace:
> [ 9443.450697] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.455826] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9443.462600] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9443.467986] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.473458] Task dump for CPU 21:
> [ 9443.476760] swapper/21 R running task 0 0 1 0x00000000
> [ 9443.483796] Call trace:
> [ 9443.486230] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.491354] [< (null)>] (null)
> [ 9443.496045] Task dump for CPU 22:
> [ 9443.499347] swapper/22 R running task 0 0 1 0x00000000
> [ 9443.506383] Call trace:
> [ 9443.508817] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.513943] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.519414] Task dump for CPU 23:
> [ 9443.522716] swapper/23 R running task 0 0 1 0x00000000
> [ 9443.529752] Call trace:
> [ 9443.532186] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.537312] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.542784] Task dump for CPU 24:
> [ 9443.546086] swapper/24 R running task 0 0 1 0x00000000
> [ 9443.553122] Call trace:
> [ 9443.555556] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.560681] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.566153] Task dump for CPU 25:
> [ 9443.569455] swapper/25 R running task 0 0 1 0x00000000
> [ 9443.576491] Call trace:
> [ 9443.578925] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.584051] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9443.590825] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9443.596211] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.601682] Task dump for CPU 26:
> [ 9443.604985] swapper/26 R running task 0 0 1 0x00000000
> [ 9443.612021] Call trace:
> [ 9443.614455] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.619581] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.625052] Task dump for CPU 27:
> [ 9443.628355] swapper/27 R running task 0 0 1 0x00000000
> [ 9443.635390] Call trace:
> [ 9443.637824] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.642949] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.648421] Task dump for CPU 28:
> [ 9443.651723] swapper/28 R running task 0 0 1 0x00000000
> [ 9443.658759] Call trace:
> [ 9443.661193] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.666318] [< (null)>] (null)
> [ 9443.671008] Task dump for CPU 29:
> [ 9443.674310] swapper/29 R running task 0 0 1 0x00000000
> [ 9443.681346] Call trace:
> [ 9443.683780] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.688905] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.694377] Task dump for CPU 30:
> [ 9443.697679] swapper/30 R running task 0 0 1 0x00000000
> [ 9443.704715] Call trace:
> [ 9443.707150] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.712275] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9443.719050] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9443.724436] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.729907] Task dump for CPU 31:
> [ 9443.733210] swapper/31 R running task 0 0 1 0x00000000
> [ 9443.740246] Call trace:
> [ 9443.742680] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.747805] [< (null)>] (null)
> [ 9443.752496] Task dump for CPU 32:
> [ 9443.755798] swapper/32 R running task 0 0 1 0x00000000
> [ 9443.762833] Call trace:
> [ 9443.765267] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.770392] [< (null)>] (null)
> [ 9443.775082] Task dump for CPU 34:
> [ 9443.778384] swapper/34 R running task 0 0 1 0x00000000
> [ 9443.785420] Call trace:
> [ 9443.787854] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.792980] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.798451] Task dump for CPU 35:
> [ 9443.801753] swapper/35 R running task 0 0 1 0x00000000
> [ 9443.808789] Call trace:
> [ 9443.811224] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.816348] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.821820] Task dump for CPU 36:
> [ 9443.825122] swapper/36 R running task 0 0 1 0x00000000
> [ 9443.832158] Call trace:
> [ 9443.834592] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.839718] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9443.846493] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9443.851878] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.857350] Task dump for CPU 37:
> [ 9443.860652] swapper/37 R running task 0 0 1 0x00000000
> [ 9443.867688] Call trace:
> [ 9443.870122] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.875248] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9443.882022] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9443.887408] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.892880] Task dump for CPU 38:
> [ 9443.896182] swapper/38 R running task 0 0 1 0x00000000
> [ 9443.903218] Call trace:
> [ 9443.905652] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.910776] [< (null)>] (null)
> [ 9443.915466] Task dump for CPU 40:
> [ 9443.918769] swapper/40 R running task 0 0 1 0x00000000
> [ 9443.925805] Call trace:
> [ 9443.928239] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.933365] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.938836] Task dump for CPU 41:
> [ 9443.942138] swapper/41 R running task 0 0 1 0x00000000
> [ 9443.949174] Call trace:
> [ 9443.951609] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.956733] [< (null)>] (null)
> [ 9443.961423] Task dump for CPU 43:
> [ 9443.964725] swapper/43 R running task 0 0 1 0x00000000
> [ 9443.971761] Call trace:
> [ 9443.974195] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9443.979320] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9443.984791] Task dump for CPU 44:
> [ 9443.988093] swapper/44 R running task 0 0 1 0x00000000
> [ 9443.995130] Call trace:
> [ 9443.997564] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.002688] [< (null)>] (null)
> [ 9444.007378] Task dump for CPU 45:
> [ 9444.010680] swapper/45 R running task 0 0 1 0x00000000
> [ 9444.017716] Call trace:
> [ 9444.020151] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.025275] [< (null)>] (null)
> [ 9444.029965] Task dump for CPU 46:
> [ 9444.033267] swapper/46 R running task 0 0 1 0x00000000
> [ 9444.040302] Call trace:
> [ 9444.042737] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.047862] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.053333] Task dump for CPU 47:
> [ 9444.056636] swapper/47 R running task 0 0 1 0x00000000
> [ 9444.063672] Call trace:
> [ 9444.066106] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.071231] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.076702] Task dump for CPU 48:
> [ 9444.080004] swapper/48 R running task 0 0 1 0x00000000
> [ 9444.087041] Call trace:
> [ 9444.089475] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.094600] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.100071] Task dump for CPU 49:
> [ 9444.103374] swapper/49 R running task 0 0 1 0x00000000
> [ 9444.110409] Call trace:
> [ 9444.112844] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.117968] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.123440] Task dump for CPU 50:
> [ 9444.126742] swapper/50 R running task 0 0 1 0x00000000
> [ 9444.133777] Call trace:
> [ 9444.136211] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.141336] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.146807] Task dump for CPU 51:
> [ 9444.150109] swapper/51 R running task 0 0 1 0x00000000
> [ 9444.157144] Call trace:
> [ 9444.159578] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.164703] [< (null)>] (null)
> [ 9444.169393] Task dump for CPU 52:
> [ 9444.172695] swapper/52 R running task 0 0 1 0x00000000
> [ 9444.179731] Call trace:
> [ 9444.182165] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.187290] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.192761] Task dump for CPU 53:
> [ 9444.196063] swapper/53 R running task 0 0 1 0x00000000
> [ 9444.203099] Call trace:
> [ 9444.205533] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.210658] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.216129] Task dump for CPU 54:
> [ 9444.219431] swapper/54 R running task 0 0 1 0x00000000
> [ 9444.226467] Call trace:
> [ 9444.228901] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.234026] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.239498] Task dump for CPU 56:
> [ 9444.242801] swapper/56 R running task 0 0 1 0x00000000
> [ 9444.249837] Call trace:
> [ 9444.252271] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.257396] [< (null)>] (null)
> [ 9444.262086] Task dump for CPU 57:
> [ 9444.265388] swapper/57 R running task 0 0 1 0x00000000
> [ 9444.272424] Call trace:
> [ 9444.274858] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.279982] [< (null)>] (null)
> [ 9444.284672] Task dump for CPU 58:
> [ 9444.287975] swapper/58 R running task 0 0 1 0x00000000
> [ 9444.295011] Call trace:
> [ 9444.297445] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.302570] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9444.309345] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9444.314731] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.320202] Task dump for CPU 59:
> [ 9444.323504] swapper/59 R running task 0 0 1 0x00000000
> [ 9444.330540] Call trace:
> [ 9444.332974] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.338100] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.343571] Task dump for CPU 60:
> [ 9444.346873] swapper/60 R running task 0 0 1 0x00000000
> [ 9444.353909] Call trace:
> [ 9444.356343] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.361469] [<ffff00000813cf78>] rcu_eqs_enter_common.isra.32+0x1b8/0x228
> [ 9444.368243] [<ffff00000813d044>] rcu_idle_enter+0x5c/0x60
> [ 9444.373629] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.379101] Task dump for CPU 61:
> [ 9444.382402] swapper/61 R running task 0 0 1 0x00000000
> [ 9444.389438] Call trace:
> [ 9444.391872] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.396997] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.402469] Task dump for CPU 62:
> [ 9444.405771] swapper/62 R running task 0 0 1 0x00000000
> [ 9444.412808] Call trace:
> [ 9444.415242] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.420367] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.425838] Task dump for CPU 63:
> [ 9444.429141] swapper/63 R running task 0 0 1 0x00000000
> [ 9444.436177] Call trace:
> [ 9444.438611] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.443736] [<ffff0000090d9df0>] __cpu_online_mask+0x0/0x8
> [ 9444.449211] rcu_sched kthread starved for 5743 jiffies! g443 c442 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> [ 9444.458416] rcu_sched S 0 10 2 0x00000000
> [ 9444.463889] Call trace:
> [ 9444.466324] [<ffff000008085cb8>] __switch_to+0x90/0xa8
> [ 9444.471453] [<ffff000008ab70a4>] __schedule+0x1a4/0x720
> [ 9444.476665] [<ffff000008ab7660>] schedule+0x40/0xa8
> [ 9444.481530] [<ffff000008abac70>] schedule_timeout+0x178/0x358
> [ 9444.487263] [<ffff00000813e694>] rcu_gp_kthread+0x534/0x7b8
> [ 9444.492824] [<ffff0000080f33d0>] kthread+0x108/0x138
> [ 9444.497775] [<ffff0000080836c0>] ret_from_fork+0x10/0x50
>
>
>
> And the relevant chunk of trace is:
> (I have a lot more. There are substantial other pauses from to time, but not this long)
>
>
> rcu_preempt-9 [057] .... 9419.837631: timer_init: timerÿff8017d5fcfda0
> rcu_preempt-9 [057] d..1 9419.837632: timer_start: timerÿff8017d5fcfda0 function=process_timeout expiresB97246837 [timeout=1] cpuW idx=0 flags> <idle>-0 [057] d..1 9419.837634: tick_stop: success=1 dependency=NONE
> <idle>-0 [057] d..2 9419.837634: hrtimer_cancel: hrtimerÿff8017db99e808
> <idle>-0 [057] d..2 9419.837635: hrtimer_start: hrtimerÿff8017db99e808 function=tick_sched_timer expires”18164000000 softexpires”18164000000
> <idle>-0 [057] d.h2 9419.845621: hrtimer_cancel: hrtimerÿff8017db99e808
> <idle>-0 [057] d.h1 9419.845621: hrtimer_expire_entry: hrtimerÿff8017db99e808 function=tick_sched_timer now”18164001440
> <idle>-0 [057] d.h1 9419.845622: hrtimer_expire_exit: hrtimerÿff8017db99e808
> <idle>-0 [057] d.s2 9419.845623: timer_cancel: timerÿff8017d5fcfda0
> <idle>-0 [057] ..s1 9419.845623: timer_expire_entry: timerÿff8017d5fcfda0 function=process_timeout nowB97246838
> <idle>-0 [057] .ns1 9419.845624: timer_expire_exit: timerÿff8017d5fcfda0
> <idle>-0 [057] dn.2 9419.845628: hrtimer_start: hrtimerÿff8017db99e808 function=tick_sched_timer expires”18168000000 softexpires”18168000000
> <idle>-0 [057] d..1 9419.845635: tick_stop: success=1 dependency=NONE
> <idle>-0 [057] d..2 9419.845636: hrtimer_cancel: hrtimerÿff8017db99e808
> <idle>-0 [057] d..2 9419.845636: hrtimer_start: hrtimerÿff8017db99e808 function=tick_sched_timer expires”18188000000 softexpires”18188000000
> <idle>-0 [057] d.h2 9419.869621: hrtimer_cancel: hrtimerÿff8017db99e808
> <idle>-0 [057] d.h1 9419.869621: hrtimer_expire_entry: hrtimerÿff8017db99e808 function=tick_sched_timer now”18188001420
> <idle>-0 [057] d.h1 9419.869622: hrtimer_expire_exit: hrtimerÿff8017db99e808
> <idle>-0 [057] d..2 9419.869626: hrtimer_start: hrtimerÿff8017db99e808 function=tick_sched_timer expires˜58983202655 softexpires˜58983202655
> <idle>-0 [016] d.h2 9419.885626: hrtimer_cancel: hrtimerÿff8017fbc3d808
> <idle>-0 [016] d.h1 9419.885627: hrtimer_expire_entry: hrtimerÿff8017fbc3d808 function=tick_sched_timer now”18204006760
> <idle>-0 [016] d.h1 9419.885629: hrtimer_expire_exit: hrtimerÿff8017fbc3d808
> <idle>-0 [016] d.s2 9419.885629: timer_cancel: timerÿff8017d37dbca0
> <idle>-0 [016] ..s1 9419.885630: timer_expire_entry: timerÿff8017d37dbca0 function=process_timeout nowB97246848
> <idle>-0 [016] .ns1 9419.885631: timer_expire_exit: timerÿff8017d37dbca0
> <idle>-0 [016] dn.2 9419.885636: hrtimer_start: hrtimerÿff8017fbc3d808 function=tick_sched_timer expires”18208000000 softexpires”18208000000
> khugepaged-778 [016] .... 9419.885668: timer_init: timerÿff8017d37dbca0
> khugepaged-778 [016] d..1 9419.885668: timer_start: timerÿff8017d37dbca0 function=process_timeout expiresB97249348 [timeout%00] cpu\x16 idx=0 flags> <idle>-0 [016] d..1 9419.885670: tick_stop: success=1 dependency=NONE
> <idle>-0 [016] d..2 9419.885671: hrtimer_cancel: hrtimerÿff8017fbc3d808
> <idle>-0 [016] d..2 9419.885671: hrtimer_start: hrtimerÿff8017fbc3d808 function=tick_sched_timer expires”28444000000 softexpires”28444000000
> <idle>-0 [045] d.h2 9419.890839: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9419.890839: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18209219940
> <idle>-0 [045] d.h3 9419.890844: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18310221420 softexpires”18309221420
> <idle>-0 [045] d.h1 9419.890844: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [000] d.h2 9419.917625: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.h1 9419.917626: hrtimer_expire_entry: hrtimerÿff8017fbe40808 function=tick_sched_timer now”18236005860
> <idle>-0 [000] d.h1 9419.917628: hrtimer_expire_exit: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.s2 9419.917628: timer_cancel: timerÿff80177fdc0840
> <idle>-0 [000] ..s1 9419.917629: timer_expire_entry: timerÿff80177fdc0840 function=link_timeout_disable_link nowB97246856
> <idle>-0 [000] d.s2 9419.917630: timer_start: timerÿff80177fdc0840 function=link_timeout_enable_link expiresB97246881 [timeout%] cpu=0 idx flags> <idle>-0 [000] ..s1 9419.917633: timer_expire_exit: timerÿff80177fdc0840
> <idle>-0 [000] d..2 9419.917648: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”18340000000 softexpires”18340000000
> <idle>-0 [045] d.h2 9419.991845: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9419.991845: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18310225960
> <idle>-0 [045] d.h3 9419.991849: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18411227320 softexpires”18410227320
> <idle>-0 [045] d.h1 9419.991850: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [000] d.h2 9420.021625: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.h1 9420.021625: hrtimer_expire_entry: hrtimerÿff8017fbe40808 function=tick_sched_timer now”18340005520
> <idle>-0 [000] d.h1 9420.021627: hrtimer_expire_exit: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.s2 9420.021627: timer_cancel: timerÿff80177fdc0840
> <idle>-0 [000] ..s1 9420.021628: timer_expire_entry: timerÿff80177fdc0840 function=link_timeout_enable_link nowB97246882
> <idle>-0 [000] d.s2 9420.021629: timer_start: timerÿff80177fdc0840 function=link_timeout_disable_link expiresB97247107 [timeout"5] cpu=0 idx4 flags> <idle>-0 [000] ..s1 9420.021632: timer_expire_exit: timerÿff80177fdc0840
> <idle>-0 [000] d..2 9420.021639: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19260000000 softexpires”19260000000
> <idle>-0 [045] d.h2 9420.092851: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.092852: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18411231780
> <idle>-0 [045] d.h3 9420.092856: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18512233720 softexpires”18511233720
> <idle>-0 [045] d.h1 9420.092856: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [055] d.h2 9420.141622: hrtimer_cancel: hrtimerÿff8017db968808
> <idle>-0 [055] d.h1 9420.141623: hrtimer_expire_entry: hrtimerÿff8017db968808 function=tick_sched_timer now”18460002540
> <idle>-0 [055] d.h1 9420.141625: hrtimer_expire_exit: hrtimerÿff8017db968808
> <idle>-0 [055] d.s2 9420.141626: timer_cancel: timerÿff80177db6cc08
> <idle>-0 [055] d.s1 9420.141626: timer_expire_entry: timerÿff80177db6cc08 functionÞlayed_work_timer_fn nowB97246912
> <idle>-0 [055] dns1 9420.141628: timer_expire_exit: timerÿff80177db6cc08
> <idle>-0 [055] dn.2 9420.141632: hrtimer_start: hrtimerÿff8017db968808 function=tick_sched_timer expires”18464000000 softexpires”18464000000
> kworker/55:1-1246 [055] d..1 9420.141634: timer_start: timerÿff80177db6cc08 functionÞlayed_work_timer_fn expiresB97247162 [timeout%0] cpuU idxˆ flags=I
> <idle>-0 [055] d..1 9420.141637: tick_stop: success=1 dependency=NONE
> <idle>-0 [055] d..2 9420.141637: hrtimer_cancel: hrtimerÿff8017db968808
> <idle>-0 [055] d..2 9420.141637: hrtimer_start: hrtimerÿff8017db968808 function=tick_sched_timer expires”19484000000 softexpires”19484000000
> <idle>-0 [045] d.h2 9420.193855: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.193855: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18512235660
> <idle>-0 [045] d.h3 9420.193859: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18613237260 softexpires”18612237260
> <idle>-0 [045] d.h1 9420.193860: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9420.294858: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.294858: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18613238380
> <idle>-0 [045] d.h3 9420.294862: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18714240000 softexpires”18713240000
> <idle>-0 [045] d.h1 9420.294863: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9420.395861: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.395861: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18714241380
> <idle>-0 [045] d.h3 9420.395865: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18815242920 softexpires”18814242920
> <idle>-0 [045] d.h1 9420.395865: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [042] d.h2 9420.461621: hrtimer_cancel: hrtimerÿff8017dbb69808
> <idle>-0 [042] d.h1 9420.461622: hrtimer_expire_entry: hrtimerÿff8017dbb69808 function=tick_sched_timer now”18780002180
> <idle>-0 [042] d.h1 9420.461623: hrtimer_expire_exit: hrtimerÿff8017dbb69808
> <idle>-0 [042] d.s2 9420.461624: timer_cancel: timerÿff80177db6d408
> <idle>-0 [042] d.s1 9420.461625: timer_expire_entry: timerÿff80177db6d408 functionÞlayed_work_timer_fn nowB97246992
> <idle>-0 [042] dns1 9420.461627: timer_expire_exit: timerÿff80177db6d408
> <idle>-0 [042] dns2 9420.461627: timer_cancel: timerÿff8017797d7868
> <idle>-0 [042] .ns1 9420.461628: timer_expire_entry: timerÿff8017797d7868 function=hns_nic_service_timer nowB97246992
> <idle>-0 [042] dns2 9420.461628: timer_start: timerÿff8017797d7868 function=hns_nic_service_timer expiresB97247242 [timeout%0] cpuB idx˜ flags> <idle>-0 [042] .ns1 9420.461629: timer_expire_exit: timerÿff8017797d7868
> <idle>-0 [042] dn.2 9420.461632: hrtimer_start: hrtimerÿff8017dbb69808 function=tick_sched_timer expires”18784000000 softexpires”18784000000
> kworker/42:1-1223 [042] d..1 9420.461773: timer_start: timerÿff80177db6d408 functionÞlayed_work_timer_fn expiresB97247242 [timeout%0] cpuB idx˜ flags=I
> <idle>-0 [042] d..1 9420.461866: tick_stop: success=1 dependency=NONE
> <idle>-0 [042] d..2 9420.461867: hrtimer_cancel: hrtimerÿff8017dbb69808
> <idle>-0 [042] d..2 9420.461867: hrtimer_start: hrtimerÿff8017dbb69808 function=tick_sched_timer expires”19804000000 softexpires”19804000000
> <idle>-0 [045] d.h2 9420.496864: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.496864: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18815244580
> <idle>-0 [045] d.h3 9420.496868: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”18916246140 softexpires”18915246140
> <idle>-0 [045] d.h1 9420.496868: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9420.597866: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.597867: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”18916247280
> <idle>-0 [045] d.h3 9420.597871: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19017248760 softexpires”19016248760
> <idle>-0 [045] d.h1 9420.597871: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [033] d.h2 9420.621621: hrtimer_cancel: hrtimerÿff8017dba76808
> <idle>-0 [033] d.h1 9420.621622: hrtimer_expire_entry: hrtimerÿff8017dba76808 function=tick_sched_timer now”18940002160
> <idle>-0 [033] d.h1 9420.621623: hrtimer_expire_exit: hrtimerÿff8017dba76808
> <idle>-0 [033] d.s2 9420.621624: timer_cancel: timerÿff00000917be40
> <idle>-0 [033] d.s1 9420.621625: timer_expire_entry: timerÿff00000917be40 functionÞlayed_work_timer_fn nowB97247032
> <idle>-0 [033] dns1 9420.621626: timer_expire_exit: timerÿff00000917be40
> <idle>-0 [033] dn.2 9420.621630: hrtimer_start: hrtimerÿff8017dba76808 function=tick_sched_timer expires”18944000000 softexpires”18944000000
> <...>-1631 [033] d..1 9420.621636: timer_start: timerÿff00000917be40 functionÞlayed_work_timer_fn expiresB97247282 [timeout%0] cpu3 idx\x103 flags=I
> <idle>-0 [033] d..1 9420.621639: tick_stop: success=1 dependency=NONE
> <idle>-0 [033] d..2 9420.621639: hrtimer_cancel: hrtimerÿff8017dba76808
> <idle>-0 [033] d..2 9420.621639: hrtimer_start: hrtimerÿff8017dba76808 function=tick_sched_timer expires”19964000000 softexpires”19964000000
> <idle>-0 [000] dn.2 9420.691401: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] dn.2 9420.691401: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19012000000 softexpires”19012000000
> <idle>-0 [002] dn.2 9420.691408: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] dn.2 9420.691408: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19012000000 softexpires”19012000000
> <idle>-0 [000] d..1 9420.691409: tick_stop: success=1 dependency=NONE
> <idle>-0 [000] d..2 9420.691409: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d..2 9420.691409: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19260000000 softexpires”19260000000
> <idle>-0 [002] d..1 9420.691423: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9420.691423: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9420.691424: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires˜59803202655 softexpires˜59803202655
> <idle>-0 [045] d.h2 9420.698872: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.698873: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19017253180
> <idle>-0 [045] d.h3 9420.698877: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19118254640 softexpires”19117254640
> <idle>-0 [045] d.h1 9420.698877: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9420.799875: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.799875: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19118255760
> <idle>-0 [045] d.h3 9420.799879: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19219257140 softexpires”19218257140
> <idle>-0 [045] d.h1 9420.799880: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [000] dn.2 9420.871369: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] dn.2 9420.871370: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19192000000 softexpires”19192000000
> <idle>-0 [002] dn.2 9420.871375: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [000] d..1 9420.871376: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] dn.2 9420.871376: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19192000000 softexpires”19192000000
> <idle>-0 [000] d..2 9420.871376: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d..2 9420.871376: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19260000000 softexpires”19260000000
> <idle>-0 [002] d..1 9420.871398: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9420.871398: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9420.871398: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires˜59983202655 softexpires˜59983202655
> <idle>-0 [045] d.h2 9420.900881: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9420.900881: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19219261580
> <idle>-0 [045] d.h3 9420.900885: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19320263160 softexpires”19319263160
> <idle>-0 [045] d.h1 9420.900886: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [001] d..2 9420.913601: hrtimer_cancel: hrtimerÿff8017fbe5b808
> <idle>-0 [001] d..2 9420.913601: hrtimer_start: hrtimerÿff8017fbe5b808 function=tick_sched_timer expires˜60023202655 softexpires˜60023202655
> <idle>-0 [000] d.h2 9420.941621: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.h1 9420.941621: hrtimer_expire_entry: hrtimerÿff8017fbe40808 function=tick_sched_timer now”19260001400
> <idle>-0 [000] d.h1 9420.941623: hrtimer_expire_exit: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.s2 9420.941623: timer_cancel: timerÿff80177fdc0840
> <idle>-0 [000] ..s1 9420.941624: timer_expire_entry: timerÿff80177fdc0840 function=link_timeout_disable_link nowB97247112
> <idle>-0 [000] d.s2 9420.941624: timer_start: timerÿff80177fdc0840 function=link_timeout_enable_link expiresB97247137 [timeout%] cpu=0 idx\x113 flags> <idle>-0 [000] ..s1 9420.941628: timer_expire_exit: timerÿff80177fdc0840
> <idle>-0 [000] d.s2 9420.941629: timer_cancel: timerÿff8017fbe42558
> <idle>-0 [000] d.s1 9420.941629: timer_expire_entry: timerÿff8017fbe42558 functionÞlayed_work_timer_fn nowB97247112
> <idle>-0 [000] dns1 9420.941630: timer_expire_exit: timerÿff8017fbe42558
> <idle>-0 [000] dns2 9420.941631: timer_cancel: timerÿff00000910a628
> <idle>-0 [000] dns1 9420.941631: timer_expire_entry: timerÿff00000910a628 functionÞlayed_work_timer_fn nowB97247112
> <idle>-0 [000] dns1 9420.941631: timer_expire_exit: timerÿff00000910a628
> <idle>-0 [000] dn.2 9420.941634: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19264000000 softexpires”19264000000
> <idle>-0 [002] dn.2 9420.941643: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] dn.2 9420.941643: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19264000000 softexpires”19264000000
> kworker/0:0-3 [000] d..1 9420.941650: timer_start: timerÿff00000910a628 functionÞlayed_work_timer_fn expiresB97247500 [timeout88] cpu=0 idx\x100 flags=D|I
> kworker/2:0-22 [002] d..1 9420.941651: timer_start: timerÿff8017fbe78558 functionÞlayed_work_timer_fn expiresB97247494 [timeout82] cpu=2 idx\x114 flags=D|I
> <idle>-0 [000] d..1 9420.941652: tick_stop: success=1 dependency=NONE
> <idle>-0 [000] d..2 9420.941652: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d..2 9420.941653: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19364000000 softexpires”19364000000
> <idle>-0 [002] d..1 9420.941654: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9420.941654: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9420.941654: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires˜60055202655 softexpires˜60055202655
> <idle>-0 [045] d.h2 9421.001887: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9421.001887: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19320267640
> <idle>-0 [045] d.h3 9421.001891: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19421269000 softexpires”19420269000
> <idle>-0 [045] d.h1 9421.001892: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [000] d.h2 9421.045625: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.h1 9421.045625: hrtimer_expire_entry: hrtimerÿff8017fbe40808 function=tick_sched_timer now”19364005380
> <idle>-0 [000] d.h1 9421.045626: hrtimer_expire_exit: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.s2 9421.045627: timer_cancel: timerÿff80177fdc0840
> <idle>-0 [000] ..s1 9421.045628: timer_expire_entry: timerÿff80177fdc0840 function=link_timeout_enable_link nowB97247138
> <idle>-0 [000] d.s2 9421.045628: timer_start: timerÿff80177fdc0840 function=link_timeout_disable_link expiresB97247363 [timeout"5] cpu=0 idx4 flags> <idle>-0 [000] ..s1 9421.045631: timer_expire_exit: timerÿff80177fdc0840
> <idle>-0 [000] d..2 9421.045644: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”20284000000 softexpires”20284000000
> <idle>-0 [045] d.h2 9421.102893: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9421.102893: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19421273420
> <idle>-0 [045] d.h3 9421.102897: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19522275040 softexpires”19521275040
> <idle>-0 [045] d.h1 9421.102897: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [055] d.h2 9421.165621: hrtimer_cancel: hrtimerÿff8017db968808
> <idle>-0 [055] d.h1 9421.165622: hrtimer_expire_entry: hrtimerÿff8017db968808 function=tick_sched_timer now”19484002280
> <idle>-0 [055] d.h1 9421.165624: hrtimer_expire_exit: hrtimerÿff8017db968808
> <idle>-0 [055] d.s2 9421.165624: timer_cancel: timerÿff80177db6cc08
> <idle>-0 [055] d.s1 9421.165625: timer_expire_entry: timerÿff80177db6cc08 functionÞlayed_work_timer_fn nowB97247168
> <idle>-0 [055] dns1 9421.165626: timer_expire_exit: timerÿff80177db6cc08
> <idle>-0 [055] dn.2 9421.165629: hrtimer_start: hrtimerÿff8017db968808 function=tick_sched_timer expires”19488000000 softexpires”19488000000
> kworker/55:1-1246 [055] d..1 9421.165632: timer_start: timerÿff80177db6cc08 functionÞlayed_work_timer_fn expiresB97247418 [timeout%0] cpuU idx\x120 flags=I
> <idle>-0 [055] d..1 9421.165634: tick_stop: success=1 dependency=NONE
> <idle>-0 [055] d..2 9421.165634: hrtimer_cancel: hrtimerÿff8017db968808
> <idle>-0 [055] d..2 9421.165635: hrtimer_start: hrtimerÿff8017db968808 function=tick_sched_timer expires”20508000000 softexpires”20508000000
> <idle>-0 [045] d.h2 9421.203896: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9421.203896: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19522276980
> <idle>-0 [045] d.h3 9421.203900: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19623278460 softexpires”19622278460
> <idle>-0 [045] d.h1 9421.203901: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9421.304899: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9421.304899: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”19623279580
> <idle>-0 [045] d.h3 9421.304903: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”19724281060 softexpires”19723281060
> <idle>-0 [045] d.h1 9421.304903: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [000] dn.2 9421.381179: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] dn.2 9421.381179: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”19700000000 softexpires”19700000000
> <idle>-0 [002] dn.2 9421.381185: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] dn.2 9421.381185: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19700000000 softexpires”19700000000
> <idle>-0 [000] d..1 9421.381185: tick_stop: success=1 dependency=NONE
> <idle>-0 [000] d..2 9421.381186: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d..2 9421.381186: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”20284000000 softexpires”20284000000
> sh-2256 [002] .... 9421.381193: timer_init: timerÿff80176c26fb40
> sh-2256 [002] d..1 9421.381194: timer_start: timerÿff80176c26fb40 function=process_timeout expiresB97247223 [timeout=2] cpu=2 idx=0 flags> <idle>-0 [002] d..1 9421.381196: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9421.381197: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9421.381197: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19708000000 softexpires”19708000000
> <idle>-0 [002] d.h2 9421.389621: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d.h1 9421.389622: hrtimer_expire_entry: hrtimerÿff8017fbe76808 function=tick_sched_timer now”19708002000
> <idle>-0 [002] d.h1 9421.389623: hrtimer_expire_exit: hrtimerÿff8017fbe76808
> <idle>-0 [002] d.s2 9421.389624: timer_cancel: timerÿff80176c26fb40
> <idle>-0 [002] ..s1 9421.389624: timer_expire_entry: timerÿff80176c26fb40 function=process_timeout nowB97247224
> <idle>-0 [002] .ns1 9421.389626: timer_expire_exit: timerÿff80176c26fb40
> <idle>-0 [002] dn.2 9421.389629: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19712000000 softexpires”19712000000
> sh-2256 [002] ...1 9421.389682: hrtimer_init: hrtimerÿff8017d4dde8a0 clockid=CLOCK_MONOTONIC mode=HRTIMER_MODE_REL
> sh-2256 [002] ...1 9421.389682: hrtimer_init: hrtimerÿff8017d4dde8e0 clockid=CLOCK_MONOTONIC mode=HRTIMER_MODE_REL
> sh-2256 [002] .... 9421.389690: hrtimer_init: hrtimerÿff80176cbb0088 clockid=CLOCK_MONOTONIC mode=HRTIMER_MODE_REL
> <idle>-0 [039] dn.2 9421.389814: hrtimer_start: hrtimerÿff8017dbb18808 function=tick_sched_timer expires”19712000000 softexpires”19712000000
> <idle>-0 [002] d..1 9421.389896: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9421.389897: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9421.389898: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”19724000000 softexpires”19724000000
This being the gap?
Interesting in that I am not seeing any timeouts at all associated with
the rcu_sched kthread...
Thanx, Paul
> <idle>-0 [002] dn.2 9444.510766: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] dn.2 9444.510767: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”42832000000 softexpires”42832000000
> <idle>-0 [036] d..1 9444.510812: tick_stop: success=1 dependency=NONE
> <idle>-0 [036] d..2 9444.510814: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.510815: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42844000000 softexpires”42844000000
> sh-2256 [002] .... 9444.510857: timer_init: timerÿff80176c26fb40
> sh-2256 [002] d..1 9444.510857: timer_start: timerÿff80176c26fb40 function=process_timeout expiresB97253006 [timeout=2] cpu=2 idx=0 flags> <idle>-0 [002] d..1 9444.510864: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9444.510865: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9444.510866: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”42844000000 softexpires”42844000000
> <idle>-0 [000] d.h2 9444.525625: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [002] d.h2 9444.525625: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [036] d.h2 9444.525625: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [002] d.h1 9444.525625: hrtimer_expire_entry: hrtimerÿff8017fbe76808 function=tick_sched_timer now”42844005600
> <idle>-0 [036] d.h1 9444.525625: hrtimer_expire_entry: hrtimerÿff8017dbac7808 function=tick_sched_timer now”42844005460
> <idle>-0 [000] d.h1 9444.525627: hrtimer_expire_entry: hrtimerÿff8017fbe40808 function=tick_sched_timer now”42844005300
> <idle>-0 [002] d.h1 9444.525627: hrtimer_expire_exit: hrtimerÿff8017fbe76808
> <idle>-0 [002] d.s2 9444.525629: timer_cancel: timerÿff8017fbe78558
> <idle>-0 [036] d.h1 9444.525629: hrtimer_expire_exit: hrtimerÿff8017dbac7808
> <idle>-0 [002] d.s1 9444.525629: timer_expire_entry: timerÿff8017fbe78558 functionÞlayed_work_timer_fn nowB97253008
> <idle>-0 [000] d.h1 9444.525629: hrtimer_expire_exit: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.s2 9444.525631: timer_cancel: timerÿff80177fdc0840
> <idle>-0 [000] ..s1 9444.525631: timer_expire_entry: timerÿff80177fdc0840 function=link_timeout_disable_link nowB97253008
> <idle>-0 [002] dns1 9444.525631: timer_expire_exit: timerÿff8017fbe78558
> <idle>-0 [000] d.s2 9444.525632: timer_start: timerÿff80177fdc0840 function=link_timeout_enable_link expiresB97253033 [timeout%] cpu=0 idx‚ flags> <idle>-0 [000] ..s1 9444.525633: timer_expire_exit: timerÿff80177fdc0840
> <idle>-0 [000] d.s2 9444.525634: timer_cancel: timerÿff00000910a628
> <idle>-0 [000] d.s1 9444.525634: timer_expire_entry: timerÿff00000910a628 functionÞlayed_work_timer_fn nowB97253008
> <idle>-0 [000] dns1 9444.525636: timer_expire_exit: timerÿff00000910a628
> <idle>-0 [036] dn.2 9444.525639: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42848000000 softexpires”42848000000
> <idle>-0 [000] dn.2 9444.525640: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”42848000000 softexpires”42848000000
> <idle>-0 [002] dn.2 9444.525640: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”42848000000 softexpires”42848000000
> rcu_preempt-9 [036] .... 9444.525648: timer_init: timerÿff8017d5fcfda0
> <idle>-0 [002] d..1 9444.525648: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9444.525648: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9444.525649: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”42860000000 softexpires”42860000000
> rcu_preempt-9 [036] d..1 9444.525649: timer_start: timerÿff8017d5fcfda0 function=process_timeout expiresB97253009 [timeout=1] cpu6 idx=0 flags> kworker/0:0-3 [000] d..1 9444.525650: timer_start: timerÿff00000910a628 functionÞlayed_work_timer_fn expiresB97253250 [timeout$2] cpu=0 idx‚ flags=D|I
> <idle>-0 [000] d..1 9444.525652: tick_stop: success=1 dependency=NONE
> <idle>-0 [000] d..2 9444.525652: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d..2 9444.525653: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”42948000000 softexpires”42948000000
> <idle>-0 [036] d..1 9444.525653: tick_stop: success=1 dependency=NONE
> <idle>-0 [036] d..2 9444.525654: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.525654: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42852000000 softexpires”42852000000
> <idle>-0 [036] d.h2 9444.533624: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d.h1 9444.533625: hrtimer_expire_entry: hrtimerÿff8017dbac7808 function=tick_sched_timer now”42852004760
> <idle>-0 [036] d.h1 9444.533626: hrtimer_expire_exit: hrtimerÿff8017dbac7808
> <idle>-0 [036] d.s2 9444.533627: timer_cancel: timerÿff8017d5fcfda0
> <idle>-0 [036] ..s1 9444.533628: timer_expire_entry: timerÿff8017d5fcfda0 function=process_timeout nowB97253010
> <idle>-0 [036] .ns1 9444.533629: timer_expire_exit: timerÿff8017d5fcfda0
> <idle>-0 [036] dn.2 9444.533634: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42856000000 softexpires”42856000000
> <idle>-0 [036] d..1 9444.533668: tick_stop: success=1 dependency=NONE
> <idle>-0 [036] d..2 9444.533668: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.533669: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42876000000 softexpires”42876000000
> <idle>-0 [002] dnh2 9444.541626: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] dnh1 9444.541627: hrtimer_expire_entry: hrtimerÿff8017fbe76808 function=tick_sched_timer now”42860007120
> <idle>-0 [002] dnh1 9444.541629: hrtimer_expire_exit: hrtimerÿff8017fbe76808
> <idle>-0 [002] dn.2 9444.541630: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”42864000000 softexpires”42864000000
> <idle>-0 [002] d..1 9444.541640: tick_stop: success=1 dependency=NONE
> <idle>-0 [002] d..2 9444.541640: hrtimer_cancel: hrtimerÿff8017fbe76808
> <idle>-0 [002] d..2 9444.541640: hrtimer_start: hrtimerÿff8017fbe76808 function=tick_sched_timer expires”44316000000 softexpires”44316000000
> <idle>-0 [036] dnh2 9444.557627: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] dnh1 9444.557628: hrtimer_expire_entry: hrtimerÿff8017dbac7808 function=tick_sched_timer now”42876008220
> <idle>-0 [036] dnh1 9444.557630: hrtimer_expire_exit: hrtimerÿff8017dbac7808
> <idle>-0 [036] dn.2 9444.557631: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42880000000 softexpires”42880000000
> <idle>-0 [036] d..1 9444.557644: tick_stop: success=1 dependency=NONE
> <idle>-0 [036] d..2 9444.557645: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.557645: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42892000000 softexpires”42892000000
> <idle>-0 [036] d.h2 9444.573621: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d.h1 9444.573621: hrtimer_expire_entry: hrtimerÿff8017dbac7808 function=tick_sched_timer now”42892001340
> <idle>-0 [036] d.h1 9444.573622: hrtimer_expire_exit: hrtimerÿff8017dbac7808
> <idle>-0 [036] dn.2 9444.573628: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42896000000 softexpires”42896000000
> rcu_preempt-9 [036] .... 9444.573631: timer_init: timerÿff8017d5fcfda0
> rcu_preempt-9 [036] d..1 9444.573632: timer_start: timerÿff8017d5fcfda0 function=process_timeout expiresB97253021 [timeout=1] cpu6 idx=0 flags> <idle>-0 [036] d..1 9444.573634: tick_stop: success=1 dependency=NONE
> <idle>-0 [036] d..2 9444.573635: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.573635: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42900000000 softexpires”42900000000
> <idle>-0 [036] d.h2 9444.581621: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d.h1 9444.581621: hrtimer_expire_entry: hrtimerÿff8017dbac7808 function=tick_sched_timer now”42900001400
> <idle>-0 [036] d.h1 9444.581622: hrtimer_expire_exit: hrtimerÿff8017dbac7808
> <idle>-0 [036] d.s2 9444.581623: timer_cancel: timerÿff8017d5fcfda0
> <idle>-0 [036] ..s1 9444.581623: timer_expire_entry: timerÿff8017d5fcfda0 function=process_timeout nowB97253022
> <idle>-0 [036] .ns1 9444.581625: timer_expire_exit: timerÿff8017d5fcfda0
> <idle>-0 [036] dn.2 9444.581628: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42904000000 softexpires”42904000000
> <idle>-0 [036] d..1 9444.581636: tick_stop: success=1 dependency=NONE
> <idle>-0 [036] d..2 9444.581636: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.581637: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires”42924000000 softexpires”42924000000
> <idle>-0 [045] d.h2 9444.581718: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9444.581719: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”42900098200
> <idle>-0 [045] d.h3 9444.581724: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”43001101380 softexpires”43000101380
> <idle>-0 [045] d.h1 9444.581725: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [036] d.h2 9444.605621: hrtimer_cancel: hrtimerÿff8017dbac7808
> <idle>-0 [036] d.h1 9444.605621: hrtimer_expire_entry: hrtimerÿff8017dbac7808 function=tick_sched_timer now”42924001600
> <idle>-0 [036] d.h1 9444.605622: hrtimer_expire_exit: hrtimerÿff8017dbac7808
> <idle>-0 [036] d..2 9444.605629: hrtimer_start: hrtimerÿff8017dbac7808 function=tick_sched_timer expires˜83719202655 softexpires˜83719202655
> <idle>-0 [000] d.h2 9444.629625: hrtimer_cancel: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.h1 9444.629625: hrtimer_expire_entry: hrtimerÿff8017fbe40808 function=tick_sched_timer now”42948005580
> <idle>-0 [000] d.h1 9444.629627: hrtimer_expire_exit: hrtimerÿff8017fbe40808
> <idle>-0 [000] d.s2 9444.629628: timer_cancel: timerÿff80177fdc0840
> <idle>-0 [000] ..s1 9444.629628: timer_expire_entry: timerÿff80177fdc0840 function=link_timeout_enable_link nowB97253034
> <idle>-0 [000] d.s2 9444.629629: timer_start: timerÿff80177fdc0840 function=link_timeout_disable_link expiresB97253259 [timeout"5] cpu=0 idxB flags> <idle>-0 [000] ..s1 9444.629638: timer_expire_exit: timerÿff80177fdc0840
> <idle>-0 [000] d..2 9444.629661: hrtimer_start: hrtimerÿff8017fbe40808 function=tick_sched_timer expires”43868000000 softexpires”43868000000
> <idle>-0 [045] d.h2 9444.682725: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9444.682725: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”43001105940
> <idle>-0 [045] d.h3 9444.682730: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”43102107440 softexpires”43101107440
> <idle>-0 [045] d.h1 9444.682730: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [055] d.h2 9444.717626: hrtimer_cancel: hrtimerÿff8017db968808
> <idle>-0 [055] d.h1 9444.717627: hrtimer_expire_entry: hrtimerÿff8017db968808 function=tick_sched_timer now”43036006240
> <idle>-0 [055] d.h1 9444.717629: hrtimer_expire_exit: hrtimerÿff8017db968808
> <idle>-0 [055] d.s2 9444.717630: timer_cancel: timerÿff80177db6cc08
> <idle>-0 [055] d.s1 9444.717630: timer_expire_entry: timerÿff80177db6cc08 functionÞlayed_work_timer_fn nowB97253056
> <idle>-0 [055] dns1 9444.717633: timer_expire_exit: timerÿff80177db6cc08
> <idle>-0 [055] dn.2 9444.717637: hrtimer_start: hrtimerÿff8017db968808 function=tick_sched_timer expires”43040000000 softexpires”43040000000
> kworker/55:1-1246 [055] d..1 9444.717640: timer_start: timerÿff80177db6cc08 functionÞlayed_work_timer_fn expiresB97253306 [timeout%0] cpuU idxˆ flags=I
> <idle>-0 [055] d..1 9444.717643: tick_stop: success=1 dependency=NONE
> <idle>-0 [055] d..2 9444.717643: hrtimer_cancel: hrtimerÿff8017db968808
> <idle>-0 [055] d..2 9444.717644: hrtimer_start: hrtimerÿff8017db968808 function=tick_sched_timer expires”44060000000 softexpires”44060000000
> <idle>-0 [045] d.h2 9444.783729: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9444.783729: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”43102109380
> <idle>-0 [045] d.h3 9444.783733: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”43203110880 softexpires”43202110880
> <idle>-0 [045] d.h1 9444.783733: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9444.884731: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9444.884731: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”43203112000
> <idle>-0 [045] d.h3 9444.884735: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”43304113380 softexpires”43303113380
> <idle>-0 [045] d.h1 9444.884736: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h2 9444.985734: hrtimer_cancel: hrtimerÿff80176cb7ca90
> <idle>-0 [045] d.h1 9444.985735: hrtimer_expire_entry: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func now”43304114500
> <idle>-0 [045] d.h3 9444.985738: hrtimer_start: hrtimerÿff80176cb7ca90 function=ehci_hrtimer_func expires”43405116440 softexpires”43404116440
> <idle>-0 [045] d.h1 9444.985739: hrtimer_expire_exit: hrtimerÿff80176cb7ca90
> <idle>-0 [042] d.h2 9445.037622: hrtimer_cancel: hrtimerÿff8017dbb69808
> >
> > Thanks,
> >
> > Jonathan
> > >
> > > Thanx, Paul
> > >
> > > > [ 1984.628602] rcu_preempt kthread starved for 5663 jiffies! g1566 c1565 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
> > > > [ 1984.638153] rcu_preempt S 0 9 2 0x00000000
> > > > [ 1984.643626] Call trace:
> > > > [ 1984.646059] [<ffff000008084fb0>] __switch_to+0x90/0xa8
> > > > [ 1984.651189] [<ffff000008962274>] __schedule+0x19c/0x5d8
> > > > [ 1984.656400] [<ffff0000089626e8>] schedule+0x38/0xa0
> > > > [ 1984.661266] [<ffff000008965844>] schedule_timeout+0x124/0x218
> > > > [ 1984.667002] [<ffff000008121424>] rcu_gp_kthread+0x4fc/0x748
> > > > [ 1984.672564] [<ffff0000080df0b4>] kthread+0xfc/0x128
> > > > [ 1984.677429] [<ffff000008082ec0>] ret_from_fork+0x10/0x50
> > > >
> > >
> >
> > _______________________________________________
> > linuxarm mailing list
> > linuxarm@huawei.com
> > http://rnd-openeuler.huawei.com/mailman/listinfo/linuxarm
>
--
To unsubscribe from this list: send the line "unsubscribe sparclinux" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
next prev parent reply other threads:[~2017-07-27 16:52 UTC|newest]
Thread overview: 80+ messages / expand[flat|nested] mbox.gz Atom feed top
[not found] <20170725193039.00007c80@huawei.com>
[not found] ` <20170725222654.5a968588@roar.ozlabs.ibm.com>
2017-07-25 13:46 ` RCU lockup issues when CONFIG_SOFTLOCKUP_DETECTOR=n - any one else seeing this? Paul E. McKenney
2017-07-25 14:42 ` Jonathan Cameron
2017-07-25 15:12 ` Paul E. McKenney
2017-07-25 16:52 ` Jonathan Cameron
2017-07-25 21:10 ` David Miller
2017-07-26 3:55 ` Paul E. McKenney
2017-07-26 4:02 ` David Miller
2017-07-26 4:12 ` Paul E. McKenney
2017-07-26 8:16 ` Jonathan Cameron
2017-07-26 9:32 ` Jonathan Cameron
2017-07-26 12:28 ` Jonathan Cameron
2017-07-26 12:49 ` Jonathan Cameron
2017-07-26 14:14 ` Paul E. McKenney
2017-07-26 14:23 ` Jonathan Cameron
2017-07-26 15:33 ` Jonathan Cameron
2017-07-26 15:49 ` Paul E. McKenney
2017-07-26 16:54 ` David Miller
2017-07-26 17:13 ` Jonathan Cameron
2017-07-27 7:41 ` Jonathan Cameron
2017-07-26 17:50 ` Paul E. McKenney
2017-07-26 22:36 ` Paul E. McKenney
2017-07-26 22:45 ` David Miller
2017-07-26 23:15 ` Paul E. McKenney
2017-07-26 23:22 ` David Miller
2017-07-27 1:42 ` Paul E. McKenney
2017-07-27 4:34 ` Nicholas Piggin
2017-07-27 12:49 ` Paul E. McKenney
2017-07-27 13:49 ` Jonathan Cameron
2017-07-27 16:39 ` Jonathan Cameron
2017-07-27 16:52 ` Paul E. McKenney [this message]
2017-07-28 7:44 ` Jonathan Cameron
2017-07-28 12:54 ` Boqun Feng
2017-07-28 13:13 ` Jonathan Cameron
2017-07-28 14:55 ` Paul E. McKenney
2017-07-28 18:41 ` Paul E. McKenney
2017-07-28 19:09 ` Paul E. McKenney
2017-07-30 13:37 ` Boqun Feng
2017-07-30 16:59 ` Paul E. McKenney
2017-07-29 1:20 ` Boqun Feng
2017-07-28 18:42 ` David Miller
2017-07-28 13:08 ` Jonathan Cameron
2017-07-28 13:24 ` Jonathan Cameron
2017-07-28 16:55 ` Paul E. McKenney
2017-07-28 17:27 ` Jonathan Cameron
2017-07-28 19:03 ` Paul E. McKenney
2017-07-31 11:08 ` Jonathan Cameron
2017-07-31 15:04 ` Paul E. McKenney
2017-07-31 15:27 ` Jonathan Cameron
2017-08-01 18:46 ` Paul E. McKenney
2017-08-02 16:25 ` Jonathan Cameron
2017-08-15 15:47 ` Paul E. McKenney
2017-08-16 1:24 ` Jonathan Cameron
2017-08-16 12:43 ` Michael Ellerman
2017-08-16 12:56 ` Paul E. McKenney
2017-08-16 15:31 ` Nicholas Piggin
2017-08-16 16:27 ` Paul E. McKenney
2017-08-17 13:55 ` Michael Ellerman
2017-08-20 4:45 ` Nicholas Piggin
2017-08-20 5:01 ` David Miller
2017-08-20 5:04 ` Paul E. McKenney
2017-08-20 13:00 ` Nicholas Piggin
2017-08-20 18:35 ` Paul E. McKenney
2017-08-20 21:14 ` Paul E. McKenney
2017-08-21 0:52 ` Nicholas Piggin
2017-08-21 6:06 ` Nicholas Piggin
2017-08-21 10:18 ` Jonathan Cameron
2017-08-21 14:19 ` Nicholas Piggin
2017-08-21 15:02 ` Jonathan Cameron
2017-08-21 20:55 ` David Miller
2017-08-22 7:49 ` Jonathan Cameron
2017-08-22 8:51 ` Abdul Haleem
2017-08-22 15:26 ` Paul E. McKenney
2017-09-06 12:28 ` Paul E. McKenney
2017-08-22 0:38 ` Paul E. McKenney
2017-07-31 11:09 ` Jonathan Cameron
2017-07-31 11:55 ` Jonathan Cameron
2017-08-01 10:53 ` Jonathan Cameron
2017-07-26 16:48 ` David Miller
2017-07-26 3:53 ` Paul E. McKenney
2017-07-26 7:51 ` Jonathan Cameron
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20170727165245.GD3730@linux.vnet.ibm.com \
--to=paulmck@linux.vnet.ibm.com \
--cc=linux-arm-kernel@lists.infradead.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox