Re: [PATCH] sunrpc.ko: RPC cache fix races

[NeilBrown <neilb@suse.de>]

[-- Attachment #1: Type: text/plain, Size: 7963 bytes --]

On 20 Feb 2013 14:57:07 +0100 bstroesser@ts.fujitsu.com wrote:

> On 20 Feb 2013 04:09:00 +0100 neilb@suse.de wrote:
> 
> > On 19 Feb 2013 18:08:40 +0100 bstroesser@ts.fujitsu.com wrote:
> > 
> > > Second attempt using the correct FROM. Sorry for the noise.
> > > 
> > > 
> > > Hi,
> > > 
> > > I found a problem in sunrpc.ko on a SLES11 SP1 (2.6.32.59-0,7.1) and 
> > > fixed it (see first patch ifor 2.6.32.60 below).
> > > For us the patch works fine (tested on 2.6.32.59-0.7.1).
> > > 
> > > AFAICS from the code, the problem seems to persist in current kernel 
> > > versions also. Thus, I added the second patch for 3.7.9.
> > > As the setup to reproduce the problem is quite complex, I couldn't 
> > > test the second patch yet. So consider this one as a RFC.
> > > 
> > > Best regards,
> > > Bodo
> > > 
> > > Please CC me, I'm not on the list.
> > > 
> > > =========================================
> > > From: Bodo Stroesser <bstroesser@ts.fujitsu.com>
> > > Date: Fri, 08 Feb 2013
> > > Subject: [PATCH] net: sunrpc: fix races in RPC cache
> > > 
> > > We found the problem and tested the patch on a SLES11 SP1 
> > > 2.6.32.59-0.7.1
> > > 
> > > This patch applies to linux-2.6.32.60 (changed monotonic_seconds -->
> > > get_seconds())
> > > 
> > > Sporadically NFS3 RPC requests to the nfs server are dropped due to
> > > cache_check() (net/sunrpc/cache.c) returning -ETIMEDOUT for an entry 
> > > of the "auth.unix.gid" cache.
> > > In this case, no NFS reply is sent to the client.
> > > 
> > > The reason for the dropped requests are races in cache_check() when
> > > cache_make_upcall() returns -EINVAL (because it is called for a cache 
> > > without readers) and cache_check() therefore refreshes the cache entry 
> > > (rv == -EAGAIN).
> > > 
> > > There are three details that need to be changed:
> > >  1) cache_revisit_request() must not be called before cache_fresh_locked()
> > >     has updated the cache entry, as cache_revisit_request() wakes up
> > >     threads waiting for the cache entry to be updated.
> > 
> > This certainly seems correct.  It is wrong to call cache_revisit_request() so early.
> > 
> > >     The explicit call to cache_revisit_request() is not needed, as
> > >     cache_fresh_unlocked() calls it anyway.
> > 
> > But cache_fresh_unlocked is only called if "rv == -EAGAIN", however we also need to call it in the case where "age > refresh_age/2" - it must always be called after clearing CACHE_PENDING.
> > 
> > Also, cache_fresh_unlocked() only calls cache_revisit_request() if CACHE_PENDING is set, but we have just cleared it!  Some definitely something wrong here.
> > (Note that I'm looking at the SLES 2.6.32 code at the moment, mainline is a bit different).
> > 
> > 
> > >     (But in case of not updating the cache entry, cache_revisit_request()
> > >     must be called. Thus, we use a fall through in the "case").
> > 
> > Hmm... I don't like case fallthroughs unless they have nice big comments:
> >     /* FALLTHROUGH */
> > or similar. :-)
> > 
> > >  2) CACHE_PENDING must not be cleared before cache_fresh_locked() has
> > >     updated the cache entry, as cache_defer_req() can return without really
> > >     sleeping if it detects CACHE_PENDING unset.
> > 
> > Agreed.  So we should leave the clearing of CACHE_PENDING to cache_fresh_unlocked().
> > 
> > 
> > >     (In case of not updating the cache entry again we use the fall 
> > > through)
> > >  3) Imagine a thread that calls cache_check() and gets rv = -ENOENT from
> > >     cache_is_valid(). Then it sets CACHE_PENDINGs and calls
> > >     cache_make_upcall().
> > >     We assume that meanwhile get_seconds() advances to the next
> > >     sec. and a second thread also calls cache_check(). It gets -EAGAIN from
> > >     cache_is_valid() for the same cache entry. As CACHE_PENDING still is
> > >     set, it calls cache_defer_req() immediately and waits for a wakeup from
> > >     the first thread.
> > >     After cache_make_upcall() returned -EINVAL, the first thread does not
> > >     update the cache entry as it had got rv = -ENOENT, but wakes up the
> > >     second thread by calling cache_revisit_request().
> > >     Thread two wakes up, calls cache_is_valid() and again gets -EAGAIN.
> > >     Thus, the result of the second cache_check() is -ETIMEDOUT and the
> > >     NFS request is dropped.
> > 
> > Yep, that's not so good....
> > 
> > 
> > >     To solve this, the cache entry now is updated not only if rv == -EAGAIN
> > >     but if rv == -ENOENT also. This is a sufficient workaround, as the
> > >     first thread would have to stay in cache_check() between its call to
> > >     cache_is_valid() and clearing CACHE_PENDING for more than 60 seconds
> > >     to break the workaround.
> > 
> > Still, it isn't nice to just have a work-around.  It would be best to have a fix.
> > The key problem here is that cache_is_valid() is time-sensitive.  This have been address in mainline - cache_is_valid doesn't depend on the current time there.
> 
> So, the solution would be a backport of the current mainline code ...

That would always be my preference, when it is practical.

> 
> Anyway, I think for SLES11 SP1 and 2.6.32.60 the work-around would be sufficient.
> BTW: it has the positive side effect, that - while a cache entry is in its second
> half of life - no longer each cache_check() tries to do a cache_make_upcall().

I agree that is an improvement.

> 
> 
> > 
> > 
> > >     
> > > Signed-off-by: Bodo Stroesser <bstroesser@ts.fujitsu.com>
> > > ---
> > > 
> > > --- a/net/sunrpc/cache.c	2012-08-08 21:35:09.000000000 +0200
> > > +++ b/net/sunrpc/cache.c	2013-02-08 14:29:41.000000000 +0100
> > > @@ -233,15 +233,14 @@ int cache_check(struct cache_detail *det
> > >  		if (!test_and_set_bit(CACHE_PENDING, &h->flags)) {
> > >  			switch (cache_make_upcall(detail, h)) {
> > >  			case -EINVAL:
> > > -				clear_bit(CACHE_PENDING, &h->flags);
> > > -				cache_revisit_request(h);
> > > -				if (rv == -EAGAIN) {
> > > +				if (rv == -EAGAIN || rv == -ENOENT) {
> > >  					set_bit(CACHE_NEGATIVE, &h->flags);
> > >  					cache_fresh_locked(h, get_seconds()+CACHE_NEW_EXPIRY);
> > > +					clear_bit(CACHE_PENDING, &h->flags);
> > >  					cache_fresh_unlocked(h, detail);
> > >  					rv = -ENOENT;
> > > +					break;
> > >  				}
> > > -				break;
> > >  
> > >  			case -EAGAIN:
> > >  				clear_bit(CACHE_PENDING, &h->flags);
> > 
> > I agree with some of this....
> > Maybe:
> > 
> >   switch(cache_make_upcall(detail, h)) {
> >   case -EINVAL:
> >         if (rv) {
> > 		set_bit(CACHE_NEGATIVE, &h->flags);
> > 		cache_fresh_locked(h, get_seconds() + CACHE_NEW_EXPIRY);
> > 		rv = -ENOENT;
> > 	}
> > 	/* FALLTHROUGH */
> >   case -EAGAIN:
> > 	cache_fresh_unlocked(h, detail);
> >   }
> 
> I agree, your patch is obviously better than the mine.
> But let me suggest one little change: I would like to substitute
> cache_fresh_unlocked() by clear_bit() and cache_revisit_request(),
> as the call to cache_dequeue() in cache_fresh_unlocked() seems to
> be obsolete here:

It is exactly this sort of thinking (on my part) that got us into this mess
in the first place.  I reasoned that the full locking/testing/whatever wasn't
necessary and took a short cut.  It wasn't a good idea.

Given that this is obviously difficult code to get right, we should make it
as easy to review as possible.  Have "cache_fresh_unlocked" makes it more
obviously correct, and that is a good thing.
Maybe cache_dequeue isn't needed here, but it won't hurt so I'd much rather
have the clearer code.
In fact, I'd also like to change

			if (test_and_clear_bit(CACHE_PENDING, &ch->flags))
				cache_dequeue(current_detail, ch);
			cache_revisit_request(ch);

near the end of cache_clean to call  cache_fresh_unlocked().


NeilBrown


[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 828 bytes --]