From: "Paul E. McKenney" <paulmck@linux.ibm.com>
To: Peter Zijlstra <peterz@infradead.org>
Cc: rcu@vger.kernel.org, linux-kernel@vger.kernel.org,
mingo@kernel.org, jiangshanlai@gmail.com, dipankar@in.ibm.com,
akpm@linux-foundation.org, mathieu.desnoyers@efficios.com,
josh@joshtriplett.org, tglx@linutronix.de, rostedt@goodmis.org,
dhowells@redhat.com, edumazet@google.com, fweisbec@gmail.com,
oleg@redhat.com, joel@joelfernandes.org
Subject: Re: [PATCH RFC tip/core/rcu 14/14] rcu/nohz: Make multi_cpu_stop() enable tick on all online CPUs
Date: Thu, 8 Aug 2019 13:35:41 -0700 [thread overview]
Message-ID: <20190808203541.GA8160@linux.ibm.com> (raw)
In-Reply-To: <20190807214131.GA15124@linux.ibm.com>
On Wed, Aug 07, 2019 at 02:41:31PM -0700, Paul E. McKenney wrote:
> On Tue, Aug 06, 2019 at 11:08:24AM -0700, Paul E. McKenney wrote:
> > On Mon, Aug 05, 2019 at 10:48:00AM -0700, Paul E. McKenney wrote:
> > > On Mon, Aug 05, 2019 at 05:50:24PM +0200, Peter Zijlstra wrote:
> > > > On Mon, Aug 05, 2019 at 07:54:48AM -0700, Paul E. McKenney wrote:
> > > >
> > > > > > Right; so clearly we're not understanding what's happening. That seems
> > > > > > like a requirement for actually doing a patch.
> > > > >
> > > > > Almost but not quite. It is a requirement for a patch *that* *is*
> > > > > *supposed* *to* *be* *a* *fix*. If you are trying to prohibit me from
> > > > > writing experimental patches, please feel free to take a long walk on
> > > > > a short pier.
> > > > >
> > > > > Understood???
> > > >
> > > > Ah, my bad, I thought you were actually proposing this as an actual
> > > > patch. I now see that is my bad, I'd overlooked the RFC part.
> > >
> > > No problem!
> > >
> > > And of course adding tracing decreases the frequency and duration of
> > > the multi_cpu_stop(). Re-running with shorter-duration triggering. ;-)
> >
> > And I did eventually get a good trace. If I am interpreting this trace
> > correctly, the torture_-135 task didn't get around to attempting to wake
> > up all of the CPUs. I will try again, but this time with the sched_switch
> > trace event enabled.
> >
> > As a side note, enabling ftrace from the command line seems to interact
> > badly with turning tracing off and on in the kernel, so I eventually
> > resorted to trace_printk() in the functions of interest. The trace
> > output is below, followed by the current diagnostic patch. Please note
> > that I am -not- using the desperation hammer-the-scheduler patches.
> >
> > More as I learn more!
>
> And of course I forgot to dump out the online CPUs, so I really had no
> idea whether or not all the CPUs were accounted for. I added tracing
> to dump out the online CPUs at the beginning of __stop_cpus() and then
> reworked it a few times to get the problem to happen in reasonable time.
> Please see below for the resulting annotated trace.
>
> I was primed to expect a lost IPI, perhaps due to yet another qemu bug,
> but all the migration threads are running within about 2 milliseconds.
> It is then almost two minutes(!) until the next trace message.
>
> Looks like time to (very carefully!) instrument multi_cpu_stop().
>
> Of course, if you have any ideas, please do not keep them a secret!
Functionally, multi_cpu_stop() is working fine, according to the trace
below (search for a line beginning with TAB). But somehow CPU 2 took
almost three -minutes- to do one iteration of the loop. The prime suspect
in that loop is cpu_relax() due to the hypervisor having an opportunity
to do something at that point. The commentary below (again, search for
a line beginning with TAB) gives my analysis.
Of course, if I am correct, it should be possible to catch cpu_relax()
in the act. That is the next step, give or take the Heisenbuggy nature
of this beast.
Another thing for me to try is to run longer with !NO_HZ_FULL, just in
case the earlier runs just got lucky.
Thoughts?
Thanx, Paul
------------------------------------------------------------------------
[ 1564.195213] Unregister pv shared memory for cpu 6
[ 1731.578001] rcu: INFO: rcu_sched self-detected stall on CPU
...
[ 1731.632619] torture_-135 0.... 1562233456us : __stop_cpus: CPUs 0-2,6-7 online
[ 1731.632619] torture_-135 0.... 1562233457us : queue_stop_cpus_work: entered
[ 1731.632619] torture_-135 0.... 1562233457us : cpu_stop_queue_work: entered for CPU 0
[ 1731.632619] torture_-135 0.... 1562233458us : wake_up_q: entered
[ 1731.632619] torture_-135 0.... 1562233458us : wake_up_process: entered
[ 1731.632619] torture_-135 0.... 1562233458us : try_to_wake_up: entered
[ 1731.632619] torture_-135 0d... 1562233458us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] torture_-135 0d... 1562233459us : ttwu_do_activate.isra.108: entered
[ 1731.632619] torture_-135 0d... 1562233459us : activate_task: entered
[ 1731.632619] torture_-135 0d... 1562233459us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] torture_-135 0d... 1562233459us : check_preempt_curr: entered
[ 1731.632619] torture_-135 0d... 1562233459us : resched_curr: entered
[ 1731.632619] torture_-135 0.N.. 1562233460us : cpu_stop_queue_work: entered for CPU 1
[ 1731.632619] torture_-135 0.N.. 1562233460us : wake_up_q: entered
[ 1731.632619] torture_-135 0.N.. 1562233460us : wake_up_process: entered
[ 1731.632619] torture_-135 0.N.. 1562233460us : try_to_wake_up: entered
[ 1731.632619] torture_-135 0dN.. 1562233461us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] torture_-135 0dN.. 1562233478us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] torture_-135 0.N.. 1562233488us : cpu_stop_queue_work: entered for CPU 2
[ 1731.632619] torture_-135 0.N.. 1562233488us : wake_up_q: entered
[ 1731.632619] torture_-135 0.N.. 1562233488us : wake_up_process: entered
[ 1731.632619] torture_-135 0.N.. 1562233488us : try_to_wake_up: entered
[ 1731.632619] torture_-135 0dN.. 1562233489us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] torture_-135 0dN.. 1562233489us : try_to_wake_up: ttwu_queue_remote entered, CPU 2
[ 1731.632619] <idle>-0 1d... 1562233493us : scheduler_ipi: entered
[ 1731.632619] <idle>-0 1d.h. 1562233495us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 1d.h. 1562233495us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] <idle>-0 1d.h. 1562233495us : ttwu_do_activate.isra.108: entered
[ 1731.632619] <idle>-0 1d.h. 1562233495us : activate_task: entered
[ 1731.632619] <idle>-0 1d.h. 1562233496us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] <idle>-0 1d.h. 1562233496us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 1d.h. 1562233496us : resched_curr: entered
[ 1731.632619] torture_-135 0.N.. 1562233498us : cpu_stop_queue_work: entered for CPU 6
[ 1731.632619] torture_-135 0.N.. 1562233498us : wake_up_q: entered
[ 1731.632619] torture_-135 0.N.. 1562233499us : wake_up_process: entered
[ 1731.632619] torture_-135 0.N.. 1562233499us : try_to_wake_up: entered
[ 1731.632619] torture_-135 0dN.. 1562233499us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] torture_-135 0dN.. 1562233499us : try_to_wake_up: ttwu_queue_remote entered, CPU 6
[ 1731.632619] torture_-135 0.N.. 1562233509us : cpu_stop_queue_work: entered for CPU 7
[ 1731.632619] torture_-135 0.N.. 1562233509us : wake_up_q: entered
[ 1731.632619] torture_-135 0.N.. 1562233509us : wake_up_process: entered
[ 1731.632619] torture_-135 0.N.. 1562233509us : try_to_wake_up: entered
[ 1731.632619] torture_-135 0dN.. 1562233510us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] torture_-135 0dN.. 1562233510us : try_to_wake_up: ttwu_queue_remote entered, CPU 7
[ 1731.632619] <idle>-0 2d... 1562233515us : scheduler_ipi: entered
[ 1731.632619] <idle>-0 2d.h. 1562233517us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 2d.h. 1562233517us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] <idle>-0 2d.h. 1562233518us : ttwu_do_activate.isra.108: entered
[ 1731.632619] <idle>-0 2d.h. 1562233519us : activate_task: entered
[ 1731.632619] <idle>-0 2d.h. 1562233519us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] <idle>-0 2d.h. 1562233519us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 2d.h. 1562233519us : resched_curr: entered
[ 1731.632619] torture_-135 0d... 1562233520us : sched_switch: prev_comm=torture_onoff prev_pid=135 prev_prio=120 prev_state=D ==> next_comm=migration/0 next_pid=11 next_prio=0
[ 1731.632619] rcu_tort-128 7d... 1562233520us : scheduler_ipi: entered
[ 1731.632619] rcu_tort-128 7d.h. 1562233521us : sched_ttwu_pending: entered
[ 1731.632619] rcu_tort-128 7d.h. 1562233521us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] rcu_tort-128 7d.h. 1562233521us : ttwu_do_activate.isra.108: entered
[ 1731.632619] rcu_tort-128 7d.h. 1562233521us : activate_task: entered
[ 1731.632619] migratio-11 0...1 1562233521us : multi_cpu_stop: curstate = 1, ack = 5
[ 1731.632619] rcu_tort-128 7d.h. 1562233521us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] rcu_tort-128 7d.h. 1562233523us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-128 7d.h. 1562233524us : resched_curr: entered
[ 1731.632619] rcu_tort-128 7d... 1562233532us : sched_switch: prev_comm=rcu_torture_rea prev_pid=128 prev_prio=139 prev_state=R+ ==> next_comm=migration/7 next_pid=52 next_prio=0
[ 1731.632619] migratio-52 7...1 1562233535us : multi_cpu_stop: curstate = 1, ack = 4
[ 1731.632619] <idle>-0 1dNs. 1562233552us : activate_task: entered
[ 1731.632619] <idle>-0 2.N.. 1562233553us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 1dNs. 1562233553us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 2d... 1562233554us : sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/2 next_pid=21 next_prio=0
[ 1731.632619] <idle>-0 1dNs. 1562233554us : resched_curr: entered
[ 1731.632619] <idle>-0 1.N.. 1562233554us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 1d... 1562233555us : sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/1 next_pid=14 next_prio=0
[ 1731.632619] migratio-21 2...1 1562233556us : multi_cpu_stop: curstate = 1, ack = 3
[ 1731.632619] migratio-14 1...1 1562233556us : multi_cpu_stop: curstate = 1, ack = 2
[ 1731.632619] migratio-11 0..s1 1562234528us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1562234528us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1562234529us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1562234529us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1562234529us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1562234529us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1562234530us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0..s1 1562235527us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1562235527us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1562235528us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1562235528us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1562235528us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1562235528us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1562235529us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 6d... 1562235529us : scheduler_ipi: entered
[ 1731.632619] <idle>-0 6d.h. 1562249376us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 6d.h. 1562249377us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] <idle>-0 6d.h. 1562249377us : ttwu_do_activate.isra.108: entered
[ 1731.632619] <idle>-0 6d.h. 1562249377us : activate_task: entered
[ 1731.632619] <idle>-0 6d.h. 1562249378us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] <idle>-0 6d.h. 1562249378us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 6d.h. 1562249378us : resched_curr: entered
[ 1731.632619] <idle>-0 6.N.. 1562249472us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 6d... 1562249480us : sched_switch: prev_comm=swapper/6 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/6 next_pid=46 next_prio=0
[ 1731.632619] migratio-46 6...1 1562249502us : multi_cpu_stop: curstate = 1, ack = 1
[ 1731.632619] migratio-14 1...1 1562249503us : multi_cpu_stop: curstate = 2, ack = 5
[ 1731.632619] migratio-52 7...1 1562249503us : multi_cpu_stop: curstate = 2, ack = 5
[ 1731.632619] migratio-11 0...1 1562249504us : multi_cpu_stop: curstate = 2, ack = 3
[ 1731.632619] migratio-46 6...1 1562249505us : multi_cpu_stop: curstate = 2, ack = 2
Almost three -minutes- delay. CPU 2 was just fine 16ms earlier:
2...1 1562233556us : multi_cpu_stop: curstate = 1, ack = 3
"curstate = 1" above corresponds to MULTI_STOP_PREPARE.
"curstate = 2" below corresponds to MULTI_STOP_DISABLE_IRQ
So what did that CPU need to execute in the meantime?
o ack_state(), which does an atomic_dec_and_test(), an
atomic_set(), an smp_wmb(), and a WRITE_ONCE().
o rcu_momentary_dyntick_idle(), which does a
raw_cpu_write(), an atomic_add_return(),
integer comparison for a WARN_ON_ONCE() and call to
rcu_preempt_deferred_qs(), which in this configuration
is an empty function.
o stop_machine_yield(), which does a cpu_relax(), which might
pass control to the hupervisor.
o Multiple passes through a loop doing READ_ONCE(msdata->state)
(paranoia on my part), a couple of comparisons, an
rcu_momentary_dyntick_idle(), and a stop_machine_yield().
o We don't call the function msdata->fn(msdata->data)
because that doesn't happen until after we get to
MULTI_STOP_RUN, which is after MULTI_STOP_DISABLE_IRQ.
o This would be easy to blame on the hypervisor, but then
why is this behavior restricted to CONFIG_NO_HZ_FULL
guest-OS kernels with lots of nohz_full CPUs? I suppose
maybe the guest's scheduling-clock interrupt attempts
might be having an effect, but...
[ 1731.632619] migratio-21 2...1 1729613677us : multi_cpu_stop: curstate = 2, ack = 1
[ 1731.632619] migratio-21 2d..1 1729613680us : multi_cpu_stop: curstate = 3, ack = 5
[ 1731.632619] migratio-46 6d..1 1729613680us : multi_cpu_stop: curstate = 3, ack = 5
[ 1731.632619] migratio-14 1d..1 1729613680us : multi_cpu_stop: curstate = 3, ack = 5
[ 1731.632619] migratio-52 7d..1 1729613680us : multi_cpu_stop: curstate = 3, ack = 4
[ 1731.632619] migratio-11 0d..1 1729613680us : multi_cpu_stop: curstate = 3, ack = 4
[ 1731.632619] migratio-46 6d..1 1729613680us : sched_ttwu_pending: entered
[ 1731.632619] migratio-14 1d..1 1729613680us : multi_cpu_stop: curstate = 4, ack = 5
[ 1731.632619] migratio-46 6d..1 1729613680us : multi_cpu_stop: curstate = 4, ack = 5
[ 1731.632619] migratio-52 7d..1 1729613680us : multi_cpu_stop: curstate = 4, ack = 5
[ 1731.632619] migratio-21 2d..1 1729614637us : multi_cpu_stop: curstate = 4, ack = 5
[ 1731.632619] migratio-14 1d... 1729614817us : sched_switch: prev_comm=migration/1 prev_pid=14 prev_prio=0 prev_state=S ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] migratio-52 7d... 1729614820us : sched_switch: prev_comm=migration/7 prev_pid=52 prev_prio=0 prev_state=S ==> next_comm=rcu_torture_rea next_pid=129 next_prio=139
[ 1731.632619] rcu_tort-129 7d... 1729614828us : sched_switch: prev_comm=rcu_torture_rea prev_pid=129 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=128 next_prio=139
[ 1731.632619] rcu_tort-128 7d... 1729614833us : sched_switch: prev_comm=rcu_torture_rea prev_pid=128 prev_prio=139 prev_state=S ==> next_comm=swapper/7 next_pid=0 next_prio=120
[ 1731.632619] rcu_tort-124 1d... 1729614834us : activate_task: entered
[ 1731.632619] rcu_tort-124 1d... 1729614836us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729614836us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729614836us : activate_task: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729614837us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729614837us : activate_task: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729614837us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729614837us : activate_task: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729614838us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729614839us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_wri next_pid=119 next_prio=120
[ 1731.632619] migratio-11 0d..1 1729614839us : multi_cpu_stop: curstate = 4, ack = 1
[ 1731.632619] migratio-11 0d.h1 1729614974us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.h1 1729614974us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.h1 1729614976us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.h1 1729614977us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.h1 1729614977us : activate_task: entered
[ 1731.632619] migratio-11 0d.h1 1729614978us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.h1 1729614979us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0..s1 1729614988us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729614989us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729614990us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729614991us : try_to_wake_up: ttwu_queue_remote entered, CPU 7
[ 1731.632619] migratio-11 0..s1 1729615008us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615008us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615009us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615010us : try_to_wake_up: ttwu_queue_remote entered, CPU 7
[ 1731.632619] migratio-11 0..s1 1729615010us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615010us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615011us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615011us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] rcu_tort-119 1d... 1729615025us : scheduler_ipi: entered
[ 1731.632619] rcu_tort-119 1d.h. 1729615026us : sched_ttwu_pending: entered
[ 1731.632619] rcu_tort-119 1d.h. 1729615026us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] rcu_tort-119 1d.h. 1729615026us : ttwu_do_activate.isra.108: entered
[ 1731.632619] rcu_tort-119 1d.h. 1729615027us : activate_task: entered
[ 1731.632619] rcu_tort-119 1d.h. 1729615028us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] rcu_tort-119 1d.h. 1729615028us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0d.s1 1729615029us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615029us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615030us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615030us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615030us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615031us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615031us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0d.s1 1729615032us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615032us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0..s1 1729615033us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615033us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615034us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615034us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615034us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615035us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615035us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0..s1 1729615036us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615036us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615038us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615038us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615038us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615039us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615039us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0d.s1 1729615040us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615040us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615042us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615042us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0..s1 1729615043us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615043us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615044us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615044us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615044us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615045us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615045us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0..s1 1729615046us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615046us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615046us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615047us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615047us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615047us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615047us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0..s1 1729615048us : wake_up_process: entered
[ 1731.632619] migratio-11 0..s1 1729615049us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615050us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615050us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615051us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615051us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615051us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0d.s1 1729615057us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615057us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615057us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-11 0d.s1 1729615058us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-11 0d.s1 1729615058us : activate_task: entered
[ 1731.632619] migratio-11 0d.s1 1729615058us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-11 0d.s1 1729615059us : check_preempt_curr: entered
[ 1731.632619] migratio-11 0d.s1 1729615060us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615060us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615061us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615061us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615094us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615094us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615095us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615095us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615096us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615096us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d.s1 1729615097us : wake_up_process: entered
[ 1731.632619] migratio-11 0d.s1 1729615097us : try_to_wake_up: entered
[ 1731.632619] migratio-11 0d... 1729615103us : sched_switch: prev_comm=migration/0 prev_pid=11 prev_prio=0 prev_state=S ==> next_comm=rcu_sched next_pid=10 next_prio=120
[ 1731.632619] rcu_sche-10 0d... 1729615108us : sched_switch: prev_comm=rcu_sched prev_pid=10 prev_prio=120 prev_state=I ==> next_comm=init next_pid=1 next_prio=120
[ 1731.632619] rcu_tort-119 1d... 1729615678us : sched_switch: prev_comm=rcu_torture_wri prev_pid=119 prev_prio=120 prev_state=S ==> next_comm=rcu_torture_rea next_pid=125 next_prio=139
[ 1731.632619] rcu_tort-125 1d... 1729615683us : sched_switch: prev_comm=rcu_torture_rea prev_pid=125 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] <idle>-0 7d... 1729615886us : scheduler_ipi: entered
[ 1731.632619] <idle>-0 7d.h. 1729616090us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 7d.h. 1729616090us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] <idle>-0 7d.h. 1729616091us : ttwu_do_activate.isra.108: entered
[ 1731.632619] <idle>-0 7d.h. 1729616091us : activate_task: entered
[ 1731.632619] <idle>-0 7d.h. 1729616092us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] <idle>-0 7d.h. 1729616093us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 7d.h. 1729616093us : resched_curr: entered
[ 1731.632619] <idle>-0 7dNh. 1729616094us : ttwu_do_activate.isra.108: entered
[ 1731.632619] <idle>-0 7dNh. 1729616094us : activate_task: entered
[ 1731.632619] <idle>-0 7dNh. 1729616095us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] <idle>-0 7dNh. 1729616095us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 7dNh. 1729616117us : resched_curr: entered
[ 1731.632619] <idle>-0 7.N.. 1729616153us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 7d... 1729616155us : sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=rcu_torture_rea next_pid=129 next_prio=139
[ 1731.632619] rcu_tort-129 7d... 1729616159us : sched_switch: prev_comm=rcu_torture_rea prev_pid=129 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=128 next_prio=139
[ 1731.632619] init-1 0d... 1729616201us : sched_switch: prev_comm=init prev_pid=1 prev_prio=120 prev_state=S ==> next_comm=kworker/u16:5 next_pid=162 next_prio=120
[ 1731.632619] kworker/-162 0d... 1729616207us : wake_up_process: entered
[ 1731.632619] kworker/-162 0d... 1729616207us : try_to_wake_up: entered
[ 1731.632619] kworker/-162 0d... 1729616208us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] kworker/-162 0d... 1729616209us : ttwu_do_activate.isra.108: entered
[ 1731.632619] kworker/-162 0d... 1729616209us : activate_task: entered
[ 1731.632619] kworker/-162 0d... 1729616211us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] kworker/-162 0d... 1729616211us : check_preempt_curr: entered
[ 1731.632619] kworker/-162 0d... 1729616213us : wake_up_process: entered
[ 1731.632619] kworker/-162 0d... 1729616214us : try_to_wake_up: entered
[ 1731.632619] kworker/-162 0d... 1729616215us : wake_up_process: entered
[ 1731.632619] kworker/-162 0d... 1729616215us : try_to_wake_up: entered
[ 1731.632619] rcu_tort-124 1d.H. 1729618001us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729618015us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=127 next_prio=139
[ 1731.632619] rcu_tort-127 1d... 1729618022us : sched_switch: prev_comm=rcu_torture_rea prev_pid=127 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=126 next_prio=139
[ 1731.632619] rcu_tort-126 1d.h. 1729620527us : resched_curr: entered
[ 1731.632619] rcu_tort-126 1d... 1729620533us : sched_switch: prev_comm=rcu_torture_rea prev_pid=126 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] rcu_tort-124 1d.h. 1729623526us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729623532us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=126 next_prio=139
[ 1731.632619] rcu_tort-126 1d.h. 1729626526us : resched_curr: entered
[ 1731.632619] rcu_tort-126 1d... 1729626534us : sched_switch: prev_comm=rcu_torture_rea prev_pid=126 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] rcu_tort-124 1d.h. 1729629526us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729629719us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=126 next_prio=139
[ 1731.632619] rcu_tort-126 1d.h. 1729632524us : resched_curr: entered
[ 1731.632619] rcu_tort-126 1d... 1729632677us : sched_switch: prev_comm=rcu_torture_rea prev_pid=126 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] rcu_tort-124 1d.h. 1729635526us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729635533us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=126 next_prio=139
[ 1731.632619] rcu_tort-126 1d.h. 1729638531us : resched_curr: entered
[ 1731.632619] rcu_tort-126 1d... 1729638541us : sched_switch: prev_comm=rcu_torture_rea prev_pid=126 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] rcu_tort-124 1d.h. 1729641526us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729641534us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=126 next_prio=139
[ 1731.632619] rcu_tort-126 1d.h. 1729644526us : resched_curr: entered
[ 1731.632619] rcu_tort-126 1d... 1729644622us : sched_switch: prev_comm=rcu_torture_rea prev_pid=126 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] rcu_tort-124 1d.h. 1729647528us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729647534us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=R+ ==> next_comm=rcu_torture_rea next_pid=126 next_prio=139
[ 1731.632619] rcu_tort-126 1d... 1729647662us : sched_switch: prev_comm=rcu_torture_rea prev_pid=126 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=124 next_prio=139
[ 1731.632619] kworker/-162 0d.h. 1729647665us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729647674us : activate_task: entered
[ 1731.632619] rcu_tort-124 1d... 1729647675us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729647675us : activate_task: entered
[ 1731.632619] rcu_tort-124 1d... 1729647675us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729647676us : resched_curr: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729647676us : activate_task: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729647676us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729647676us : activate_task: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729647677us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729647677us : activate_task: entered
[ 1731.632619] rcu_tort-124 1dN.. 1729647677us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-124 1d... 1729647679us : sched_switch: prev_comm=rcu_torture_rea prev_pid=124 prev_prio=139 prev_state=S ==> next_comm=torture_stutter next_pid=133 next_prio=120
[ 1731.632619] torture_-133 1d... 1729647682us : sched_switch: prev_comm=torture_stutter prev_pid=133 prev_prio=120 prev_state=S ==> next_comm=rcu_torture_fwd next_pid=136 next_prio=139
[ 1731.632619] kworker/-162 0.Ns. 1729647684us : wake_up_process: entered
[ 1731.632619] kworker/-162 0.Ns. 1729647685us : try_to_wake_up: entered
[ 1731.632619] kworker/-162 0dNs. 1729647688us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] kworker/-162 0dNs. 1729647690us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] rcu_tort-128 7d... 1729647690us : sched_switch: prev_comm=rcu_torture_rea prev_pid=128 prev_prio=139 prev_state=S ==> next_comm=swapper/7 next_pid=0 next_prio=120
[ 1731.632619] kworker/-162 0.Ns. 1729647707us : wake_up_process: entered
[ 1731.632619] kworker/-162 0.Ns. 1729647707us : try_to_wake_up: entered
[ 1731.632619] rcu_tort-136 1d... 1729647709us : scheduler_ipi: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647709us : sched_ttwu_pending: entered
[ 1731.632619] kworker/-162 0dNs. 1729647709us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647709us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] rcu_tort-136 1d.h. 1729647710us : ttwu_do_activate.isra.108: entered
[ 1731.632619] kworker/-162 0dNs. 1729647710us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] rcu_tort-136 1d.h. 1729647710us : activate_task: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647711us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647711us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-136 1.... 1729647714us : wake_up_process: entered
[ 1731.632619] rcu_tort-136 1.... 1729647714us : try_to_wake_up: entered
[ 1731.632619] rcu_tort-136 1d... 1729647716us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] rcu_tort-136 1d... 1729647716us : try_to_wake_up: ttwu_queue_remote entered, CPU 2
[ 1731.632619] kworker/-162 0.Ns. 1729647723us : wake_up_process: entered
[ 1731.632619] kworker/-162 0.Ns. 1729647723us : try_to_wake_up: entered
[ 1731.632619] kworker/-162 0dNs. 1729647724us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] kworker/-162 0dNs. 1729647724us : ttwu_do_activate.isra.108: entered
[ 1731.632619] kworker/-162 0dNs. 1729647725us : activate_task: entered
[ 1731.632619] kworker/-162 0dNs. 1729647726us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] kworker/-162 0dNs. 1729647726us : check_preempt_curr: entered
[ 1731.632619] kworker/-162 0.Ns. 1729647727us : wake_up_process: entered
[ 1731.632619] kworker/-162 0.Ns. 1729647727us : try_to_wake_up: entered
[ 1731.632619] kworker/-162 0dNs. 1729647728us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] kworker/-162 0dNs. 1729647729us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] rcu_tort-136 1d... 1729647730us : scheduler_ipi: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647730us : sched_ttwu_pending: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647730us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] rcu_tort-136 1d.h. 1729647731us : ttwu_do_activate.isra.108: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647731us : activate_task: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647731us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647732us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-136 1d.h. 1729647732us : resched_curr: entered
[ 1731.632619] rcu_tort-136 1dNh. 1729647732us : ttwu_do_activate.isra.108: entered
[ 1731.632619] rcu_tort-136 1dNh. 1729647732us : activate_task: entered
[ 1731.632619] rcu_tort-136 1dNh. 1729647733us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] kworker/-162 0d... 1729647733us : sched_switch: prev_comm=kworker/u16:5 prev_pid=162 prev_prio=120 prev_state=R+ ==> next_comm=kworker/0:3 next_pid=171 next_prio=120
[ 1731.632619] rcu_tort-136 1dNh. 1729647733us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-136 1d... 1729647734us : sched_switch: prev_comm=rcu_torture_fwd prev_pid=136 prev_prio=139 prev_state=D ==> next_comm=rcu_torture_wri next_pid=119 next_prio=120
[ 1731.632619] kworker/-171 0d... 1729647752us : sched_switch: prev_comm=kworker/0:3 prev_pid=171 prev_prio=120 prev_state=I ==> next_comm=kworker/u16:4 next_pid=161 next_prio=120
[ 1731.632619] kworker/-161 0d... 1729647754us : sched_switch: prev_comm=kworker/u16:4 prev_pid=161 prev_prio=120 prev_state=I ==> next_comm=rcu_sched next_pid=10 next_prio=120
[ 1731.632619] rcu_tort-119 1d... 1729648207us : sched_switch: prev_comm=rcu_torture_wri prev_pid=119 prev_prio=120 prev_state=D ==> next_comm=rcu_torture_sta next_pid=131 next_prio=120
[ 1731.632619] rcu_sche-10 0d... 1729648662us : resched_curr: entered
[ 1731.632619] rcu_sche-10 0..s. 1729650719us : wake_up_process: entered
[ 1731.632619] rcu_sche-10 0..s. 1729650719us : try_to_wake_up: entered
[ 1731.632619] rcu_sche-10 0d.s. 1729650720us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-21 2dNs1 1729650720us : scheduler_ipi: entered
[ 1731.632619] rcu_sche-10 0d.s. 1729650721us : try_to_wake_up: ttwu_queue_remote entered, CPU 7
[ 1731.632619] migratio-21 2dNH1 1729650721us : sched_ttwu_pending: entered
[ 1731.632619] migratio-21 2dNH1 1729650721us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] migratio-21 2dNH1 1729650721us : ttwu_do_activate.isra.108: entered
[ 1731.632619] migratio-21 2dNH1 1729650722us : activate_task: entered
[ 1731.632619] migratio-21 2dNH1 1729650723us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] migratio-21 2dNH1 1729650723us : check_preempt_curr: entered
[ 1731.632619] rcu_sche-10 0..s. 1729650734us : wake_up_process: entered
[ 1731.632619] rcu_sche-10 0..s. 1729650735us : try_to_wake_up: entered
[ 1731.632619] rcu_sche-10 0d.s. 1729650735us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] rcu_sche-10 0d.s. 1729650736us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] <idle>-0 7d... 1729650736us : scheduler_ipi: entered
[ 1731.632619] rcu_sche-10 0..s. 1729650747us : wake_up_process: entered
[ 1731.632619] rcu_sche-10 0..s. 1729650747us : try_to_wake_up: entered
[ 1731.632619] rcu_sche-10 0d.s. 1729650748us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] rcu_sche-10 0d.s. 1729650748us : try_to_wake_up: ttwu_queue_remote entered, CPU 1
[ 1731.632619] <idle>-0 7d.h. 1729650749us : sched_ttwu_pending: entered
[ 1731.632619] <idle>-0 7d.h. 1729650749us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] <idle>-0 7d.h. 1729650750us : ttwu_do_activate.isra.108: entered
[ 1731.632619] <idle>-0 7d.h. 1729650750us : activate_task: entered
[ 1731.632619] rcu_sche-10 0d... 1729650754us : sched_switch: prev_comm=rcu_sched prev_pid=10 prev_prio=120 prev_state=I ==> next_comm=kworker/u16:5 next_pid=162 next_prio=120
[ 1731.632619] <idle>-0 7d.h. 1729650755us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] <idle>-0 7d.h. 1729650755us : check_preempt_curr: entered
[ 1731.632619] <idle>-0 7d.h. 1729650755us : resched_curr: entered
[ 1731.632619] migratio-21 2dNs1 1729650758us : wake_up_process: entered
[ 1731.632619] migratio-21 2dNs1 1729650758us : try_to_wake_up: entered
[ 1731.632619] migratio-21 2dNs1 1729650759us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-21 2dNs1 1729650759us : try_to_wake_up: ttwu_queue_remote entered, CPU 0
[ 1731.632619] kworker/-162 0d... 1729650763us : activate_task: entered
[ 1731.632619] kworker/-162 0d... 1729650764us : check_preempt_curr: entered
[ 1731.632619] kworker/-162 0d... 1729650765us : activate_task: entered
[ 1731.632619] kworker/-162 0d... 1729650765us : check_preempt_curr: entered
[ 1731.632619] kworker/-162 0d... 1729650765us : activate_task: entered
[ 1731.632619] kworker/-162 0d... 1729650766us : check_preempt_curr: entered
[ 1731.632619] migratio-21 2dN.1 1729650770us : try_to_wake_up: entered
[ 1731.632619] kworker/-162 0d... 1729650770us : sched_switch: prev_comm=kworker/u16:5 prev_pid=162 prev_prio=120 prev_state=I ==> next_comm=rcu_torture_rea next_pid=125 next_prio=139
[ 1731.632619] migratio-21 2dN.1 1729650771us : try_to_wake_up: ttwu_queue entered
[ 1731.632619] migratio-21 2dN.1 1729650771us : try_to_wake_up: ttwu_queue_remote entered, CPU 0
[ 1731.632619] migratio-21 2d... 1729650774us : sched_switch: prev_comm=migration/2 prev_pid=21 prev_prio=0 prev_state=S ==> next_comm=rcuog/1 next_pid=18 next_prio=120
[ 1731.632619] rcu_tort-125 0d... 1729650775us : scheduler_ipi: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650775us : sched_ttwu_pending: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650775us : sched_ttwu_pending: non-NULL llist
[ 1731.632619] rcu_tort-125 0d.h. 1729650776us : ttwu_do_activate.isra.108: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650777us : activate_task: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650778us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650778us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650779us : ttwu_do_activate.isra.108: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650779us : activate_task: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650779us : ttwu_do_wakeup.isra.107: entered
[ 1731.632619] rcu_tort-125 0d.h. 1729650779us : check_preempt_curr: entered
[ 1731.632619] rcu_tort-125 0d... 1729650783us : sched_switch: prev_comm=rcu_torture_rea prev_pid=125 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=127 next_prio=139
[ 1731.632619] rcuog/1-18 2d... 1729650783us : sched_switch: prev_comm=rcuog/1 prev_pid=18 prev_prio=120 prev_state=S ==> next_comm=swapper/2 next_pid=0 next_prio=120
[ 1731.632619] rcu_tort-127 0d... 1729650786us : sched_switch: prev_comm=rcu_torture_rea prev_pid=127 prev_prio=139 prev_state=S ==> next_comm=rcu_torture_rea next_pid=130 next_prio=139
[ 1731.632619] rcu_tort-130 0d... 1729650789us : sched_switch: prev_comm=rcu_torture_rea prev_pid=130 prev_prio=139 prev_state=S ==> next_comm=torture_onoff next_pid=135 next_prio=120
[ 1731.632619] ---------------------------------
[ 1795.802039] smpboot: CPU 6 is now offline
next prev parent reply other threads:[~2019-08-08 20:35 UTC|newest]
Thread overview: 57+ messages / expand[flat|nested] mbox.gz Atom feed top
2019-08-02 15:14 [PATCH tip/core/rcu 0/14] No-CBs bypass addition for v5.4 Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 01/14] rcu/nocb: Atomic ->len field in rcu_segcblist structure Paul E. McKenney
2019-08-04 14:50 ` Peter Zijlstra
2019-08-04 14:52 ` Peter Zijlstra
2019-08-04 18:45 ` Paul E. McKenney
2019-08-04 18:42 ` Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 02/14] rcu/nocb: Add bypass callback queueing Paul E. McKenney
2019-08-07 0:03 ` Joel Fernandes
2019-08-07 0:16 ` Joel Fernandes
2019-08-07 0:35 ` Paul E. McKenney
2019-08-07 0:40 ` Steven Rostedt
2019-08-07 1:17 ` Paul E. McKenney
2019-08-07 1:24 ` Steven Rostedt
2019-08-07 3:47 ` Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 03/14] rcu/nocb: EXP Check use and usefulness of ->nocb_lock_contended Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 04/14] rcu/nocb: Print no-CBs diagnostics when rcutorture writer unduly delayed Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 05/14] rcu/nocb: Avoid synchronous wakeup in __call_rcu_nocb_wake() Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 06/14] rcu/nocb: Advance CBs after merge in rcutree_migrate_callbacks() Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 07/14] rcu/nocb: Reduce nocb_cb_wait() leaf rcu_node ->lock contention Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 08/14] rcu/nocb: Reduce __call_rcu_nocb_wake() " Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 09/14] rcu/nocb: Don't wake no-CBs GP kthread if timer posted under overload Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 10/14] rcu: Allow rcu_do_batch() to dynamically adjust batch sizes Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 11/14] EXP nohz: Add TICK_DEP_BIT_RCU Paul E. McKenney
2019-08-02 15:14 ` [PATCH RFC tip/core/rcu 12/14] rcu/nohz: Force on tick when invoking lots of callbacks Paul E. McKenney
2019-08-02 15:15 ` [PATCH RFC tip/core/rcu 13/14] rcutorture: Force on tick for readers and callback flooders Paul E. McKenney
2019-08-02 15:15 ` [PATCH RFC tip/core/rcu 14/14] rcu/nohz: Make multi_cpu_stop() enable tick on all online CPUs Paul E. McKenney
2019-08-04 14:43 ` Peter Zijlstra
2019-08-04 14:48 ` Peter Zijlstra
2019-08-04 18:41 ` Paul E. McKenney
2019-08-04 20:24 ` Paul E. McKenney
2019-08-05 4:19 ` Paul E. McKenney
2019-08-05 8:07 ` Peter Zijlstra
2019-08-05 14:47 ` Paul E. McKenney
2019-08-05 8:05 ` Peter Zijlstra
2019-08-05 14:54 ` Paul E. McKenney
2019-08-05 15:50 ` Peter Zijlstra
2019-08-05 17:48 ` Paul E. McKenney
2019-08-06 18:08 ` Paul E. McKenney
2019-08-07 21:41 ` Paul E. McKenney
2019-08-08 20:35 ` Paul E. McKenney [this message]
2019-08-08 21:30 ` Paul E. McKenney
2019-08-09 16:51 ` Paul E. McKenney
2019-08-09 18:07 ` Joel Fernandes
2019-08-09 18:39 ` Paul E. McKenney
2019-08-12 21:02 ` Frederic Weisbecker
2019-08-12 23:23 ` Paul E. McKenney
2019-08-13 1:33 ` Joel Fernandes
2019-08-13 12:30 ` Frederic Weisbecker
2019-08-13 14:48 ` Paul E. McKenney
2019-08-14 17:55 ` Joel Fernandes
2019-08-14 22:05 ` Paul E. McKenney
2019-08-15 15:07 ` Joel Fernandes
2019-08-15 17:23 ` Paul E. McKenney
2019-08-15 18:15 ` Joel Fernandes
2019-08-15 18:39 ` Paul E. McKenney
2019-08-15 19:42 ` Joel Fernandes
2019-08-13 21:06 ` Paul E. McKenney
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=20190808203541.GA8160@linux.ibm.com \
--to=paulmck@linux.ibm.com \
--cc=akpm@linux-foundation.org \
--cc=dhowells@redhat.com \
--cc=dipankar@in.ibm.com \
--cc=edumazet@google.com \
--cc=fweisbec@gmail.com \
--cc=jiangshanlai@gmail.com \
--cc=joel@joelfernandes.org \
--cc=josh@joshtriplett.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mathieu.desnoyers@efficios.com \
--cc=mingo@kernel.org \
--cc=oleg@redhat.com \
--cc=peterz@infradead.org \
--cc=rcu@vger.kernel.org \
--cc=rostedt@goodmis.org \
--cc=tglx@linutronix.de \
/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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.