kernel BUG at kernel/timer.c:951!

kernel BUG at kernel/timer.c:951!

[Bernard Pidoux]

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

I am experiencing a few kernel panics on my Linux system using 2.6.32 and 2.6.32.1 kernels
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

 

[-- Attachment #2: nc_u_l_p_6666 --]
[-- Type: text/plain, Size: 21881 bytes --]

-------------------------------
general protection fault: 0000 [#1] 
last sysfs file: /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq
CPU 0 
Modules linked in: netconsole netrom mkiss rose ax25 nfsd exportfs nfs lockd nfs_acl auth_rpcgss sunrpc af_packet 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 soundcore shpchp 8139cp 8139too pci_hotplug sr_mod i2c_viapro i2c_core mii ipv6 binfmt_misc ext3 jbd cpufreq_ondemand cpufreq_conservative cpufreq_powersave acpi_cpufreq freq_table rtc_cmos floppy processor thermal via_agp button evdev sg pata_via ata_generic ide_pci_generic pata_acpi sata_via libata sd_mod scsi_mod crc_t10dif
Pid: 0, comm: swapper Not tainted 2.6.32-nosmp #1 MS-7258
RIP: 0010:[<ffffffff81057c16>]  [<ffffffff81057c16>] run_timer_softirq+0x176/0x300
RSP: 0018:ffffffff814fbe70  EFLAGS: 00010246
RAX: 0000000000000000 RBX: ffff880049c6f040 RCX: 1bc0000000000000
RDX: ffffffff814fbeb0 RSI: 3a75ffe60e489c6f RDI: ffff880049c6f000
RBP: ffffffff814fbef0 R08: de00000000000000 R09: ffff880049c6f040
R10: ffffffff81506e60 R11: 0000000000000000 R12: ffffffff81610268
R13: ffffffff816104c0 R14: ffffffff814fbeb0 R15: ff0000fb001001f0
FS:  0000000000000000(0000) GS:ffffffff814f8000(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00007f34976aa000 CR3: 000000002cbd4000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff4ff0 DR7: 0000000000000400
Process swapper (pid: 0, threadinfo ffffffff814da000, task ffffffff814ece40)
Stack:
 ffffffff814dbfd8 ffffffff814dbfd8 00000100810178c6 ffff880049c6f000
<0> ffffffff816120d8 ffffffff81611cd8 ffffffff816118d8 ffffffff816114d8
<0> ffffffff814fbeb0 ffffffff814fbeb0 ffffffff81027d98 ffffffff814dbfd8
Call Trace:
 <IRQ> 
 [<ffffffff81027d98>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104f642>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e0a>] call_softirq+0x1a/0x30
 [<ffffffff81013b55>] do_softirq+0x65/0xa0
 [<ffffffff8104f22d>] irq_exit+0x3d/0x50
 [<ffffffff81028869>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011933>] apic_timer_interrupt+0x13/0x20
 <EOI> 
 [<ffffffff81018880>] ? mwait_idle+0x80/0xc0
 [<ffffffff81068851>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff8101012c>] ? cpu_idle+0x8c/0xb0
 [<ffffffff8135cfcb>] ? rest_init+0x5b/0x70
 [<ffffffff8155bc9d>] ? start_kernel+0x3a6/0x46f
 [<ffffffff8155b2b9>] ? x86_64_start_reservations+0x99/0xb9
 [<ffffffff8155b3df>] ? x86_64_start_kernel+0x106/0x121
 [<ffffffff8155b140>] ? early_idt_handler+0x0/0x71
Code: 4c 8b 25 4e 62 4f 00 4d 85 e4 74 1b 49 8b 04 24 0f 1f 44 00 00 49 83 c4 08 48 89 df ff d0 49 8b 04 24 48 85 c0 75 ee 48 8b 7d 98 <41> ff d7 8b 05 49 62 4f 00 85 c0 74 27 4c 8b 25 56 62 4f 00 4d 
RIP  [<ffffffff81057c16>] run_timer_softirq+0x176/0x300
 RSP <ffffffff814fbe70>
---[ end trace b7400eefcee63331 ]---
Kernel panic - not syncing: Fatal exception in interrupt
Pid: 0, comm: swapper Tainted: G      D    2.6.32-nosmp #1
Call Trace:
 <IRQ>  [<ffffffff813640ab>] panic+0xa0/0x172
 [<ffffffff812cf8c2>] ? __kfree_skb+0x42/0xb0
 [<ffffffff810117d3>] ? ret_from_intr+0x0/0x10
 [<ffffffff812cf8c2>] ? __kfree_skb+0x42/0xb0
 [<ffffffff81014ea5>] ? oops_end+0xc5/0xe0
 [<ffffffff81014eac>] oops_end+0xcc/0xe0
 [<ffffffff81015076>] die+0x56/0x90
 [<ffffffff81013138>] do_general_protection+0x158/0x160
 [<ffffffff81366665>] general_protection+0x25/0x30
 [<ffffffff81057c16>] ? run_timer_softirq+0x176/0x300
 [<ffffffff81027d98>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104f642>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e0a>] call_softirq+0x1a/0x30
 [<ffffffff81013b55>] do_softirq+0x65/0xa0
 [<ffffffff8104f22d>] irq_exit+0x3d/0x50
 [<ffffffff81028869>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011933>] apic_timer_interrupt+0x13/0x20
 <EOI>  [<ffffffff81018880>] ? mwait_idle+0x80/0xc0
 [<ffffffff81068851>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff8101012c>] ? cpu_idle+0x8c/0xb0
 [<ffffffff8135cfcb>] ? rest_init+0x5b/0x70
 [<ffffffff8155bc9d>] ? start_kernel+0x3a6/0x46f
 [<ffffffff8155b2b9>] ? x86_64_start_reservations+0x99/0xb9
 [<ffffffff8155b3df>] ? x86_64_start_kernel+0x106/0x121
 [<ffffffff8155b140>] ? early_idt_handler+0x0/0x71
Rebooting in 60 seconds..  
-------------------------------
-------------------------------
BUG: unable to handle kernel paging request at 00000000000075d0
IP: [<00000000000075d0>] 0x75d0
PGD 67cf2067 PUD 78b65067 PMD 0 
Thread overran stack, or stack corrupted
Oops: 0000 [#1] 
last sysfs file: /sys/devices/system/cpu/cpu0/cpufreq/scaling_cur_freq
CPU 0 
Modules linked in: netconsole netrom mkiss rose ax25 nfsd exportfs nfs lockd nfs_acl auth_rpcgss sunrpc af_packet ipv6 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 8139cp i2c_viapro 8139too shpchp soundcore i2c_core pci_hotplug mii sr_mod binfmt_misc ext3 jbd cpufreq_ondemand cpufreq_conservative cpufreq_powersave acpi_cpufreq freq_table floppy rtc_cmos processor via_agp button thermal evdev sg pata_via ata_generic ide_pci_generic pata_acpi sata_via libata sd_mod scsi_mod crc_t10dif
Pid: 0, comm: swapper Not tainted 2.6.32-nosmp #1 MS-7258
RIP: 0010:[<00000000000075d0>]  [<00000000000075d0>] 0x75d0
RSP: 0018:ffffffff814fbe68  EFLAGS: 00010246
RAX: 0000000000000000 RBX: ffff880003842618 RCX: 1080000000000000
RDX: ffff8800666ba910 RSI: 0a9dfff79ef83842 RDI: 0000000000000000
RBP: ffffffff814fbef0 R08: 8400000000000000 R09: ffff880003842618
R10: ffffffff81506e60 R11: 0000000000000000 R12: ffffffff81610268
R13: ffffffff816104c0 R14: ffffffff814fbeb0 R15: 00000000000075d0
FS:  0000000000000000(0000) GS:ffffffff814f8000(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00000000000075d0 CR3: 0000000067cce000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process swapper (pid: 0, threadinfo ffffffff814da000, task ffffffff814ece40)
Stack:
 ffffffff81057c19 ffffffff814dbfd8 ffffffff814dbfd8 00000100810178c6
<0> 0000000000000000 ffffffff816120d8 ffffffff81611cd8 ffffffff816118d8
<0> ffffffff816114d8 ffff8800666ba910 ffff8800666ba910 ffffffff81027d98
Call Trace:
 <IRQ> 
 [<ffffffff81057c19>] ? run_timer_softirq+0x179/0x300
 [<ffffffff81027d98>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104f642>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e0a>] call_softirq+0x1a/0x30
 [<ffffffff81013b55>] do_softirq+0x65/0xa0
 [<ffffffff8104f22d>] irq_exit+0x3d/0x50
 [<ffffffff81028869>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011933>] apic_timer_interrupt+0x13/0x20
 <EOI> 
 [<ffffffff81018880>] ? mwait_idle+0x80/0xc0
 [<ffffffff81068851>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff8101012c>] ? cpu_idle+0x8c/0xb0
 [<ffffffff8135cfcb>] ? rest_init+0x5b/0x70
 [<ffffffff8155bc9d>] ? start_kernel+0x3a6/0x46f
 [<ffffffff8155b2b9>] ? x86_64_start_reservations+0x99/0xb9
 [<ffffffff8155b3df>] ? x86_64_start_kernel+0x106/0x121
 [<ffffffff8155b140>] ? early_idt_handler+0x0/0x71
Code:  Bad RIP value.
RIP  [<00000000000075d0>] 0x75d0
 RSP <ffffffff814fbe68>
CR2: 00000000000075d0
---[ end trace 1d821a4ff312041a ]---
Kernel panic - not syncing: Fatal exception in interrupt
Pid: 0, comm: swapper Tainted: G      D    2.6.32-nosmp #1
Call Trace:
 <IRQ>  [<ffffffff813640ab>] panic+0xa0/0x172
 [<ffffffff812cf8c2>] ? __kfree_skb+0x42/0xb0
 [<ffffffff810117d3>] ? ret_from_intr+0x0/0x10
 [<ffffffff81014e3a>] ? oops_end+0x5a/0xe0
 [<ffffffff81014eac>] oops_end+0xcc/0xe0
 [<ffffffff81030c08>] no_context+0xe8/0x260
 [<ffffffff812cf9d4>] ? kfree_skb+0x64/0x90
 [<ffffffff81030eb5>] __bad_area_nosemaphore+0x135/0x200
 [<ffffffff81045df6>] ? enqueue_task_fair+0x186/0x3a0
 [<ffffffff8103a791>] ? activate_task+0x51/0x80
 [<ffffffff81030f8e>] bad_area_nosemaphore+0xe/0x10
 [<ffffffff8103138e>] do_page_fault+0x23e/0x2f0
 [<ffffffff81366695>] page_fault+0x25/0x30
 [<ffffffff81057c19>] ? run_timer_softirq+0x179/0x300
 [<ffffffff81027d98>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104f642>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e0a>] call_softirq+0x1a/0x30
 [<ffffffff81013b55>] do_softirq+0x65/0xa0
 [<ffffffff8104f22d>] irq_exit+0x3d/0x50
 [<ffffffff81028869>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011933>] apic_timer_interrupt+0x13/0x20
 <EOI>  [<ffffffff81018880>] ? mwait_idle+0x80/0xc0
 [<ffffffff81068851>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff8101012c>] ? cpu_idle+0x8c/0xb0
 [<ffffffff8135cfcb>] ? rest_init+0x5b/0x70
 [<ffffffff8155bc9d>] ? start_kernel+0x3a6/0x46f
 [<ffffffff8155b2b9>] ? x86_64_start_reservations+0x99/0xb9
 [<ffffffff8155b3df>] ? x86_64_start_kernel+0x106/0x121
 [<ffffffff8155b140>] ? early_idt_handler+0x0/0x71
Rebooting in 60 seconds..   
-------------------------------
-------------------------------
BUG: unable to handle kernel NULL pointer dereference at 0000000000000268
IP: [<ffffffff810ceb11>] bdi_register+0x31/0x190
PGD d563067 PUD d417067 PMD 0 
Oops: 0000 [#1] 
last sysfs file: /sys/devices/pci0000:00/0000:00:00.0/modalias
CPU 0 
Modules linked in: loop(+) netconsole netrom mkiss rose ax25 nfsd exportfs nfs lockd nfs_acl auth_rpcgss sunrpc af_packet ipv6 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 8139cp 8139too snd shpchp rtc_cmos i2c_viapro soundcore pci_hotplug i2c_core mii sr_mod binfmt_misc ext3 jbd via_agp evdev sg pata_via ata_generic ide_pci_generic sata_via libata sd_mod scsi_mod crc_t10dif
Pid: 28774, comm: modprobe Tainted: G        W  2.6.32-nosmp #2 MS-7258
RIP: 0010:[<ffffffff810ceb11>]  [<ffffffff810ceb11>] bdi_register+0x31/0x190
RSP: 0018:ffff88000c6e3da8  EFLAGS: 00010282
RAX: 0000000000000000 RBX: 0000000000000140 RCX: 0000000000000007
RDX: ffffffff81401845 RSI: 0000000000000000 RDI: 0000000000000140
RBP: ffff88000c6e3e98 R08: 0000000000000000 R09: 0000000000000001
R10: 0000000000000010 R11: 0000000000000000 R12: ffff880061659000
R13: 0000000000100000 R14: 0000000000ce41b0 R15: 0000000000cdc388
FS:  00002ac71c305f90(0000) GS:ffffffff8148e000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000000000000268 CR3: 000000001da23000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process modprobe (pid: 28774, threadinfo ffff88000c6e2000, task ffff88007ece2d20)
Stack:
 ffff88000c6e3dc8 0000000000000002 ffff88000c6e3e28 ffffffff8142d76c
<0> 0000000000000000 0000000000cdc388 ffff88000c6e3de8 0000000000000007
<0> 0000000000000000 0000000000000001 ffffffff814876a7 ffffffff81076c4f
Call Trace:
 [<ffffffff81076c4f>] ? print_modules+0x5f/0xc0
 [<ffffffff811caa8a>] ? blk_register_queue+0xea/0xf0
 [<ffffffff811caa8a>] ? blk_register_queue+0xea/0xf0
 [<ffffffff810476dc>] ? warn_slowpath_common+0x9c/0xd0
 [<ffffffff8104771f>] ? warn_slowpath_null+0xf/0x20
 [<ffffffff811caa8a>] ? blk_register_queue+0xea/0xf0
 [<ffffffff810cec93>] bdi_register_dev+0x23/0x30
 [<ffffffff811cf761>] add_disk+0x121/0x160
 [<ffffffffa00af834>] ? loop_alloc+0x144/0x180 [loop]
 [<ffffffffa00a0185>] loop_init+0x185/0x1e2 [loop]
 [<ffffffffa00a0000>] ? loop_init+0x0/0x1e2 [loop]
 [<ffffffff8100a037>] do_one_initcall+0x37/0x1a0
 [<ffffffff8107aba0>] sys_init_module+0xe0/0x260
 [<ffffffff81010e7f>] system_call_fastpath+0x16/0x1b
Code: 48 81 ec f0 00 00 00 48 89 5d e8 4c 89 65 f0 48 89 fb 4c 89 6d f8 48 89 8d 48 ff ff ff 4c 89 85 50 ff ff ff 4c 89 8d 58 ff ff ff <48> 83 bf 28 01 00 00 00 74 15 48 8b 5d e8 4c 8b 65 f0 4c 8b 6d 
RIP  [<ffffffff810ceb11>] bdi_register+0x31/0x190
 RSP <ffff88000c6e3da8>
CR2: 0000000000000268
---[ end trace f6be10bc0c089fe3 ]---
Kernel panic - not syncing: Fatal exception
Pid: 28774, comm: modprobe Tainted: G      D W  2.6.32-nosmp #2
Call Trace:
 [<ffffffff8132246b>] panic+0xa0/0x172
 [<ffffffff8107cac4>] ? crash_kexec+0x74/0x100
 [<ffffffff8128e572>] ? __kfree_skb+0x42/0xb0
 [<ffffffff8101192e>] ? apic_timer_interrupt+0xe/0x20
 [<ffffffff81014e3a>] ? oops_end+0x5a/0xe0
 [<ffffffff81014e77>] oops_end+0x97/0xe0
 [<ffffffff8102f458>] no_context+0xe8/0x260
 [<ffffffff8102f705>] __bad_area_nosemaphore+0x135/0x200
 [<ffffffff811e38f7>] ? vsnprintf+0x217/0x600
 [<ffffffff8102f828>] bad_area+0x48/0x60
 [<ffffffff8102fc3c>] do_page_fault+0x29c/0x2f0
 [<ffffffff81324a55>] page_fault+0x25/0x30
 [<ffffffff810ceb11>] ? bdi_register+0x31/0x190
 [<ffffffff81076c4f>] ? print_modules+0x5f/0xc0
 [<ffffffff811caa8a>] ? blk_register_queue+0xea/0xf0
 [<ffffffff811caa8a>] ? blk_register_queue+0xea/0xf0
 [<ffffffff810476dc>] ? warn_slowpath_common+0x9c/0xd0
 [<ffffffff8104771f>] ? warn_slowpath_null+0xf/0x20
 [<ffffffff811caa8a>] ? blk_register_queue+0xea/0xf0
 [<ffffffff810cec93>] bdi_register_dev+0x23/0x30
 [<ffffffff811cf761>] add_disk+0x121/0x160
 [<ffffffffa00af834>] ? loop_alloc+0x144/0x180 [loop]
 [<ffffffffa00a0185>] loop_init+0x185/0x1e2 [loop]
 [<ffffffffa00a0000>] ? loop_init+0x0/0x1e2 [loop]
 [<ffffffff8100a037>] do_one_initcall+0x37/0x1a0
 [<ffffffff8107aba0>] sys_init_module+0xe0/0x260
 [<ffffffff81010e7f>] system_call_fastpath+0x16/0x1b
Rebooting in 60 seconds..   
-------------------------------
-------------------------------
general protection fault: 0000 [#1] 
last sysfs file: /sys/devices/pci0000:00/0000:00:0f.1/host3/target3:0:1/3:0:1:0/model
CPU 0 
Modules linked in: 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 soundcore i2c_core floppy sr_mod sg shpchp pci_hotplug 8139too mii via_agp rtc_cmos button evdev pata_via ata_generic ide_pci_generic sata_via libata sd_mod scsi_mod crc_t10dif
Pid: 0, comm: swapper Not tainted 2.6.32.1-nosmp #4 MS-7258
RIP: 0010:[<ffffffffa028fe4d>]  [<ffffffffa028fe4d>] ax25_heartbeat_expiry+0xd/0x60 [ax25]
RSP: 0018:ffffffff814fbe60  EFLAGS: 00010286
RAX: 0000000000000000 RBX: ffff880059831a18 RCX: 0c40000000000000
RDX: ac846c8cff811900 RSI: 08e5ffe21f419831 RDI: ffff880059831800
RBP: ffffffff814fbe60 R08: 6200000000000000 R09: ffff880059831a18
R10: ffffffff81506dc0 R11: 0000000000000000 R12: ffffffff81607128
R13: ffffffff81607380 R14: ffffffff814fbeb0 R15: ffffffffa028fe40
FS:  0000000000000000(0000) GS:ffffffff814f8000(0000) knlGS:0000000000000000
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 00007f156815c000 CR3: 00000000637e2000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process swapper (pid: 0, threadinfo ffffffff814da000, task ffffffff814ece40)
Stack:
 ffffffff814fbef0 ffffffff810574d9 ffffffff814dbfd8 ffffffff814dbfd8
<0> 0000010081017906 ffff880059831800 ffffffff81608f98 ffffffff81608b98
<0> ffffffff81608798 ffffffff81608398 ffffffff814fbeb0 ffffffff814fbeb0
Call Trace:
 <IRQ> 
 [<ffffffff810574d9>] run_timer_softirq+0x179/0x300
 [<ffffffff81027c08>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104ef02>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e4a>] call_softirq+0x1a/0x30
 [<ffffffff81013b95>] do_softirq+0x65/0xa0
 [<ffffffff8104eaed>] irq_exit+0x3d/0x50
 [<ffffffff810286d9>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011973>] apic_timer_interrupt+0x13/0x20
 <EOI> 
 [<ffffffff81018720>] ? mwait_idle+0x80/0xc0
 [<ffffffff81068101>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff8101012c>] ? cpu_idle+0x8c/0xb0
 [<ffffffff813597fb>] ? rest_init+0x5b/0x70
 [<ffffffff8155ac8d>] ? start_kernel+0x396/0x45f
 [<ffffffff8155a2b9>] ? x86_64_start_reservations+0x99/0xb9
 [<ffffffff8155a3df>] ? x86_64_start_kernel+0x106/0x121
 [<ffffffff8155a140>] ? early_idt_handler+0x0/0x71
Code: 80 7a 58 00 66 90 74 da c9 0f 1f 44 00 00 c3 66 66 66 66 66 66 2e 0f 1f 84 00 00 00 00 00 55 48 8b 57 28 48 89 e5 48 85 d2 74 0c <8b> 42 50 85 c0 78 11 83 f8 01 7f 17 0f 1f 80 00 00 00 00 e8 cb 
RIP  [<ffffffffa028fe4d>] ax25_heartbeat_expiry+0xd/0x60 [ax25]
 RSP <ffffffff814fbe60>
---[ end trace 44c0364064d76fee ]---
Kernel panic - not syncing: Fatal exception in interrupt
Pid: 0, comm: swapper Tainted: G      D    2.6.32.1-nosmp #4
Call Trace:
 <IRQ>  [<ffffffff8136086b>] panic+0xa0/0x172
 [<ffffffff812cc0f2>] ? __kfree_skb+0x42/0xb0
 [<ffffffff81011813>] ? ret_from_intr+0x0/0x10
 [<ffffffff81014e7a>] ? oops_end+0x5a/0xe0
 [<ffffffff81014eec>] oops_end+0xcc/0xe0
 [<ffffffff810150b6>] die+0x56/0x90
 [<ffffffff81013178>] do_general_protection+0x158/0x160
 [<ffffffff81362e25>] general_protection+0x25/0x30
 [<ffffffffa028fe40>] ? ax25_heartbeat_expiry+0x0/0x60 [ax25]
 [<ffffffffa028fe4d>] ? ax25_heartbeat_expiry+0xd/0x60 [ax25]
 [<ffffffff810574d9>] run_timer_softirq+0x179/0x300
 [<ffffffff81027c08>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104ef02>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e4a>] call_softirq+0x1a/0x30
 [<ffffffff81013b95>] do_softirq+0x65/0xa0
 [<ffffffff8104eaed>] irq_exit+0x3d/0x50
 [<ffffffff810286d9>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011973>] apic_timer_interrupt+0x13/0x20
 <EOI>  [<ffffffff81018720>] ? mwait_idle+0x80/0xc0
 [<ffffffff81068101>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff8101012c>] ? cpu_idle+0x8c/0xb0
 [<ffffffff813597fb>] ? rest_init+0x5b/0x70
 [<ffffffff8155ac8d>] ? start_kernel+0x396/0x45f
 [<ffffffff8155a2b9>] ? x86_64_start_reservations+0x99/0xb9
 [<ffffffff8155a3df>] ? x86_64_start_kernel+0x106/0x121
 [<ffffffff8155a140>] ? early_idt_handler+0x0/0x71
Rebooting in 60 seconds..   
-------------------------------
------------[ cut here ]------------
kernel BUG at kernel/timer.c:951!
invalid opcode: 0000 [#1] 
last sysfs file: /sys/devices/pci0000:00/0000:00:00.0/modalias
CPU 0 
Modules linked in: 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 8139cp i2c_viapro i2c_core 8139too soundcore floppy sr_mod via_agp shpchp pci_hotplug mii sg rtc_cmos button evdev pata_via ata_generic ide_pci_generic sata_via libata sd_mod scsi_mod crc_t10dif
Pid: 25429, comm: setiathome-5.28 Not tainted 2.6.32.1-nosmp #4 MS-7258
RIP: 0010:[<ffffffff810538cb>]  [<ffffffff810538cb>] cascade+0x9b/0xa0
RSP: 0000:ffffffff814fbe30  EFLAGS: 00010082
RAX: 0000000000000000 RBX: ffff88005e5b6618 RCX: 0000000100c05204
RDX: ffffffff814fbe30 RSI: ffff88005e5b6618 RDI: ffffffff81607380
RBP: ffffffff814fbe60 R08: 0000000000000004 R09: ffffffff815090a0
R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81607380
R13: ffffffff814fbe30 R14: 0000000000000012 R15: 0000000000000001
FS:  00000000422f4940(0063) GS:ffffffff814f8000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f448ac9a000 CR3: 00000000525aa000 CR4: 00000000000006f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process setiathome-5.28 (pid: 25429, threadinfo ffff880074ed0000, task ffff8800525b2d20)
Stack:
 ffff880074c75970 ffff88005e5b6618 0000000000000000 ffffffff81607128
<0> ffffffff81607380 ffffffff814fbeb0 ffffffff814fbef0 ffffffff81057455
<0> ffff880074ed1fd8 ffff880074ed1fd8 ffffffff81017906 ffffffff814f4fa0
Call Trace:
 <IRQ> 
 [<ffffffff81057455>] run_timer_softirq+0xf5/0x300
 [<ffffffff81017906>] ? read_tsc+0x16/0x40
 [<ffffffff81027c08>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104ef02>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e4a>] call_softirq+0x1a/0x30
 [<ffffffff81013b95>] do_softirq+0x65/0xa0
 [<ffffffff8104eaed>] irq_exit+0x3d/0x50
 [<ffffffff810286d9>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011973>] apic_timer_interrupt+0x13/0x20
 <EOI> 
Code: 83 e0 fe 49 39 c4 75 23 48 89 d3 4c 89 e7 e8 7d fe ff ff 4c 39 eb 48 8b 13 75 dd 48 83 c4 10 44 89 f0 5b 41 5c 41 5d 41 5e c9 c3 <0f> 0b eb fe 90 55 48 8b 04 25 40 70 4f 81 48 8b 80 20 04 00 00 
RIP  [<ffffffff810538cb>] cascade+0x9b/0xa0
 RSP <ffffffff814fbe30>
---[ end trace 5feab457f7d8d266 ]---
Kernel panic - not syncing: Fatal exception in interrupt
Pid: 25429, comm: setiathome-5.28 Tainted: G      D    2.6.32.1-nosmp #4
Call Trace:
 <IRQ>  [<ffffffff8136086b>] panic+0xa0/0x172
 [<ffffffff8107ec14>] ? crash_kexec+0x74/0x100
 [<ffffffff812cc0f2>] ? __kfree_skb+0x42/0xb0
 [<ffffffff810491d5>] ? console_unblank+0x75/0x90
 [<ffffffff81014eec>] oops_end+0xcc/0xe0
 [<ffffffff810150b6>] die+0x56/0x90
 [<ffffffff810129b6>] do_trap+0x146/0x170
 [<ffffffff81068101>] ? atomic_notifier_call_chain+0x11/0x20
 [<ffffffff81012e30>] do_invalid_op+0x90/0xb0
 [<ffffffff810538cb>] ? cascade+0x9b/0xa0
 [<ffffffffa0279f1d>] ? ax25_kiss_rcv+0x1ed/0x900 [ax25]
 [<ffffffff81011adb>] invalid_op+0x1b/0x20
 [<ffffffff810538cb>] ? cascade+0x9b/0xa0
 [<ffffffff81057455>] run_timer_softirq+0xf5/0x300
 [<ffffffff81017906>] ? read_tsc+0x16/0x40
 [<ffffffff81027c08>] ? lapic_next_event+0x18/0x20
 [<ffffffff8104ef02>] __do_softirq+0xd2/0x1b0
 [<ffffffff81011e4a>] call_softirq+0x1a/0x30
 [<ffffffff81013b95>] do_softirq+0x65/0xa0
 [<ffffffff8104eaed>] irq_exit+0x3d/0x50
 [<ffffffff810286d9>] smp_apic_timer_interrupt+0x59/0x90
 [<ffffffff81011973>] apic_timer_interrupt+0x13/0x20
 <EOI> 
Rebooting in 60 seconds..   
-------------------------------

Re: kernel BUG at kernel/timer.c:951!

[Jarek Poplawski]

Bernard Pidoux wrote, On 12/19/2009 02:38 PM:

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

Re: kernel BUG at kernel/timer.c:951!

[Bernard Pidoux]

Hi Jarek,

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 wrote, On 12/19/2009 02:38 PM:
> 
>> 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.
> 
> 

Re: kernel BUG at kernel/timer.c:951!

[Bernard Pidoux]

Hi Jarek,

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 :
> Hi Jarek,
> 
> 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 wrote, On 12/19/2009 02:38 PM:
>>
>>> 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.
>>
>>
> 
> 

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

[Jarek Poplawski]

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

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

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

[David Miller]

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.

[PATCH 07/13] net: ax25: use seq_hlist_foo() helpers

[Bernard Pidoux]

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

[AX25] inconsistent lock state

[f6bvp]

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

Re: [AX25] inconsistent lock state

[Ralf Baechle]

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

Re: [AX25] inconsistent lock state

[Arnd Bergmann]

On Thursday 16 June 2011 22:23:09 f6bvp wrote:

> 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 <arnd@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;

Re: [AX25] inconsistent lock state

[Ralf Baechle]

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.

  Ralf

Re: [AX25] inconsistent lock state

[Arnd Bergmann]

On Friday 17 June 2011 15:51:48 Ralf Baechle wrote:
> 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

Re: [AX25] inconsistent lock state

[f6bvp]

Hi Arnd,

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


Le 17/06/2011 16:11, Arnd Bergmann a écrit :
> On Friday 17 June 2011 15:51:48 Ralf Baechle wrote:
>> 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

Re: [AX25] inconsistent lock state

[f6bvp]

Hi,

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 :
> On Friday 17 June 2011 15:51:48 Ralf Baechle wrote:
>> 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

Re: [AX25] inconsistent lock state

[Ralf Baechle DL5RB]

On Sat, Jun 25, 2011 at 05:51:39PM +0200, f6bvp wrote:

> 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 <ralf@linux-mips.org>

  Ralf

Re: [AX25] inconsistent lock state

[Bernard F6BVP]

Hi all,

Now, who is going to commit this mkiss patch and the equivalent one for 
sixpack.c ?

Bernard, f6bvp


Le 25/06/2011 18:39, Ralf Baechle DL5RB a écrit :
> On Sat, Jun 25, 2011 at 05:51:39PM +0200, f6bvp wrote:
>
>> 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<ralf@linux-mips.org>
>
>    Ralf

[PATCH] 6pack,mkiss: fix lock inconsistency

[Arnd Bergmann]

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 <f6bvp@free.fr>
Tested-by: Bernard F6BVP <f6bvp@free.fr>
Signed-off-by: Arnd Bergmann <arnd@arndb.de>
Acked-by: Ralf Baechle<ralf@linux-mips.org>
Cc: stable@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;

Re: [PATCH] 6pack,mkiss: fix lock inconsistency

[David Miller]

From: Arnd Bergmann <arnd@arndb.de>
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 <f6bvp@free.fr>
> Tested-by: Bernard F6BVP <f6bvp@free.fr>
> Signed-off-by: Arnd Bergmann <arnd@arndb.de>
> Acked-by: Ralf Baechle<ralf@linux-mips.org>
> Cc: stable@kernel.org

Applied, thanks!

[NetRom] possible circular locking dependency detected

[Bernard f6bvp]

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

Hi,

When shutting down my dual core system, there was a possible circular 
locking dependency detected that is related to NetRom.

Here is the syslog report.

Regards,

Bernard, f6bvp







[-- Attachment #2: ax25ipd_not_tainted.txt --]
[-- Type: text/plain, Size: 13574 bytes --]


Oct 21 12:10:35 f6bvp-8 aprslist[1773]: terminating on SIGTERM
Oct 21 12:10:35 f6bvp-8 fpacstat: terminating on SIGTERM
Oct 21 12:10:35 f6bvp-8 netromd[1653]: terminating on SIGTERM
Oct 21 12:10:35 f6bvp-8 ax25ipd: 
Oct 21 12:10:35 f6bvp-8 ax25ipd:   socket     udp on port 10094
Oct 21 12:10:35 f6bvp-8 ax25ipd:   mode       tnc
Oct 21 12:10:35 f6bvp-8 ax25ipd:   device     /dev/ptmx
Oct 21 12:10:35 f6bvp-8 ax25ipd:   speed      115200
Oct 21 12:10:35 f6bvp-8 ax25ipd:   loglevel   1
Oct 21 12:10:35 f6bvp-8 ax25ipd: 
Oct 21 12:10:35 f6bvp-8 ax25ipd:   K4GBB 184.4.148.122 udp 10094 1
Oct 21 12:10:35 f6bvp-8 ax25ipd:   F8COJ 0.0.0.0 udp 10093 1
Oct 21 12:10:35 f6bvp-8 ax25ipd:   F3KT 62.147.189.164 udp 10093 1
Oct 21 12:10:35 f6bvp-8 ax25ipd:   F6BVP-12 192.168.0.68 udp 10093 4
Oct 21 12:10:35 f6bvp-8 ax25ipd:   F6BVP-11 192.168.0.115 udp 10093 4
Oct 21 12:10:35 f6bvp-8 ax25ipd:   F6BVP-10 192.168.0.115 udp 10093 5
Oct 21 12:10:35 f6bvp-8 ax25ipd:   VA2BBS 24.212.252.110 udp 10093 1
Oct 21 12:10:35 f6bvp-8 ax25ipd:   ON4HU 81.243.88.115 udp 10093 1
Oct 21 12:10:35 f6bvp-8 ax25ipd:   IZ3LSV 88.149.155.158 udp 10094 5
Oct 21 12:10:35 f6bvp-8 ax25ipd: 
Oct 21 12:10:35 f6bvp-8 nfs-server[27474]: Arrêt de NFS kernel daemon
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150299] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150313] ======================================================
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150317] [ INFO: possible circular locking dependency detected ]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150321] 3.6.1 #1 Not tainted
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150325] -------------------------------------------------------
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150329] ax25ipd/1580 is trying to acquire lock:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150333]  (nr_node_list_lock){+.....}, at: [<ffffffffa06775ec>] nr_rt_device_down+0x7c/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150352] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150352] but task is already holding lock:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150356]  (nr_neigh_list_lock){+.-.-.}, at: [<ffffffffa0677596>] nr_rt_device_down+0x26/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150373] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150373] which lock already depends on the new lock.
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150373] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150378] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150378] the existing dependency chain (in reverse order) is:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150382] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150382] -> #2 (nr_neigh_list_lock){+.-.-.}:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150396]        [<ffffffff810b6452>] lock_acquire+0x92/0x120
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150409]        [<ffffffff81482b76>] _raw_spin_lock_bh+0x36/0x50
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150418]        [<ffffffffa06769eb>] nr_remove_neigh+0x1b/0xb0 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150429]        [<ffffffffa0677c20>] nr_rt_ioctl+0x2b0/0xa60 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150438]        [<ffffffffa0673fa1>] nr_ioctl+0x51/0x1d0 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150445]        [<ffffffff813973e0>] sock_do_ioctl+0x30/0x70
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150454]        [<ffffffff813976f9>] sock_ioctl+0x79/0x2f0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150460]        [<ffffffff8118dd08>] do_vfs_ioctl+0x98/0x560
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150468]        [<ffffffff8118e261>] sys_ioctl+0x91/0xa0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150477]        [<ffffffff8148b6b9>] system_call_fastpath+0x16/0x1b
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150486] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150486] -> #1 (&(&nr_node->node_lock)->rlock){+.....}:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150498]        [<ffffffff810b6452>] lock_acquire+0x92/0x120
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150505]        [<ffffffff81482b76>] _raw_spin_lock_bh+0x36/0x50
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150512]        [<ffffffffa0676acc>] nr_node_show+0x4c/0x150 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150522]        [<ffffffff8119da5c>] seq_read+0x26c/0x420
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150529]        [<ffffffff811e1046>] proc_reg_read+0x86/0xc0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150537]        [<ffffffff8117b01c>] vfs_read+0xac/0x180
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150546]        [<ffffffff8117b13a>] sys_read+0x4a/0x90
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150552]        [<ffffffff8148b6b9>] system_call_fastpath+0x16/0x1b
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150559] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150559] -> #0 (nr_node_list_lock){+.....}:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150571]        [<ffffffff810b5c41>] __lock_acquire+0x1a91/0x1ce0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150578]        [<ffffffff810b6452>] lock_acquire+0x92/0x120
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150586]        [<ffffffff81482b76>] _raw_spin_lock_bh+0x36/0x50
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150592]        [<ffffffffa06775ec>] nr_rt_device_down+0x7c/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150601]        [<ffffffffa0674b4d>] nr_device_event+0x7d/0xa0 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150608]        [<ffffffff81487388>] notifier_call_chain+0x58/0xb0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150617]        [<ffffffff810810c6>] raw_notifier_call_chain+0x16/0x20
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150625]        [<ffffffff813ae526>] call_netdevice_notifiers+0x36/0x60
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150633]        [<ffffffff813ae71f>] dev_close_many+0xbf/0x100
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150639]        [<ffffffff813ae838>] rollback_registered_many+0xd8/0x250
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150645]        [<ffffffff813aea4d>] rollback_registered+0x2d/0x40
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150653]        [<ffffffff813b17a8>] unregister_netdevice_queue+0x68/0xc0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150659]        [<ffffffff813b1820>] unregister_netdev+0x20/0x30
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150666]        [<ffffffffa05df4e7>] mkiss_close+0x57/0x90 [mkiss]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150674]        [<ffffffff81309ed1>] tty_ldisc_close.isra.2+0x41/0x60
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150683]        [<ffffffff8130a0d0>] tty_ldisc_reinit+0x40/0x80
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150689]        [<ffffffff8130a850>] tty_ldisc_hangup+0x190/0x340
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150695]        [<ffffffff81301f8a>] __tty_hangup+0x10a/0x3c0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150703]        [<ffffffff8130226e>] tty_vhangup+0xe/0x10
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150709]        [<ffffffff8130c66e>] pty_close+0x10e/0x180
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150716]        [<ffffffff81303212>] tty_release+0x182/0x5c0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150724]        [<ffffffff8117bf9e>] __fput+0xae/0x230
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150734]        [<ffffffff8117c12e>] ____fput+0xe/0x10
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150740]        [<ffffffff81076fb9>] task_work_run+0x69/0x90
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150748]        [<ffffffff8105abef>] do_exit+0x87f/0x900
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150756]        [<ffffffff8105afce>] do_group_exit+0x4e/0xc0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150763]        [<ffffffff8105b057>] sys_exit_group+0x17/0x20
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150770]        [<ffffffff8148b6b9>] system_call_fastpath+0x16/0x1b
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150778] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150778] other info that might help us debug this:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150778] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150782] Chain exists of:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150782]   nr_node_list_lock --> &(&nr_node->node_lock)->rlock --> nr_neigh_list_lock
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150782] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150799]  Possible unsafe locking scenario:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150799] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150803]        CPU0                    CPU1
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150806]        ----                    ----
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150809]   lock(nr_neigh_list_lock);
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150819]                                lock(&(&nr_node->node_lock)->rlock);
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150826]                                lock(nr_neigh_list_lock);
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150834]   lock(nr_node_list_lock);
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150842] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150842]  *** DEADLOCK ***
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150842] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150847] 4 locks held by ax25ipd/1580:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150851]  #0:  (big_tty_mutex){+.+.+.}, at: [<ffffffff814832d7>] tty_lock+0x17/0x19
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150867]  #1:  (&tty->ldisc_mutex){+.+.+.}, at: [<ffffffff8130a7d7>] tty_ldisc_hangup+0x117/0x340
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150885]  #2:  (rtnl_mutex){+.+.+.}, at: [<ffffffff813c11c7>] rtnl_lock+0x17/0x20
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150901]  #3:  (nr_neigh_list_lock){+.-.-.}, at: [<ffffffffa0677596>] nr_rt_device_down+0x26/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150921] 
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150921] stack backtrace:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150927] Pid: 1580, comm: ax25ipd Not tainted 3.6.1 #1
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150930] Call Trace:
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150938]  [<ffffffff81479b5a>] print_circular_bug+0x289/0x29a
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150945]  [<ffffffff810b5c41>] __lock_acquire+0x1a91/0x1ce0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150954]  [<ffffffffa06775ec>] ? nr_rt_device_down+0x7c/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150960]  [<ffffffff810b6452>] lock_acquire+0x92/0x120
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150969]  [<ffffffffa06775ec>] ? nr_rt_device_down+0x7c/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150976]  [<ffffffff81482b76>] _raw_spin_lock_bh+0x36/0x50
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150984]  [<ffffffffa06775ec>] ? nr_rt_device_down+0x7c/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150990]  [<ffffffff810b6ec5>] ? trace_hardirqs_on_caller+0x105/0x190
Oct 21 12:10:36 f6bvp-8 kernel: [522519.150997]  [<ffffffffa0674b41>] ? nr_device_event+0x71/0xa0 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151005]  [<ffffffffa06775ec>] nr_rt_device_down+0x7c/0x240 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151011]  [<ffffffff8105d1a7>] ? local_bh_enable_ip+0x97/0x100
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151019]  [<ffffffffa0674b4d>] nr_device_event+0x7d/0xa0 [netrom]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151026]  [<ffffffff81487388>] notifier_call_chain+0x58/0xb0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151033]  [<ffffffff810810c6>] raw_notifier_call_chain+0x16/0x20
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151038]  [<ffffffff813ae526>] call_netdevice_notifiers+0x36/0x60
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151044]  [<ffffffff813ae71f>] dev_close_many+0xbf/0x100
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151050]  [<ffffffff813ae838>] rollback_registered_many+0xd8/0x250
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151055]  [<ffffffff813aea4d>] rollback_registered+0x2d/0x40
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151061]  [<ffffffff813b17a8>] unregister_netdevice_queue+0x68/0xc0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151068]  [<ffffffff813b1820>] unregister_netdev+0x20/0x30
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151077]  [<ffffffffa05df4e7>] mkiss_close+0x57/0x90 [mkiss]
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151083]  [<ffffffff81309ed1>] tty_ldisc_close.isra.2+0x41/0x60
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151089]  [<ffffffff8130a0d0>] tty_ldisc_reinit+0x40/0x80
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151094]  [<ffffffff8130a850>] tty_ldisc_hangup+0x190/0x340
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151101]  [<ffffffff81301f8a>] __tty_hangup+0x10a/0x3c0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151107]  [<ffffffff810b6f5d>] ? trace_hardirqs_on+0xd/0x10
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151114]  [<ffffffff8130226e>] tty_vhangup+0xe/0x10
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151120]  [<ffffffff8130c66e>] pty_close+0x10e/0x180
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151126]  [<ffffffff81303212>] tty_release+0x182/0x5c0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151132]  [<ffffffff81192d92>] ? dput+0x62/0x1b0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151138]  [<ffffffff8117bf9e>] __fput+0xae/0x230
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151144]  [<ffffffff8117c12e>] ____fput+0xe/0x10
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151148]  [<ffffffff81076fb9>] task_work_run+0x69/0x90
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151148]  [<ffffffff8105abef>] do_exit+0x87f/0x900
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151148]  [<ffffffff81483495>] ? retint_swapgs+0x13/0x1b
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151148]  [<ffffffff8105afce>] do_group_exit+0x4e/0xc0
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151148]  [<ffffffff8105b057>] sys_exit_group+0x17/0x20
Oct 21 12:10:36 f6bvp-8 kernel: [522519.151148]  [<ffffffff8148b6b9>] system_call_fastpath+0x16/0x1b

Re: [AX25] inconsistent lock state

[f6bvp]

Hi Ralf,

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

khubd [ INFO: possible circular locking dependency detected ]

[f6bvp]

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

[AX25] inconsistent lock state

[f6bvp]

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

[PATCH 00/13] net: simplify seq_file code

[Li Zefan]

This patchset introduces seq_hlist_foo() helpers, and convert
net/* to seq_hlist_foo() and seq_list_foo().

---
 fs/seq_file.c                 |   37 ++++++++++++-
 include/linux/seq_file.h      |   11 ++++
 include/net/sock.h            |    5 ++
 net/appletalk/atalk_proc.c    |   30 +----------
 net/atm/proc.c                |    2 +-
 net/atm/resources.c           |   28 +++--------
 net/ax25/af_ax25.c            |   18 +-----
 net/ax25/ax25_uid.c           |   25 ++--------
 net/ipx/ipx_proc.c            |   89 ++++---------------------------
 net/irda/irlan/irlan_common.c |   26 ++--------
 net/key/af_key.c              |   20 +------
 net/netrom/af_netrom.c        |   21 +-------
 net/netrom/nr_route.c         |   53 +++----------------
 net/packet/af_packet.c        |   20 +------
 net/rose/af_rose.c            |   22 +-------
 net/x25/x25_proc.c            |  114 ++++-------------------------------------
 16 files changed, 116 insertions(+), 405 deletions(-)

[PATCH 07/13] net: ax25: use seq_hlist_foo() helpers

[Li Zefan]

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

diff --git a/net/ax25/af_ax25.c b/net/ax25/af_ax25.c
index 5588ba6..a5beedf 100644
--- a/net/ax25/af_ax25.c
+++ b/net/ax25/af_ax25.c
@@ -1863,25 +1863,13 @@ static int ax25_ioctl(struct socket *sock, unsigned int cmd, unsigned long arg)
 static void *ax25_info_start(struct seq_file *seq, loff_t *pos)
 	__acquires(ax25_list_lock)
 {
-	struct ax25_cb *ax25;
-	struct hlist_node *node;
-	int i = 0;
-
 	spin_lock_bh(&ax25_list_lock);
-	ax25_for_each(ax25, node, &ax25_list) {
-		if (i == *pos)
-			return ax25;
-		++i;
-	}
-	return NULL;
+	return seq_hlist_start(&ax25_list, *pos);
 }
 
 static void *ax25_info_next(struct seq_file *seq, void *v, loff_t *pos)
 {
-	++*pos;
-
-	return hlist_entry( ((struct ax25_cb *)v)->ax25_node.next,
-			    struct ax25_cb, ax25_node);
+	return seq_hlist_next(v, &ax25_list, pos);
 }
 
 static void ax25_info_stop(struct seq_file *seq, void *v)
@@ -1892,7 +1880,7 @@ static void ax25_info_stop(struct seq_file *seq, void *v)
 
 static int ax25_info_show(struct seq_file *seq, void *v)
 {
-	ax25_cb *ax25 = v;
+	ax25_cb *ax25 = hlist_entry(v, struct ax25_cb, ax25_node);
 	char buf[11];
 	int k;
 
diff --git a/net/ax25/ax25_uid.c b/net/ax25/ax25_uid.c
index 832bcf0..9f13f6e 100644
--- a/net/ax25/ax25_uid.c
+++ b/net/ax25/ax25_uid.c
@@ -146,31 +146,13 @@ int ax25_uid_ioctl(int cmd, struct sockaddr_ax25 *sax)
 static void *ax25_uid_seq_start(struct seq_file *seq, loff_t *pos)
 	__acquires(ax25_uid_lock)
 {
-	struct ax25_uid_assoc *pt;
-	struct hlist_node *node;
-	int i = 1;
-
 	read_lock(&ax25_uid_lock);
-
-	if (*pos == 0)
-		return SEQ_START_TOKEN;
-
-	ax25_uid_for_each(pt, node, &ax25_uid_list) {
-		if (i == *pos)
-			return pt;
-		++i;
-	}
-	return NULL;
+	return seq_hlist_start_head(&ax25_uid_list, *pos);
 }
 
 static void *ax25_uid_seq_next(struct seq_file *seq, void *v, loff_t *pos)
 {
-	++*pos;
-	if (v == SEQ_START_TOKEN)
-		return ax25_uid_list.first;
-	else
-		return hlist_entry(((ax25_uid_assoc *)v)->uid_node.next,
-			   ax25_uid_assoc, uid_node);
+	return seq_hlist_next(v, &ax25_uid_list, pos);
 }
 
 static void ax25_uid_seq_stop(struct seq_file *seq, void *v)
@@ -186,8 +168,9 @@ static int ax25_uid_seq_show(struct seq_file *seq, void *v)
 	if (v == SEQ_START_TOKEN)
 		seq_printf(seq, "Policy: %d\n", ax25_uid_policy);
 	else {
-		struct ax25_uid_assoc *pt = v;
+		struct ax25_uid_assoc *pt;
 
+		pt = hlist_entry(v, struct ax25_uid_assoc, uid_node);
 		seq_printf(seq, "%6d %s\n", pt->uid, ax2asc(buf, &pt->call));
 	}
 	return 0;
-- 
1.6.3

[PATCH 00/13] net: simplify seq_file code, revised

[Li Zefan]

This patchset introduces seq_hlist_foo() helpers, and convert
net/* to seq_hlist_foo() and seq_list_foo().

Changelog:

- Add kerneldoc in patch 1/13
- Fix compile warning in patch 11/13
- Fix a bug in patch 12/13

---
 fs/seq_file.c                 |   60 ++++++++++++++++++++-
 include/linux/seq_file.h      |   11 ++++
 include/net/sock.h            |    5 ++
 net/appletalk/atalk_proc.c    |   30 +----------
 net/atm/proc.c                |    2 +-
 net/atm/resources.c           |   28 +++--------
 net/ax25/af_ax25.c            |   18 +-----
 net/ax25/ax25_uid.c           |   25 ++--------
 net/ipx/ipx_proc.c            |   90 ++++----------------------------
 net/irda/irlan/irlan_common.c |   28 ++---------
 net/key/af_key.c              |   20 +------
 net/netrom/af_netrom.c        |   21 +-------
 net/netrom/nr_route.c         |   53 +++----------------
 net/packet/af_packet.c        |   20 +------
 net/rose/af_rose.c            |   22 +-------
 net/x25/x25_proc.c            |  114 ++++-------------------------------------
 16 files changed, 139 insertions(+), 408 deletions(-)

[PATCH 07/13] net: ax25: use seq_hlist_foo() helpers

[Li Zefan]

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

diff --git a/net/ax25/af_ax25.c b/net/ax25/af_ax25.c
index 5588ba6..a5beedf 100644
--- a/net/ax25/af_ax25.c
+++ b/net/ax25/af_ax25.c
@@ -1863,25 +1863,13 @@ static int ax25_ioctl(struct socket *sock, unsigned int cmd, unsigned long arg)
 static void *ax25_info_start(struct seq_file *seq, loff_t *pos)
 	__acquires(ax25_list_lock)
 {
-	struct ax25_cb *ax25;
-	struct hlist_node *node;
-	int i = 0;
-
 	spin_lock_bh(&ax25_list_lock);
-	ax25_for_each(ax25, node, &ax25_list) {
-		if (i == *pos)
-			return ax25;
-		++i;
-	}
-	return NULL;
+	return seq_hlist_start(&ax25_list, *pos);
 }
 
 static void *ax25_info_next(struct seq_file *seq, void *v, loff_t *pos)
 {
-	++*pos;
-
-	return hlist_entry( ((struct ax25_cb *)v)->ax25_node.next,
-			    struct ax25_cb, ax25_node);
+	return seq_hlist_next(v, &ax25_list, pos);
 }
 
 static void ax25_info_stop(struct seq_file *seq, void *v)
@@ -1892,7 +1880,7 @@ static void ax25_info_stop(struct seq_file *seq, void *v)
 
 static int ax25_info_show(struct seq_file *seq, void *v)
 {
-	ax25_cb *ax25 = v;
+	ax25_cb *ax25 = hlist_entry(v, struct ax25_cb, ax25_node);
 	char buf[11];
 	int k;
 
diff --git a/net/ax25/ax25_uid.c b/net/ax25/ax25_uid.c
index 832bcf0..9f13f6e 100644
--- a/net/ax25/ax25_uid.c
+++ b/net/ax25/ax25_uid.c
@@ -146,31 +146,13 @@ int ax25_uid_ioctl(int cmd, struct sockaddr_ax25 *sax)
 static void *ax25_uid_seq_start(struct seq_file *seq, loff_t *pos)
 	__acquires(ax25_uid_lock)
 {
-	struct ax25_uid_assoc *pt;
-	struct hlist_node *node;
-	int i = 1;
-
 	read_lock(&ax25_uid_lock);
-
-	if (*pos == 0)
-		return SEQ_START_TOKEN;
-
-	ax25_uid_for_each(pt, node, &ax25_uid_list) {
-		if (i == *pos)
-			return pt;
-		++i;
-	}
-	return NULL;
+	return seq_hlist_start_head(&ax25_uid_list, *pos);
 }
 
 static void *ax25_uid_seq_next(struct seq_file *seq, void *v, loff_t *pos)
 {
-	++*pos;
-	if (v == SEQ_START_TOKEN)
-		return ax25_uid_list.first;
-	else
-		return hlist_entry(((ax25_uid_assoc *)v)->uid_node.next,
-			   ax25_uid_assoc, uid_node);
+	return seq_hlist_next(v, &ax25_uid_list, pos);
 }
 
 static void ax25_uid_seq_stop(struct seq_file *seq, void *v)
@@ -186,8 +168,9 @@ static int ax25_uid_seq_show(struct seq_file *seq, void *v)
 	if (v == SEQ_START_TOKEN)
 		seq_printf(seq, "Policy: %d\n", ax25_uid_policy);
 	else {
-		struct ax25_uid_assoc *pt = v;
+		struct ax25_uid_assoc *pt;
 
+		pt = hlist_entry(v, struct ax25_uid_assoc, uid_node);
 		seq_printf(seq, "%6d %s\n", pt->uid, ax2asc(buf, &pt->call));
 	}
 	return 0;
-- 
1.6.3