On Thu, 25 Aug 2011 12:42:00 -0500, Jonathan Nieder <jrnieder@gmail.com> wrote: > Please send the full content of /var/log/dmesg after running > > echo d >/proc/sysrq-trigger/proc/sysrq-trigger > echo w >/proc/sysrq-trigger > > when a process is in this hung state. Attached is a diff of the output of dmesg before and after echo'ing 'd' and 'w' to /proc/sysrq-trigger. You can see the cdrom_id process hung in D state. I can also confirm that the cdrom_id process becomes hung after I physically remove my laptop from it's dock (after ejecting it with eject button on the dock). This can be seen in the second attachment, which is a diff of syslog before and after the removal. jamie.
--- 3-sleepattempt/dmesg 2011-08-27 11:47:03.258128750 -0700 +++ 5-echo-w/dmesg 2011-08-27 11:48:09.427721925 -0700 @@ -1,175 +1,4 @@ -[ 0.000000] Initializing cgroup subsys cpuset -[ 0.000000] Initializing cgroup subsys cpu -[ 0.000000] Linux version 3.0.0-1-amd64 (Debian 3.0.0-1) (ben@decadent.org.uk) (gcc version 4.5.3 (Debian 4.5.3-4) ) #1 SMP Sun Jul 24 02:24:44 UTC 2011 -[ 0.000000] Command line: BOOT_IMAGE=/vmlinuz-3.0.0-1-amd64 root=/dev/mapper/servo-root ro vga=788 -[ 0.000000] BIOS-provided physical RAM map: -[ 0.000000] BIOS-e820: 0000000000000000 - 000000000009e800 (usable) -[ 0.000000] BIOS-e820: 000000000009e800 - 00000000000a0000 (reserved) -[ 0.000000] BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved) -[ 0.000000] BIOS-e820: 0000000000100000 - 00000000bb27c000 (usable) -[ 0.000000] BIOS-e820: 00000000bb27c000 - 00000000bb282000 (reserved) -[ 0.000000] BIOS-e820: 00000000bb282000 - 00000000bb35f000 (usable) -[ 0.000000] BIOS-e820: 00000000bb35f000 - 00000000bb371000 (reserved) -[ 0.000000] BIOS-e820: 00000000bb371000 - 00000000bb3f2000 (ACPI NVS) -[ 0.000000] BIOS-e820: 00000000bb3f2000 - 00000000bb40f000 (reserved) -[ 0.000000] BIOS-e820: 00000000bb40f000 - 00000000bb46f000 (usable) -[ 0.000000] BIOS-e820: 00000000bb46f000 - 00000000bb668000 (reserved) -[ 0.000000] BIOS-e820: 00000000bb668000 - 00000000bb6e8000 (ACPI NVS) -[ 0.000000] BIOS-e820: 00000000bb6e8000 - 00000000bb70f000 (reserved) -[ 0.000000] BIOS-e820: 00000000bb70f000 - 00000000bb717000 (usable) -[ 0.000000] BIOS-e820: 00000000bb717000 - 00000000bb71f000 (reserved) -[ 0.000000] BIOS-e820: 00000000bb71f000 - 00000000bb76c000 (usable) -[ 0.000000] BIOS-e820: 00000000bb76c000 - 00000000bb778000 (ACPI NVS) -[ 0.000000] BIOS-e820: 00000000bb778000 - 00000000bb77b000 (ACPI data) -[ 0.000000] BIOS-e820: 00000000bb77b000 - 00000000bb78b000 (ACPI NVS) -[ 0.000000] BIOS-e820: 00000000bb78b000 - 00000000bb78c000 (ACPI data) -[ 0.000000] BIOS-e820: 00000000bb78c000 - 00000000bb79f000 (ACPI NVS) -[ 0.000000] BIOS-e820: 00000000bb79f000 - 00000000bb7ff000 (ACPI data) -[ 0.000000] BIOS-e820: 00000000bb7ff000 - 00000000bb800000 (usable) -[ 0.000000] BIOS-e820: 00000000bb800000 - 00000000c0000000 (reserved) -[ 0.000000] BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved) -[ 0.000000] BIOS-e820: 00000000feaff000 - 00000000feb00000 (reserved) -[ 0.000000] BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved) -[ 0.000000] BIOS-e820: 00000000fed00000 - 00000000fed00400 (reserved) -[ 0.000000] BIOS-e820: 00000000fed1c000 - 00000000fed90000 (reserved) -[ 0.000000] BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved) -[ 0.000000] BIOS-e820: 00000000ff000000 - 0000000100000000 (reserved) -[ 0.000000] BIOS-e820: 0000000100000000 - 00000001fc000000 (usable) -[ 0.000000] BIOS-e820: 0000000200000000 - 000000023c000000 (usable) -[ 0.000000] NX (Execute Disable) protection: active -[ 0.000000] DMI present. -[ 0.000000] DMI: LENOVO 3626WVF/3626WVF, BIOS 6QET62WW (1.32 ) 12/17/2010 -[ 0.000000] e820 update range: 0000000000000000 - 0000000000010000 (usable) ==> (reserved) -[ 0.000000] e820 remove range: 00000000000a0000 - 0000000000100000 (usable) -[ 0.000000] No AGP bridge found -[ 0.000000] last_pfn = 0x23c000 max_arch_pfn = 0x400000000 -[ 0.000000] MTRR default type: uncachable -[ 0.000000] MTRR fixed ranges enabled: -[ 0.000000] 00000-9FFFF write-back -[ 0.000000] A0000-BFFFF uncachable -[ 0.000000] C0000-FFFFF write-protect -[ 0.000000] MTRR variable ranges enabled: -[ 0.000000] 0 disabled -[ 0.000000] 1 base 000000000 mask F80000000 write-back -[ 0.000000] 2 base 080000000 mask FC0000000 write-back -[ 0.000000] 3 base 100000000 mask F00000000 write-back -[ 0.000000] 4 base 200000000 mask FC0000000 write-back -[ 0.000000] 5 base 23C000000 mask FFC000000 uncachable -[ 0.000000] 6 base 0BC000000 mask FFC000000 uncachable -[ 0.000000] 7 disabled -[ 0.000000] x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106 -[ 0.000000] e820 update range: 00000000bc000000 - 0000000100000000 (usable) ==> (reserved) -[ 0.000000] last_pfn = 0xbb800 max_arch_pfn = 0x400000000 -[ 0.000000] found SMP MP-table at [ffff8800000f6910] f6910 -[ 0.000000] initial memory mapped : 0 - 20000000 -[ 0.000000] Base memory trampoline at [ffff880000099000] 99000 size 20480 -[ 0.000000] init_memory_mapping: 0000000000000000-00000000bb800000 -[ 0.000000] 0000000000 - 00bb800000 page 2M -[ 0.000000] kernel direct mapping tables up to bb800000 @ bb768000-bb76c000 -[ 0.000000] init_memory_mapping: 0000000100000000-000000023c000000 -[ 0.000000] 0100000000 - 023c000000 page 2M -[ 0.000000] kernel direct mapping tables up to 23c000000 @ 23bff6000-23c000000 -[ 0.000000] RAMDISK: 374b3000 - 37ff0000 -[ 0.000000] ACPI: RSDP 00000000000f68e0 00024 (v02 LENOVO) -[ 0.000000] ACPI: XSDT 00000000bb7f08bc 00094 (v01 LENOVO TP-6Q 00001320 LTP 00000000) -[ 0.000000] ACPI: FACP 00000000bb7f0a00 000F4 (v04 LENOVO TP-6Q 00001320 LNVO 00000001) -[ 0.000000] ACPI: DSDT 00000000bb7f0d6b 0DDDA (v01 LENOVO TP-6Q 00001320 MSFT 03000001) -[ 0.000000] ACPI: FACS 00000000bb6e7000 00040 -[ 0.000000] ACPI: SSDT 00000000bb7f0bb4 001B7 (v01 LENOVO TP-6Q 00001320 MSFT 03000001) -[ 0.000000] ACPI: ECDT 00000000bb7feb45 00052 (v01 LENOVO TP-6Q 00001320 LNVO 00000001) -[ 0.000000] ACPI: APIC 00000000bb7feb97 00084 (v01 LENOVO TP-6Q 00001320 LNVO 00000001) -[ 0.000000] ACPI: MCFG 00000000bb7fec53 0003C (v01 LENOVO TP-6Q 00001320 LNVO 00000001) -[ 0.000000] ACPI: HPET 00000000bb7fec8f 00038 (v01 LENOVO TP-6Q 00001320 LNVO 00000001) -[ 0.000000] ACPI: ASF! 00000000bb7fedbe 000A4 (v16 LENOVO TP-6Q 00001320 PTL 00000001) -[ 0.000000] ACPI: SLIC 00000000bb7fee62 00176 (v01 LENOVO TP-6Q 00001320 LTP 00000000) -[ 0.000000] ACPI: BOOT 00000000bb7fefd8 00028 (v01 LENOVO TP-6Q 00001320 LTP 00000001) -[ 0.000000] ACPI: SSDT 00000000bb6e590a 0085B (v01 LENOVO TP-6Q 00001320 INTL 20050513) -[ 0.000000] ACPI: TCPA 00000000bb78b000 00032 (v02 PTL CRESTLN 06040000 00005A52) -[ 0.000000] ACPI: SSDT 00000000bb77a000 009F1 (v01 PmRef CpuPm 00003000 INTL 20050513) -[ 0.000000] ACPI: SSDT 00000000bb779000 00259 (v01 PmRef Cpu0Tst 00003000 INTL 20050513) -[ 0.000000] ACPI: SSDT 00000000bb778000 0049F (v01 PmRef ApTst 00003000 INTL 20050513) -[ 0.000000] ACPI: Local APIC address 0xfee00000 -[ 0.000000] No NUMA configuration found -[ 0.000000] Faking a node at 0000000000000000-000000023c000000 -[ 0.000000] Initmem setup node 0 0000000000000000-000000023c000000 -[ 0.000000] NODE_DATA [000000023bffb000 - 000000023bffffff] -[ 0.000000] [ffffea0000000000-ffffea0007dfffff] PMD -> [ffff880233600000-ffff88023a5fffff] on node 0 -[ 0.000000] Zone PFN ranges: -[ 0.000000] DMA 0x00000010 -> 0x00001000 -[ 0.000000] DMA32 0x00001000 -> 0x00100000 -[ 0.000000] Normal 0x00100000 -> 0x0023c000 -[ 0.000000] Movable zone start PFN for each node -[ 0.000000] early_node_map[9] active PFN ranges -[ 0.000000] 0: 0x00000010 -> 0x0000009e -[ 0.000000] 0: 0x00000100 -> 0x000bb27c -[ 0.000000] 0: 0x000bb282 -> 0x000bb35f -[ 0.000000] 0: 0x000bb40f -> 0x000bb46f -[ 0.000000] 0: 0x000bb70f -> 0x000bb717 -[ 0.000000] 0: 0x000bb71f -> 0x000bb76c -[ 0.000000] 0: 0x000bb7ff -> 0x000bb800 -[ 0.000000] 0: 0x00100000 -> 0x001fc000 -[ 0.000000] 0: 0x00200000 -> 0x0023c000 -[ 0.000000] On node 0 totalpages: 2044829 -[ 0.000000] DMA zone: 56 pages used for memmap -[ 0.000000] DMA zone: 5 pages reserved -[ 0.000000] DMA zone: 3921 pages, LIFO batch:0 -[ 0.000000] DMA32 zone: 14280 pages used for memmap -[ 0.000000] DMA32 zone: 748615 pages, LIFO batch:31 -[ 0.000000] Normal zone: 17696 pages used for memmap -[ 0.000000] Normal zone: 1260256 pages, LIFO batch:31 -[ 0.000000] ACPI: PM-Timer IO Port: 0x1008 -[ 0.000000] ACPI: Local APIC address 0xfee00000 -[ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled) -[ 0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled) -[ 0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x04] enabled) -[ 0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x05] enabled) -[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1]) -[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1]) -[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x02] high edge lint[0x1]) -[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x03] high edge lint[0x1]) -[ 0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0]) -[ 0.000000] IOAPIC[0]: apic_id 1, version 32, address 0xfec00000, GSI 0-23 -[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl) -[ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level) -[ 0.000000] ACPI: IRQ0 used by override. -[ 0.000000] ACPI: IRQ2 used by override. -[ 0.000000] ACPI: IRQ9 used by override. -[ 0.000000] Using ACPI (MADT) for SMP configuration information -[ 0.000000] ACPI: HPET id: 0x8086a701 base: 0xfed00000 -[ 0.000000] SMP: Allowing 4 CPUs, 0 hotplug CPUs -[ 0.000000] nr_irqs_gsi: 40 -[ 0.000000] PM: Registered nosave memory: 000000000009e000 - 000000000009f000 -[ 0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000 -[ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000dc000 -[ 0.000000] PM: Registered nosave memory: 00000000000dc000 - 0000000000100000 -[ 0.000000] PM: Registered nosave memory: 00000000bb27c000 - 00000000bb282000 -[ 0.000000] PM: Registered nosave memory: 00000000bb35f000 - 00000000bb371000 -[ 0.000000] PM: Registered nosave memory: 00000000bb371000 - 00000000bb3f2000 -[ 0.000000] PM: Registered nosave memory: 00000000bb3f2000 - 00000000bb40f000 -[ 0.000000] PM: Registered nosave memory: 00000000bb46f000 - 00000000bb668000 -[ 0.000000] PM: Registered nosave memory: 00000000bb668000 - 00000000bb6e8000 -[ 0.000000] PM: Registered nosave memory: 00000000bb6e8000 - 00000000bb70f000 -[ 0.000000] PM: Registered nosave memory: 00000000bb717000 - 00000000bb71f000 -[ 0.000000] PM: Registered nosave memory: 00000000bb76c000 - 00000000bb778000 -[ 0.000000] PM: Registered nosave memory: 00000000bb778000 - 00000000bb77b000 -[ 0.000000] PM: Registered nosave memory: 00000000bb77b000 - 00000000bb78b000 -[ 0.000000] PM: Registered nosave memory: 00000000bb78b000 - 00000000bb78c000 -[ 0.000000] PM: Registered nosave memory: 00000000bb78c000 - 00000000bb79f000 -[ 0.000000] PM: Registered nosave memory: 00000000bb79f000 - 00000000bb7ff000 -[ 0.000000] PM: Registered nosave memory: 00000000bb800000 - 00000000c0000000 -[ 0.000000] PM: Registered nosave memory: 00000000c0000000 - 00000000e0000000 -[ 0.000000] PM: Registered nosave memory: 00000000e0000000 - 00000000f0000000 -[ 0.000000] PM: Registered nosave memory: 00000000f0000000 - 00000000feaff000 -[ 0.000000] PM: Registered nosave memory: 00000000feaff000 - 00000000feb00000 -[ 0.000000] PM: Registered nosave memory: 00000000feb00000 - 00000000fec00000 -[ 0.000000] PM: Registered nosave memory: 00000000fec00000 - 00000000fec10000 -[ 0.000000] PM: Registered nosave memory: 00000000fec10000 - 00000000fed00000 -[ 0.000000] PM: Registered nosave memory: 00000000fed00000 - 00000000fed1c000 -[ 0.000000] PM: Registered nosave memory: 00000000fed1c000 - 00000000fed90000 -[ 0.000000] PM: Registered nosave memory: 00000000fed90000 - 00000000fee00000 -[ 0.000000] PM: Registered nosave memory: 00000000fee00000 - 00000000fee01000 -[ 0.000000] PM: Registered nosave memory: 00000000fee01000 - 00000000ff000000 -[ 0.000000] PM: Registered nosave memory: 00000000ff000000 - 0000000100000000 +egistered nosave memory: 00000000ff000000 - 0000000100000000 [ 0.000000] PM: Registered nosave memory: 00000001fc000000 - 0000000200000000 [ 0.000000] Allocating PCI resources starting at c0000000 (gap: c0000000:20000000) [ 0.000000] Booting paravirtualized kernel on bare hardware @@ -1832,3 +1661,301 @@ [38111.816486] sdb: sdb1 sdb2 [38111.828126] sd 7:0:0:0: [sdb] Attached SCSI disk [38118.779858] eth0: no IPv6 routers present +[38167.863277] SysRq : HELP : loglevel(0-9) reBoot Crash terminate-all-tasks(E) memory-full-oom-kill(F) kill-all-tasks(I) thaw-filesystems(J) saK show-backtrace-all-active-cpus(L) show-memory-usage(M) nice-all-RT-tasks(N) powerOff show-registers(P) show-all-timers(Q) unRaw Sync show-task-states(T) Unmount force-fb(V) show-blocked-tasks(W) dump-ftrace-buffer(Z) +[38169.961678] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +[38170.017389] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +[38170.018518] ADDRCONF(NETDEV_UP): eth0: link is not ready +[38170.441038] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +[38170.496215] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +[38170.497543] ADDRCONF(NETDEV_UP): eth0: link is not ready +[38173.051734] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: Rx +[38173.052978] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready +[38183.276528] eth0: no IPv6 routers present +[38186.448844] INFO: task cdrom_id:30820 blocked for more than 120 seconds. +[38186.448850] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. +[38186.448854] cdrom_id D ffff88020ee24300 0 30820 30818 0x00000004 +[38186.448862] ffff88020ee24300 0000000000000082 ffff88020ee246b8 00ff880200000000 +[38186.448870] ffff880232e18f60 0000000000012800 ffff8801a5e09fd8 ffff8801a5e09fd8 +[38186.448877] 0000000000012800 ffff88020ee24300 0000000000012800 0000000000012800 +[38186.448884] Call Trace: +[38186.448898] [<ffffffff81335939>] ? schedule_timeout+0x2d/0xd7 +[38186.448907] [<ffffffff81038189>] ? test_tsk_need_resched+0xe/0x17 +[38186.448913] [<ffffffff81335713>] ? wait_for_common+0x9d/0x116 +[38186.448920] [<ffffffff8103f0a4>] ? try_to_wake_up+0x199/0x199 +[38186.448928] [<ffffffff8105b266>] ? start_flush_work+0xec/0x103 +[38186.448933] [<ffffffff8105b57c>] ? flush_work+0x24/0x2c +[38186.448938] [<ffffffff8105ae8f>] ? do_work_for_cpu+0x1b/0x1b +[38186.448945] [<ffffffff811994be>] ? disk_clear_events+0x86/0xe4 +[38186.448954] [<ffffffff81121c0e>] ? check_disk_change+0x22/0x50 +[38186.448962] [<ffffffffa05a9051>] ? cdrom_open+0x45/0x4aa [cdrom] +[38186.448969] [<ffffffff811a4c79>] ? kobject_get+0x12/0x17 +[38186.448974] [<ffffffff81198079>] ? get_disk+0x6d/0x8d +[38186.448979] [<ffffffff8103840a>] ? should_resched+0x5/0x24 +[38186.448985] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 +[38186.448993] [<ffffffff8124b9df>] ? kobj_lookup+0x13a/0x174 +[38186.448998] [<ffffffff811a4c79>] ? kobject_get+0x12/0x17 +[38186.449005] [<ffffffffa05b57c3>] ? sr_block_open+0x93/0xbc [sr_mod] +[38186.449010] [<ffffffff811229b1>] ? __blkdev_get+0xe3/0x380 +[38186.449017] [<ffffffff810cf775>] ? set_pte_at+0x5/0x8 +[38186.449022] [<ffffffff81122ef5>] ? blkdev_get+0x2a7/0x2a7 +[38186.449027] [<ffffffff81122e15>] ? blkdev_get+0x1c7/0x2a7 +[38186.449033] [<ffffffff81122ef5>] ? blkdev_get+0x2a7/0x2a7 +[38186.449058] [<ffffffff810fa32e>] ? __dentry_open+0x182/0x29c +[38186.449068] [<ffffffff811035df>] ? dget+0x12/0x1e +[38186.449075] [<ffffffff81105861>] ? do_last+0x46d/0x584 +[38186.449083] [<ffffffff81106bea>] ? path_openat+0xc7/0x349 +[38186.449090] [<ffffffff810d0312>] ? tlb_flush_mmu+0x37/0x50 +[38186.449097] [<ffffffff81106e98>] ? do_filp_open+0x2c/0x72 +[38186.449104] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 +[38186.449112] [<ffffffff811ac741>] ? __strncpy_from_user+0x19/0x4a +[38186.449120] [<ffffffff81110208>] ? alloc_fd+0x69/0x110 +[38186.449127] [<ffffffff810fb138>] ? do_sys_open+0x5f/0xe6 +[38186.449135] [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b +[38193.203659] SysRq : Show Blocked State +[38193.203668] task PC stack pid father +[38193.203779] kworker/3:2 D ffff8801ea9e3690 0 26398 2 0x00000000 +[38193.203787] ffff8801ea9e3690 0000000000000046 ffff88020edf5800 ffffffff81071e64 +[38193.203794] ffff88020e0620c0 0000000000012800 ffff8801eab8ffd8 ffff8801eab8ffd8 +[38193.203801] 0000000000012800 ffff8801ea9e3690 0000000000012800 0000000000012800 +[38193.203808] Call Trace: +[38193.203820] [<ffffffff81071e64>] ? arch_local_irq_save+0x14/0x1d +[38193.203831] [<ffffffff813359ac>] ? schedule_timeout+0xa0/0xd7 +[38193.203838] [<ffffffff81052bcf>] ? run_timer_softirq+0x28a/0x28a +[38193.203845] [<ffffffff81335713>] ? wait_for_common+0x9d/0x116 +[38193.203852] [<ffffffff8103f0a4>] ? try_to_wake_up+0x199/0x199 +[38193.203857] [<ffffffff81336815>] ? _raw_spin_lock_irq+0xd/0x1a +[38193.203866] [<ffffffff8119595f>] ? blk_execute_rq+0xa5/0xe6 +[38193.203874] [<ffffffff811206aa>] ? bio_phys_segments+0xf/0x14 +[38193.203880] [<ffffffff81192d47>] ? blk_rq_bio_prep+0x39/0x6c +[38193.203886] [<ffffffff811955d3>] ? blk_rq_map_kern+0xef/0x11f +[38193.203926] [<ffffffffa0062992>] ? scsi_execute+0xed/0x13e [scsi_mod] +[38193.203941] [<ffffffffa0062a6c>] ? scsi_execute_req+0x89/0xb9 [scsi_mod] +[38193.203948] [<ffffffff81197f1c>] ? disk_events_set_dfl_poll_msecs+0x44/0x44 +[38193.203956] [<ffffffffa05b52c2>] ? sr_check_events+0x9a/0x196 [sr_mod] +[38193.203966] [<ffffffff81030008>] ? compound_head+0x7/0x10 +[38193.203974] [<ffffffffa05a6041>] ? cdrom_check_events+0xf/0x22 [cdrom] +[38193.203979] [<ffffffff81197f56>] ? disk_events_workfn+0x3a/0xd5 +[38193.203985] [<ffffffff81197f1c>] ? disk_events_set_dfl_poll_msecs+0x44/0x44 +[38193.203992] [<ffffffff8105b943>] ? process_one_work+0x193/0x28f +[38193.203998] [<ffffffff8105cacf>] ? worker_thread+0xef/0x172 +[38193.204004] [<ffffffff8105c9e0>] ? manage_workers.clone.17+0x15b/0x15b +[38193.204010] [<ffffffff8105c9e0>] ? manage_workers.clone.17+0x15b/0x15b +[38193.204015] [<ffffffff8105fc0b>] ? kthread+0x7a/0x82 +[38193.204021] [<ffffffff8133cba4>] ? kernel_thread_helper+0x4/0x10 +[38193.204027] [<ffffffff8105fb91>] ? kthread_worker_fn+0x149/0x149 +[38193.204032] [<ffffffff8133cba0>] ? gs_change+0x13/0x13 +[38193.204044] cdrom_id D ffff88020ee24300 0 30820 30818 0x00000004 +[38193.204051] ffff88020ee24300 0000000000000082 ffff88020ee246b8 00ff880200000000 +[38193.204058] ffff880232e18f60 0000000000012800 ffff8801a5e09fd8 ffff8801a5e09fd8 +[38193.204065] 0000000000012800 ffff88020ee24300 0000000000012800 0000000000012800 +[38193.204071] Call Trace: +[38193.204078] [<ffffffff81335939>] ? schedule_timeout+0x2d/0xd7 +[38193.204085] [<ffffffff81038189>] ? test_tsk_need_resched+0xe/0x17 +[38193.204091] [<ffffffff81335713>] ? wait_for_common+0x9d/0x116 +[38193.204096] [<ffffffff8103f0a4>] ? try_to_wake_up+0x199/0x199 +[38193.204102] [<ffffffff8105b266>] ? start_flush_work+0xec/0x103 +[38193.204107] [<ffffffff8105b57c>] ? flush_work+0x24/0x2c +[38193.204112] [<ffffffff8105ae8f>] ? do_work_for_cpu+0x1b/0x1b +[38193.204118] [<ffffffff811994be>] ? disk_clear_events+0x86/0xe4 +[38193.204124] [<ffffffff81121c0e>] ? check_disk_change+0x22/0x50 +[38193.204131] [<ffffffffa05a9051>] ? cdrom_open+0x45/0x4aa [cdrom] +[38193.204138] [<ffffffff811a4c79>] ? kobject_get+0x12/0x17 +[38193.204143] [<ffffffff81198079>] ? get_disk+0x6d/0x8d +[38193.204148] [<ffffffff8103840a>] ? should_resched+0x5/0x24 +[38193.204153] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 +[38193.204162] [<ffffffff8124b9df>] ? kobj_lookup+0x13a/0x174 +[38193.204167] [<ffffffff811a4c79>] ? kobject_get+0x12/0x17 +[38193.204173] [<ffffffffa05b57c3>] ? sr_block_open+0x93/0xbc [sr_mod] +[38193.204179] [<ffffffff811229b1>] ? __blkdev_get+0xe3/0x380 +[38193.204186] [<ffffffff810cf775>] ? set_pte_at+0x5/0x8 +[38193.204192] [<ffffffff81122ef5>] ? blkdev_get+0x2a7/0x2a7 +[38193.204197] [<ffffffff81122e15>] ? blkdev_get+0x1c7/0x2a7 +[38193.204202] [<ffffffff81122ef5>] ? blkdev_get+0x2a7/0x2a7 +[38193.204211] [<ffffffff810fa32e>] ? __dentry_open+0x182/0x29c +[38193.204218] [<ffffffff811035df>] ? dget+0x12/0x1e +[38193.204223] [<ffffffff81105861>] ? do_last+0x46d/0x584 +[38193.204228] [<ffffffff81106bea>] ? path_openat+0xc7/0x349 +[38193.204234] [<ffffffff810d0312>] ? tlb_flush_mmu+0x37/0x50 +[38193.204239] [<ffffffff81106e98>] ? do_filp_open+0x2c/0x72 +[38193.204245] [<ffffffff8133565f>] ? _cond_resched+0x9/0x20 +[38193.204251] [<ffffffff811ac741>] ? __strncpy_from_user+0x19/0x4a +[38193.204258] [<ffffffff81110208>] ? alloc_fd+0x69/0x110 +[38193.204264] [<ffffffff810fb138>] ? do_sys_open+0x5f/0xe6 +[38193.204270] [<ffffffff8133ba92>] ? system_call_fastpath+0x16/0x1b +[38193.204282] Sched Debug Version: v0.10, 3.0.0-1-amd64 #1 +[38193.204286] ktime : 38287920.330194 +[38193.204290] sched_clk : 38193204.280576 +[38193.204293] cpu_clk : 38193204.280645 +[38193.204297] jiffies : 4304464276 +[38193.204300] sched_clock_stable : 1 +[38193.204302] +[38193.204304] sysctl_sched +[38193.204307] .sysctl_sched_latency : 18.000000 +[38193.204310] .sysctl_sched_min_granularity : 2.250000 +[38193.204314] .sysctl_sched_wakeup_granularity : 3.000000 +[38193.204317] .sysctl_sched_child_runs_first : 0 +[38193.204320] .sysctl_sched_features : 15471 +[38193.204323] .sysctl_sched_tunable_scaling : 1 (logaritmic) +[38193.204328] +[38193.204329] cpu#0, 2660.149 MHz +[38193.204331] .nr_running : 0 +[38193.204334] .load : 0 +[38193.204337] .nr_switches : 19321785 +[38193.204340] .nr_load_updates : 2359315 +[38193.204343] .nr_uninterruptible : -4950 +[38193.204347] .next_balance : 4304.464319 +[38193.204350] .curr->pid : 0 +[38193.204353] .clock : 38193203.395770 +[38193.204356] .cpu_load[0] : 0 +[38193.204359] .cpu_load[1] : 0 +[38193.204361] .cpu_load[2] : 18 +[38193.204364] .cpu_load[3] : 37 +[38193.204366] .cpu_load[4] : 35 +[38193.204370] +[38193.204371] cfs_rq[0]:/ +[38193.204374] .exec_clock : 0.000000 +[38193.204377] .MIN_vruntime : 0.000001 +[38193.204380] .min_vruntime : 1507160.258024 +[38193.204383] .max_vruntime : 0.000001 +[38193.204387] .spread : 0.000000 +[38193.204390] .spread0 : 0.000000 +[38193.204393] .nr_spread_over : 0 +[38193.204395] .nr_running : 0 +[38193.204398] .load : 0 +[38193.204401] .load_avg : 0.000000 +[38193.204404] .load_period : 0.000000 +[38193.204407] .load_contrib : 0 +[38193.204409] .load_tg : 0 +[38193.204412] +[38193.204413] rt_rq[0]: +[38193.204415] .rt_nr_running : 0 +[38193.204418] .rt_throttled : 0 +[38193.204421] .rt_time : 0.000000 +[38193.204424] .rt_runtime : 950.000000 +[38193.204428] +[38193.204429] runnable tasks: +[38193.204430] task PID tree-key switches prio exec-runtime sum-exec sum-sleep +[38193.204433] ---------------------------------------------------------------------------------------------------------- +[38193.204456] +[38193.204457] cpu#1, 2660.149 MHz +[38193.204460] .nr_running : 0 +[38193.204462] .load : 0 +[38193.204465] .nr_switches : 16989349 +[38193.204468] .nr_load_updates : 2040614 +[38193.204471] .nr_uninterruptible : 4668 +[38193.204474] .next_balance : 4304.464183 +[38193.204477] .curr->pid : 0 +[38193.204480] .clock : 38193203.426382 +[38193.204483] .cpu_load[0] : 0 +[38193.204486] .cpu_load[1] : 0 +[38193.204488] .cpu_load[2] : 0 +[38193.204491] .cpu_load[3] : 1 +[38193.204494] .cpu_load[4] : 13 +[38193.204497] +[38193.204498] cfs_rq[1]:/ +[38193.204500] .exec_clock : 0.000000 +[38193.204504] .MIN_vruntime : 0.000001 +[38193.204507] .min_vruntime : 1937193.264071 +[38193.204510] .max_vruntime : 0.000001 +[38193.204513] .spread : 0.000000 +[38193.204516] .spread0 : 430033.006047 +[38193.204519] .nr_spread_over : 0 +[38193.204522] .nr_running : 0 +[38193.204525] .load : 0 +[38193.204527] .load_avg : 0.000000 +[38193.204530] .load_period : 0.000000 +[38193.204533] .load_contrib : 0 +[38193.204536] .load_tg : 0 +[38193.204538] +[38193.204539] rt_rq[1]: +[38193.204542] .rt_nr_running : 0 +[38193.204544] .rt_throttled : 0 +[38193.204547] .rt_time : 0.000000 +[38193.204550] .rt_runtime : 950.000000 +[38193.204554] +[38193.204555] runnable tasks: +[38193.204556] task PID tree-key switches prio exec-runtime sum-exec sum-sleep +[38193.204559] ---------------------------------------------------------------------------------------------------------- +[38193.204575] +[38193.204576] cpu#2, 2660.149 MHz +[38193.204579] .nr_running : 2 +[38193.204582] .load : 2048 +[38193.204585] .nr_switches : 11164285 +[38193.204588] .nr_load_updates : 761000 +[38193.204590] .nr_uninterruptible : 124 +[38193.204594] .next_balance : 4304.464246 +[38193.204597] .curr->pid : 30538 +[38193.204600] .clock : 38193203.456281 +[38193.204603] .cpu_load[0] : 1024 +[38193.204606] .cpu_load[1] : 512 +[38193.204608] .cpu_load[2] : 256 +[38193.204611] .cpu_load[3] : 135 +[38193.204614] .cpu_load[4] : 79 +[38193.204617] +[38193.204618] cfs_rq[2]:/ +[38193.204621] .exec_clock : 0.000000 +[38193.204624] .MIN_vruntime : 702507.098507 +[38193.204627] .min_vruntime : 702516.098507 +[38193.204631] .max_vruntime : 702507.098507 +[38193.204634] .spread : 0.000000 +[38193.204637] .spread0 : -804644.159517 +[38193.204640] .nr_spread_over : 0 +[38193.204643] .nr_running : 2 +[38193.204646] .load : 2048 +[38193.204649] .load_avg : 0.000000 +[38193.204652] .load_period : 0.000000 +[38193.204654] .load_contrib : 0 +[38193.204657] .load_tg : 0 +[38193.204660] +[38193.204661] rt_rq[2]: +[38193.204663] .rt_nr_running : 0 +[38193.204666] .rt_throttled : 0 +[38193.204669] .rt_time : 0.000000 +[38193.204672] .rt_runtime : 950.000000 +[38193.204676] +[38193.204676] runnable tasks: +[38193.204677] task PID tree-key switches prio exec-runtime sum-exec sum-sleep +[38193.204680] ---------------------------------------------------------------------------------------------------------- +[38193.204694] kworker/2:2 21447 702507.098507 62419 120 0 0 0.000000 0.000000 0.000000 / +[38193.204706] R bash 30538 702507.125825 525 120 0 0 0.000000 0.000000 0.000000 / +[38193.204719] +[38193.204720] cpu#3, 2660.149 MHz +[38193.204723] .nr_running : 0 +[38193.204726] .load : 0 +[38193.204729] .nr_switches : 9954939 +[38193.204732] .nr_load_updates : 1120052 +[38193.204735] .nr_uninterruptible : 160 +[38193.204738] .next_balance : 4304.464277 +[38193.204741] .curr->pid : 0 +[38193.204744] .clock : 38193203.335462 +[38193.204747] .cpu_load[0] : 1024 +[38193.204750] .cpu_load[1] : 512 +[38193.204752] .cpu_load[2] : 256 +[38193.204755] .cpu_load[3] : 128 +[38193.204757] .cpu_load[4] : 73 +[38193.204760] +[38193.204761] cfs_rq[3]:/ +[38193.204764] .exec_clock : 0.000000 +[38193.204767] .MIN_vruntime : 0.000001 +[38193.204770] .min_vruntime : 1238869.827460 +[38193.204774] .max_vruntime : 0.000001 +[38193.204777] .spread : 0.000000 +[38193.204780] .spread0 : -268290.430564 +[38193.204783] .nr_spread_over : 0 +[38193.204785] .nr_running : 0 +[38193.204788] .load : 0 +[38193.204791] .load_avg : 0.000000 +[38193.204794] .load_period : 0.000000 +[38193.204797] .load_contrib : 0 +[38193.204800] .load_tg : 0 +[38193.204802] +[38193.204803] rt_rq[3]: +[38193.204805] .rt_nr_running : 0 +[38193.204808] .rt_throttled : 0 +[38193.204811] .rt_time : 0.000000 +[38193.204814] .rt_runtime : 950.000000 +[38193.204817] +[38193.204818] runnable tasks: +[38193.204819] task PID tree-key switches prio exec-runtime sum-exec sum-sleep +[38193.204822] ---------------------------------------------------------------------------------------------------------- +[38193.204838]
--- 1-posteject/syslog 2011-08-27 11:43:54.749044172 -0700 +++ 2-postundock/syslog 2011-08-27 11:44:29.567760195 -0700 @@ -298,3 +298,90 @@ Aug 27 11:43:04 servo kernel: [37895.878595] sd 6:0:0:0: [sdb] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK Aug 27 11:43:04 servo kernel: [37896.405087] ata2: SATA link down (SStatus 0 SControl 300) Aug 27 11:43:04 servo kernel: [37896.420970] ata2: EH complete +Aug 27 11:44:04 servo kernel: [37956.260591] ACPI: \_SB_.GDCK - undocking +Aug 27 11:44:05 servo kernel: [37956.560954] e1000e: eth0 NIC Link is Down +Aug 27 11:44:05 servo udevd[30818]: timeout 'cdrom_id --lock-media /dev/sr0' +Aug 27 11:44:05 servo kernel: [37956.835717] EXT4-fs (dm-1): re-mounted. Opts: errors=remount-ro,commit=600 +Aug 27 11:44:05 servo kernel: [37956.838245] EXT4-fs (sda1): re-mounted. Opts: commit=600 +Aug 27 11:44:05 servo kernel: [37956.848420] EXT4-fs (dm-5): re-mounted. Opts: commit=600 +Aug 27 11:44:05 servo kernel: [37956.851163] EXT4-fs (dm-3): re-mounted. Opts: commit=600 +Aug 27 11:44:05 servo kernel: [37956.859489] EXT4-fs (dm-2): re-mounted. Opts: commit=600 +Aug 27 11:44:05 servo kernel: [37956.884576] thinkpad_acpi: EC reports that Thermal Table has changed +Aug 27 11:44:06 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:07 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:07 servo postfix/master[1841]: reload -- version 2.8.3, configuration /etc/postfix +Aug 27 11:44:07 servo dhclient: Internet Systems Consortium DHCP Client 4.1.1-P1 +Aug 27 11:44:07 servo dhclient: Copyright 2004-2010 Internet Systems Consortium. +Aug 27 11:44:07 servo dhclient: All rights reserved. +Aug 27 11:44:07 servo dhclient: For info, please visit https://www.isc.org/software/dhcp/ +Aug 27 11:44:07 servo dhclient: +Aug 27 11:44:07 servo dhclient: Listening on LPF/eth0/f0:de:f1:50:ad:9d +Aug 27 11:44:07 servo dhclient: Sending on LPF/eth0/f0:de:f1:50:ad:9d +Aug 27 11:44:07 servo dhclient: Sending on Socket/fallback +Aug 27 11:44:07 servo dhclient: DHCPRELEASE on eth0 to 10.10.10.1 port 67 +Aug 27 11:44:07 servo avahi-daemon[1752]: Withdrawing address record for 10.10.10.20 on eth0. +Aug 27 11:44:07 servo avahi-daemon[1752]: Leaving mDNS multicast group on interface eth0.IPv4 with address 10.10.10.20. +Aug 27 11:44:07 servo avahi-daemon[1752]: Interface eth0.IPv4 no longer relevant for mDNS. +Aug 27 11:44:07 servo avahi-daemon[1752]: Interface eth0.IPv6 no longer relevant for mDNS. +Aug 27 11:44:07 servo avahi-daemon[1752]: Leaving mDNS multicast group on interface eth0.IPv6 with address fe80::f2de:f1ff:fe50:ad9d. +Aug 27 11:44:07 servo avahi-daemon[1752]: Withdrawing address record for fe80::f2de:f1ff:fe50:ad9d on eth0. +Aug 27 11:44:07 servo dhclient: receive_packet failed on eth0: Network is down +Aug 27 11:44:07 servo kernel: [37959.263127] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +Aug 27 11:44:07 servo kernel: [37959.317726] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +Aug 27 11:44:07 servo kernel: [37959.318405] ADDRCONF(NETDEV_UP): eth0: link is not ready +Aug 27 11:44:07 servo postfix/master[1841]: reload -- version 2.8.3, configuration /etc/postfix +Aug 27 11:44:07 servo dhclient: Internet Systems Consortium DHCP Client 4.1.1-P1 +Aug 27 11:44:07 servo dhclient: Copyright 2004-2010 Internet Systems Consortium. +Aug 27 11:44:07 servo dhclient: All rights reserved. +Aug 27 11:44:07 servo dhclient: For info, please visit https://www.isc.org/software/dhcp/ +Aug 27 11:44:07 servo dhclient: +Aug 27 11:44:07 servo dhclient: Listening on LPF/wlan0/8c:a9:82:67:87:26 +Aug 27 11:44:07 servo dhclient: Sending on LPF/wlan0/8c:a9:82:67:87:26 +Aug 27 11:44:07 servo dhclient: Sending on Socket/fallback +Aug 27 11:44:07 servo dhclient: DHCPRELEASE on wlan0 to 10.0.0.1 port 67 +Aug 27 11:44:07 servo dhclient: send_packet: Network is unreachable +Aug 27 11:44:07 servo dhclient: send_packet: please consult README file regarding broadcast address. +Aug 27 11:44:08 servo postfix/master[1841]: reload -- version 2.8.3, configuration /etc/postfix +Aug 27 11:44:08 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:08 servo dhclient: Internet Systems Consortium DHCP Client 4.1.1-P1 +Aug 27 11:44:08 servo dhclient: Copyright 2004-2010 Internet Systems Consortium. +Aug 27 11:44:08 servo dhclient: All rights reserved. +Aug 27 11:44:08 servo dhclient: For info, please visit https://www.isc.org/software/dhcp/ +Aug 27 11:44:08 servo dhclient: +Aug 27 11:44:08 servo dhclient: Listening on LPF/eth0/f0:de:f1:50:ad:9d +Aug 27 11:44:08 servo dhclient: Sending on LPF/eth0/f0:de:f1:50:ad:9d +Aug 27 11:44:08 servo dhclient: Sending on Socket/fallback +Aug 27 11:44:08 servo dhclient: DHCPRELEASE on eth0 to 10.10.10.1 port 67 +Aug 27 11:44:08 servo dhclient: send_packet: Network is unreachable +Aug 27 11:44:08 servo dhclient: send_packet: please consult README file regarding broadcast address. +Aug 27 11:44:08 servo dhclient: receive_packet failed on eth0: Network is down +Aug 27 11:44:08 servo kernel: [37959.876524] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +Aug 27 11:44:08 servo kernel: [37959.932269] e1000e 0000:00:19.0: irq 44 for MSI/MSI-X +Aug 27 11:44:08 servo kernel: [37959.933438] ADDRCONF(NETDEV_UP): eth0: link is not ready +Aug 27 11:44:09 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:10 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:11 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:12 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:13 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:13 servo acpid: client 1889[0:0] has disconnected +Aug 27 11:44:14 servo acpid: client connected from 1889[0:0] +Aug 27 11:44:14 servo acpid: 1 client rule loaded +Aug 27 11:44:14 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:15 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:16 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:17 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:18 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:19 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:20 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:21 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:22 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:23 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:24 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:25 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:26 servo dhclient: DHCPREQUEST on eth0 to 10.10.10.1 port 67 +Aug 27 11:44:26 servo dhclient: send_packet: Network is unreachable +Aug 27 11:44:26 servo dhclient: send_packet: please consult README file regarding broadcast address. +Aug 27 11:44:26 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:27 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:28 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820] +Aug 27 11:44:29 servo udevd[30818]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [30820]
Attachment:
pgp9dvOyO8Qtj.pgp
Description: PGP signature