kernel BUG at kernel/timer.c:951!
Bernard Pidoux
with nosmp.
Linux f6bvp-11 2.6.32.1-nosmp #4 Tue Dec 15 23:13:28 CET 2009 x86_64 Intel(R) Core(TM)2 Duo CPU E4500 @ 2.20GHz GNU/Linux
Gnu C 4.3.2
Gnu make 3.81
binutils 2.19.51.0.2.20090204
util-linux 2.14.1
mount support
module-init-tools 3.6
e2fsprogs 1.41.4
PPP 2.4.4
Linux C Library 2.9
Dynamic linker (ldd) 2.9
Procps 3.2.7
Net-tools 1.60
Kbd 1.15
Sh-utils 7.1
Modules Loaded netconsole netrom mkiss rose ax25 nfsd exportfs nfs lockd nfs_acl auth_rpcgss sunrpc af_packet ipv6 binfmt_misc loop ext3 jbd snd_via82xx snd_ac97_codec ac97_bus snd_mpu401_uart snd_rawmidi snd_seq_dummy snd_seq_oss snd_seq_midi_event snd_seq snd_seq_device snd_pcm_oss snd_pcm snd_timer snd_page_alloc snd_mixer_oss snd i2c_viapro 8139cp i2c_core floppy sg sr_mod shpchp 8139too rtc_cmos soundcore pci_hotplug button via_agp mii evdev pata_via ata_generic ide_pci_generic sata_via libata sd_mod scsi_mod crc_t10dif
The last kernel panic is reporting a kernel BUG at kernel/timer.c:951!
Bernard Pidoux
Jarek Poplawski
> I am experiencing a few kernel panics on my Linux system using 2.6.32 and 2.6.32.1 kernels
> with nosmp.
Some of these oopses look similarly to those:
http://markmail.org/message/scjov36zm2wf2ytv
How about this patch I sent you for testing?:
http://markmail.org/message/nymi7xyd5c43hyfu
Jarek P.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majo...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Bernard Pidoux
Your patch seemed to be working well until 2.6.31.6 kernel.
I did not apply your patch to kernel 2.6.32.
I agree that this may explain why these kernel panics are back.
I will apply this patch to 2.6.32.2 and will report the results soon.
Thanks.
Bernard Pidoux
Jarek Poplawski a ï¿œcrit :
Bernard Pidoux
Congratulation. With your patch I did not see any more kernel panics
since my last post.
I think it should be commited.
Many thanks.
Wishing you a happy new year 2010.
Bernard
Bernard Pidoux a ï¿œcrit :
Jarek Poplawski
> Hi Jarek,
Hi Bernard,
>
> Congratulation. With your patch I did not see any more kernel panics
> since my last post.
> I think it should be commited.
> Many thanks.
>
> Wishing you a happy new year 2010.
>
Happy new year to you as well.
Thanks,
Jarek P.
-------------------->
Wrong ax25_cb refcounting in ax25_send_frame() and by its callers can
cause timer oopses (first reported with 2.6.29.6 kernel).
Fixes: http://bugzilla.kernel.org/show_bug.cgi?id=14905
Reported-by: Bernard Pidoux <bpi...@free.fr>
Tested-by: Bernard Pidoux <bpi...@free.fr>
Signed-off-by: Jarek Poplawski <jar...@gmail.com>
---
include/net/netrom.h | 2 ++
net/ax25/ax25_out.c | 6 ++++++
net/netrom/nr_route.c | 11 ++++++-----
net/rose/rose_link.c | 8 ++++++++
net/rose/rose_route.c | 5 +++++
5 files changed, 27 insertions(+), 5 deletions(-)
diff --git a/include/net/netrom.h b/include/net/netrom.h
index 15696b1..ab170a6 100644
--- a/include/net/netrom.h
+++ b/include/net/netrom.h
@@ -132,6 +132,8 @@ static __inline__ void nr_node_put(struct nr_node *nr_node)
static __inline__ void nr_neigh_put(struct nr_neigh *nr_neigh)
{
if (atomic_dec_and_test(&nr_neigh->refcount)) {
+ if (nr_neigh->ax25)
+ ax25_cb_put(nr_neigh->ax25);
kfree(nr_neigh->digipeat);
kfree(nr_neigh);
}
diff --git a/net/ax25/ax25_out.c b/net/ax25/ax25_out.c
index bf706f8..1491260 100644
--- a/net/ax25/ax25_out.c
+++ b/net/ax25/ax25_out.c
@@ -92,6 +92,12 @@ ax25_cb *ax25_send_frame(struct sk_buff *skb, int paclen, ax25_address *src, ax2
#endif
}
+ /*
+ * There is one ref for the state machine; a caller needs
+ * one more to put it back, just like with the existing one.
+ */
+ ax25_cb_hold(ax25);
+
ax25_cb_add(ax25);
ax25->state = AX25_STATE_1;
diff --git a/net/netrom/nr_route.c b/net/netrom/nr_route.c
index aacba76..e2e2d33 100644
--- a/net/netrom/nr_route.c
+++ b/net/netrom/nr_route.c
@@ -843,12 +843,13 @@ int nr_route_frame(struct sk_buff *skb, ax25_cb *ax25)
dptr = skb_push(skb, 1);
*dptr = AX25_P_NETROM;
- ax25s = ax25_send_frame(skb, 256, (ax25_address *)dev->dev_addr, &nr_neigh->callsign, nr_neigh->digipeat, nr_neigh->dev);
- if (nr_neigh->ax25 && ax25s) {
- /* We were already holding this ax25_cb */
+ ax25s = nr_neigh->ax25;
+ nr_neigh->ax25 = ax25_send_frame(skb, 256,
+ (ax25_address *)dev->dev_addr,
+ &nr_neigh->callsign,
+ nr_neigh->digipeat, nr_neigh->dev);
+ if (ax25s)
ax25_cb_put(ax25s);
- }
- nr_neigh->ax25 = ax25s;
dev_put(dev);
ret = (nr_neigh->ax25 != NULL);
diff --git a/net/rose/rose_link.c b/net/rose/rose_link.c
index bd86a63..5ef5f69 100644
--- a/net/rose/rose_link.c
+++ b/net/rose/rose_link.c
@@ -101,13 +101,17 @@ static void rose_t0timer_expiry(unsigned long param)
static int rose_send_frame(struct sk_buff *skb, struct rose_neigh *neigh)
{
ax25_address *rose_call;
+ ax25_cb *ax25s;
if (ax25cmp(&rose_callsign, &null_ax25_address) == 0)
rose_call = (ax25_address *)neigh->dev->dev_addr;
else
rose_call = &rose_callsign;
+ ax25s = neigh->ax25;
neigh->ax25 = ax25_send_frame(skb, 260, rose_call, &neigh->callsign, neigh->digipeat, neigh->dev);
+ if (ax25s)
+ ax25_cb_put(ax25s);
return (neigh->ax25 != NULL);
}
@@ -120,13 +124,17 @@ static int rose_send_frame(struct sk_buff *skb, struct rose_neigh *neigh)
static int rose_link_up(struct rose_neigh *neigh)
{
ax25_address *rose_call;
+ ax25_cb *ax25s;
if (ax25cmp(&rose_callsign, &null_ax25_address) == 0)
rose_call = (ax25_address *)neigh->dev->dev_addr;
else
rose_call = &rose_callsign;
+ ax25s = neigh->ax25;
neigh->ax25 = ax25_find_cb(rose_call, &neigh->callsign, neigh->digipeat, neigh->dev);
+ if (ax25s)
+ ax25_cb_put(ax25s);
return (neigh->ax25 != NULL);
}
diff --git a/net/rose/rose_route.c b/net/rose/rose_route.c
index 795c4b0..70a0b3b 100644
--- a/net/rose/rose_route.c
+++ b/net/rose/rose_route.c
@@ -235,6 +235,8 @@ static void rose_remove_neigh(struct rose_neigh *rose_neigh)
if ((s = rose_neigh_list) == rose_neigh) {
rose_neigh_list = rose_neigh->next;
+ if (rose_neigh->ax25)
+ ax25_cb_put(rose_neigh->ax25);
kfree(rose_neigh->digipeat);
kfree(rose_neigh);
return;
@@ -243,6 +245,8 @@ static void rose_remove_neigh(struct rose_neigh *rose_neigh)
while (s != NULL && s->next != NULL) {
if (s->next == rose_neigh) {
s->next = rose_neigh->next;
+ if (rose_neigh->ax25)
+ ax25_cb_put(rose_neigh->ax25);
kfree(rose_neigh->digipeat);
kfree(rose_neigh);
return;
@@ -812,6 +816,7 @@ void rose_link_failed(ax25_cb *ax25, int reason)
if (rose_neigh != NULL) {
rose_neigh->ax25 = NULL;
+ ax25_cb_put(ax25);
rose_del_route_by_neigh(rose_neigh);
rose_kill_by_neigh(rose_neigh);
David Miller
Date: Fri, 15 Jan 2010 21:36:54 +0100
> Wrong ax25_cb refcounting in ax25_send_frame() and by its callers can
> cause timer oopses (first reported with 2.6.29.6 kernel).
>
> Fixes: http://bugzilla.kernel.org/show_bug.cgi?id=14905
>
> Reported-by: Bernard Pidoux <bpi...@free.fr>
> Tested-by: Bernard Pidoux <bpi...@free.fr>
> Signed-off-by: Jarek Poplawski <jar...@gmail.com>
Applied, thanks everyone.
Bernard Pidoux
Your patches 1, 2, 3, 4, 6, 7, 9, 10/13 applied.
kernel and modules compiled ok.
AX25 and ROSE are working fine.
Thanks.
Bernard
Simplify seq_file code.
Signed-off-by: Li Zefan <li...@cn.fujitsu.com>
---
net/ax25/af_ax25.c | 18 +++---------------
net/ax25/ax25_uid.c | 25 ++++---------------------
2 files changed, 7 insertions(+), 36 deletions(-)
f6bvp
When unpluging ethernet connector a few seconds I observed the following
kernel message :
Jun 16 12:03:25 f6bvp-9 kernel: e1000e: eth1 NIC Link is Down
Jun 16 12:03:25 f6bvp-9 ifplugd(eth1)[1541]: Link beat lost.
Jun 16 12:03:31 f6bvp-9 ifplugd(eth1)[1541]: Executing
'/etc/ifplugd/ifplugd.action eth1 down'.
Jun 16 12:03:31 f6bvp-9 avahi-daemon[2197]: Withdrawing address record
for 192.168.0.66 on eth1.
Jun 16 12:03:31 f6bvp-9 avahi-daemon[2197]: Leaving mDNS multicast group
on interface eth1.IPv4 with address 192.168.0.66.
Jun 16 12:03:31 f6bvp-9 avahi-daemon[2197]: Interface eth1.IPv4 no
longer relevant for mDNS.
Jun 16 12:03:31 f6bvp-9 avahi-daemon[2197]: Withdrawing address record
for fe80::21c:c0ff:fe36:723e on eth1.
Jun 16 12:03:31 f6bvp-9 vnstatd[2022]: SIGHUP received, flushing data to
disk and reloading config.
Jun 16 12:03:31 f6bvp-9 ifplugd(eth1)[1541]: client: Rechargement de la
configuration de vnstatd : #033[65G[#033[1;32m OK #033[0;39m]#015
Jun 16 12:03:31 f6bvp-9 ifplugd(eth1)[1541]: Program executed successfully.
Jun 16 12:03:31 f6bvp-9 kernel: ADDRCONF(NETDEV_UP): eth1: link is not ready
Jun 16 12:03:34 f6bvp-9 kernel:
Jun 16 12:03:34 f6bvp-9 kernel: =================================
Jun 16 12:03:34 f6bvp-9 kernel: [ INFO: inconsistent lock state ]
Jun 16 12:03:34 f6bvp-9 kernel: 2.6.39.1 #3
Jun 16 12:03:34 f6bvp-9 kernel: ---------------------------------
Jun 16 12:03:34 f6bvp-9 kernel: inconsistent {IN-SOFTIRQ-R} ->
{SOFTIRQ-ON-W} usage.
Jun 16 12:03:34 f6bvp-9 kernel: ax25ipd/2813 [HC0[0]:SC0[0]:HE1:SE1] takes:
Jun 16 12:03:34 f6bvp-9 kernel: (disc_data_lock){+++?.-}, at:
[<ffffffffa018552b>] mkiss_close+0x1b/0x90 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: {IN-SOFTIRQ-R} state was registered at:
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8109484e>]
__lock_acquire+0x57e/0x14c0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81095836>]
lock_acquire+0xa6/0x160
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813f64f4>]
_raw_read_lock+0x34/0x50
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa01850ed>]
mkiss_get+0x1d/0x50 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa018517e>]
mkiss_write_wakeup+0x1e/0xb0 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129457e>] tty_wakeup+0x6e/0x80
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129f243>] pty_write+0x73/0x80
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa0185d2e>]
ax_xmit+0x27e/0x5e0 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81339dac>]
dev_hard_start_xmit+0x34c/0x6f0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81358b4d>]
sch_direct_xmit+0xdd/0x260
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8133cc8f>]
dev_queue_xmit+0x1af/0x8a0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa0325072>]
ax25_queue_xmit+0x52/0x60 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa032516f>]
ax25_transmit_buffer+0xef/0x130 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa0325238>]
ax25_send_iframe+0x88/0xe0 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa032536e>]
ax25_kick+0xde/0x220 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa0326715>]
ax25_std_frame_in+0x65/0x920 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa03241da>]
ax25_rcv+0x3aa/0x9a0 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa032486f>]
ax25_kiss_rcv+0x9f/0xb0 [ax25]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8133bba5>]
__netif_receive_skb+0x205/0x6d0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8133c144>]
process_backlog+0xd4/0x1e0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8133c995>]
net_rx_action+0x125/0x270
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff810618f1>]
__do_softirq+0xc1/0x210
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813ffa9c>] call_softirq+0x1c/0x30
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff810627db>]
local_bh_enable_ip+0xeb/0xf0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813f6594>]
_raw_spin_unlock_bh+0x34/0x40
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa0186522>]
mkiss_receive_buf+0x2e2/0x3dc [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129e122>]
flush_to_ldisc+0x1b2/0x1d0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff810762c0>]
process_one_work+0x1a0/0x510
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81078ba2>]
worker_thread+0x172/0x400
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8107d816>] kthread+0xb6/0xc0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813ff9a4>]
kernel_thread_helper+0x4/0x10
Jun 16 12:03:34 f6bvp-9 kernel: irq event stamp: 76635461
Jun 16 12:03:34 f6bvp-9 kernel: hardirqs last enabled at (76635461):
[<ffffffff813f6620>] _raw_spin_unlock_irqrestore+0x40/0x70
Jun 16 12:03:34 f6bvp-9 kernel: hardirqs last disabled at (76635460):
[<ffffffff813f5f1e>] _raw_spin_lock_irqsave+0x2e/0x70
Jun 16 12:03:34 f6bvp-9 kernel: softirqs last enabled at (76635394):
[<ffffffff81329337>] sk_common_release+0x67/0xd0
Jun 16 12:03:34 f6bvp-9 kernel: softirqs last disabled at (76635392):
[<ffffffff813f60f6>] _raw_write_lock_bh+0x16/0x50
Jun 16 12:03:34 f6bvp-9 kernel:
Jun 16 12:03:34 f6bvp-9 kernel: other info that might help us debug this:
Jun 16 12:03:34 f6bvp-9 kernel: 2 locks held by ax25ipd/2813:
Jun 16 12:03:34 f6bvp-9 kernel: #0: (big_tty_mutex){+.+.+.}, at:
[<ffffffff813f67ce>] tty_lock+0x2e/0x4f
Jun 16 12:03:34 f6bvp-9 kernel: #1: (&tty->ldisc_mutex){+.+.+.}, at:
[<ffffffff8129d597>] tty_ldisc_hangup+0xe7/0x250
Jun 16 12:03:34 f6bvp-9 kernel:
Jun 16 12:03:34 f6bvp-9 kernel: stack backtrace:
Jun 16 12:03:34 f6bvp-9 kernel: Pid: 2813, comm: ax25ipd Not tainted
2.6.39.1 #3
Jun 16 12:03:34 f6bvp-9 kernel: Call Trace:
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81092dc0>]
print_usage_bug+0x170/0x180
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81093a81>] mark_lock+0x211/0x3f0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff810948c4>]
__lock_acquire+0x5f4/0x14c0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81093ccb>] ?
mark_held_locks+0x6b/0xa0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813f65d0>] ?
_raw_spin_unlock_irq+0x30/0x40
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81093fcd>] ?
trace_hardirqs_on_caller+0x13d/0x180
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81095836>] lock_acquire+0xa6/0x160
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa018552b>] ?
mkiss_close+0x1b/0x90 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81093ccb>] ?
mark_held_locks+0x6b/0xa0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813f6221>]
_raw_write_lock+0x31/0x40
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa018552b>] ?
mkiss_close+0x1b/0x90 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8113775e>] ?
kmem_cache_alloc_trace+0x7e/0x140
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffffa018552b>]
mkiss_close+0x1b/0x90 [mkiss]
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129c84b>]
tty_ldisc_close+0x4b/0x70
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129ce90>]
tty_ldisc_reinit+0x40/0x80
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129d5b4>]
tty_ldisc_hangup+0x104/0x250
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129588c>]
__tty_hangup+0x15c/0x3e0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8109401d>] ?
trace_hardirqs_on+0xd/0x10
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81295b3e>] tty_vhangup+0xe/0x10
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8129f37e>] pty_close+0x10e/0x160
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81295ceb>] tty_release+0x16b/0x640
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8113920a>] ?
kmem_cache_free+0x11a/0x160
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81142f9a>] fput+0xea/0x230
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8113ee03>] filp_close+0x63/0x90
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8105dab1>]
put_files_struct+0x171/0x190
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8105d978>] ?
put_files_struct+0x38/0x190
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8105db22>] exit_files+0x52/0x60
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8105deb9>] do_exit+0x189/0x860
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff81142cc0>] ? fget+0xd0/0xd0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813f69b9>] ?
retint_swapgs+0x13/0x1b
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8105e5eb>] do_group_exit+0x5b/0xd0
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff8105e677>]
sys_exit_group+0x17/0x20
Jun 16 12:03:34 f6bvp-9 kernel: [<ffffffff813fe812>]
system_call_fastpath+0x16/0x1b
Kernel is 2.6.39.1
Is there something wrong in AX25 code or (more unlikely) is this
operation not permitted ?
Thanks for help.
Bernard Pidoux
f6bvp
Here is a kernel message dump reporting a possible circular locking :
Jun 13 11:58:55 f6bvp-9 kernel: usb 5-2: New USB device strings: Mfr=1,
Product=2, SerialNumber=0
Jun 13 11:58:55 f6bvp-9 kernel: usb 5-2: Product: FUNcube Dongle V1.0
Jun 13 11:58:55 f6bvp-9 kernel: usb 5-2: Manufacturer: Hanlincrest Ltd.
Jun 13 11:58:55 f6bvp-9 kernel: generic-usb 0003:04D8:FB56.0004:
hiddev0,hidraw3: USB HID v1.11 Device [Hanlincrest Ltd. FUNcube
Dongle V1.0 ] on usb-0000:00:1d.3-2/input2
Jun 13 11:58:56 f6bvp-9 kernel: usbcore: registered new interface driver
snd-usb-audio
Jun 13 11:58:56 f6bvp-9 udevd-work[11414]: symlink(snd/controlC1,
/dev/FCD.udev-tmp) failed: File exists
Jun 13 11:58:57 f6bvp-9 rtkit-daemon[3119]: Successfully made thread
11434 of process 3117 (/usr/bin/pulseaudio) owned by '500' RT at priority 5.
Jun 13 11:59:18 f6bvp-9 kernel: usb 5-2: USB disconnect, device number 2
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel:
=======================================================
Jun 13 11:59:18 f6bvp-9 kernel: [ INFO: possible circular locking
dependency detected ]
Jun 13 11:59:18 f6bvp-9 kernel: 2.6.39 #2
Jun 13 11:59:18 f6bvp-9 kernel:
-------------------------------------------------------
Jun 13 11:59:18 f6bvp-9 kernel: khubd/41 is trying to acquire lock:
Jun 13 11:59:18 f6bvp-9 kernel: (sound_oss_mutex){+.+.+.}, at:
[<ffffffffa02e134b>] snd_unregister_oss_device+0x4b/0x110 [snd]
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: but task is already holding lock:
Jun 13 11:59:18 f6bvp-9 kernel: (&chip->shutdown_mutex){+.+.+.}, at:
[<ffffffffa05e3258>] usb_audio_disconnect+0x48/0x1b0 [snd_usb_audio]
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: which lock already depends on the new lock.
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: the existing dependency chain (in
reverse order) is:
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: -> #5 (&chip->shutdown_mutex){+.+.+.}:
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff810958d6>]
lock_acquire+0xa6/0x160
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813f469c>]
__mutex_lock_common+0x4c/0x3c0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813f4ac5>]
mutex_lock_nested+0x35/0x40
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffffa05ed874>]
snd_usb_hw_free+0x44/0x70 [snd_usb_audio]
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffffa02f3523>]
snd_pcm_release_substream+0x63/0xc0 [snd_pcm]
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffffa02f35d0>]
snd_pcm_release+0x50/0xe0 [snd_pcm]
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff8114303a>] fput+0xea/0x230
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff811185e5>]
remove_vma+0x45/0x90
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff8111a378>]
do_munmap+0x318/0x3b0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff8111a469>]
sys_munmap+0x59/0x80
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813fe5d2>]
system_call_fastpath+0x16/0x1b
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: -> #4 (&pcm->open_mutex){+.+.+.}:
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff810958d6>]
lock_acquire+0xa6/0x160
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813f469c>]
__mutex_lock_common+0x4c/0x3c0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813f4ac5>]
mutex_lock_nested+0x35/0x40
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffffa02f35c8>]
snd_pcm_release+0x48/0xe0 [snd_pcm]
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff8114303a>] fput+0xea/0x230
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff811185e5>]
remove_vma+0x45/0x90
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff8111a378>]
do_munmap+0x318/0x3b0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff8111a469>]
sys_munmap+0x59/0x80
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813fe5d2>]
system_call_fastpath+0x16/0x1b
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: -> #3 (&mm->mmap_sem){++++++}:
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff810958d6>]
lock_acquire+0xa6/0x160
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff811106e2>]
might_fault+0x72/0xa0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff81153642>] filldir+0x82/0xf0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff81165dee>]
dcache_readdir+0x5e/0x260
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff81153848>]
vfs_readdir+0xb8/0xe0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff811539d9>]
sys_getdents+0x89/0xf0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813fe5d2>]
system_call_fastpath+0x16/0x1b
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: -> #2 (&sb->s_type->i_mutex_key#3){+.+.+.}:
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff810958d6>]
lock_acquire+0xa6/0x160
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813f469c>]
__mutex_lock_common+0x4c/0x3c0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813f4ac5>]
mutex_lock_nested+0x35/0x40
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff812d0412>]
devtmpfs_create_node+0x1f2/0x290
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff812c90a8>]
device_add+0x218/0x6e0
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff812c958e>]
device_register+0x1e/0x30
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff812c96b0>]
device_create_vargs+0x110/0x120
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff812c96f1>]
device_create+0x31/0x40
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff812bc392>]
misc_register+0x92/0x140
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff817478c0>]
vga_arb_device_init+0x13/0x77
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff81002043>]
do_one_initcall+0x43/0x190
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff81713655>]
kernel_init+0xb5/0x135
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff813ff764>]
kernel_thread_helper+0x4/0x10
Jun 13 11:59:18 f6bvp-9 kernel:
Jun 13 11:59:18 f6bvp-9 kernel: -> #1
(&sb->s_type->i_mutex_key#2/1){+.+.+.}:
Jun 13 11:59:18 f6bvp-9 kernel: [<ffffffff810958d6>]
lock_acquire+0xa6/0x160
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f469c>]
__mutex_lock_common+0x4c/0x3c0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f4ac5>]
mutex_lock_nested+0x35/0x40
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8114bcb2>]
lookup_create+0x32/0xd0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812d032a>]
devtmpfs_create_node+0x10a/0x290
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812c90a8>]
device_add+0x218/0x6e0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812c958e>]
device_register+0x1e/0x30
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812c96b0>]
device_create_vargs+0x110/0x120
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812c96f1>]
device_create+0x31/0x40
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa017c44c>]
sound_insert_unit+0x29c/0x300 [soundcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa017c644>]
register_sound_special_device+0xb4/0x240 [soundcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02e152c>]
snd_register_oss_device+0x11c/0x220 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa038103b>]
0xffffffffa038103b
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff81002043>]
do_one_initcall+0x43/0x190
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff810a200a>]
sys_init_module+0xba/0x200
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813fe5d2>]
system_call_fastpath+0x16/0x1b
Jun 13 11:59:19 f6bvp-9 kernel:
Jun 13 11:59:19 f6bvp-9 kernel: -> #0 (sound_oss_mutex){+.+.+.}:
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8109571d>]
__lock_acquire+0x13ad/0x14c0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff810958d6>]
lock_acquire+0xa6/0x160
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f469c>]
__mutex_lock_common+0x4c/0x3c0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f4ac5>]
mutex_lock_nested+0x35/0x40
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02e134b>]
snd_unregister_oss_device+0x4b/0x110 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa01de5dd>]
snd_mixer_oss_notify_handler+0x11d/0x330 [snd_mixer_oss]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02dae5f>]
snd_card_disconnect+0x16f/0x250 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa05e32a0>]
usb_audio_disconnect+0x90/0x1b0 [snd_usb_audio]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa000ccc0>]
usb_unbind_interface+0x60/0x1a0 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812cb525>]
__device_release_driver+0x75/0xe0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812cbacf>]
device_release_driver+0x2f/0x50
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812ca564>]
bus_remove_device+0xb4/0x100
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812c878f>]
device_del+0x12f/0x1b0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa0009b1f>]
usb_disable_device+0x6f/0x130 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa0003b99>]
usb_disconnect+0x99/0x130 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa00044e1>]
hub_thread+0x621/0x12d0 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8107d816>] kthread+0xb6/0xc0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813ff764>]
kernel_thread_helper+0x4/0x10
Jun 13 11:59:19 f6bvp-9 kernel:
Jun 13 11:59:19 f6bvp-9 kernel: other info that might help us debug this:
Jun 13 11:59:19 f6bvp-9 kernel:
Jun 13 11:59:19 f6bvp-9 kernel: 5 locks held by khubd/41:
Jun 13 11:59:19 f6bvp-9 kernel: #0: (&__lockdep_no_validate__){+.+.+.},
at: [<ffffffffa0003ff0>] hub_thread+0x130/0x12d0 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: #1: (&__lockdep_no_validate__){+.+.+.},
at: [<ffffffffa0003b5d>] usb_disconnect+0x5d/0x130 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: #2: (&__lockdep_no_validate__){+.+.+.},
at: [<ffffffff812cbac7>] device_release_driver+0x27/0x50
Jun 13 11:59:19 f6bvp-9 kernel: #3: (register_mutex#6){+.+.+.}, at:
[<ffffffffa05e324e>] usb_audio_disconnect+0x3e/0x1b0 [snd_usb_audio]
Jun 13 11:59:19 f6bvp-9 kernel: #4: (&chip->shutdown_mutex){+.+.+.},
at: [<ffffffffa05e3258>] usb_audio_disconnect+0x48/0x1b0 [snd_usb_audio]
Jun 13 11:59:19 f6bvp-9 kernel:
Jun 13 11:59:19 f6bvp-9 kernel: stack backtrace:
Jun 13 11:59:19 f6bvp-9 kernel: Pid: 41, comm: khubd Not tainted 2.6.39 #2
Jun 13 11:59:19 f6bvp-9 kernel: Call Trace:
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff81093299>]
print_circular_bug+0xe9/0xf0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8109571d>]
__lock_acquire+0x13ad/0x14c0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff810958d6>] lock_acquire+0xa6/0x160
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02e134b>] ?
snd_unregister_oss_device+0x4b/0x110 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff81093d6b>] ?
mark_held_locks+0x6b/0xa0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f469c>]
__mutex_lock_common+0x4c/0x3c0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02e134b>] ?
snd_unregister_oss_device+0x4b/0x110 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02e134b>] ?
snd_unregister_oss_device+0x4b/0x110 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f4403>] ?
__mutex_unlock_slowpath+0xd3/0x170
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8109406d>] ?
trace_hardirqs_on_caller+0x13d/0x180
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f4ac5>]
mutex_lock_nested+0x35/0x40
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02e134b>]
snd_unregister_oss_device+0x4b/0x110 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa01de5dd>]
snd_mixer_oss_notify_handler+0x11d/0x330 [snd_mixer_oss]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02dadb8>] ?
snd_card_disconnect+0xc8/0x250 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f4403>] ?
__mutex_unlock_slowpath+0xd3/0x170
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8109406d>] ?
trace_hardirqs_on_caller+0x13d/0x180
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa02dae5f>]
snd_card_disconnect+0x16f/0x250 [snd]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa05e32a0>]
usb_audio_disconnect+0x90/0x1b0 [snd_usb_audio]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa000ccc0>]
usb_unbind_interface+0x60/0x1a0 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812cb525>]
__device_release_driver+0x75/0xe0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812cbacf>]
device_release_driver+0x2f/0x50
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812ca564>]
bus_remove_device+0xb4/0x100
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff812c878f>] device_del+0x12f/0x1b0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa0009b1f>]
usb_disable_device+0x6f/0x130 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa0003b99>]
usb_disconnect+0x99/0x130 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa00044e1>]
hub_thread+0x621/0x12d0 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f6380>] ?
_raw_spin_unlock_irq+0x30/0x40
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8104acad>] ?
finish_task_switch+0x7d/0x110
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8104ac78>] ?
finish_task_switch+0x48/0x110
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa0003ec0>] ?
hub_disconnect+0x120/0x120 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8107dd50>] ? wake_up_bit+0x40/0x40
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffffa0003ec0>] ?
hub_disconnect+0x120/0x120 [usbcore]
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8107d816>] kthread+0xb6/0xc0
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8109406d>] ?
trace_hardirqs_on_caller+0x13d/0x180
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813ff764>]
kernel_thread_helper+0x4/0x10
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813f6794>] ?
retint_restore_args+0x13/0x13
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff8107d760>] ?
__init_kthread_worker+0x70/0x70
Jun 13 11:59:19 f6bvp-9 kernel: [<ffffffff813ff760>] ? gs_change+0x13/0x13
Jun 13 11:59:20 f6bvp-9 kernel: usb 5-1: new full speed USB device
number 3 using uhci_hcd
Jun 13 11:59:20 f6bvp-9 kernel: usb 5-1: New USB device found,
idVendor=04d8, idProduct=fb56
Jun 13 11:59:20 f6bvp-9 kernel: usb 5-1: New USB device strings: Mfr=1,
Product=2, SerialNumber=0
Jun 13 11:59:20 f6bvp-9 kernel: usb 5-1: Product: FUNcube Dongle V1.0
Jun 13 11:59:20 f6bvp-9 kernel: usb 5-1: Manufacturer: Hanlincrest Ltd.
Jun 13 11:59:20 f6bvp-9 kernel: generic-usb 0003:04D8:FB56.0005:
hiddev0,hidraw3: USB HID v1.11 Device [Hanlincrest Ltd. FUNcube
Dongle V1.0 ] on usb-0000:00:1d.3-1/input2
Jun 13 11:59:21 f6bvp-9 rtkit-daemon[3119]: Successfully made thread
12523 of process 3117 (/usr/bin/pulseaudio) owned by '500' RT at priority 5.
Jun 13 11:59:22 f6bvp-9 kernel: hald-probe-hidd: page allocation
failure. order:4, mode:0xc0d0
Jun 13 11:59:22 f6bvp-9 kernel: Pid: 12500, comm: hald-probe-hidd Not
tainted 2.6.39 #2
Jun 13 11:59:22 f6bvp-9 kernel: Call Trace:
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff810f8482>]
__alloc_pages_nodemask+0x612/0x820
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8112d4af>]
alloc_pages_current+0x8f/0xe0
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff810f757e>]
__get_free_pages+0xe/0x50
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8113549e>]
kmalloc_order_trace+0x3e/0xb0
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffffa0000a80>] ?
usb_find_interface+0x40/0x60 [usbcore]
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffffa005ecd4>]
hiddev_open+0x74/0x1c0 [usbhid]
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff813f4e69>] ? down_read+0x39/0x50
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffffa000f464>] ?
usb_open+0x44/0x1a0 [usbcore]
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffffa000f4e8>] usb_open+0xc8/0x1a0
[usbcore]
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff811452b7>] chrdev_open+0xf7/0x210
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff811451c0>] ? cdev_alloc+0x60/0x60
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8113f146>]
__dentry_open+0x146/0x310
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8113f411>]
nameidata_to_filp+0x71/0x80
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8114e79c>] do_last+0x1ec/0x870
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8114f980>] path_openat+0xd0/0x430
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8114fdf9>] do_filp_open+0x49/0xa0
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff813f642b>] ?
_raw_spin_unlock+0x2b/0x40
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff8115d8fa>] ? alloc_fd+0xfa/0x140
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff811407b7>] do_sys_open+0x107/0x1e0
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff811408d0>] sys_open+0x20/0x30
Jun 13 11:59:22 f6bvp-9 kernel: [<ffffffff813fe5d2>]
system_call_fastpath+0x16/0x1b
Jun 13 11:59:22 f6bvp-9 kernel: Mem-Info:
Jun 13 11:59:22 f6bvp-9 kernel: Node 0 DMA per-cpu:
Jun 13 11:59:22 f6bvp-9 kernel: CPU 0: hi: 0, btch: 1 usd: 0
Jun 13 11:59:22 f6bvp-9 kernel: CPU 1: hi: 0, btch: 1 usd: 0
Jun 13 11:59:22 f6bvp-9 kernel: Node 0 DMA32 per-cpu:
Jun 13 11:59:22 f6bvp-9 kernel: CPU 0: hi: 186, btch: 31 usd: 0
Jun 13 11:59:22 f6bvp-9 kernel: CPU 1: hi: 186, btch: 31 usd: 0
Jun 13 11:59:22 f6bvp-9 kernel: active_anon:21438 inactive_anon:41165
isolated_anon:11
Jun 13 11:59:22 f6bvp-9 kernel: active_file:50805 inactive_file:93727
isolated_file:31
Jun 13 11:59:22 f6bvp-9 kernel: unevictable:0 dirty:19022 writeback:359
unstable:0
Jun 13 11:59:22 f6bvp-9 kernel: free:18969 slab_reclaimable:12604
slab_unreclaimable:4850
Jun 13 11:59:22 f6bvp-9 kernel: mapped:6458 shmem:849 pagetables:3938
bounce:0
Jun 13 11:59:22 f6bvp-9 kernel: Node 0 DMA free:4048kB min:60kB low:72kB
high:88kB active_anon:0kB inactive_anon:72kB active_file:2656kB
inactive_file:7768kB unevictable:0kB isolated(anon):0kB
isolated(file):0kB present:15624kB mlocked:0kB dirty:0kB writeback:0kB
mapped:124kB shmem:0kB slab_reclaimable:1252kB slab_unreclaimable:48kB
kernel_stack:0kB pagetables:4kB unstable:0kB bounce:0kB
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jun 13 11:59:22 f6bvp-9 kernel: lowmem_reserve[]: 0 992 992 992
Jun 13 11:59:22 f6bvp-9 kernel: Node 0 DMA32 free:71828kB min:3996kB
low:4992kB high:5992kB active_anon:85752kB inactive_anon:164588kB
active_file:200564kB inactive_file:367140kB unevictable:0kB
isolated(anon):44kB isolated(file):124kB present:1016072kB mlocked:0kB
dirty:76088kB writeback:1436kB mapped:25708kB shmem:3396kB
slab_reclaimable:49164kB slab_unreclaimable:19352kB kernel_stack:2312kB
pagetables:15748kB unstable:0kB bounce:0kB writeback_tmp:0kB
pages_scanned:0 all_unreclaimable? no
Jun 13 11:59:22 f6bvp-9 kernel: lowmem_reserve[]: 0 0 0 0
Jun 13 11:59:22 f6bvp-9 kernel: Node 0 DMA: 114*4kB 45*8kB 14*16kB
6*32kB 8*64kB 2*128kB 0*256kB 0*512kB 0*1024kB 1*2048kB 0*4096kB = 4048kB
Jun 13 11:59:22 f6bvp-9 kernel: Node 0 DMA32: 3925*4kB 3502*8kB
1643*16kB 55*32kB 1*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB
0*4096kB = 71828kB
Jun 13 11:59:22 f6bvp-9 kernel: 150823 total pagecache pages
Jun 13 11:59:22 f6bvp-9 kernel: 5394 pages in swap cache
Regards,
Bernard Pidoux
f6bvp
Kernel is 2.6.39.1
Bernard Pidoux
Ralf Baechle
> When unpluging ethernet connector a few seconds I observed the
> following kernel message :
Can you describe your setup and what you did to trigger this?
Ralf
Arnd Bergmann
> Jun 16 12:03:34 f6bvp-9 kernel: =================================
> Jun 16 12:03:34 f6bvp-9 kernel: [ INFO: inconsistent lock state ]
> Jun 16 12:03:34 f6bvp-9 kernel: 2.6.39.1 #3
> Jun 16 12:03:34 f6bvp-9 kernel: ---------------------------------
> Jun 16 12:03:34 f6bvp-9 kernel: inconsistent {IN-SOFTIRQ-R} -> {SOFTIRQ-ON-W} usage.
> Jun 16 12:03:34 f6bvp-9 kernel: ax25ipd/2813 [HC0[0]:SC0[0]:HE1:SE1] takes:
> Jun 16 12:03:34 f6bvp-9 kernel: (disc_data_lock){+++?.-}, at: [<ffffffffa018552b>] mkiss_close+0x1b/0x90 [mkiss]
> Jun 16 12:03:34 f6bvp-9 kernel: {IN-SOFTIRQ-R} state was registered at:
> ...
> Is there something wrong in AX25 code or (more unlikely) is this
> operation not permitted ?
The message hints that disc_data_lock is aquired with softirqs disabled,
but does not itself disable softirqs, which can in rare circumstances
lead to a deadlock.
Does this fix it?
Signed-off-by: Arnd Bergmann <ar...@arndb.de>
--- a/drivers/net/hamradio/mkiss.c
+++ b/drivers/net/hamradio/mkiss.c
@@ -708,11 +708,11 @@ static struct mkiss *mkiss_get(struct tty_struct *tty)
{
struct mkiss *ax;
- read_lock(&disc_data_lock);
+ read_lock_bh(&disc_data_lock);
ax = tty->disc_data;
if (ax)
atomic_inc(&ax->refcnt);
- read_unlock(&disc_data_lock);
+ read_unlock_bh(&disc_data_lock);
return ax;
}
@@ -813,10 +813,10 @@ static void mkiss_close(struct tty_struct *tty)
{
struct mkiss *ax;
- write_lock(&disc_data_lock);
+ write_lock_bh(&disc_data_lock);
ax = tty->disc_data;
tty->disc_data = NULL;
- write_unlock(&disc_data_lock);
+ write_unlock_bh(&disc_data_lock);
if (!ax)
return;
Ralf Baechle
(Removed Jarek from cc; his email bounces.)
> The message hints that disc_data_lock is aquired with softirqs disabled,
> but does not itself disable softirqs, which can in rare circumstances
> lead to a deadlock.
>
> Does this fix it?
If so, drivers/net/hamradio.c, function sp_get() would probably need the
equivalent fix. Same for drivers/net/ppp_async.c:ap_get() and sp_get() in
drivers/net/ppp_synctty.c.
Ralf
Arnd Bergmann
> On Fri, Jun 17, 2011 at 03:36:15PM +0200, Arnd Bergmann wrote:
>
> (Removed Jarek from cc; his email bounces.)
>
> > The message hints that disc_data_lock is aquired with softirqs disabled,
> > but does not itself disable softirqs, which can in rare circumstances
> > lead to a deadlock.
> >
> > Does this fix it?
>
> If so, drivers/net/hamradio.c, function sp_get() would probably need the
> equivalent fix. Same for drivers/net/ppp_async.c:ap_get() and sp_get() in
> drivers/net/ppp_synctty.c.
It seems that ppp_synctty.c is ok, it uses write_lock_irq() already,
sixpack.c looks like it has the same bug as mkiss. I also realized
after sending out the patch that only the write_lock needs to be
changed to write_lock_bh, while read_lock can leave softirqs enabled
because it can be called recursively.
Arnd
f6bvp
I wanted to check FPAC ROSE application behaviour when Ethernet link was
shutdown.
To do this I removed the ethernet connector !
I agree this was a very agressive action.
73s de Bernard, f6bvp
Le 17/06/2011 15:51, Ralf Baechle a �crit :
f6bvp
I will apply your patch with write_lock_bh only following your
remark about recursive call.
I agree that the error message did not appear systematically
when doing what I did i.e. unpluging the ethernet cable from
the computer interface.
However, I will perform the same a few times and see what happens.
Many thanks.
Bernard
f6bvp
I applied the patch and since then I could not reproduce the
inconsistent lock state.
Thus mkiss patch fixed it.
Thanks,
Bernard
Le 17/06/2011 16:11, Arnd Bergmann a �crit :
Ralf Baechle DL5RB
> I applied the patch and since then I could not reproduce the
> inconsistent lock state.
> Thus mkiss patch fixed it.
I also think the patch is the right thing, so
Acked-by: Ralf Baechle <ra...@linux-mips.org>
Ralf
Bernard F6BVP
Now, who is going to commit this mkiss patch and the equivalent one for
sixpack.c ?
Bernard, f6bvp
Arnd Bergmann
> kernel: [ INFO: inconsistent lock state ]
> kernel: 2.6.39.1 #3
> kernel: ---------------------------------
> kernel: inconsistent {IN-SOFTIRQ-R} -> {SOFTIRQ-ON-W} usage.
> kernel: ax25ipd/2813 [HC0[0]:SC0[0]:HE1:SE1] takes:
> kernel: (disc_data_lock){+++?.-}, at: [<ffffffffa018552b>] mkiss_close+0x1b/0x90 [mkiss]
> kernel: {IN-SOFTIRQ-R} state was registered at:
The message hints that disc_data_lock is aquired with softirqs disabled,
but does not itself disable softirqs, which can in rare circumstances
lead to a deadlock.
The same problem is present in the 6pack driver, this patch fixes both
by using write_lock_bh instead of write_lock.
Reported-by: Bernard F6BVP <f6...@free.fr>
Tested-by: Bernard F6BVP <f6...@free.fr>
Signed-off-by: Arnd Bergmann <ar...@arndb.de>
Acked-by: Ralf Baechle<ra...@linux-mips.org>
Cc: sta...@kernel.org
---
On Friday 01 July 2011 15:00:35 Bernard F6BVP wrote:
>
> Now, who is going to commit this mkiss patch and the equivalent one for
> sixpack.c ?
Here's a formal patch with all the right tags, I assume that David Miller
will apply that to the netdev tree.
diff --git a/drivers/net/hamradio/6pack.c b/drivers/net/hamradio/6pack.c
index 9624cbf..fea7cb4 100644
--- a/drivers/net/hamradio/6pack.c
+++ b/drivers/net/hamradio/6pack.c
@@ -694,10 +694,10 @@ static void sixpack_close(struct tty_struct *tty)
{
struct sixpack *sp;
- write_lock(&disc_data_lock);
+ write_lock_bh(&disc_data_lock);
sp = tty->disc_data;
tty->disc_data = NULL;
- write_unlock(&disc_data_lock);
+ write_unlock_bh(&disc_data_lock);
if (!sp)
return;
diff --git a/drivers/net/hamradio/mkiss.c b/drivers/net/hamradio/mkiss.c
index 9f84c83..324f7bf 100644
--- a/drivers/net/hamradio/mkiss.c
+++ b/drivers/net/hamradio/mkiss.c
@@ -813,10 +813,10 @@ static void mkiss_close(struct tty_struct *tty)
{
struct mkiss *ax;
- write_lock(&disc_data_lock);
+ write_lock_bh(&disc_data_lock);
ax = tty->disc_data;
tty->disc_data = NULL;
- write_unlock(&disc_data_lock);
+ write_unlock_bh(&disc_data_lock);
if (!ax)
return;
David Miller
Date: Fri, 1 Jul 2011 23:28:46 +0200
> Lockdep found a locking inconsistency in the mkiss_close function:
>
>> kernel: [ INFO: inconsistent lock state ]
>> kernel: 2.6.39.1 #3
>> kernel: ---------------------------------
>> kernel: inconsistent {IN-SOFTIRQ-R} -> {SOFTIRQ-ON-W} usage.
>> kernel: ax25ipd/2813 [HC0[0]:SC0[0]:HE1:SE1] takes:
>> kernel: (disc_data_lock){+++?.-}, at: [<ffffffffa018552b>] mkiss_close+0x1b/0x90 [mkiss]
>> kernel: {IN-SOFTIRQ-R} state was registered at:
>
> The message hints that disc_data_lock is aquired with softirqs disabled,
> but does not itself disable softirqs, which can in rare circumstances
> lead to a deadlock.
> The same problem is present in the 6pack driver, this patch fixes both
> by using write_lock_bh instead of write_lock.
>
> Reported-by: Bernard F6BVP <f6...@free.fr>
> Tested-by: Bernard F6BVP <f6...@free.fr>
> Signed-off-by: Arnd Bergmann <ar...@arndb.de>
> Acked-by: Ralf Baechle<ra...@linux-mips.org>
> Cc: sta...@kernel.org
Applied, thanks!