Re: "Badness" again

Re: "Badness" again

[Herbert Xu]

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

On Fri, Jan 14, 2005 at 05:16:12PM -0500, Jeff Garzik wrote:
> 
> Blah.  Any other suggestions for debugging this thing?

Yes I have a better theory now :)

All your "badness" messages start with a call to udpv6_sendmsg().
That function calls ip6_dst_lookup() to get its dst entry.  Note
that udpv6_sendmsg() does not hold a lock on the sk at all.  However,
ip6_dst_lookup() uses __sk_dst_check() which is only safe if you can
either guarantee single-threadedness or if you hold sk_dst_lock.

Neither is true here and therefore we may have a situation where
the cached dst is released twice.  In fact I tracked down the
address closest to the "badness" messages and it belongs to
one of your domain's name servers.  That means the requests were
probably made by named, which is multi-threaded.

So please give this patch a spin and see if it makes things any
better.  I've verified that no callers to ip6_dst_lookup() holds
sk_dst_lock so it's safe (but possibly redundant in cases where
they hold locks on the sk itself) to use sk_dst_check().

Cheers,
-- 
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

[-- Attachment #2: p --]
[-- Type: text/plain, Size: 667 bytes --]

===== net/ipv6/ip6_output.c 1.79 vs edited =====
--- 1.79/net/ipv6/ip6_output.c	2005-01-14 15:41:06 +11:00
+++ edited/net/ipv6/ip6_output.c	2005-01-15 11:17:44 +11:00
@@ -745,7 +745,7 @@
 	if (sk) {
 		struct ipv6_pinfo *np = inet6_sk(sk);
 	
-		*dst = __sk_dst_check(sk, np->dst_cookie);
+		*dst = sk_dst_check(sk, np->dst_cookie);
 		if (*dst) {
 			struct rt6_info *rt = (struct rt6_info*)*dst;
 	
@@ -772,9 +772,9 @@
 			     && (np->daddr_cache == NULL ||
 				 !ipv6_addr_equal(&fl->fl6_dst, np->daddr_cache)))
 			    || (fl->oif && fl->oif != (*dst)->dev->ifindex)) {
+				dst_release(*dst);
 				*dst = NULL;
-			} else
-				dst_hold(*dst);
+			}
 		}
 	}
 

Re: "Badness" again

[Jeff Garzik]

Herbert Xu wrote:
> On Fri, Jan 14, 2005 at 05:16:12PM -0500, Jeff Garzik wrote:
> 
>>Blah.  Any other suggestions for debugging this thing?
> 
> 
> Yes I have a better theory now :)
> 
> All your "badness" messages start with a call to udpv6_sendmsg().
> That function calls ip6_dst_lookup() to get its dst entry.  Note
> that udpv6_sendmsg() does not hold a lock on the sk at all.  However,
> ip6_dst_lookup() uses __sk_dst_check() which is only safe if you can
> either guarantee single-threadedness or if you hold sk_dst_lock.
> 
> Neither is true here and therefore we may have a situation where
> the cached dst is released twice.  In fact I tracked down the
> address closest to the "badness" messages and it belongs to
> one of your domain's name servers.  That means the requests were
> probably made by named, which is multi-threaded.
> 
> So please give this patch a spin and see if it makes things any
> better.  I've verified that no callers to ip6_dst_lookup() holds
> sk_dst_lock so it's safe (but possibly redundant in cases where
> they hold locks on the sk itself) to use sk_dst_check().

Running with this patch now, we'll see how it goes.  Thanks.

FWIW I also see ICMP code paths in the tracebacks (but that may be 
"second message" noise).

	Jeff

Re: "Badness" again

[Herbert Xu]

On Fri, Jan 14, 2005 at 11:20:30PM -0500, Jeff Garzik wrote:
> 
> FWIW I also see ICMP code paths in the tracebacks (but that may be 
> "second message" noise).

I haven't figured out how they can occur as a result of the
first problem but let's hope so :)
-- 
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

Re: "Badness" again

[David S. Miller]

On Sat, 15 Jan 2005 11:26:38 +1100
Herbert Xu <herbert@gondor.apana.org.au> wrote:

> All your "badness" messages start with a call to udpv6_sendmsg().
> That function calls ip6_dst_lookup() to get its dst entry.  Note
> that udpv6_sendmsg() does not hold a lock on the sk at all.  However,
> ip6_dst_lookup() uses __sk_dst_check() which is only safe if you can
> either guarantee single-threadedness or if you hold sk_dst_lock.

Good catch, that looks to be it.

I wouldn't have caught the necessary dst_hold(*dst) removal
too, in fact I thought this hunk of your patch was a bug at
first :-)

I'll apply this, thanks a lot Herbert.

Re: "Badness" again

[YOSHIFUJI Hideaki / 吉藤英明]

In article <20050114210651.654b22de.davem@davemloft.net> (at Fri, 14 Jan 2005 21:06:51 -0800), "David S. Miller" <davem@davemloft.net> says:

> On Sat, 15 Jan 2005 11:26:38 +1100
> Herbert Xu <herbert@gondor.apana.org.au> wrote:
> 
> > All your "badness" messages start with a call to udpv6_sendmsg().
> > That function calls ip6_dst_lookup() to get its dst entry.  Note
> > that udpv6_sendmsg() does not hold a lock on the sk at all.  However,
> > ip6_dst_lookup() uses __sk_dst_check() which is only safe if you can
> > either guarantee single-threadedness or if you hold sk_dst_lock.
> 
> Good catch, that looks to be it.

I agree too; this is one of changeset what I was going to send.
Thanks.

--yoshfuji

Re: "Badness" again

[Lennert Buytenhek]

On Sat, Jan 15, 2005 at 11:26:38AM +1100, Herbert Xu wrote:

> Neither is true here and therefore we may have a situation where
> the cached dst is released twice.  In fact I tracked down the
> address closest to the "badness" messages and it belongs to
> one of your domain's name servers.  That means the requests were
> probably made by named, which is multi-threaded.

The machine where I was seeing this (a HT P4) was indeed running
named as well.  This is the slave server for some zones, and the
master server, which had a pretty much identical sw configuration
(both Fedora 2, both using 6to4), is a (non-HT) Celeron and I never
saw it happening there.


--L