LinuxLists.cc - kernel BUG at kernel/timer.c:951!

2009-12-19 13:39:21

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

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

Attachments:

nc_u_l_p_6666 (21.37 kB)

2009-12-19 17:41:25

by Jarek Poplawski

[permalink] [raw]

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

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.

2009-12-20 18:04:40

by Bernard Pidoux

[permalink] [raw]

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

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

2010-01-15 14:46:21

by Bernard Pidoux

[permalink] [raw]

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

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

2010-01-15 20:37:06

by Jarek Poplawski

[permalink] [raw]

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

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 <[email protected]>
Tested-by: Bernard Pidoux <[email protected]>
Signed-off-by: Jarek Poplawski <[email protected]>
---

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

2010-01-16 09:04:33

by David Miller

[permalink] [raw]

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

From: Jarek Poplawski <[email protected]>
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 <[email protected]>
> Tested-by: Bernard Pidoux <[email protected]>
> Signed-off-by: Jarek Poplawski <[email protected]>

Applied, thanks everyone.

2010-02-11 16:35:05

by Bernard Pidoux

[permalink] [raw]

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

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 <[email protected]>
---
net/ax25/af_ax25.c | 18 +++---------------
net/ax25/ax25_uid.c | 25 ++++---------------------
2 files changed, 7 insertions(+), 36 deletions(-)

2011-06-16 20:23:24

by f6bvp

[permalink] [raw]

Subject: [AX25] inconsistent lock state

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

2011-06-16 20:29:41

by f6bvp

[permalink] [raw]

Subject: khubd [ INFO: possible circular locking dependency detected ]

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

2011-06-16 20:41:10

by f6bvp

[permalink] [raw]

Subject: [AX25] inconsistent lock state

2011-06-17 13:28:32

by Ralf Baechle

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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

2011-06-17 13:36:38

by Arnd Bergmann

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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 <[email protected]>

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

2011-06-17 14:01:00

by Ralf Baechle

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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

2011-06-17 14:11:34

by Arnd Bergmann

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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

2011-06-17 15:26:48

by f6bvp

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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

2011-06-17 15:31:41

by f6bvp

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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

2011-06-25 15:51:51

by f6bvp

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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

2011-06-25 16:39:50

by Ralf Baechle

[permalink] [raw]

Subject: Re: [AX25] inconsistent lock state

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 <[email protected]>

Ralf

2012-10-21 15:19:06

by f6bvp

[permalink] [raw]

Subject: [NetRom] possible circular locking dependency detected

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

Attachments:

ax25ipd_not_tainted.txt (13.26 kB)