linux-kernel - Re: tree rcu: call_rcu scalability problem?

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <20090902164504.GD28052@wotan.suse.de>
Date:	Wed, 2 Sep 2009 18:45:04 +0200
From:	Nick Piggin <npiggin@...e.de>
To:	"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
Cc:	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: Re: tree rcu: call_rcu scalability problem?

On Wed, Sep 02, 2009 at 09:37:05AM -0700, Paul E. McKenney wrote:
> On Wed, Sep 02, 2009 at 06:24:51PM +0200, Nick Piggin wrote:
> > On Wed, Sep 02, 2009 at 08:19:27AM -0700, Paul E. McKenney wrote:
> > > On Wed, Sep 02, 2009 at 02:27:56PM +0200, Nick Piggin wrote:
> > > > On Wed, Sep 02, 2009 at 11:48:35AM +0200, Nick Piggin wrote:
> > > > > Hi Paul,
> > > > > 
> > > > > I'm testing out scalability of some vfs code paths, and I'm seeing
> > > > > a problem with call_rcu. This is a 2s8c opteron system, so nothing
> > > > > crazy.
> > > > > 
> > > > > I'll show you the profile results for 1-8 threads:
> > > > > 
> > > > > 1:
> > > > >  29768 total                                      0.0076
> > > > >  15550 default_idle                              48.5938
> > > > >   1340 __d_lookup                                 3.6413
> > > > >    954 __link_path_walk                           0.2559
> > > > >    816 system_call_after_swapgs                   8.0792
> > > > >    680 kmem_cache_alloc                           1.4167
> > > > >    669 dput                                       1.1946
> > > > >    591 __call_rcu                                 2.0521
> > > > > 
> > > > > 2:
> > > > >  56733 total                                      0.0145
> > > > >  20074 default_idle                              62.7313
> > > > >   3075 __call_rcu                                10.6771
> > > > >   2650 __d_lookup                                 7.2011
> > > > >   2019 dput                                       3.6054
> > > > > 
> > > > > 4:
> > > > >  98889 total                                      0.0253
> > > > >  21759 default_idle                              67.9969
> > > > >  10994 __call_rcu                                38.1736
> > > > >   5185 __d_lookup                                14.0897
> > > > >   4475 dput                                       7.9911
> > > 
> > > Four threads runs on one socket but 8 threads runs on two sockets,
> > > I take it?
> > 
> > Yes.
> > 
> > 
> > > > > 8:
> > > > > 170391 total                                      0.0437
> > > > >  31815 __call_rcu                               110.4688
> > > > >  12958 dput                                      23.1393
> > > > >  10417 __d_lookup                                28.3071
> > > > > 
> > > > > Of course there are other scalability factors involved too, but
> > > > > __call_rcu is taking 54 times more CPU to do 8 times the amount
> > > > > of work from 1-8 threads, or a factor of 6.7 slowdown.
> > > > > 
> > > > > This is with tree RCU.
> > > > 
> > > > It seems like nearly 2/3 of the cost is here:
> > > >         /* Add the callback to our list. */
> > > >         *rdp->nxttail[RCU_NEXT_TAIL] = head; <<<
> > > >         rdp->nxttail[RCU_NEXT_TAIL] = &head->next;
> > > 
> > > Hmmm...  That certainly is not the first list of code in call_rcu() that
> > > would come to mind...
> > 
> > It's weird. I *think* I read the asm right, but oprofile maybe is
> > not attributing the cost to the right instruction.
> > 
> > 
> > > > In loading the pointer to the next tail pointer. If I'm reading the profile
> > > > correctly. Can't see why that should be a probem though...
> > > 
> > > The usual diagnosis would be false sharing.
> > 
> > Hmm that's possible yes.
> > 
> > 
> > > Hmmm...  What is the workload?  CPU-bound?  If CONFIG_PREEMPT=n, I might
> > > expect interference from force_quiescent_state(), except that it should
> > > run only every few clock ticks.  So this seems quite unlikely.
> > 
> > It's CPU bound and preempt=y.
> > 
> > Workload is just 8 processes running a loop of close(open("file$i")) as
> > I said though you probably won't be able to reproduce it on a vanilla
> > kernel.
> 
> OK, so you are executing call_rcu() a -lot-!!!

Oh yeah. The combined frequency in the 8 proc case is once per 270ns, so
nearly half a million times per second per core.

It's not *slow* by any means, but it is increasing much faster than other
functions on the profile so I just want to understand what is happening.
 

> Could you also please try CONFIG_RCU_TRACE=y, and send me the contents of
> the files in the "rcu" subdirectory in debugfs?  Please take a snapshot
> of these files, run your test for a fixed time interval (perhaps ten
> seconds, but please tell me how long), then take a second snapshot.

Will do.

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