2008-02-03 23:02:55

by Andrew Morton

[permalink] [raw]
Subject: locking api self-test hanging


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.


2008-02-03 23:08:26

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:

>
> 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.

2008-02-04 12:43:42

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:

> On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
>
> >
> > 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.

CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.

>
> 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.

2008-02-04 13:04:45

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]> wrote:

> On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:
>
> > On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
> >
> > >
> > > 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.
>
> CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
>
> >
> > 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.
>

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:

--- a/include/asm-generic/rtc.h~a
+++ a/include/asm-generic/rtc.h
@@ -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.

2008-02-04 13:15:25

by Peter Zijlstra

[permalink] [raw]
Subject: Re: locking api self-test hanging


On Mon, 2008-02-04 at 05:04 -0800, Andrew Morton wrote:

> 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.

2008-02-04 13:18:51

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]> wrote:

> On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:
>
> > On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
> >
> > >
> > > 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.
>
> CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
>
> >
> > 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.
>

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.

2008-02-05 13:24:21

by Bernhard Walle

[permalink] [raw]
Subject: Re: locking api self-test hanging

* Andrew Morton <[email protected]> [2008-02-04 14:04]:
>
> 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.

> 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

2008-02-06 08:34:23

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]> wrote:

> On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:
>
> > On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
> >
> > >
> > > 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.
>
> CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
>
> >
> > 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.
>

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

2008-02-06 09:17:12

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Wed, 6 Feb 2008 00:34:12 -0800 Andrew Morton <[email protected]> wrote:

> On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]> wrote:
>
> > On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:
> >
> > > On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
> > >
> > > >
> > > > 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.
> >
> > CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
> >
> > >
> > > 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.
> >
>
> 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.

2008-03-04 05:06:56

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Wed, 6 Feb 2008 01:16:43 -0800 Andrew Morton <[email protected]> wrote:

> On Wed, 6 Feb 2008 00:34:12 -0800 Andrew Morton <[email protected]> wrote:
>
> > On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]> wrote:
> >
> > > On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:
> > >
> > > > On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
> > > >
> > > > >
> > > > > 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.
> > >
> > > CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
> > >
> > > >
> > > > 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.
> > >
> >
> > 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.
>

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?

2008-03-04 08:07:22

by Ingo Molnar

[permalink] [raw]
Subject: [patch] mark netconsole broken


* Andrew Morton <[email protected]> wrote:

> 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(-)

Index: linux/drivers/net/Kconfig
===================================================================
--- linux.orig/drivers/net/Kconfig
+++ 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.

2008-03-04 08:39:40

by Jarek Poplawski

[permalink] [raw]
Subject: Re: locking api self-test hanging

On 04-03-2008 06:05, Andrew Morton wrote:
...
>>>> 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.

2008-03-04 09:11:52

by Andrew Morton

[permalink] [raw]
Subject: Re: locking api self-test hanging

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

> On 04-03-2008 06:05, Andrew Morton wrote:
> ...
> >>>> 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?
>

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]>

diff --git a/net/core/netpoll.c b/net/core/netpoll.c
index cf6acd3..9e3aea0 100644
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -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.

2008-03-04 16:21:34

by Randy Dunlap

[permalink] [raw]
Subject: Re: [patch] mark netconsole broken

On Tue, 4 Mar 2008 09:06:44 +0100 Ingo Molnar wrote:

>
> * Andrew Morton <[email protected]> wrote:
>
> > 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.


> 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
> ===================================================================
> --- linux.orig/drivers/net/Kconfig
> +++ 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

2008-03-04 19:05:51

by Marcin Ślusarz

[permalink] [raw]
Subject: Re: locking api self-test hanging

On Mon, Mar 03, 2008 at 09:05:40PM -0800, Andrew Morton wrote:
> On Wed, 6 Feb 2008 01:16:43 -0800 Andrew Morton <[email protected]> wrote:
>
> > On Wed, 6 Feb 2008 00:34:12 -0800 Andrew Morton <[email protected]> wrote:
> >
> > > On Mon, 4 Feb 2008 04:43:04 -0800 Andrew Morton <[email protected]> wrote:
> > >
> > > > On Sun, 3 Feb 2008 15:07:44 -0800 Andrew Morton <[email protected]> wrote:
> > > >
> > > > > On Sun, 3 Feb 2008 15:02:46 -0800 Andrew Morton <[email protected]> wrote:
> > > > >
> > > > > >
> > > > > > 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.
> > > >
> > > > CONFIG_DEBUG_LOCKING_API_SELFTESTS=n fixed that up.
> > > >
> > > > >
> > > > > 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.
> > > >
> > >
> > > 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.
> >
I've seen it once too. But I thought it had something to do with this:
http://lkml.org/lkml/2008/3/2/91

> 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

2008-03-04 20:30:53

by David Miller

[permalink] [raw]
Subject: Re: [patch] mark netconsole broken

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

> 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]>

diff --git a/include/linux/netpoll.h b/include/linux/netpoll.h
index a0525a1..e3d7959 100644
--- a/include/linux/netpoll.h
+++ b/include/linux/netpoll.h
@@ -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);

diff --git a/net/core/netpoll.c b/net/core/netpoll.c
index 6faa128..4b7e756 100644
--- a/net/core/netpoll.c
+++ b/net/core/netpoll.c
@@ -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);
}

2008-03-04 20:53:09

by Ingo Molnar

[permalink] [raw]
Subject: Re: [patch] mark netconsole broken


* David Miller <[email protected]> wrote:

> From: Ingo Molnar <[email protected]>
> Date: Tue, 4 Mar 2008 09:06:44 +0100
>
> > 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