Re: mmotm 2010-04-05-16-09 uploaded

Re: mmotm 2010-04-05-16-09 uploaded

[Valdis.Kletnieks]

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

On Mon, 05 Apr 2010 16:09:45 PDT, akpm@linux-foundation.org said:
> The mm-of-the-moment snapshot 2010-04-05-16-09 has been uploaded to
> 
>    http://userweb.kernel.org/~akpm/mmotm/

Seen in dmesg, 2.6.34-rc2-mmotm0323 didn't do this. Tossing it at all the
likely suspects, hopefully somebody will recognize it and save me the
bisecting. ;)

[   11.488535] ctnetlink v0.93: registering with nfnetlink.
[   11.488579] 
[   11.488579] ===================================================
[   11.489529] [ INFO: suspicious rcu_dereference_check() usage. ]
[   11.489988] ---------------------------------------------------
[   11.490494] net/netfilter/nf_conntrack_ecache.c:88 invoked rcu_dereference_check() without protection!
[   11.491024] 
[   11.491024] other info that might help us debug this:
[   11.491025] 
[   11.492834] 
[   11.492835] rcu_scheduler_active = 1, debug_locks = 0
[   11.494124] 1 lock held by swapper/1:
[   11.494776]  #0:  (nf_ct_ecache_mutex){+.+...}, at: [<ffffffff8148c606>] nf_conntrack_register_notifier+0x1a/0x76
[   11.495505] 
[   11.495506] stack backtrace:
[   11.496927] Pid: 1, comm: swapper Not tainted 2.6.34-rc3-mmotm0405 #1
[   11.497668] Call Trace:
[   11.498419]  [<ffffffff810638c5>] lockdep_rcu_dereference+0xaa/0xb2
[   11.499185]  [<ffffffff8148c629>] nf_conntrack_register_notifier+0x3d/0x76
[   11.499967]  [<ffffffff81b5dd7b>] ctnetlink_init+0x71/0xd5
[   11.500775]  [<ffffffff81b5dd0a>] ? ctnetlink_init+0x0/0xd5
[   11.501579]  [<ffffffff810001ef>] do_one_initcall+0x59/0x14e
[   11.502396]  [<ffffffff81b3268a>] kernel_init+0x144/0x1ce
[   11.503218]  [<ffffffff81003514>] kernel_thread_helper+0x4/0x10
[   11.504047]  [<ffffffff8159cc00>] ? restore_args+0x0/0x30
[   11.504882]  [<ffffffff81b32546>] ? kernel_init+0x0/0x1ce
[   11.505715]  [<ffffffff81003510>] ? kernel_thread_helper+0x0/0x10
[   11.506636] ip_tables: (C) 2000-2006 Netfilter Core Team
[   11.507372] TCP bic registered


[-- Attachment #2: Type: application/pgp-signature, Size: 227 bytes --]

Re: mmotm 2010-04-05-16-09 uploaded

[Patrick McHardy]

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

Valdis.Kletnieks@vt.edu wrote:
> On Mon, 05 Apr 2010 16:09:45 PDT, akpm@linux-foundation.org said:
>> The mm-of-the-moment snapshot 2010-04-05-16-09 has been uploaded to
>>
>>    http://userweb.kernel.org/~akpm/mmotm/
> 
> Seen in dmesg, 2.6.34-rc2-mmotm0323 didn't do this. Tossing it at all the
> likely suspects, hopefully somebody will recognize it and save me the
> bisecting. ;)
> 
> [   11.488535] ctnetlink v0.93: registering with nfnetlink.
> [   11.488579] 
> [   11.488579] ===================================================
> [   11.489529] [ INFO: suspicious rcu_dereference_check() usage. ]
> [   11.489988] ---------------------------------------------------
> [   11.490494] net/netfilter/nf_conntrack_ecache.c:88 invoked rcu_dereference_check() without protection!
> [   11.491024] 
> [   11.491024] other info that might help us debug this:
> [   11.491025] 
> [   11.492834] 
> [   11.492835] rcu_scheduler_active = 1, debug_locks = 0
> [   11.494124] 1 lock held by swapper/1:
> [   11.494776]  #0:  (nf_ct_ecache_mutex){+.+...}, at: [<ffffffff8148c606>] nf_conntrack_register_notifier+0x1a/0x76
> [   11.495505] 

There are some unnecessary rcu_dereference() calls in the conntrack
notifier registration and unregistration functions.

Does this fix it?


[-- Attachment #2: x --]
[-- Type: text/plain, Size: 1834 bytes --]

diff --git a/net/netfilter/nf_conntrack_ecache.c b/net/netfilter/nf_conntrack_ecache.c
index d5a9bcd..849614a 100644
--- a/net/netfilter/nf_conntrack_ecache.c
+++ b/net/netfilter/nf_conntrack_ecache.c
@@ -81,11 +81,9 @@ EXPORT_SYMBOL_GPL(nf_ct_deliver_cached_events);
 int nf_conntrack_register_notifier(struct nf_ct_event_notifier *new)
 {
 	int ret = 0;
-	struct nf_ct_event_notifier *notify;
 
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_conntrack_event_cb);
-	if (notify != NULL) {
+	if (nf_conntrack_event_cb != NULL) {
 		ret = -EBUSY;
 		goto out_unlock;
 	}
@@ -101,11 +99,8 @@ EXPORT_SYMBOL_GPL(nf_conntrack_register_notifier);
 
 void nf_conntrack_unregister_notifier(struct nf_ct_event_notifier *new)
 {
-	struct nf_ct_event_notifier *notify;
-
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_conntrack_event_cb);
-	BUG_ON(notify != new);
+	BUG_ON(nf_conntrack_event_cb != new);
 	rcu_assign_pointer(nf_conntrack_event_cb, NULL);
 	mutex_unlock(&nf_ct_ecache_mutex);
 }
@@ -114,11 +109,9 @@ EXPORT_SYMBOL_GPL(nf_conntrack_unregister_notifier);
 int nf_ct_expect_register_notifier(struct nf_exp_event_notifier *new)
 {
 	int ret = 0;
-	struct nf_exp_event_notifier *notify;
 
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_expect_event_cb);
-	if (notify != NULL) {
+	if (nf_expect_event_cb != NULL) {
 		ret = -EBUSY;
 		goto out_unlock;
 	}
@@ -134,11 +127,8 @@ EXPORT_SYMBOL_GPL(nf_ct_expect_register_notifier);
 
 void nf_ct_expect_unregister_notifier(struct nf_exp_event_notifier *new)
 {
-	struct nf_exp_event_notifier *notify;
-
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_expect_event_cb);
-	BUG_ON(notify != new);
+	BUG_ON(nf_expect_event_cb != new);
 	rcu_assign_pointer(nf_expect_event_cb, NULL);
 	mutex_unlock(&nf_ct_ecache_mutex);
 }

Re: mmotm 2010-04-05-16-09 uploaded

[Valdis.Kletnieks]

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

On Thu, 08 Apr 2010 13:41:00 +0200, Patrick McHardy said:

> Valdis.Kletnieks@vt.edu wrote:
> > On Mon, 05 Apr 2010 16:09:45 PDT, akpm@linux-foundation.org said:
> >> The mm-of-the-moment snapshot 2010-04-05-16-09 has been uploaded to
> >>
> >>    http://userweb.kernel.org/~akpm/mmotm/
> > 
> > Seen in dmesg, 2.6.34-rc2-mmotm0323 didn't do this. Tossing it at all the
> > likely suspects, hopefully somebody will recognize it and save me the
> > bisecting. ;)
> > 
> > [   11.488535] ctnetlink v0.93: registering with nfnetlink.
> > [   11.488579] 
> > [   11.488579] ===================================================
> > [   11.489529] [ INFO: suspicious rcu_dereference_check() usage. ]
> > [   11.489988] ---------------------------------------------------
> > [   11.490494] net/netfilter/nf_conntrack_ecache.c:88 invoked rcu_dereference_check() without protection!
> > [   11.491024] 
> > [   11.491024] other info that might help us debug this:
> > [   11.491025] 
> > [   11.492834] 
> > [   11.492835] rcu_scheduler_active = 1, debug_locks = 0
> > [   11.494124] 1 lock held by swapper/1:
> > [   11.494776]  #0:  (nf_ct_ecache_mutex){+.+...}, at: [<ffffffff8148c606>] nf_conntrack_register_notifier+0x1a/0x76
> > [   11.495505] 
> 
> There are some unnecessary rcu_dereference() calls in the conntrack
> notifier registration and unregistration functions.
> 
> Does this fix it?

Well, it *changed* it.  Does the rcu_defererence_check() only fire on the
first time it hits something, so we've fixed the first one and now we get to
see the second one?

(For what it's worth, if this is going to be one-at-a-time whack-a-mole, I'm
OK on that, just want to know up front.)

[    9.299425] ip_tables: (C) 2000-2006 Netfilter Core Team
[    9.299486] 
[    9.299486] ===================================================
[    9.300499] [ INFO: suspicious rcu_dereference_check() usage. ]
[    9.301001] ---------------------------------------------------
[    9.301523] net/netfilter/nf_log.c:55 invoked rcu_dereference_check() without protection!
[    9.302066] 
[    9.302066] other info that might help us debug this:
[    9.302067] 
[    9.303748] 
[    9.303748] rcu_scheduler_active = 1, debug_locks = 0
[    9.304990] 1 lock held by swapper/1:
[    9.305645]  #0:  (nf_log_mutex){+.+...}, at: [<ffffffff8148427a>] nf_log_register+0x57/0x111
[    9.306342] 
[    9.306343] stack backtrace:
[    9.307729] Pid: 1, comm: swapper Not tainted 2.6.34-rc3-mmotm0405 #2
[    9.308447] Call Trace:
[    9.309170]  [<ffffffff810638c5>] lockdep_rcu_dereference+0xaa/0xb2
[    9.309935]  [<ffffffff81484301>] nf_log_register+0xde/0x111
[    9.310688]  [<ffffffff81b6064b>] ? log_tg_init+0x0/0x29
[    9.311465]  [<ffffffff81b60670>] log_tg_init+0x25/0x29
[    9.312233]  [<ffffffff810001ef>] do_one_initcall+0x59/0x14e
[    9.313030]  [<ffffffff81b3268a>] kernel_init+0x144/0x1ce
[    9.313819]  [<ffffffff81003514>] kernel_thread_helper+0x4/0x10
[    9.314625]  [<ffffffff8159cb80>] ? restore_args+0x0/0x30
[    9.315434]  [<ffffffff81b32546>] ? kernel_init+0x0/0x1ce
[    9.316224]  [<ffffffff81003510>] ? kernel_thread_helper+0x0/0x10
[    9.317037] TCP bic registered


[-- Attachment #2: Type: application/pgp-signature, Size: 227 bytes --]

Re: mmotm 2010-04-05-16-09 uploaded

[Patrick McHardy]

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

Valdis.Kletnieks@vt.edu wrote:
> On Thu, 08 Apr 2010 13:41:00 +0200, Patrick McHardy said:
>>> [   11.488579] ===================================================
>>> [   11.489529] [ INFO: suspicious rcu_dereference_check() usage. ]
>>> [   11.489988] ---------------------------------------------------
>>> [   11.490494] net/netfilter/nf_conntrack_ecache.c:88 invoked rcu_dereference_check() without protection!
>>> [   11.491024] 
>> There are some unnecessary rcu_dereference() calls in the conntrack
>> notifier registration and unregistration functions.
>>
>> Does this fix it?
> 
> Well, it *changed* it.  Does the rcu_defererence_check() only fire on the
> first time it hits something, so we've fixed the first one and now we get to
> see the second one?

It appears that way, otherwise you should have seen a second warning in
nf_conntrack_ecache the last time.

> (For what it's worth, if this is going to be one-at-a-time whack-a-mole, I'm
> OK on that, just want to know up front.)

I went through the other files and I believe this should be it.
We already removed most of these incorrect rcu_dereference()
calls a while back.

> [    9.299425] ip_tables: (C) 2000-2006 Netfilter Core Team
> [    9.299486] 
> [    9.299486] ===================================================
> [    9.300499] [ INFO: suspicious rcu_dereference_check() usage. ]
> [    9.301001] ---------------------------------------------------
> [    9.301523] net/netfilter/nf_log.c:55 invoked rcu_dereference_check() without protection!
> [    9.302066] 


[-- Attachment #2: x --]
[-- Type: text/plain, Size: 3053 bytes --]

diff --git a/net/netfilter/nf_conntrack_ecache.c b/net/netfilter/nf_conntrack_ecache.c
index d5a9bcd..849614a 100644
--- a/net/netfilter/nf_conntrack_ecache.c
+++ b/net/netfilter/nf_conntrack_ecache.c
@@ -81,11 +81,9 @@ EXPORT_SYMBOL_GPL(nf_ct_deliver_cached_events);
 int nf_conntrack_register_notifier(struct nf_ct_event_notifier *new)
 {
 	int ret = 0;
-	struct nf_ct_event_notifier *notify;
 
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_conntrack_event_cb);
-	if (notify != NULL) {
+	if (nf_conntrack_event_cb != NULL) {
 		ret = -EBUSY;
 		goto out_unlock;
 	}
@@ -101,11 +99,8 @@ EXPORT_SYMBOL_GPL(nf_conntrack_register_notifier);
 
 void nf_conntrack_unregister_notifier(struct nf_ct_event_notifier *new)
 {
-	struct nf_ct_event_notifier *notify;
-
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_conntrack_event_cb);
-	BUG_ON(notify != new);
+	BUG_ON(nf_conntrack_event_cb != new);
 	rcu_assign_pointer(nf_conntrack_event_cb, NULL);
 	mutex_unlock(&nf_ct_ecache_mutex);
 }
@@ -114,11 +109,9 @@ EXPORT_SYMBOL_GPL(nf_conntrack_unregister_notifier);
 int nf_ct_expect_register_notifier(struct nf_exp_event_notifier *new)
 {
 	int ret = 0;
-	struct nf_exp_event_notifier *notify;
 
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_expect_event_cb);
-	if (notify != NULL) {
+	if (nf_expect_event_cb != NULL) {
 		ret = -EBUSY;
 		goto out_unlock;
 	}
@@ -134,11 +127,8 @@ EXPORT_SYMBOL_GPL(nf_ct_expect_register_notifier);
 
 void nf_ct_expect_unregister_notifier(struct nf_exp_event_notifier *new)
 {
-	struct nf_exp_event_notifier *notify;
-
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_expect_event_cb);
-	BUG_ON(notify != new);
+	BUG_ON(nf_expect_event_cb != new);
 	rcu_assign_pointer(nf_expect_event_cb, NULL);
 	mutex_unlock(&nf_ct_ecache_mutex);
 }
diff --git a/net/netfilter/nf_log.c b/net/netfilter/nf_log.c
index 015725a..908f599 100644
--- a/net/netfilter/nf_log.c
+++ b/net/netfilter/nf_log.c
@@ -35,7 +35,6 @@ static struct nf_logger *__find_logger(int pf, const char *str_logger)
 /* return EEXIST if the same logger is registred, 0 on success. */
 int nf_log_register(u_int8_t pf, struct nf_logger *logger)
 {
-	const struct nf_logger *llog;
 	int i;
 
 	if (pf >= ARRAY_SIZE(nf_loggers))
@@ -52,8 +51,7 @@ int nf_log_register(u_int8_t pf, struct nf_logger *logger)
 	} else {
 		/* register at end of list to honor first register win */
 		list_add_tail(&logger->list[pf], &nf_loggers_l[pf]);
-		llog = rcu_dereference(nf_loggers[pf]);
-		if (llog == NULL)
+		if (nf_loggers[pf] == NULL)
 			rcu_assign_pointer(nf_loggers[pf], logger);
 	}
 
@@ -65,13 +63,11 @@ EXPORT_SYMBOL(nf_log_register);
 
 void nf_log_unregister(struct nf_logger *logger)
 {
-	const struct nf_logger *c_logger;
 	int i;
 
 	mutex_lock(&nf_log_mutex);
 	for (i = 0; i < ARRAY_SIZE(nf_loggers); i++) {
-		c_logger = rcu_dereference(nf_loggers[i]);
-		if (c_logger == logger)
+		if (nf_loggers[i] == logger)
 			rcu_assign_pointer(nf_loggers[i], NULL);
 		list_del(&logger->list[i]);
 	}

Re: mmotm 2010-04-05-16-09 uploaded

[Valdis.Kletnieks]

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

On Thu, 08 Apr 2010 17:36:07 +0200, Patrick McHardy said:

> Valdis.Kletnieks@vt.edu wrote:

> > Well, it *changed* it.  Does the rcu_defererence_check() only fire on the
> > first time it hits something, so we've fixed the first one and now we get to
> > see the second one?
> 
> It appears that way, otherwise you should have seen a second warning in
> nf_conntrack_ecache the last time.
> 
> > (For what it's worth, if this is going to be one-at-a-time whack-a-mole, I'm
> > OK on that, just want to know up front.)
> 
> I went through the other files and I believe this should be it.
> We already removed most of these incorrect rcu_dereference()
> calls a while back.

Confirming - the second version of the patch fixes all the network-related
RCU complaints I've been able to trigger...

[-- Attachment #2: Type: application/pgp-signature, Size: 227 bytes --]

Re: mmotm 2010-04-05-16-09 uploaded

[Patrick McHardy]

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

Valdis.Kletnieks@vt.edu wrote:
> On Thu, 08 Apr 2010 17:36:07 +0200, Patrick McHardy said:
> 
>> Valdis.Kletnieks@vt.edu wrote:
> 
>>> Well, it *changed* it.  Does the rcu_defererence_check() only fire on the
>>> first time it hits something, so we've fixed the first one and now we get to
>>> see the second one?
>> It appears that way, otherwise you should have seen a second warning in
>> nf_conntrack_ecache the last time.
>>
>>> (For what it's worth, if this is going to be one-at-a-time whack-a-mole, I'm
>>> OK on that, just want to know up front.)
>> I went through the other files and I believe this should be it.
>> We already removed most of these incorrect rcu_dereference()
>> calls a while back.
> 
> Confirming - the second version of the patch fixes all the network-related
> RCU complaints I've been able to trigger...

Thanks. I've added the attached commit to the nf-next tree. I'll push
it to Dave shortly so this can get included in the next tree.


[-- Attachment #2: x --]
[-- Type: text/plain, Size: 4009 bytes --]

>From ed86308f6179d8fa6151c2d0f652aad0091548e2 Mon Sep 17 00:00:00 2001
From: Patrick McHardy <kaber@trash.net>
Date: Fri, 9 Apr 2010 16:42:15 +0200
Subject: [PATCH] netfilter: remove invalid rcu_dereference() calls

The CONFIG_PROVE_RCU option discovered a few invalid uses of
rcu_dereference() in netfilter. In all these cases, the code code
intends to check whether a pointer is already assigned when
performing registration or whether the assigned pointer matches
when performing unregistration. The entire registration/
unregistration is protected by a mutex, so we don't need the
rcu_dereference() calls.

Reported-by: Valdis Kletnieks <Valdis.Kletnieks@vt.edu>
Tested-by: Valdis Kletnieks <Valdis.Kletnieks@vt.edu>
Signed-off-by: Patrick McHardy <kaber@trash.net>
---
 net/netfilter/nf_conntrack_ecache.c |   18 ++++--------------
 net/netfilter/nf_log.c              |    8 ++------
 2 files changed, 6 insertions(+), 20 deletions(-)

diff --git a/net/netfilter/nf_conntrack_ecache.c b/net/netfilter/nf_conntrack_ecache.c
index d5a9bcd..849614a 100644
--- a/net/netfilter/nf_conntrack_ecache.c
+++ b/net/netfilter/nf_conntrack_ecache.c
@@ -81,11 +81,9 @@ EXPORT_SYMBOL_GPL(nf_ct_deliver_cached_events);
 int nf_conntrack_register_notifier(struct nf_ct_event_notifier *new)
 {
 	int ret = 0;
-	struct nf_ct_event_notifier *notify;
 
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_conntrack_event_cb);
-	if (notify != NULL) {
+	if (nf_conntrack_event_cb != NULL) {
 		ret = -EBUSY;
 		goto out_unlock;
 	}
@@ -101,11 +99,8 @@ EXPORT_SYMBOL_GPL(nf_conntrack_register_notifier);
 
 void nf_conntrack_unregister_notifier(struct nf_ct_event_notifier *new)
 {
-	struct nf_ct_event_notifier *notify;
-
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_conntrack_event_cb);
-	BUG_ON(notify != new);
+	BUG_ON(nf_conntrack_event_cb != new);
 	rcu_assign_pointer(nf_conntrack_event_cb, NULL);
 	mutex_unlock(&nf_ct_ecache_mutex);
 }
@@ -114,11 +109,9 @@ EXPORT_SYMBOL_GPL(nf_conntrack_unregister_notifier);
 int nf_ct_expect_register_notifier(struct nf_exp_event_notifier *new)
 {
 	int ret = 0;
-	struct nf_exp_event_notifier *notify;
 
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_expect_event_cb);
-	if (notify != NULL) {
+	if (nf_expect_event_cb != NULL) {
 		ret = -EBUSY;
 		goto out_unlock;
 	}
@@ -134,11 +127,8 @@ EXPORT_SYMBOL_GPL(nf_ct_expect_register_notifier);
 
 void nf_ct_expect_unregister_notifier(struct nf_exp_event_notifier *new)
 {
-	struct nf_exp_event_notifier *notify;
-
 	mutex_lock(&nf_ct_ecache_mutex);
-	notify = rcu_dereference(nf_expect_event_cb);
-	BUG_ON(notify != new);
+	BUG_ON(nf_expect_event_cb != new);
 	rcu_assign_pointer(nf_expect_event_cb, NULL);
 	mutex_unlock(&nf_ct_ecache_mutex);
 }
diff --git a/net/netfilter/nf_log.c b/net/netfilter/nf_log.c
index 015725a..908f599 100644
--- a/net/netfilter/nf_log.c
+++ b/net/netfilter/nf_log.c
@@ -35,7 +35,6 @@ static struct nf_logger *__find_logger(int pf, const char *str_logger)
 /* return EEXIST if the same logger is registred, 0 on success. */
 int nf_log_register(u_int8_t pf, struct nf_logger *logger)
 {
-	const struct nf_logger *llog;
 	int i;
 
 	if (pf >= ARRAY_SIZE(nf_loggers))
@@ -52,8 +51,7 @@ int nf_log_register(u_int8_t pf, struct nf_logger *logger)
 	} else {
 		/* register at end of list to honor first register win */
 		list_add_tail(&logger->list[pf], &nf_loggers_l[pf]);
-		llog = rcu_dereference(nf_loggers[pf]);
-		if (llog == NULL)
+		if (nf_loggers[pf] == NULL)
 			rcu_assign_pointer(nf_loggers[pf], logger);
 	}
 
@@ -65,13 +63,11 @@ EXPORT_SYMBOL(nf_log_register);
 
 void nf_log_unregister(struct nf_logger *logger)
 {
-	const struct nf_logger *c_logger;
 	int i;
 
 	mutex_lock(&nf_log_mutex);
 	for (i = 0; i < ARRAY_SIZE(nf_loggers); i++) {
-		c_logger = rcu_dereference(nf_loggers[i]);
-		if (c_logger == logger)
+		if (nf_loggers[i] == logger)
 			rcu_assign_pointer(nf_loggers[i], NULL);
 		list_del(&logger->list[i]);
 	}
-- 
1.7.0.4