KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Ingo Molnar]

i got one such message:

 KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at
 net/netlink/af_netlink.c (126)

this was on a box that is DSL connected and thus gets lots of trash 
packets over the wire. It is running -RT ontop of 2.6.12-rc1, and got 
this message after 2 days of uptime.

There was no apparent bad side-effect after this happened - no crash, no 
hung applications, no hung connections, the box is still up and running 
fine. The message is not reproducible, unfortunately. Never saw this 
message with 2.6.11-ish kernels on the same box.

since the locking is so different under PREEMPT_RT it may very well be
caused by PREEMPT_RT itself - but it could also be some real bug that
only triggers under PREEMPT_RT. Based on current bug trends i'd say the
likelyhood is 70% for this to be a genuine upstream bug, and 30% for
this to be a PREEMPT_RT artifact. (These days most PREEMPT_RT artifacts 
get detected by PREEMPT_RT's own debugging features - and all of them 
were enabled on this box. Due to its preemption model, PREEMPT_RT is 
pretty good at catching races that are near-impossible to trigger on the 
stock kernel. It already caught more than a dozen such upstream races in 
various kernel subsystems.)

	Ingo

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Herbert Xu]

Ingo Molnar <mingo@elte.hu> wrote:
> 
> i got one such message:
> 
> KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at
> net/netlink/af_netlink.c (126)

Interesting.  I've seen one report about this assertion before yours.
Unfortunately there was very little to go on there apart from the
fact that vrrpd was involved.

> this was on a box that is DSL connected and thus gets lots of trash 
> packets over the wire. It is running -RT ontop of 2.6.12-rc1, and got 
> this message after 2 days of uptime.

This assertion can only be caused by netlink applications.  What
netlink applications do you use on this machine? Examples include
ip(8), the ULOG target of iptables, vrrpd, etc.

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

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Ingo Molnar]

* Herbert Xu <herbert@gondor.apana.org.au> wrote:

> > this was on a box that is DSL connected and thus gets lots of trash 
> > packets over the wire. It is running -RT ontop of 2.6.12-rc1, and got 
> > this message after 2 days of uptime.
> 
> This assertion can only be caused by netlink applications.  What 
> netlink applications do you use on this machine? Examples include 
> ip(8), the ULOG target of iptables, vrrpd, etc.

no vrrpd on this box. There's ipsec and wshaper on the box - both use 
netlink? No ULOG target AFAIK (it's a pretty much stock FC4 install).

	Ingo

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Herbert Xu]

On Sun, Mar 27, 2005 at 03:38:11PM +0200, Ingo Molnar wrote:
> 
> no vrrpd on this box. There's ipsec and wshaper on the box - both use 

ipsec: Depends on whether you're using ipsec-tools or *swan.

The former doesn't use netlink while the latter does.

wshaper: Yes when it's setting things up.

> netlink? No ULOG target AFAIK (it's a pretty much stock FC4 install).

cat /proc/net/netlink

should tell you what's using it all the time.

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

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Ingo Molnar]

* Herbert Xu <herbert@gondor.apana.org.au> wrote:

> On Sun, Mar 27, 2005 at 03:38:11PM +0200, Ingo Molnar wrote:
> > 
> > no vrrpd on this box. There's ipsec and wshaper on the box - both use 
> 
> ipsec: Depends on whether you're using ipsec-tools or *swan.
> 
> The former doesn't use netlink while the latter does.

it's openswan/pluto.

> wshaper: Yes when it's setting things up.

so it could be both - the ipsec startup/restart script that is used on 
the box uses wshaper too.

> > netlink? No ULOG target AFAIK (it's a pretty much stock FC4 install).
> 
> cat /proc/net/netlink
> 
> should tell you what's using it all the time.

pluto (ipsec/openswan), dbus-daemon, hald.

(i guess the debug message should be extended to do a dump_stack() so 
that we see which process does?)

	Ingo

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Herbert Xu]

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

On Tue, Mar 29, 2005 at 01:49:26PM +0200, Ingo Molnar wrote:
> 
> (i guess the debug message should be extended to do a dump_stack() so 
> that we see which process does?)

Never mind.  I think I've found what it is.  The only thing I can't
figure out is why we're only seeing it now when this bug has been
around since day one.

In netlink_dump we're operating on sk after dropping the cb lock.
This is racy because the owner of the socket could close it after
we drop the cb lock.

This is possible because netlink_dump isn't always called from the
context of the process that owns the socket.  For instance, if there
is contention on rtnl then rtnetlink requests will be processed by
the process that owns the rtnl.

The solution is to hold a ref count on the socket before we drop
the cb lock.

Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>

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: 408 bytes --]

===== net/netlink/af_netlink.c 1.72 vs edited =====
--- 1.72/net/netlink/af_netlink.c	2005-03-23 14:17:09 +11:00
+++ edited/net/netlink/af_netlink.c	2005-03-30 16:24:27 +10:00
@@ -1080,9 +1080,11 @@
 	len = cb->dump(skb, cb);
 
 	if (len > 0) {
+		sock_hold(sk);
 		spin_unlock(&nlk->cb_lock);
 		skb_queue_tail(&sk->sk_receive_queue, skb);
 		sk->sk_data_ready(sk, len);
+		sock_put(sk);
 		return 0;
 	}
 

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[David S. Miller]

On Wed, 30 Mar 2005 18:26:40 +1000
Herbert Xu <herbert@gondor.apana.org.au> wrote:

> In netlink_dump we're operating on sk after dropping the cb lock.
> This is racy because the owner of the socket could close it after
> we drop the cb lock.
> 
> This is possible because netlink_dump isn't always called from the
> context of the process that owns the socket.  For instance, if there
> is contention on rtnl then rtnetlink requests will be processed by
> the process that owns the rtnl.
> 
> The solution is to hold a ref count on the socket before we drop
> the cb lock.
> 
> Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>

Applied, thanks Herbert.

Looks like 2.4.x needs the same fix, correct?

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Herbert Xu]

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

On Wed, Mar 30, 2005 at 05:02:36PM -0800, David S. Miller wrote:
> 
> Looks like 2.4.x needs the same fix, correct?

Indeed it does.  Here it is for 2.4.

In netlink_dump we're operating on sk after dropping the cb lock.
This is racy because the owner of the socket could close it after
we drop the cb lock.

This is possible because netlink_dump isn't always called from the
context of the process that owns the socket.  For instance, if there
is contention on rtnl then rtnetlink requests will be processed by
the process that owns the rtnl.

The solution is to hold a ref count on the socket before we drop
the cb lock.

Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>

I think I know why we're only seeing it now.  Without preemption
this race is very unlikely to trigger.  This plus the fact that
we now have a lot more netlink applications probably made it
just a tad more likely.

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: 420 bytes --]

===== net/netlink/af_netlink.c 1.21 vs edited =====
--- 1.21/net/netlink/af_netlink.c	2005-02-17 06:21:57 +11:00
+++ edited/net/netlink/af_netlink.c	2005-03-31 11:07:40 +10:00
@@ -981,9 +981,11 @@
 	len = cb->dump(skb, cb);
 
 	if (len > 0) {
+		sock_hold(sk);
 		spin_unlock(&sk->protinfo.af_netlink->cb_lock);
 		skb_queue_tail(&sk->receive_queue, skb);
 		sk->data_ready(sk, len);
+		sock_put(sk);
 		return 0;
 	}
 

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[David S. Miller]

On Thu, 31 Mar 2005 11:10:01 +1000
Herbert Xu <herbert@gondor.apana.org.au> wrote:

> On Wed, Mar 30, 2005 at 05:02:36PM -0800, David S. Miller wrote:
> > 
> > Looks like 2.4.x needs the same fix, correct?
> 
> Indeed it does.  Here it is for 2.4.

Applied, thanks Herbert.

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Krzysztof Oledzki]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 1051 bytes --]



On Wed, 30 Mar 2005, Herbert Xu wrote:

> On Tue, Mar 29, 2005 at 01:49:26PM +0200, Ingo Molnar wrote:
>>
>> (i guess the debug message should be extended to do a dump_stack() so
>> that we see which process does?)
>
> Never mind.  I think I've found what it is.  The only thing I can't
> figure out is why we're only seeing it now when this bug has been
> around since day one.
>
> In netlink_dump we're operating on sk after dropping the cb lock.
> This is racy because the owner of the socket could close it after
> we drop the cb lock.
>
> This is possible because netlink_dump isn't always called from the
> context of the process that owns the socket.  For instance, if there
> is contention on rtnl then rtnetlink requests will be processed by
> the process that owns the rtnl.
>
> The solution is to hold a ref count on the socket before we drop
> the cb lock.

OK. I'm no longer able to trigger this error. And the patch is 
already in the linux-2.6 repository. Thank you.

Best regards,

 			Krzysztof Olędzki

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Herbert Xu]

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

Hi Dave:

On Wed, Mar 30, 2005 at 05:02:36PM -0800, David S. Miller wrote:
> On Wed, 30 Mar 2005 18:26:40 +1000
> Herbert Xu <herbert@gondor.apana.org.au> wrote:
>
> > The solution is to hold a ref count on the socket before we drop
> > the cb lock.
> 
> Applied, thanks Herbert.

Unfortunately my patch only closed half the race.  There is still
a chunk of code between netlink_dump_start and netlink_dump that runs
outside the cb lock which isn't protected by an sk reference.

Here is a better patch which protects the entire netlink_dump function
with a sk reference.

The other call to netlink_dump by recvmsg is safe as the open file
descriptor already holds a reference.  As such the final sock_put
in netlink_dump can be turned into a __sock_put since there is at
least one reference held by the caller.

Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>

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: 708 bytes --]

===== net/netlink/af_netlink.c 1.73 vs edited =====
--- 1.73/net/netlink/af_netlink.c	2005-03-31 10:58:04 +10:00
+++ edited/net/netlink/af_netlink.c	2005-04-01 09:06:20 +10:00
@@ -1080,11 +1080,9 @@
 	len = cb->dump(skb, cb);
 
 	if (len > 0) {
-		sock_hold(sk);
 		spin_unlock(&nlk->cb_lock);
 		skb_queue_tail(&sk->sk_receive_queue, skb);
 		sk->sk_data_ready(sk, len);
-		sock_put(sk);
 		return 0;
 	}
 
@@ -1099,7 +1097,7 @@
 	spin_unlock(&nlk->cb_lock);
 
 	netlink_destroy_callback(cb);
-	sock_put(sk);
+	__sock_put(sk);
 	return 0;
 }
 
@@ -1138,9 +1136,11 @@
 		return -EBUSY;
 	}
 	nlk->cb = cb;
+	sock_hold(sk);
 	spin_unlock(&nlk->cb_lock);
 
 	netlink_dump(sk);
+	sock_put(sk);
 	return 0;
 }
 

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[Herbert Xu]

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

Hi Dave:

Here is the version for 2.4.
 
Unfortunately my patch only closed half the race.  There is still
a chunk of code between netlink_dump_start and netlink_dump that runs
outside the cb lock which isn't protected by an sk reference.

Here is a better patch which protects the entire netlink_dump function
with a sk reference.

The other call to netlink_dump by recvmsg is safe as the open file
descriptor already holds a reference.  As such the final sock_put
in netlink_dump can be turned into a __sock_put since there is at
least one reference held by the caller.

Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>
 
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: 758 bytes --]

--- linux-2.4/net/netlink/af_netlink.c.orig	2005-04-01 09:20:05.000000000 +1000
+++ linux-2.4/net/netlink/af_netlink.c	2005-04-01 09:21:06.000000000 +1000
@@ -981,11 +981,9 @@
 	len = cb->dump(skb, cb);
 
 	if (len > 0) {
-		sock_hold(sk);
 		spin_unlock(&sk->protinfo.af_netlink->cb_lock);
 		skb_queue_tail(&sk->receive_queue, skb);
 		sk->data_ready(sk, len);
-		sock_put(sk);
 		return 0;
 	}
 
@@ -1000,7 +998,7 @@
 	spin_unlock(&sk->protinfo.af_netlink->cb_lock);
 
 	netlink_destroy_callback(cb);
-	sock_put(sk);
+	__sock_put(sk);
 	return 0;
 }
 
@@ -1037,9 +1035,11 @@
 		return -EBUSY;
 	}
 	sk->protinfo.af_netlink->cb = cb;
+	sock_hold(sk);
 	spin_unlock(&sk->protinfo.af_netlink->cb_lock);
 
 	netlink_dump(sk);
+	sock_put(sk);
 	return 0;
 }
 

Re: KERNEL: assertion (!atomic_read(&sk->sk_rmem_alloc)) failed at net/netlink/af_netlink.c (126)

[David S. Miller]

On Fri, 1 Apr 2005 09:23:22 +1000
Herbert Xu <herbert@gondor.apana.org.au> wrote:

> Hi Dave:
> 
> Here is the version for 2.4.
>  
> Unfortunately my patch only closed half the race.

Both applied, thanks Herbert.

[NETLINK] cb_lock does not needs ref count on sk

[Herbert Xu]

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

Hi Dave:

Here is a little optimisation for the cb_lock used by netlink_dump.
While fixing that race earlier, I noticed that the reference count
held by cb_lock is completely useless.  The reason is that in order
to obtain the protection of the reference count, you have to take
the cb_lock.  But the only way to take the cb_lock is through
dereferencing the socket.

That is, you must already possess a reference count on the socket
before you can take advantage of the reference count held by cb_lock.
As a corollary, we can remve the reference count held by the cb_lock.

Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>

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: 585 bytes --]

===== net/netlink/af_netlink.c 1.75 vs edited =====
--- 1.75/net/netlink/af_netlink.c	2005-04-01 16:25:14 +10:00
+++ edited/net/netlink/af_netlink.c	2005-04-01 19:30:22 +10:00
@@ -374,7 +374,6 @@
 		nlk->cb->done(nlk->cb);
 		netlink_destroy_callback(nlk->cb);
 		nlk->cb = NULL;
-		__sock_put(sk);
 	}
 	spin_unlock(&nlk->cb_lock);
 
@@ -1100,7 +1099,6 @@
 	spin_unlock(&nlk->cb_lock);
 
 	netlink_destroy_callback(cb);
-	__sock_put(sk);
 	return 0;
 }
 
@@ -1139,7 +1137,6 @@
 		return -EBUSY;
 	}
 	nlk->cb = cb;
-	sock_hold(sk);
 	spin_unlock(&nlk->cb_lock);
 
 	netlink_dump(sk);

Re: [NETLINK] cb_lock does not needs ref count on sk

[David S. Miller]

On Fri, 1 Apr 2005 19:36:33 +1000
Herbert Xu <herbert@gondor.apana.org.au> wrote:

> Here is a little optimisation for the cb_lock used by netlink_dump.
> While fixing that race earlier, I noticed that the reference count
> held by cb_lock is completely useless.  The reason is that in order
> to obtain the protection of the reference count, you have to take
> the cb_lock.  But the only way to take the cb_lock is through
> dereferencing the socket.
> 
> That is, you must already possess a reference count on the socket
> before you can take advantage of the reference count held by cb_lock.
> As a corollary, we can remve the reference count held by the cb_lock.
> 
> Signed-off-by: Herbert Xu <herbert@gondor.apana.org.au>

Looks good, applied.