[lkml]   [2012]   [Jan]   [25]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
Messages in this thread
SubjectRe: RCU qsmask !=0 warnings on large-SMP...
On 1/25/2012 19:14, Paul E. McKenney wrote:
>> CONFIG_NO_HZ is not set, so it should not happen. We see that the behavior is the same with CONFIG_NO_HZ=y though, but it takes longer to reproduce usually.
> OK, the CONFIG_NO_HZ=n has the least code involved, so it would be best
> for debugging.

Good, that was my thought also when looking at the code. I'm reducing
NR_CPUS to 512 now to get two levels just for simpler debugging (the
issue is still present).

>> Because the RCU tree is 3 levels, the printout function we added in the patch gets called 3 times each time with the same RDP but with different RNPs (in rcu_start_gp()).
> Ah, good point. Hmmm...
> Looking back at Daniel's original email, we have the root rcu_node
> structure with ->qsmask=0x1 (indicating first descendent), the next
> level having ->qsmask=0x8 (indicating fourth descendent) and the last
> level having ->qsmask=0x1, again indicating first descendent. So,
> zero, 16, 32, 48. Which agrees with the CPU number below that has not
> yet caught up to the current grace period.
> Another really odd thing... If we are starting the new grace period,
> we should have incremented rsp->gpnum. And in fact, we do have
> rsp->gpnum being one larger than rsp->completed, as expected. But
> if we have only initialized the root rcu_node structures, how can
> the per-CPU rcudata structures know about the new grace period yet?
> There was a time when the CPUs could find out early, but I think that
> was a long time ago. Yes, check_for_new_grace_period() does compare
> rdp->gpnum against rsp->gpnum, but it calls note_new_gpnum() which
> acquires the rnp->lock(), and nothing happens unless __note_new_gpnum()
> sees that rnp->gpnum is different rdp->gpnum.
> So, it would be very interesting to add the values rdp->mynode->gpnum
> and rdp->mynode->completed to your list, perhaps labeling them something
> like "rng" and "rnc" respectively.

I will add this to the printout.

> Of course, CPU 48 should not have decided that it was done with the
> old grace period before clearing its bit. For that matter, some
> CPU somewhere decided that the grace period was done despite the
> root rcu_node's ->qsmask being non-zero, which should be prevented
> by the:
> if (rnp->qsmask != 0 || rcu_preempt_blocked_readers_cgp(rnp)) {
> line in rcu_report_qs_rnp().
> 3.2 has some event tracing that would be extremely helpful in tracking
> this down. Are you able to run 3.2?

Yes, 3.2.1 is our debug target right now.

>>> Same here, but most of the ql= values are larger. Later printout?
>> The loop in rcu_start_gp() releases the node lock between each time it gets a new level in the RCU tree (it has to) :
>> rcu_for_each_node_breadth_first(rsp, rnp) {
>> raw_spin_lock(&rnp->lock); /* irqs already disabled. */
>> rcu_debug_print(rsp, rnp);
>> so I guess this allows ql= values to increase maybe, no ?
> The ql= levels can increase anyway -- those queues are only accessed by
> the corresponding CPU or from stop_machine context. The small increases
> are entirely consistent with your having bits set at all levels of the
> rcu_node tree. The reason I was surprised is that my earlier bugs (as
> in before the code hit mainline) only ever resulted in a single level
> having a stray bit.


>> Thanks for looking into this Paul, we'd be more than happy to test out theories and patches.
> The event tracing, particularly the "rcu_grace_period" set, would be
> very helpful.

Are you talking about the data from /sys/kernel/debug/rcu/ ? I have
CONFIG_RCU_TRACE (and consequently CONFIG_TREE_RCU_TRACE) set, is this
enough to get the event data you want ?

Steffen Persvold, Chief Architect NumaChip
Numascale AS -
Tel: +47 92 49 25 54 Skype: spersvold

 \ /
  Last update: 2012-01-25 21:37    [W:0.117 / U:33.824 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site