locking api self-test hanging

PATCH In review Andrew Morton 9 participants 21 messages Feb 3, 2008 – Mar 5, 2008

Subsystems (3)

Networking Network drivers Generic include/asm header files

lore

Share & tools

lore

Andrew Morton

author

2008-02-03 23:02 UTC #0 lore raw

With current mainline I'm getting intermittent hangs here:

	http://userweb.kernel.org/~akpm/p2033590.jpg

with this config:

http://userweb.kernel.org/~akpm/config-sony.txt

on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.

Andrew Morton

author

2008-02-03 23:08 UTC #1 lore raw

Quoted 12 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…

With current mainline I'm getting intermittent hangs here:
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.

The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().

These things make bisecting all the other bugs rather hard.

Andrew Morton

author

2008-02-04 12:43 UTC #2 lore raw

Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…

Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:

Quoted 8 lines

Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.

CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.

Quoted 3 lines

The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().

And I've fully bisected this hang twice and both times came up with

commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7

Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800

[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.

which is stupid because that patch doesn't do anything.

However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.

I'd say it's some timing thing in netpoll/netconsole/napi/etc.

Andrew Morton

author

2008-02-04 13:04 UTC #3 lore raw

Quoted 28 lines · On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]>…

Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…
Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:
Quoted 8 lines
Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.
CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
Quoted 3 lines
The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800

Quoted 7 lines

[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.

After disabling both CONFIG_DEBUG_LOCKING_API_SELFTESTS and netconsole (using current mainline) I get a login prompt, and also...

[    5.181668] SELinux: policy loaded with handle_unknown=deny
[    5.183315] type=1403 audit(1202100038.157:3): policy loaded auid=4294967295 ses=4294967295
[    5.822073] SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts
[    7.819146] ------------[ cut here ]------------
[    7.819146] WARNING: at kernel/lockdep.c:2033 trace_hardirqs_on+0x9b/0x10d()
[    7.819146] Modules linked in: generic ext3 jbd ide_disk ide_core
[    7.819146] Pid: 399, comm: hwclock Not tainted 2.6.24 #4
[    7.819146]  [<c011d140>] warn_on_slowpath+0x41/0x51
[    7.819146]  [<c01364a9>] ? lock_release_holdtime+0x50/0x56
[    7.819146]  [<c013770c>] ? check_usage_forwards+0x19/0x3b
[    7.819146]  [<c01390c4>] ? __lock_acquire+0xac3/0xb0b
[    7.819146]  [<c0108c98>] ? native_sched_clock+0x8b/0x9f
[    7.819146]  [<c01364a9>] ? lock_release_holdtime+0x50/0x56
[    7.819146]  [<c030ca6c>] ? _spin_unlock_irq+0x22/0x42
[    7.819146]  [<c013848b>] trace_hardirqs_on+0x9b/0x10d
[    7.819146]  [<c030ca6c>] _spin_unlock_irq+0x22/0x42
[    7.819146]  [<c011481e>] hpet_rtc_interrupt+0xdf/0x290
[    7.819146]  [<c014ea90>] handle_IRQ_event+0x1a/0x46
[    7.819146]  [<c014f8ea>] handle_edge_irq+0xbe/0xff
[    7.819146]  [<c0106e08>] do_IRQ+0x6d/0x84
[    7.819146]  [<c0105596>] common_interrupt+0x2e/0x34
[    7.819146]  [<c013007b>] ? ktime_get_ts+0x8/0x3f
[    7.819146]  [<c0139420>] ? lock_release+0x167/0x16f
[    7.819146]  [<c017974a>] ? core_sys_select+0x2c/0x327
[    7.819146]  [<c0179792>] core_sys_select+0x74/0x327
[    7.819146]  [<c0108c98>] ? native_sched_clock+0x8b/0x9f
[    7.819146]  [<c01364a9>] ? lock_release_holdtime+0x50/0x56
[    7.819146]  [<c030ca6c>] ? _spin_unlock_irq+0x22/0x42
[    7.819146]  [<c01384d6>] ? trace_hardirqs_on+0xe6/0x10d
[    7.819146]  [<c030ca77>] ? _spin_unlock_irq+0x2d/0x42
[    7.819146]  [<c023b437>] ? rtc_do_ioctl+0x11b/0x677
[    7.819146]  [<c01c487e>] ? inode_has_perm+0x5e/0x68
[    7.819146]  [<c01364a9>] ? lock_release_holdtime+0x50/0x56
[    7.819146]  [<c0108c98>] ? native_sched_clock+0x8b/0x9f
[    7.819146]  [<c01c490b>] ? file_has_perm+0x83/0x8c
[    7.819146]  [<c023ba08>] ? rtc_ioctl+0xf/0x11
[    7.819146]  [<c017898d>] ? do_ioctl+0x55/0x67
[    7.819146]  [<c0179d15>] sys_select+0x93/0x163
[    7.819146]  [<c0104b39>] ? sysenter_past_esp+0x9a/0xa5
[    7.819146]  [<c0104afe>] sysenter_past_esp+0x5f/0xa5
[    7.819146]  =======================
[    7.819146] ---[ end trace 96540ca301ffb84c ]---
[    7.819210] rtc: lost 6 interrupts
[    7.870668] type=1400 audit(1202128840.794:4): avc:  denied  { audit_write } for  pid=399 comm="hwclock" capability=29 scontext=system_u:system_r:hwclock_t:s0 tcontext=system_u:system_r:hwclock_t:s0 tclass=capability
[    9.538866] input: PC Speaker as /class/input/input5

Because hpet_rtc_interrupt()'s call to get_rtc_time() ends up resolving to include/asm-generic/rtc.h's (hilariously inlined) get_rtc_time(), which does spin_unlock_irq() from hard IRQ context.

That warning in lockdep.c should have a comment explaining to readers under which circumstances it will trigger, and what they did wrong. In fact if I've interpreted it correctly I don't see why it's a DEBUG_LOCKS_WARN_ON thing at all? It should be a first-class lockdep warning?

The obvious patch fixes it:

include/asm-generic/rtc.h renamed from include/asm-generic/rtc.h~a +7 -4

@@ -35,10 +35,11 @@
 static inline unsigned char rtc_is_updating(void)
 {
 	unsigned char uip;
+	unsigned long flags;
 
-	spin_lock_irq(&rtc_lock);
+	spin_lock_irqsave(&rtc_lock, flags);
 	uip = (CMOS_READ(RTC_FREQ_SELECT) & RTC_UIP);
-	spin_unlock_irq(&rtc_lock);
+	spin_unlock_irqrestore(&rtc_lock, flags);
 	return uip;
 }

@@ -46,6 +47,8 @@ static inline unsigned int get_rtc_time(
 {
 	unsigned long uip_watchdog = jiffies;
 	unsigned char ctrl;
+	unsigned long flags;
+
 #ifdef CONFIG_MACH_DECSTATION
 	unsigned int real_year;
 #endif

@@ -72,7 +75,7 @@ static inline unsigned int get_rtc_time(
 	 * RTC has RTC_DAY_OF_WEEK, we ignore it, as it is only updated
 	 * by the RTC when initially set to a non-zero value.
 	 */
-	spin_lock_irq(&rtc_lock);
+	spin_lock_irqsave(&rtc_lock, flags);
 	time->tm_sec = CMOS_READ(RTC_SECONDS);
 	time->tm_min = CMOS_READ(RTC_MINUTES);
 	time->tm_hour = CMOS_READ(RTC_HOURS);

@@ -83,7 +86,7 @@ static inline unsigned int get_rtc_time(
 	real_year = CMOS_READ(RTC_DEC_YEAR);
 #endif
 	ctrl = CMOS_READ(RTC_CONTROL);
-	spin_unlock_irq(&rtc_lock);
+	spin_unlock_irqrestore(&rtc_lock, flags);
 
 	if (!(ctrl & RTC_DM_BINARY) || RTC_ALWAYS_BCD)
 	{

but that code really needs help.

Bernhard, I believe the checklist items in Documentation/SubmitChecklist would have prevented this at the source.

ObProcessObservation: afacit the offending commit went mailing list -> git-x86 -> mainline in about three days flat, a week after the merge window had opened.

Peter Zijlstra

2008-02-04 13:15 UTC #4 lore raw

Quoted 9 lines · Andrew Morton

After disabling both CONFIG_DEBUG_LOCKING_API_SELFTESTS and netconsole (using current mainline) I get a login prompt, and also...
[    7.819146] WARNING: at kernel/lockdep.c:2033 trace_hardirqs_on+0x9b/0x10d()
That warning in lockdep.c should have a comment explaining to readers under which circumstances it will trigger, and what they did wrong. In fact if I've interpreted it correctly I don't see why it's a DEBUG_LOCKS_WARN_ON thing at all? It should be a first-class lockdep warning?

Agreed, I'll make lockdep print a nice error.

Bernhard Walle

2008-02-05 13:23 UTC #5 lore raw

In reply to Andrew Morton

Quoted 2 lines · Andrew Morton

but that code really needs help.

Using spin_lock_irqsave() is what rtc_get_rtc_time() does which was used before I changed to get_rtc_time() does. So it should be ok. I missed that difference. However, I agree with you the whole RTC "emulation" per HPET is a bit unclean. However, I have too little experience in this code area to come up with a proper redesign. I just ported it from the old RTC to the new RTC module interface.

Quoted 2 lines

Bernhard, I believe the checklist items in Documentation/SubmitChecklist would have prevented this at the source.

Yes. I must admit that I didn't know that document. I used checkpatch.pl, but that's of course only for coding style. I'll try to follow the points in SubmitChecklist in future.

Bernhard

Andrew Morton

author

2008-02-04 13:18 UTC #6 lore raw

In reply to Andrew Morton

Quoted 28 lines · On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]>…

Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…
Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:
Quoted 8 lines
Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.
CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
Quoted 3 lines
The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800

Quoted 9 lines

[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.
I'd say it's some timing thing in netpoll/netconsole/napi/etc.

I expect the locking API self-tests are innocent - the netconsole lockup happened to strike during the locking API tests and fooled me. When I disabled those tests, the netconsole lockup struck later on.

Andrew Morton

author

2008-02-06 08:34 UTC #7 lore raw

In reply to Andrew Morton

Quoted 28 lines · On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]>…

Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…
Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:
Quoted 8 lines
Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.
CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
Quoted 3 lines
The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800

Quoted 9 lines

[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.
I'd say it's some timing thing in netpoll/netconsole/napi/etc.

I'm seeing this netconsole hang on a second machine now. Current mainline. It also has e100. This one is SMP ancient PIII.

Config: http://userweb.kernel.org/~akpm/config-vmm.txt

Andrew Morton

author

2008-02-06 09:16 UTC #8 lore raw

Quoted 37 lines · On Wed, 6 Feb 2008 00:34:12 -0800 Andrew Morton <[email protected]>…

Quoted 35 lines · On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]>…
Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…
Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:
Quoted 8 lines
Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.
CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
Quoted 3 lines
The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800
[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.

Quoted 8 lines

Quoted 2 lines
I'd say it's some timing thing in netpoll/netconsole/napi/etc.
I'm seeing this netconsole hang on a second machine now. Current mainline. It also has e100. This one is SMP ancient PIII.
Config: http://userweb.kernel.org/~akpm/config-vmm.txt

I can reproduce this on a third machine: the t61p laptop: dual x86_64 with e1000.

It seems to need quite a lot of printk activity to make it happen. Turning on initcall_debug is a suitable way of triggering it.

Andrew Morton

author

2008-03-04 05:06 UTC #9 lore raw

Quoted 45 lines · On Wed, 6 Feb 2008 01:16:43 -0800 Andrew Morton <[email protected]>…

Quoted 43 lines · On Wed, 6 Feb 2008 00:34:12 -0800 Andrew Morton <[email protected]>…
Quoted 28 lines · On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]>…
Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…
Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:
Quoted 8 lines
Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.
CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
Quoted 3 lines
The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800
Quoted 9 lines
[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.
I'd say it's some timing thing in netpoll/netconsole/napi/etc.
I'm seeing this netconsole hang on a second machine now. Current mainline. It also has e100. This one is SMP ancient PIII.

Quoted 9 lines

Quoted 2 lines
Config: http://userweb.kernel.org/~akpm/config-vmm.txt
I can reproduce this on a third machine: the t61p laptop: dual x86_64 with e1000.
It seems to need quite a lot of printk activity to make it happen. Turning on initcall_debug is a suitable way of triggering it.

This netconsole regression is still present in current mainline. Rafael, can you please add it to the list?

It's strange that I can hit it on three separate machines with e100 and e1000 yet nobody else has reported it (afaik). Is nobody using netconsole?

Ingo Molnar

2008-03-04 08:07 UTC #10 lore raw

PATCH 1/1 mark netconsole broken

Quoted 6 lines · Andrew Morton

This netconsole regression is still present in current mainline. Rafael, can you please add it to the list?
It's strange that I can hit it on three separate machines with e100 and e1000 yet nobody else has reported it (afaik). Is nobody using netconsole?

i'd suggest the patch below, to mark it broken.

Ingo

---
 drivers/net/Kconfig |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

drivers/net/Kconfig +1 -1

Index: linux/drivers/net/Kconfig
===================================================================
@@ -3109,7 +3109,7 @@ config NET_FC
 
 config NETCONSOLE
 	tristate "Network console logging support (EXPERIMENTAL)"
-	depends on EXPERIMENTAL
+	depends on EXPERIMENTAL && BROKEN
 	---help---
 	If you want to log kernel messages over the network, enable this.
 	See <file:Documentation/networking/netconsole.txt> for details.

Randy Dunlap

2008-03-04 16:21 UTC #11 lore raw

Re: [patch] mark netconsole broken

Quoted 9 lines · On Tue, 4 Mar 2008 09:06:44 +0100 Ingo Molnar wrote:

Quoted 6 lines · Andrew Morton
This netconsole regression is still present in current mainline. Rafael, can you please add it to the list?
It's strange that I can hit it on three separate machines with e100 and e1000 yet nobody else has reported it (afaik). Is nobody using netconsole?

Sorry, I don't read 100% of any mailing list.

I use netconsole on my automated testing systems daily or at least as often as there is a linus (-git) or -mm release. It's still working for me, but I'm not using an e100[0] driver, I'm using a Broadcom.

Quoted 13 lines

i'd suggest the patch below, to mark it broken.
Ingo
---
 drivers/net/Kconfig |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
Index: linux/drivers/net/Kconfig
===================================================================

drivers/net/Kconfig config NET_FC · line 3115

Quoted 8 lines

drivers/net/Kconfig +1 -1

@@ -3109,7 +3109,7 @@ config NET_FC
 
 config NETCONSOLE
 	tristate "Network console logging support (EXPERIMENTAL)"
-	depends on EXPERIMENTAL
+	depends on EXPERIMENTAL && BROKEN
 	---help---
 	If you want to log kernel messages over the network, enable this.
 	See <file:Documentation/networking/netconsole.txt> for details.

---
~Randy

David Miller

maintainer

2008-03-04 20:30 UTC #12 lore raw

Re: [patch] mark netconsole broken

In reply to Ingo Molnar

From: Ingo Molnar <[email protected]>
Date: Tue, 4 Mar 2008 09:06:44 +0100

Quoted 1 line

i'd suggest the patch below, to mark it broken.

Why bother when we know what the bug is and can fix it? :-)

commit d9452e9f81e997cbd0c9bface8d2c2a4b064cc3e

Author: David S. Miller <[email protected]>
Date:   Tue Mar 4 12:28:49 2008 -0800

[NETPOLL]: Revert two bogus cleanups that broke netconsole.

Based upon a report by Andrew Morton and code analysis done by Jarek Poplawski.

This reverts 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7 ("[NETPOLL]:
Kill NETPOLL_RX_DROP, set but never tested.") and c7b6ea24b43afb5749cb704e143df19d70e23dea ("[NETPOLL]: Don't need rx_flags.").

The rx_flags did get tested for zero vs. non-zero and therefore we do need those tests and that code which sets NETPOLL_RX_DROP et al.

Signed-off-by David S. Miller <[email protected]>

include/linux/netpoll.h +4 -3

index a0525a1..e3d7959 100644
@@ -25,6 +25,7 @@ struct netpoll {
 
 struct netpoll_info {
 	atomic_t refcnt;
+	int rx_flags;
 	spinlock_t rx_lock;
 	struct netpoll *rx_np; /* netpoll that registered an rx_hook */
 	struct sk_buff_head arp_tx; /* list of arp requests to reply to */

@@ -50,12 +51,12 @@ static inline int netpoll_rx(struct sk_buff *skb)
 	unsigned long flags;
 	int ret = 0;
 
-	if (!npinfo || !npinfo->rx_np)
+	if (!npinfo || (!npinfo->rx_np && !npinfo->rx_flags))
 		return 0;
 
 	spin_lock_irqsave(&npinfo->rx_lock, flags);
-	/* check rx_np again with the lock held */
-	if (npinfo->rx_np && __netpoll_rx(skb))
+	/* check rx_flags again with the lock held */
+	if (npinfo->rx_flags && __netpoll_rx(skb))
 		ret = 1;
 	spin_unlock_irqrestore(&npinfo->rx_lock, flags);

net/core/netpoll.c +8 -4

index 6faa128..4b7e756 100644
@@ -39,6 +39,8 @@ static struct sk_buff_head skb_pool;
 static atomic_t trapped;
 
 #define USEC_PER_POLL	50
+#define NETPOLL_RX_ENABLED  1
+#define NETPOLL_RX_DROP     2
 
 #define MAX_SKB_SIZE \
 		(MAX_UDP_CHUNK + sizeof(struct udphdr) + \

@@ -126,11 +128,13 @@ static int poll_one_napi(struct netpoll_info *npinfo,
 	if (!test_bit(NAPI_STATE_SCHED, &napi->state))
 		return budget;
 
+	npinfo->rx_flags |= NETPOLL_RX_DROP;
 	atomic_inc(&trapped);
 
 	work = napi->poll(napi, budget);
 
 	atomic_dec(&trapped);
+	npinfo->rx_flags &= ~NETPOLL_RX_DROP;
 
 	return budget - work;
 }

@@ -472,7 +476,7 @@ int __netpoll_rx(struct sk_buff *skb)
 	if (skb->dev->type != ARPHRD_ETHER)
 		goto out;
 
-	/* if receive ARP during middle of NAPI poll, then queue */
+	/* check if netpoll clients need ARP */
 	if (skb->protocol == htons(ETH_P_ARP) &&
 	    atomic_read(&trapped)) {
 		skb_queue_tail(&npi->arp_tx, skb);

@@ -534,9 +538,6 @@ int __netpoll_rx(struct sk_buff *skb)
 	return 1;
 
 out:
-	/* If packet received while already in poll then just
-	 * silently drop.
-	 */
 	if (atomic_read(&trapped)) {
 		kfree_skb(skb);
 		return 1;

@@ -675,6 +676,7 @@ int netpoll_setup(struct netpoll *np)
 			goto release;
 		}
 
+		npinfo->rx_flags = 0;
 		npinfo->rx_np = NULL;
 
 		spin_lock_init(&npinfo->rx_lock);

@@ -756,6 +758,7 @@ int netpoll_setup(struct netpoll *np)
 
 	if (np->rx_hook) {
 		spin_lock_irqsave(&npinfo->rx_lock, flags);
+		npinfo->rx_flags |= NETPOLL_RX_ENABLED;
 		npinfo->rx_np = np;
 		spin_unlock_irqrestore(&npinfo->rx_lock, flags);
 	}

@@ -797,6 +800,7 @@ void netpoll_cleanup(struct netpoll *np)
 			if (npinfo->rx_np == np) {
 				spin_lock_irqsave(&npinfo->rx_lock, flags);
 				npinfo->rx_np = NULL;
+				npinfo->rx_flags &= ~NETPOLL_RX_ENABLED;
 				spin_unlock_irqrestore(&npinfo->rx_lock, flags);
 			}

Ingo Molnar

2008-03-04 20:52 UTC #13 lore raw

Re: [patch] mark netconsole broken

Quoted 6 lines · David Miller

From: Ingo Molnar <[email protected]>
Date: Tue, 4 Mar 2008 09:06:44 +0100
Quoted 1 line
i'd suggest the patch below, to mark it broken.
Why bother when we know what the bug is and can fix it? :-)

music to my ears :-)

Ingo

Jarek Poplawski

2008-03-04 08:39 UTC #14 lore raw

In reply to Andrew Morton

On 04-03-2008 06:05, Andrew Morton wrote:
...

Quoted 9 lines

Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800
[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.

...or maybe apparently doesn't do anything?

@@ -128,13 +127,11 @@ static int poll_one_napi(struct netpoll_info *npinfo,

        if (!test_bit(NAPI_STATE_SCHED, &napi->state))
                return budget;

- npinfo->rx_flags |= NETPOLL_RX_DROP;

But in a next patch we can see:

@@ -51,12 +50,12 @@ static inline int netpoll_rx(struct sk_buff *skb)

        unsigned long flags;
        int ret = 0;

-       if (!npinfo || (!npinfo->rx_np && !npinfo->rx_flags))
+       if (!npinfo || !npinfo->rx_np)

So, it seems rx_flags could have been tested here for NETPOLL_RX_DROP yet?

Regards,
Jarek P.

Andrew Morton

author

2008-03-04 09:11 UTC #15 lore raw

Quoted 30 lines · On Tue, 4 Mar 2008 08:40:24 +0000 Jarek Poplawski <[email protected]> wrote:

On 04-03-2008 06:05, Andrew Morton wrote:
...
Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800
[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
...or maybe apparently doesn't do anything?
(quoted diff) +0 -1
@@ -128,13 +127,11 @@ static int poll_one_napi(struct netpoll_info *npinfo,
        if (!test_bit(NAPI_STATE_SCHED, &napi->state))
                return budget;
 
-       npinfo->rx_flags |= NETPOLL_RX_DROP;
 
 
But in a next patch we can see:
(quoted diff) +1 -1
@@ -51,12 +50,12 @@ static inline int netpoll_rx(struct sk_buff *skb)
        unsigned long flags;
        int ret = 0;
 
-       if (!npinfo || (!npinfo->rx_np && !npinfo->rx_flags))
+       if (!npinfo || !npinfo->rx_np)
 

Quoted 3 lines

So, it seems rx_flags could have been tested here for NETPOLL_RX_DROP yet?

Oh damn. I bisected this three times and the second two times both landed on this:

commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7

Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800

[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.

Signed-off-by Stephen Hemminger <[email protected]>

Signed-off-by David S. Miller <[email protected]>

net/core/netpoll.c +4 -4

index cf6acd3..9e3aea0 100644
@@ -40,7 +40,6 @@ static atomic_t trapped;
 
 #define USEC_PER_POLL	50
 #define NETPOLL_RX_ENABLED  1
-#define NETPOLL_RX_DROP     2
 
 #define MAX_SKB_SIZE \
 		(MAX_UDP_CHUNK + sizeof(struct udphdr) + \

@@ -128,13 +127,11 @@ static int poll_one_napi(struct netpoll_info *npinfo,
 	if (!test_bit(NAPI_STATE_SCHED, &napi->state))
 		return budget;
 
-	npinfo->rx_flags |= NETPOLL_RX_DROP;
 	atomic_inc(&trapped);
 
 	work = napi->poll(napi, budget);
 
 	atomic_dec(&trapped);
-	npinfo->rx_flags &= ~NETPOLL_RX_DROP;
 
 	return budget - work;
 }

@@ -475,7 +472,7 @@ int __netpoll_rx(struct sk_buff *skb)
 	if (skb->dev->type != ARPHRD_ETHER)
 		goto out;
 
-	/* check if netpoll clients need ARP */
+	/* if receive ARP during middle of NAPI poll, then queue */
 	if (skb->protocol == htons(ETH_P_ARP) &&
 	    atomic_read(&trapped)) {
 		skb_queue_tail(&npi->arp_tx, skb);

@@ -537,6 +534,9 @@ int __netpoll_rx(struct sk_buff *skb)
 	return 1;
 
 out:
+	/* If packet received while already in poll then just
+	 * silently drop.
+	 */
 	if (atomic_read(&trapped)) {
 		kfree_skb(skb);
 		return 1;

and I stupidly assumed that it couldn't be this commit because it was a no-op. I didn't think to look for an _impicit_ test of NETPOLL_RX_DROP such as the one above. That's pretty poor style IMO :(

That bisecting took me several hours and at the time I hoped that it would receive a more-than-zero response. btw.

Stephen Hemminger

2008-03-04 15:52 UTC #16 lore raw

Quoted 95 lines · On Tue, 4 Mar 2008 01:10:50 -0800 Andrew Morton <[email protected]>…

Quoted 30 lines · On Tue, 4 Mar 2008 08:40:24 +0000 Jarek Poplawski <[email protected]> wrote:

On 04-03-2008 06:05, Andrew Morton wrote:
...
Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
Quoted 9 lines
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800
[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
...or maybe apparently doesn't do anything?
net/core/netpoll.c +0 -1
@@ -128,13 +127,11 @@ static int poll_one_napi(struct netpoll_info *npinfo,
        if (!test_bit(NAPI_STATE_SCHED, &napi->state))
                return budget;
 
-       npinfo->rx_flags |= NETPOLL_RX_DROP;
 
 
But in a next patch we can see:
(quoted diff) +1 -1
@@ -51,12 +50,12 @@ static inline int netpoll_rx(struct sk_buff *skb)
        unsigned long flags;
        int ret = 0;
 
-       if (!npinfo || (!npinfo->rx_np && !npinfo->rx_flags))
+       if (!npinfo || !npinfo->rx_np)
 

Quoted 3 lines

So, it seems rx_flags could have been tested here for NETPOLL_RX_DROP yet?

Oh damn. I bisected this three times and the second two times both landed on this:

commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7

Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800

[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.

Signed-off-by Stephen Hemminger <[email protected]>

Signed-off-by David S. Miller <[email protected]>

net/core/netpoll.c +4 -4

index cf6acd3..9e3aea0 100644
@@ -40,7 +40,6 @@ static atomic_t trapped;
 
 #define USEC_PER_POLL	50
 #define NETPOLL_RX_ENABLED  1
-#define NETPOLL_RX_DROP     2
 
 #define MAX_SKB_SIZE \
 		(MAX_UDP_CHUNK + sizeof(struct udphdr) + \

@@ -128,13 +127,11 @@ static int poll_one_napi(struct netpoll_info *npinfo,
 	if (!test_bit(NAPI_STATE_SCHED, &napi->state))
 		return budget;
 
-	npinfo->rx_flags |= NETPOLL_RX_DROP;
 	atomic_inc(&trapped);
 
 	work = napi->poll(napi, budget);
 
 	atomic_dec(&trapped);
-	npinfo->rx_flags &= ~NETPOLL_RX_DROP;
 
 	return budget - work;
 }

@@ -475,7 +472,7 @@ int __netpoll_rx(struct sk_buff *skb)
 	if (skb->dev->type != ARPHRD_ETHER)
 		goto out;
 
-	/* check if netpoll clients need ARP */
+	/* if receive ARP during middle of NAPI poll, then queue */
 	if (skb->protocol == htons(ETH_P_ARP) &&
 	    atomic_read(&trapped)) {
 		skb_queue_tail(&npi->arp_tx, skb);

@@ -537,6 +534,9 @@ int __netpoll_rx(struct sk_buff *skb)
 	return 1;
 
 out:
+	/* If packet received while already in poll then just
+	 * silently drop.
+	 */
 	if (atomic_read(&trapped)) {
 		kfree_skb(skb);
 		return 1;

Quoted 7 lines

and I stupidly assumed that it couldn't be this commit because it was a no-op. I didn't think to look for an _impicit_ test of NETPOLL_RX_DROP such as the one above. That's pretty poor style IMO :(
That bisecting took me several hours and at the time I hoped that it would receive a more-than-zero response. btw.

Mia culpa, individual tests of the netconsole when I did the patch worked. But obviously didn't stress it enough or trigger that drop code.

Plus, I didn't believe the bisect.

David Miller

maintainer

2008-03-04 20:30 UTC #17 lore raw

From: Stephen Hemminger <[email protected]>
Date: Tue, 4 Mar 2008 07:51:37 -0800

Quoted 10 lines

Quoted 2 lines · On Tue, 4 Mar 2008 01:10:50 -0800 Andrew Morton <[email protected]>…
That bisecting took me several hours and at the time I hoped that it would receive a more-than-zero response. btw.
Mia culpa, individual tests of the netconsole when I did the patch worked. But obviously didn't stress it enough or trigger that drop code.
Plus, I didn't believe the bisect.

At least Jarek figured it out in the end :-) I'll revert these two changesets like so:

commit d9452e9f81e997cbd0c9bface8d2c2a4b064cc3e

Author: David S. Miller <[email protected]>
Date:   Tue Mar 4 12:28:49 2008 -0800

[NETPOLL]: Revert two bogus cleanups that broke netconsole.

Based upon a report by Andrew Morton and code analysis done by Jarek Poplawski.

The rx_flags did get tested for zero vs. non-zero and therefore we do need those tests and that code which sets NETPOLL_RX_DROP et al.

Signed-off-by David S. Miller <[email protected]>

include/linux/netpoll.h +4 -3

index a0525a1..e3d7959 100644
@@ -25,6 +25,7 @@ struct netpoll {
 
 struct netpoll_info {
 	atomic_t refcnt;
+	int rx_flags;
 	spinlock_t rx_lock;
 	struct netpoll *rx_np; /* netpoll that registered an rx_hook */
 	struct sk_buff_head arp_tx; /* list of arp requests to reply to */

@@ -50,12 +51,12 @@ static inline int netpoll_rx(struct sk_buff *skb)
 	unsigned long flags;
 	int ret = 0;
 
-	if (!npinfo || !npinfo->rx_np)
+	if (!npinfo || (!npinfo->rx_np && !npinfo->rx_flags))
 		return 0;
 
 	spin_lock_irqsave(&npinfo->rx_lock, flags);
-	/* check rx_np again with the lock held */
-	if (npinfo->rx_np && __netpoll_rx(skb))
+	/* check rx_flags again with the lock held */
+	if (npinfo->rx_flags && __netpoll_rx(skb))
 		ret = 1;
 	spin_unlock_irqrestore(&npinfo->rx_lock, flags);

net/core/netpoll.c +8 -4

index 6faa128..4b7e756 100644
@@ -39,6 +39,8 @@ static struct sk_buff_head skb_pool;
 static atomic_t trapped;
 
 #define USEC_PER_POLL	50
+#define NETPOLL_RX_ENABLED  1
+#define NETPOLL_RX_DROP     2
 
 #define MAX_SKB_SIZE \
 		(MAX_UDP_CHUNK + sizeof(struct udphdr) + \

@@ -126,11 +128,13 @@ static int poll_one_napi(struct netpoll_info *npinfo,
 	if (!test_bit(NAPI_STATE_SCHED, &napi->state))
 		return budget;
 
+	npinfo->rx_flags |= NETPOLL_RX_DROP;
 	atomic_inc(&trapped);
 
 	work = napi->poll(napi, budget);
 
 	atomic_dec(&trapped);
+	npinfo->rx_flags &= ~NETPOLL_RX_DROP;
 
 	return budget - work;
 }

@@ -472,7 +476,7 @@ int __netpoll_rx(struct sk_buff *skb)
 	if (skb->dev->type != ARPHRD_ETHER)
 		goto out;
 
-	/* if receive ARP during middle of NAPI poll, then queue */
+	/* check if netpoll clients need ARP */
 	if (skb->protocol == htons(ETH_P_ARP) &&
 	    atomic_read(&trapped)) {
 		skb_queue_tail(&npi->arp_tx, skb);

@@ -534,9 +538,6 @@ int __netpoll_rx(struct sk_buff *skb)
 	return 1;
 
 out:
-	/* If packet received while already in poll then just
-	 * silently drop.
-	 */
 	if (atomic_read(&trapped)) {
 		kfree_skb(skb);
 		return 1;

@@ -675,6 +676,7 @@ int netpoll_setup(struct netpoll *np)
 			goto release;
 		}
 
+		npinfo->rx_flags = 0;
 		npinfo->rx_np = NULL;
 
 		spin_lock_init(&npinfo->rx_lock);

@@ -756,6 +758,7 @@ int netpoll_setup(struct netpoll *np)
 
 	if (np->rx_hook) {
 		spin_lock_irqsave(&npinfo->rx_lock, flags);
+		npinfo->rx_flags |= NETPOLL_RX_ENABLED;
 		npinfo->rx_np = np;
 		spin_unlock_irqrestore(&npinfo->rx_lock, flags);
 	}

@@ -797,6 +800,7 @@ void netpoll_cleanup(struct netpoll *np)
 			if (npinfo->rx_np == np) {
 				spin_lock_irqsave(&npinfo->rx_lock, flags);
 				npinfo->rx_np = NULL;
+				npinfo->rx_flags &= ~NETPOLL_RX_ENABLED;
 				spin_unlock_irqrestore(&npinfo->rx_lock, flags);
 			}

Andrew Morton

author

2008-03-05 08:24 UTC #18 lore raw

Quoted 1 line · On Tue, 04 Mar 2008 12:30:00 -0800 (PST) David Miller <[email protected]>…

[NETPOLL]: Revert two bogus cleanups that broke netconsole.

Seems OK now, thanks.

David Miller

maintainer

2008-03-05 08:27 UTC #19 lore raw

From: Andrew Morton <[email protected]>
Date: Wed, 5 Mar 2008 00:23:38 -0800

Quoted 5 lines · On Tue, 04 Mar 2008 12:30:00 -0800 (PST) David Miller <[email protected]>…

Quoted 2 lines
[NETPOLL]: Revert two bogus cleanups that broke netconsole.
Seems OK now, thanks.

Great, thanks for testing.

Marcin Slusarz

2008-03-04 19:05 UTC #20 lore raw

In reply to Andrew Morton

Quoted 50 lines · Andrew Morton

Quoted 48 lines · On Wed, 6 Feb 2008 01:16:43 -0800 Andrew Morton <[email protected]>…
Quoted 45 lines · On Wed, 6 Feb 2008 00:34:12 -0800 Andrew Morton <[email protected]>…
Quoted 28 lines · On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]>…
Quoted 5 lines · On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]>…
Quoted 3 lines · On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]>…
With current mainline I'm getting intermittent hangs here:
Quoted 8 lines
Quoted 8 lines
	http://userweb.kernel.org/~akpm/p2033590.jpg
with this config:
http://userweb.kernel.org/~akpm/config-sony.txt
on the Vaio. Sometimes it boots (then hits another different hang), sometimes it gets stuck there.
CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
Quoted 3 lines
The second hang is in kobject_uevent_init(). All that function does is call netlink_kernel_create().
And I've fully bisected this hang twice and both times came up with
commit 33f807ba0d9259e7c75c7a2ce8bd2787e5b540c7
Author: Stephen Hemminger <[email protected]>
Date:   Mon Nov 19 19:24:52 2007 -0800
Quoted 9 lines
[NETPOLL]: Kill NETPOLL_RX_DROP, set but never tested.
which is stupid because that patch doesn't do anything.
However I am using netconsole-over-e100 and the hang does go away when I disable netconsole on the kernel boot command line.
I'd say it's some timing thing in netpoll/netconsole/napi/etc.
I'm seeing this netconsole hang on a second machine now. Current mainline. It also has e100. This one is SMP ancient PIII.
Config: http://userweb.kernel.org/~akpm/config-vmm.txt

Quoted 6 lines

Quoted 6 lines
I can reproduce this on a third machine: the t61p laptop: dual x86_64 with e1000.
It seems to need quite a lot of printk activity to make it happen. Turning on initcall_debug is a suitable way of triggering it.

I've seen it once too. But I thought it had something to do with this:
http://lkml.org/lkml/2008/3/2/91

Quoted 5 lines

This netconsole regression is still present in current mainline. Rafael, can you please add it to the list?
It's strange that I can hit it on three separate machines with e100 and e1000 yet nobody else has reported it (afaik). Is nobody using netconsole?

ps: I don't have any e100* card