diff mbox

[net-2.6] ax25: netrom: rose: Fix timer oopses

Message ID 20100115203654.GA3084@del.dom.local
State Accepted, archived
Delegated to: David Miller
Headers show

Commit Message

Jarek Poplawski Jan. 15, 2010, 8:36 p.m. UTC 
On Fri, Jan 15, 2010 at 03:46:02PM +0100, Bernard Pidoux wrote:
> 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 <bpidoux@free.fr>
Tested-by: Bernard Pidoux <bpidoux@free.fr>
Signed-off-by: Jarek Poplawski <jarkao2@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(-)

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Comments

David Miller Jan. 16, 2010, 9:04 a.m. UTC | #1 
From: Jarek Poplawski <jarkao2@gmail.com>
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 <bpidoux@free.fr>
> Tested-by: Bernard Pidoux <bpidoux@free.fr>
> Signed-off-by: Jarek Poplawski <jarkao2@gmail.com>

Applied, thanks everyone.
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Bernard Pidoux Feb. 11, 2010, 4:34 p.m. UTC | #2 
Hi Li Zefan,

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 <lizf@cn.fujitsu.com>
---
 net/ax25/af_ax25.c  |   18 +++---------------
 net/ax25/ax25_uid.c |   25 ++++---------------------
 2 files changed, 7 insertions(+), 36 deletions(-)

--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Bernard Pidoux June 16, 2011, 8:23 p.m. UTC | #3 
Hi,

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


--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Bernard Pidoux June 16, 2011, 8:29 p.m. UTC | #4 
Hi,

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


--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Bernard Pidoux June 16, 2011, 8:40 p.m. UTC | #5 
Hi,

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


--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Ralf Baechle June 17, 2011, 1:28 p.m. UTC | #6 
On Thu, Jun 16, 2011 at 10:23:09PM +0200, f6bvp wrote:

> 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
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
diff mbox

Patch

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