Re: 2.6.24-rc8-rt1: Strange latencies on mpc5200 powerpc - RCU issue?

[Wolfgang Grandegger]

Wolfgang Grandegger wrote:
> Steven Rostedt wrote:
> > On Tue, 1 Jul 2008, Wolfgang Grandegger wrote:
> > > I continue this thread because it's still not understood why enabling
> > > CONFIG_RCU_TRACE is necessary to get reasonable latencies on the
> > > MPC5200. It might also explain, why I get much worse latencies with
> > > 2.6.25.8-rt7.
> >
> > Have you tried turning on ftrace?
>
> Not yet.
>
> > > To recapitulate, with CONFIG_RCU_TRACE enabled, cyclictest reports max.
> > > latencies of approx. 130 us with 2.6.24.4-rt4 on my MPC5200 PowerPC
> > > board. If I disable it, the latency goes up to 600 us. Obviously, the
> > > trace_mark() calls in rcupreempt*.c have some positive impact on the
> > > latency. I narrowed down, that the 2 calls in __rcu_preempt_boost() in
> > > rcupreempt-boost.c are the important one:
> > >
> > > void __rcu_preempt_unboost(void)
> > > {
> > >     struct task_struct *curr = current;
> > >     struct rcu_boost_dat *rbd;
> > >     int prio;
> > >     unsigned long flags;
> > >
> > >     trace_mark(unboost_called, "NULL");
>
> To make it clear: If I just comment out the line above and ...
>
> > >     /* if not boosted, then ignore */
> > >     if (likely(!rcu_is_boosted(curr)))
> > >         return;
> >
> > I wonder if the "likely" is faulty on the PPC code generation. Have you
> > tried removing that "likely" statement.
> >
> > >     /*
> > >      * Need to be very careful with NMIs.
> > >      * If we take the lock and an NMI comes in
> > >      * and it may try to unboost us if curr->rcub_rbdp
> > >      * is still set. So we zero it before grabbing the lock.
> > >      * But this also means that we might be boosted again
> > >      * so the boosting code needs to be aware of this.
> > >      */
> > >     rbd = curr->rcub_rbdp;
> > >     curr->rcub_rbdp = NULL;
> > >
> > >     /*
> > >      * Now an NMI might have came in after we grab
> > >      * the below lock. This check makes sure that
> > >      * the NMI doesn't try grabbing the lock
> > >      * while we already have it.
> > >      */
> > >     if (unlikely(!rbd))
> > >         return;
> >
> > Actually, remove all "likely" and "unlikely". The marker code could be
> > making it work better. But still, this shouldn't cause 600us latencies.
> >
> > >     spin_lock_irqsave(&rbd->rbs_lock, flags);
> > >     /*
> > >      * It is still possible that an NMI came in
> > >      * between the "is_boosted" check and setting
> > >      * the rcu_rbdp to NULL. This would mean that
> > >      * the NMI already dequeued us.
> > >      */
> > >     if (unlikely(!rcu_is_boosted(curr)))
> > >         goto out;
> > >
> > >     list_del_init(&curr->rcub_entry);
> > >
> > >     trace_mark(unboosted, "NULL");
>
> .. this one as well, then the latency goes *up* to 600us. The first one 
> has more influence, though.
>
> > >     curr->rcu_prio = MAX_PRIO;
> > >
> > >     spin_lock(&curr->pi_lock);
> > >     prio = rt_mutex_getprio(curr);
> > >     task_setprio(curr, prio);
> > >
> > >     curr->rcub_rbdp = NULL;
> > >
> > >     spin_unlock(&curr->pi_lock);
> > >   out:
> > >     spin_unlock_irqrestore(&rbd->rbs_lock, flags);
> > > }
> > >
> > > With them and all other trace_mark() calls commented out, the latency is
> > > still OK. The first one has a bigger impact.
> > >
> > > In 2.6.25.8-rt7, trace_mark() is not used any more but a function
> > > incrementing the corresponding counter directly and I suspect that's the
> > > reason why I'm seeing high latencies with both, CONFIG_RCU_TRACE enabled
> > > and disabled.
> > >
> > > I hope this observation sheds some light on the issue.
> >
> > It is still a mystery to me. Maybe looking at the different assembly
> > outputs with the different configurations.
>
> There seems to be something in trace_mark() keeping latency low:
>
>   http://lxr.linux.no/linux+v2.6.24.4/include/linux/marker.h#L52
>
> I will follow your suggestions.

I removed all "likely" and "unlikely" macros, but the latencies did not 
improve. Then I added

	preempt_disable();
	preempt_enable();

at the two locations mentioned above, like trace_mark() does,  and 
disabled CONFIG_RCU_TRACE. That helped to keep the latencies low, and it 
did for 2.6.25.8-rt7 as well. As I see it, adding preemption points seem 
to prevent high latencies.

Wolfgang.



--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/