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 a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).