2007-12-01 09:15:50

by Tomas Carnecky

[permalink] [raw]
Subject: WARNING: smp_call_function_single() and smp_call_function_mask()

WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
WARNING: at arch/x86/kernel/smp_64.c:397 smp_call_function_mask()

dmesg and config attached.

I'm getting about three of each at boot. I'm running:
commit e1cca7e8d484390169777b423a7fe46c7021fec1
Date: Thu Nov 29 16:25:29 2007 -0800
which is the latest git as of yesterday plus a one (unrelated) debug
statement patch in usb uhci.

There was a similar bug report after 2.6.23-rc8-mm was released. Though
there seems to be a fundamental problem with how people use
smp_call_function*() [1]. And this can just as well be another
incarnation of it.

Is that easy enough to fix or do I need to bisect (it didn't happen in
2.6.24-rc3)?

tom

[1] http://kerneltrap.org/mailarchive/linux-kernel/2007/9/27/324310


2007-12-01 09:22:25

by Tomas Carnecky

[permalink] [raw]
Subject: Re: WARNING: smp_call_function_single() and smp_call_function_mask()

Initializing cgroup subsys cpuset
Linux version 2.6.24-rc3-gdea7d55d (tomc@localhost) (gcc version 4.1.1 (Gentoo 4.1.1-r3)) #60 SMP PREEMPT Sat Dec 1 20:54:18 CET 2007
Command line: auto BOOT_IMAGE=2.6.git ro root=802 resume=/dev/sda4 acpi_sleep=s3_bios,s3_mode thinkpad_acpi.fan_control=1
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009d800 (usable)
BIOS-e820: 000000000009d800 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000e0000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 000000007d6b0000 (usable)
BIOS-e820: 000000007d6b0000 - 000000007d6cc000 (ACPI data)
BIOS-e820: 000000007d6cc000 - 000000007d700000 (ACPI NVS)
BIOS-e820: 000000007d700000 - 000000007e000000 (reserved)
BIOS-e820: 00000000f0000000 - 00000000f4000000 (reserved)
BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
BIOS-e820: 00000000fed00000 - 00000000fed00400 (reserved)
BIOS-e820: 00000000fed14000 - 00000000fed1a000 (reserved)
BIOS-e820: 00000000fed1c000 - 00000000fed90000 (reserved)
BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
BIOS-e820: 00000000ff000000 - 0000000100000000 (reserved)
Entering add_active_range(0, 0, 157) 0 entries of 256 used
Entering add_active_range(0, 256, 513712) 1 entries of 256 used
end_pfn_map = 1048576
DMI present.
ACPI: RSDP 000F6950, 0024 (r2 LENOVO)
ACPI: XSDT 7D6BCEF0, 0094 (r1 LENOVO TP-7S 1070 LTP 0)
ACPI: FACP 7D6BD000, 00F4 (r3 LENOVO TP-7S 1070 LNVO 1)
ACPI Warning (tbfadt-0442): Optional field "Gpe1Block" has zero address or length: 000000000000102C/0 [20070126]
ACPI: DSDT 7D6BD3DB, E7A2 (r1 LENOVO TP-7S 1070 MSFT 3000000)
ACPI: FACS 7D6E4000, 0040
ACPI: SSDT 7D6BD1B4, 0227 (r1 LENOVO TP-7S 1070 MSFT 3000000)
ACPI: ECDT 7D6CBB7D, 0052 (r1 LENOVO TP-7S 1070 LNVO 1)
ACPI: TCPA 7D6CBBCF, 0032 (r2 LENOVO TP-7S 1070 LNVO 1)
ACPI: APIC 7D6CBC01, 0068 (r1 LENOVO TP-7S 1070 LNVO 1)
ACPI: MCFG 7D6CBC69, 003C (r1 LENOVO TP-7S 1070 LNVO 1)
ACPI: HPET 7D6CBCA5, 0038 (r1 LENOVO TP-7S 1070 LNVO 1)
ACPI: SLIC 7D6CBDF0, 0176 (r1 LENOVO TP-7S 1070 LTP 0)
ACPI: BOOT 7D6CBF66, 0028 (r1 LENOVO TP-7S 1070 LTP 1)
ACPI: ASF! 7D6CBF8E, 0072 (r16 LENOVO TP-7S 1070 PTL 1)
ACPI: SSDT 7D6E2697, 025F (r1 LENOVO TP-7S 1070 INTL 20050513)
ACPI: SSDT 7D6E28F6, 00A6 (r1 LENOVO TP-7S 1070 INTL 20050513)
ACPI: SSDT 7D6E299C, 04F7 (r1 LENOVO TP-7S 1070 INTL 20050513)
ACPI: SSDT 7D6E2E93, 01D8 (r1 LENOVO TP-7S 1070 INTL 20050513)
Entering add_active_range(0, 0, 157) 0 entries of 256 used
Entering add_active_range(0, 256, 513712) 1 entries of 256 used
Zone PFN ranges:
DMA 0 -> 4096
DMA32 4096 -> 1048576
Normal 1048576 -> 1048576
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
0: 0 -> 157
0: 256 -> 513712
On node 0 totalpages: 513613
DMA zone: 56 pages used for memmap
DMA zone: 1814 pages reserved
DMA zone: 2127 pages, LIFO batch:0
DMA32 zone: 6967 pages used for memmap
DMA32 zone: 502649 pages, LIFO batch:31
Normal zone: 0 pages used for memmap
Movable zone: 0 pages used for memmap
ACPI: PM-Timer IO Port: 0x1008
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
Processor #0 (Bootup-CPU)
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
Processor #1
ACPI: LAPIC_NMI (acpi_id[0x00] high edge lint[0x1])
ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
IOAPIC[0]: apic_id 1, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: IRQ0 used by override.
ACPI: IRQ2 used by override.
ACPI: IRQ9 used by override.
Setting APIC routing to flat
ACPI: HPET id: 0x8086a201 base: 0xfed00000
Using ACPI (MADT) for SMP configuration information
swsusp: Registered nosave memory region: 000000000009d000 - 000000000009e000
swsusp: Registered nosave memory region: 000000000009e000 - 00000000000a0000
swsusp: Registered nosave memory region: 00000000000a0000 - 00000000000e0000
swsusp: Registered nosave memory region: 00000000000e0000 - 0000000000100000
Allocating PCI resources starting at 80000000 (gap: 7e000000:72000000)
SMP: Allowing 2 CPUs, 0 hotplug CPUs
PERCPU: Allocating 33312 bytes of per cpu data
Built 1 zonelists in Zone order, mobility grouping on. Total pages: 504776
Kernel command line: auto BOOT_IMAGE=2.6.git ro root=802 resume=/dev/sda4 acpi_sleep=s3_bios,s3_mode thinkpad_acpi.fan_control=1
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 32768 bytes)
Extended CMOS year: 2000
hpet clockevent registered
TSC calibrated against HPET
Marking TSC unstable due to TSCs unsynchronized
time.c: Detected 1595.993 MHz processor.
Console: colour dummy device 80x25
console [tty0] enabled
Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
Checking aperture...
Memory: 2015512k/2054848k available (4454k kernel code, 38608k reserved, 1871k data, 244k init)
SLUB: Genslabs=11, HWalign=64, Order=0-1, MinObjects=4, CPUs=2, Nodes=1
Calibrating delay using timer specific routine.. 3195.86 BogoMIPS (lpj=1597931)
Mount-cache hash table entries: 256
Initializing cgroup subsys debug
Initializing cgroup subsys ns
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
using mwait in idle threads.
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 0
CPU0: Thermal monitoring enabled (TM2)
SMP alternatives: switching to UP code
ACPI: Core revision 20070126
Using local APIC timer interrupts.
APIC timer calibration result 12468704
Detected 12.468 MHz APIC timer.
SMP alternatives: switching to SMP code
Booting processor 1/2 APIC 0x1
Initializing CPU#1
Calibrating delay using timer specific routine.. 3191.84 BogoMIPS (lpj=1595921)
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 1
CPU1: Thermal monitoring enabled (TM2)
Intel(R) Core(TM)2 Duo CPU L7500 @ 1.60GHz stepping 0b
Brought up 2 CPUs
net_namespace: 120 bytes
Time: 6:56:10 Date: 12/02/07
NET: Registered protocol family 16
ACPI: ACPI Dock Station Driver
ACPI: \_SB_.PCI0.IDE0.PRIM.MSTR: found ejectable bay
ACPI: \_SB_.PCI0.IDE0.PRIM.MSTR: Adding notify handler
ACPI: Bay [\_SB_.PCI0.IDE0.PRIM.MSTR] Added
ACPI: bus type pci registered
PCI: Using MMCONFIG at f0000000 - f3ffffff
ACPI: EC: EC description table is found, configuring boot EC
ACPI: EC: non-query interrupt received, switching to interrupt mode
ACPI: Interpreter enabled
ACPI: (supports S0 S3 S4 S5)
ACPI: Using IOAPIC for interrupt routing
ACPI: EC: GPE = 0x12, I/O: command/status = 0x66, data = 0x62
ACPI: EC: driver started in poll mode
ACPI: PCI Root Bridge [PCI0] (0000:00)
PCI: Transparent bridge - 0000:00:1e.0
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP1._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PCI1._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 *10 11)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: EC: non-query interrupt received, switching to interrupt mode
ACPI: Power Resource [PUBS] (on)
Linux Plug and Play Support v0.97 (c) Adam Belay
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnpacpi: exceeded the max number of mem resources: 12
pnpacpi: exceeded the max number of mem resources: 12
pnpacpi: exceeded the max number of mem resources: 12
pnpacpi: exceeded the max number of mem resources: 12
pnpacpi: exceeded the max number of mem resources: 12
pnp 00:00: Plug and Play ACPI device, IDs PNP0c01 (active)
pnp 00:01: Plug and Play ACPI device, IDs PNP0a08 PNP0a03 (active)
pnp 00:02: Plug and Play ACPI device, IDs PNP0c02 (active)
pnp 00:03: Plug and Play ACPI device, IDs PNP0103 (active)
pnp 00:04: Plug and Play ACPI device, IDs PNP0200 (active)
pnp 00:05: Plug and Play ACPI device, IDs PNP0800 (active)
pnp 00:06: Plug and Play ACPI device, IDs PNP0c04 (active)
pnp 00:07: Plug and Play ACPI device, IDs PNP0b00 (active)
pnp 00:08: Plug and Play ACPI device, IDs LEN0003 PNP0303 (active)
pnp 00:09: Plug and Play ACPI device, IDs IBM3780 PNP0f13 (active)
pnp 00:0a: Plug and Play ACPI device, IDs PNP0501 (disabled)
pnp 00:0b: Plug and Play ACPI device, IDs PNP0400 (disabled)
pnp 00:0c: Plug and Play ACPI device, IDs WACf004 (disabled)
pnp: PnP ACPI: found 13 devices
ACPI: ACPI bus type pnp unregistered
SCSI subsystem initialized
libata version 3.00 loaded.
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
PCI: If a device doesn't work, try "pci=routeirq". If it helps, post a report
DMAR:No DMAR devices found
PCI-GART: No AMD northbridge found.
hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
hpet0: 3 64-bit timers, 14318180 Hz
Time: hpet clocksource has been installed.
Switched to high resolution mode on CPU 0
Switched to high resolution mode on CPU 1
pnp: the driver 'system' has been registered
system 00:00: iomem range 0x0-0x9ffff could not be reserved
system 00:00: iomem range 0xc0000-0xc3fff has been reserved
system 00:00: iomem range 0xc4000-0xc7fff has been reserved
system 00:00: iomem range 0xc8000-0xcbfff has been reserved
system 00:00: iomem range 0xcc000-0xcffff has been reserved
system 00:00: iomem range 0x0-0x0 could not be reserved
system 00:00: iomem range 0x0-0x0 could not be reserved
system 00:00: iomem range 0x0-0x0 could not be reserved
system 00:00: iomem range 0x0-0x0 could not be reserved
system 00:00: iomem range 0xe0000-0xe3fff could not be reserved
system 00:00: iomem range 0xe4000-0xe7fff could not be reserved
system 00:00: iomem range 0xe8000-0xebfff could not be reserved
system 00:00: driver attached
system 00:02: ioport range 0x164e-0x164f has been reserved
system 00:02: ioport range 0x1000-0x107f has been reserved
system 00:02: ioport range 0x1180-0x11bf has been reserved
system 00:02: ioport range 0x800-0x80f has been reserved
system 00:02: ioport range 0x15e0-0x15ef has been reserved
system 00:02: ioport range 0x1600-0x165f could not be reserved
system 00:02: iomem range 0xf0000000-0xf3ffffff could not be reserved
system 00:02: iomem range 0xfed1c000-0xfed1ffff could not be reserved
system 00:02: iomem range 0xfed14000-0xfed17fff could not be reserved
system 00:02: iomem range 0xfed18000-0xfed18fff could not be reserved
system 00:02: iomem range 0xfed19000-0xfed19fff could not be reserved
system 00:02: iomem range 0xfed45000-0xfed4bfff could not be reserved
system 00:02: iomem range 0xfed40000-0xfed44fff could not be reserved
system 00:02: driver attached
PCI: Bridge: 0000:00:1c.0
IO window: 2000-2fff
MEM window: f4000000-f5ffffff
PREFETCH window: f8500000-f85fffff
PCI: Bridge: 0000:00:1c.1
IO window: 3000-3fff
MEM window: f6000000-f7ffffff
PREFETCH window: f8600000-f86fffff
PCI: Bus 6, cardbus bridge: 0000:05:00.0
IO window: 00004000-000040ff
IO window: 00004400-000044ff
PREFETCH window: d8000000-dbffffff
MEM window: 80000000-83ffffff
PCI: Bridge: 0000:00:1e.0
IO window: 4000-7fff
MEM window: d4000000-d7efffff
PREFETCH window: d8000000-dbffffff
ACPI: PCI Interrupt 0000:00:1c.0[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:1c.0 to 64
ACPI: PCI Interrupt 0000:00:1c.1[B] -> GSI 21 (level, low) -> IRQ 21
PCI: Setting latency timer of device 0000:00:1c.1 to 64
PCI: Enabling device 0000:00:1e.0 (0005 -> 0007)
PCI: Setting latency timer of device 0000:00:1e.0 to 64
ACPI: PCI Interrupt 0000:05:00.0[A] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:05:00.0 to 64
NET: Registered protocol family 2
IP route cache hash table entries: 65536 (order: 7, 524288 bytes)
TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
TCP: Hash tables configured (established 262144 bind 65536)
TCP reno registered
Simple Boot Flag at 0x35 set to 0x1
IA-32 Microcode Update Driver: v1.14a <[email protected]>
Total HugeTLB memory allocated, 0
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
SGI XFS Quota Management subsystem
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
Boot video device is 0000:00:02.0
PCI: Setting latency timer of device 0000:00:1c.0 to 64
assign_interrupt_mode Found MSI capability
Allocate Port Service[0000:00:1c.0:pcie00]
Allocate Port Service[0000:00:1c.0:pcie02]
Allocate Port Service[0000:00:1c.0:pcie03]
PCI: Setting latency timer of device 0000:00:1c.1 to 64
assign_interrupt_mode Found MSI capability
Allocate Port Service[0000:00:1c.1:pcie00]
Allocate Port Service[0000:00:1c.1:pcie02]
Allocate Port Service[0000:00:1c.1:pcie03]
ALI M7101 PMU not found.
vesafb: framebuffer at 0xe0000000, mapped to 0xffffc20004100000, using 7616k, total 7616k
vesafb: mode is 1280x1024x32, linelength=5120, pages=0
vesafb: scrolling: redraw
vesafb: Truecolor: size=8:8:8:8, shift=24:16:8:0
Console: switching to colour frame buffer device 160x64
fb0: VESA VGA frame buffer device
ACPI: AC Adapter [AC] (on-line)
ACPI: Battery Slot [BAT0] (battery absent)
input: Power Button (FF) as /devices/virtual/input/input0
ACPI: Power Button (FF) [PWRF]
input: Lid Switch as /devices/virtual/input/input1
ACPI: Lid Switch [LID]
input: Sleep Button (CM) as /devices/virtual/input/input2
ACPI: Sleep Button (CM) [SLPB]
input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/LNXVIDEO:00/input/input3
ACPI: Video Device [VID] (multi-head: yes rom: no post: no)
input: Video Bus as /devices/LNXSYSTM:00/device:00/PNP0A08:00/device:05/LNXVIDEO:01/input/input4
ACPI: Video Device [VID1] (multi-head: yes rom: no post: no)
ACPI: SSDT 7D6E1D72, 0282 (r1 PmRef Cpu0Ist 100 INTL 20050513)
ACPI: SSDT 7D6E2079, 061E (r1 PmRef Cpu0Cst 100 INTL 20050513)
WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
Pid: 1, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
[<ffffffff80466044>] acpi_ut_update_ref_count+0x4e/0x9b
[<ffffffff8021f991>] smp_call_function_single+0x101/0x110
[<ffffffff80428c3c>] _rdmsr_on_cpu+0x5c/0x60
[<ffffffff8047382f>] acpi_processor_get_throttling_ptc+0xf0/0x156
[<ffffffff804734f1>] acpi_processor_get_throttling_info+0x3cc/0x4a2
[<ffffffff804728e7>] acpi_processor_start+0x5a1/0x634
[<ffffffff802924cb>] kmem_cache_alloc+0x9b/0xa0
[<ffffffff80468937>] acpi_start_single_object+0x21/0x45
[<ffffffff80469d33>] acpi_device_probe+0x77/0x8a
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac107>] driver_probe_device+0xa7/0x1d0
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac3b5>] __driver_attach+0xa5/0xb0
[<ffffffff804ab3ad>] bus_for_each_dev+0x4d/0x80
[<ffffffff804ab79f>] bus_add_driver+0x9f/0x200
[<ffffffff808621e7>] acpi_processor_init+0x93/0x100
[<ffffffff8084b6f4>] kernel_init+0x154/0x330
[<ffffffff8022f6b1>] finish_task_switch+0x31/0x90
[<ffffffff8020cb08>] child_rip+0xa/0x12
[<ffffffff8084b5a0>] kernel_init+0x0/0x330
[<ffffffff8020cafe>] child_rip+0x0/0x12

WARNING: at arch/x86/kernel/smp_64.c:397 smp_call_function_mask()
Pid: 1, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
[<ffffffff8021f575>] smp_call_function_mask+0x95/0xa0
[<ffffffff8021f8f5>] smp_call_function_single+0x65/0x110
[<ffffffff80428c3c>] _rdmsr_on_cpu+0x5c/0x60
[<ffffffff8047382f>] acpi_processor_get_throttling_ptc+0xf0/0x156
[<ffffffff804734f1>] acpi_processor_get_throttling_info+0x3cc/0x4a2
[<ffffffff804728e7>] acpi_processor_start+0x5a1/0x634
[<ffffffff802924cb>] kmem_cache_alloc+0x9b/0xa0
[<ffffffff80468937>] acpi_start_single_object+0x21/0x45
[<ffffffff80469d33>] acpi_device_probe+0x77/0x8a
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac107>] driver_probe_device+0xa7/0x1d0
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac3b5>] __driver_attach+0xa5/0xb0
[<ffffffff804ab3ad>] bus_for_each_dev+0x4d/0x80
[<ffffffff804ab79f>] bus_add_driver+0x9f/0x200
[<ffffffff808621e7>] acpi_processor_init+0x93/0x100
[<ffffffff8084b6f4>] kernel_init+0x154/0x330
[<ffffffff8022f6b1>] finish_task_switch+0x31/0x90
[<ffffffff8020cb08>] child_rip+0xa/0x12
[<ffffffff8084b5a0>] kernel_init+0x0/0x330
[<ffffffff8020cafe>] child_rip+0x0/0x12

WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
Pid: 1, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
[<ffffffff8021f991>] smp_call_function_single+0x101/0x110
[<ffffffff80428bab>] _wrmsr_on_cpu+0x4b/0x60
[<ffffffff80473717>] acpi_processor_set_throttling_ptc+0x101/0x129
[<ffffffff8047350c>] acpi_processor_get_throttling_info+0x3e7/0x4a2
[<ffffffff804728e7>] acpi_processor_start+0x5a1/0x634
[<ffffffff802924cb>] kmem_cache_alloc+0x9b/0xa0
[<ffffffff80468937>] acpi_start_single_object+0x21/0x45
[<ffffffff80469d33>] acpi_device_probe+0x77/0x8a
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac107>] driver_probe_device+0xa7/0x1d0
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac3b5>] __driver_attach+0xa5/0xb0
[<ffffffff804ab3ad>] bus_for_each_dev+0x4d/0x80
[<ffffffff804ab79f>] bus_add_driver+0x9f/0x200
[<ffffffff808621e7>] acpi_processor_init+0x93/0x100
[<ffffffff8084b6f4>] kernel_init+0x154/0x330
[<ffffffff8022f6b1>] finish_task_switch+0x31/0x90
[<ffffffff8020cb08>] child_rip+0xa/0x12
[<ffffffff8084b5a0>] kernel_init+0x0/0x330
[<ffffffff8020cafe>] child_rip+0x0/0x12

WARNING: at arch/x86/kernel/smp_64.c:397 smp_call_function_mask()
Pid: 1, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
[<ffffffff8021f575>] smp_call_function_mask+0x95/0xa0
[<ffffffff8021f8f5>] smp_call_function_single+0x65/0x110
[<ffffffff80428bab>] _wrmsr_on_cpu+0x4b/0x60
[<ffffffff80473717>] acpi_processor_set_throttling_ptc+0x101/0x129
[<ffffffff8047350c>] acpi_processor_get_throttling_info+0x3e7/0x4a2
[<ffffffff804728e7>] acpi_processor_start+0x5a1/0x634
[<ffffffff802924cb>] kmem_cache_alloc+0x9b/0xa0
[<ffffffff80468937>] acpi_start_single_object+0x21/0x45
[<ffffffff80469d33>] acpi_device_probe+0x77/0x8a
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac107>] driver_probe_device+0xa7/0x1d0
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac3b5>] __driver_attach+0xa5/0xb0
[<ffffffff804ab3ad>] bus_for_each_dev+0x4d/0x80
[<ffffffff804ab79f>] bus_add_driver+0x9f/0x200
[<ffffffff808621e7>] acpi_processor_init+0x93/0x100
[<ffffffff8084b6f4>] kernel_init+0x154/0x330
[<ffffffff8022f6b1>] finish_task_switch+0x31/0x90
[<ffffffff8020cb08>] child_rip+0xa/0x12
[<ffffffff8084b5a0>] kernel_init+0x0/0x330
[<ffffffff8020cafe>] child_rip+0x0/0x12

Monitor-Mwait will be used to enter C-1 state
Monitor-Mwait will be used to enter C-2 state
Monitor-Mwait will be used to enter C-3 state
ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
ACPI: Processor [CPU0] (supports 8 throttling states)
ACPI: SSDT 7D6E1CAA, 00C8 (r1 PmRef Cpu1Ist 100 INTL 20050513)
ACPI: SSDT 7D6E1FF4, 0085 (r1 PmRef Cpu1Cst 100 INTL 20050513)
WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
Pid: 1, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
[<ffffffff80466044>] acpi_ut_update_ref_count+0x4e/0x9b
[<ffffffff8021f991>] smp_call_function_single+0x101/0x110
[<ffffffff80428c3c>] _rdmsr_on_cpu+0x5c/0x60
[<ffffffff8047382f>] acpi_processor_get_throttling_ptc+0xf0/0x156
[<ffffffff804734f1>] acpi_processor_get_throttling_info+0x3cc/0x4a2
[<ffffffff804728e7>] acpi_processor_start+0x5a1/0x634
[<ffffffff802dec09>] sysfs_find_dirent+0x29/0x40
[<ffffffff802924cb>] kmem_cache_alloc+0x9b/0xa0
[<ffffffff80468937>] acpi_start_single_object+0x21/0x45
[<ffffffff80469d33>] acpi_device_probe+0x77/0x8a
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac107>] driver_probe_device+0xa7/0x1d0
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac3b5>] __driver_attach+0xa5/0xb0
[<ffffffff804ab3ad>] bus_for_each_dev+0x4d/0x80
[<ffffffff804ab79f>] bus_add_driver+0x9f/0x200
[<ffffffff808621e7>] acpi_processor_init+0x93/0x100
[<ffffffff8084b6f4>] kernel_init+0x154/0x330
[<ffffffff8022f6b1>] finish_task_switch+0x31/0x90
[<ffffffff8020cb08>] child_rip+0xa/0x12
[<ffffffff8084b5a0>] kernel_init+0x0/0x330
[<ffffffff8020cafe>] child_rip+0x0/0x12

WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
Pid: 1, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
[<ffffffff8021f991>] smp_call_function_single+0x101/0x110
[<ffffffff80428bab>] _wrmsr_on_cpu+0x4b/0x60
[<ffffffff80473717>] acpi_processor_set_throttling_ptc+0x101/0x129
[<ffffffff8047350c>] acpi_processor_get_throttling_info+0x3e7/0x4a2
[<ffffffff804728e7>] acpi_processor_start+0x5a1/0x634
[<ffffffff802dec09>] sysfs_find_dirent+0x29/0x40
[<ffffffff802924cb>] kmem_cache_alloc+0x9b/0xa0
[<ffffffff80468937>] acpi_start_single_object+0x21/0x45
[<ffffffff80469d33>] acpi_device_probe+0x77/0x8a
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac107>] driver_probe_device+0xa7/0x1d0
[<ffffffff804ac310>] __driver_attach+0x0/0xb0
[<ffffffff804ac3b5>] __driver_attach+0xa5/0xb0
[<ffffffff804ab3ad>] bus_for_each_dev+0x4d/0x80
[<ffffffff804ab79f>] bus_add_driver+0x9f/0x200
[<ffffffff808621e7>] acpi_processor_init+0x93/0x100
[<ffffffff8084b6f4>] kernel_init+0x154/0x330
[<ffffffff8022f6b1>] finish_task_switch+0x31/0x90
[<ffffffff8020cb08>] child_rip+0xa/0x12
[<ffffffff8084b5a0>] kernel_init+0x0/0x330
[<ffffffff8020cafe>] child_rip+0x0/0x12

ACPI: CPU1 (power states: C1[C1] C2[C2] C3[C3])
ACPI: Processor [CPU1] (supports 8 throttling states)
ACPI: Thermal Zone [THM0] (36 C)
ACPI: Thermal Zone [THM1] (37 C)
Real Time Clock Driver v1.12ac
hpet_resources: 0xfed00000 is busy
Non-volatile memory driver v1.2
Linux agpgart interface v0.102
agpgart: Detected an Intel 965GM Chipset.
agpgart: Detected 7676K stolen memory.
agpgart: AGP aperture is 256M @ 0xe0000000
Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing disabled
pnp: the driver 'serial' has been registered
pnp: Res cnt 2
pnp: res cnt 2
pnp: Encode io
pnp: Encode irq
serial 00:0a: activated
00:0a: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
serial 00:0a: driver attached
pnp: Res cnt 2
pnp: res cnt 2
pnp: Encode io
pnp: Encode irq
serial 00:0c: activated
00:0c: ttyS1 at I/O 0x200 (irq = 5) is a NS16550A
serial 00:0c: driver attached
loop: module loaded
nbd: registered device at major 43
thinkpad_acpi: ThinkPad ACPI Extras v0.17
thinkpad_acpi: http://ibm-acpi.sf.net/
thinkpad_acpi: ThinkPad BIOS 7SET21WW (1.07 ), EC 7RHT16WW-1.02
thinkpad_acpi: Lenovo ThinkPad X61 Tablet
thinkpad_acpi: radio switch found; radios are enabled
thinkpad_acpi: standard ACPI backlight interface available, not loading native one...
input: ThinkPad Extra Buttons as /devices/virtual/input/input5
Intel(R) PRO/1000 Network Driver - version 7.3.20-k2-NAPI
Copyright (c) 1999-2006 Intel Corporation.
ACPI: PCI Interrupt 0000:00:19.0[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:19.0 to 64
e1000: 0000:00:19.0: e1000_probe: (PCI Express:2.5Gb/s:Width x1) 00:16:d3:ce:57:d9
e1000: eth0: e1000_probe: Intel(R) PRO/1000 Network Connection
e1000e: Intel(R) PRO/1000 Network Driver - 0.2.0
e1000e: Copyright (c) 1999-2007 Intel Corporation.
SCSI Media Changer driver v0.25
ahci 0000:00:1f.2: version 3.0
ACPI: PCI Interrupt 0000:00:1f.2[B] -> GSI 16 (level, low) -> IRQ 16
ahci 0000:00:1f.2: nr_ports (3) and implemented port map (0x1) don't match, using nr_ports
ahci 0000:00:1f.2: forcing PORTS_IMPL to 0x7
ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 3 ports 1.5 Gbps 0x7 impl SATA mode
ahci 0000:00:1f.2: flags: 64bit ncq sntf pm led clo pio slum part
PCI: Setting latency timer of device 0000:00:1f.2 to 64
scsi0 : ahci
scsi1 : ahci
scsi2 : ahci
ata1: SATA max UDMA/133 abar m2048@0xf8426000 port 0xf8426100 irq 317
ata2: SATA max UDMA/133 abar m2048@0xf8426000 port 0xf8426180 irq 317
ata3: SATA max UDMA/133 abar m2048@0xf8426000 port 0xf8426200 irq 317
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata1.00: ATA-7: HITACHI HTS541680J9SA00, SB2IC7UP, max UDMA/100
ata1.00: 156301488 sectors, multi 16: LBA48 NCQ (depth 31/32)
ata1.00: configured for UDMA/100
ata2: SATA link down (SStatus 0 SControl 0)
ata3: SATA link down (SStatus 0 SControl 0)
scsi 0:0:0:0: Direct-Access ATA HITACHI HTS54168 SB2I PQ: 0 ANSI: 5
sd 0:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda2 sda3 sda4
sd 0:0:0:0: [sda] Attached SCSI disk
sd 0:0:0:0: Attached scsi generic sg0 type 0
ata_piix 0000:00:1f.1: version 2.12
ACPI: PCI Interrupt 0000:00:1f.1[C] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:00:1f.1 to 64
scsi3 : ata_piix
scsi4 : ata_piix
ata4: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x18e0 irq 14
ata5: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x18e8 irq 15
ata4.00: ATAPI: DVD/CDRW UJDA775, CB03, max UDMA/33
ata4.00: configured for UDMA/33
ata5: port disabled. ignoring.
scsi 3:0:0:0: CD-ROM MATSHITA DVD/CDRW UJDA775 CB03 PQ: 0 ANSI: 5
sr0: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Uniform CD-ROM driver Revision: 3.20
sr 3:0:0:0: Attached scsi CD-ROM sr0
sr 3:0:0:0: Attached scsi generic sg1 type 5
USB Universal Host Controller Interface driver v3.0
ACPI: PCI Interrupt 0000:00:1a.0[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:1a.0 to 64
uhci_hcd 0000:00:1a.0: UHCI Host Controller
uhci_hcd 0000:00:1a.0: new USB bus registered, assigned bus number 1
uhci_hcd 0000:00:1a.0: irq 20, io base 0x00001860
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1a.1[B] -> GSI 21 (level, low) -> IRQ 21
PCI: Setting latency timer of device 0000:00:1a.1 to 64
uhci_hcd 0000:00:1a.1: UHCI Host Controller
uhci_hcd 0000:00:1a.1: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1a.1: irq 21, io base 0x00001880
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:00:1d.0 to 64
uhci_hcd 0000:00:1d.0: UHCI Host Controller
uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:1d.0: irq 16, io base 0x000018a0
usb 1-1: new full speed USB device using uhci_hcd and address 2
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 17 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:00:1d.1 to 64
uhci_hcd 0000:00:1d.1: UHCI Host Controller
usb 1-1: configuration #1 chosen from 1 choice
uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:1d.1: irq 17, io base 0x000018c0
usb usb4: configuration #1 chosen from 1 choice
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
Initializing USB Mass Storage driver...
usb 2-2: new full speed USB device using uhci_hcd and address 2
usb 2-2: configuration #1 chosen from 1 choice
hub 2-2:1.0: USB hub found
hub 2-2:1.0: 4 ports detected
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
pnp: the driver 'i8042 kbd' has been registered
i8042 kbd 00:08: driver attached
pnp: the driver 'i8042 aux' has been registered
i8042 aux 00:09: driver attached
PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input6
ACPI: PCI Interrupt 0000:00:1f.3[A] -> GSI 23 (level, low) -> IRQ 23
IBM TrackPoint firmware: 0x0e, buttons: 3/3
input: TPPS/2 IBM TrackPoint as /devices/platform/i8042/serio1/input/input7
i2c-parport-light: adapter type unspecified
cpuidle: using governor ladder
cpuidle: using governor menu
usbcore: registered new interface driver usbhid
drivers/hid/usbhid/hid-core.c: v2.6:USB HID core driver
Advanced Linux Sound Architecture Driver Version 1.0.15 (Tue Nov 20 19:16:42 2007 UTC).
ACPI: PCI Interrupt 0000:00:1b.0[B] -> GSI 17 (level, low) -> IRQ 17
hda_intel: probe_mask set to 0x1 for device 17aa:20ac
PCI: Setting latency timer of device 0000:00:1b.0 to 64
ALSA device list:
#0: HDA Intel at 0xf8220000 irq 17
TCP cubic registered
Initializing XFRM netlink socket
NET: Registered protocol family 1
NET: Registered protocol family 17
NET: Registered protocol family 15
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
swsusp: Resume From Partition /dev/sda4
PM: Checking swsusp image.
PM: Resume from disk failed.
Magic number: 3:710:922
UDF-fs: No VRS found
XFS mounting filesystem sda2
Ending clean XFS mount for filesystem: sda2
VFS: Mounted root (xfs filesystem) readonly.
Freeing unused kernel memory: 244k freed
ACPI: PCI Interrupt 0000:00:1a.7[C] -> GSI 22 (level, low) -> IRQ 22
PCI: Setting latency timer of device 0000:00:1a.7 to 64
ehci_hcd 0000:00:1a.7: EHCI Host Controller
ehci_hcd 0000:00:1a.7: new USB bus registered, assigned bus number 5
PCI: cache line size of 32 is not supported by device 0000:00:1a.7
ehci_hcd 0000:00:1a.7: irq 22, io mem 0xf8426c00
ehci_hcd 0000:00:1a.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb5: configuration #1 chosen from 1 choice
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 4 ports detected
usb 2-2: USB disconnect, address 2
ACPI: PCI Interrupt 0000:00:1d.7[D] -> GSI 19 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1d.7 to 64
ehci_hcd 0000:00:1d.7: EHCI Host Controller
ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 6
ehci_hcd 0000:00:1d.7: debug port 1
PCI: cache line size of 32 is not supported by device 0000:00:1d.7
ehci_hcd 0000:00:1d.7: irq 19, io mem 0xf8427000
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb6: configuration #1 chosen from 1 choice
hub 6-0:1.0: USB hub found
hub 6-0:1.0: 4 ports detected
iwl4965: Intel(R) Wireless WiFi Link 4965AGN driver for Linux, 1.1.17ks
iwl4965: Copyright(c) 2003-2007 Intel Corporation
ACPI: PCI Interrupt 0000:03:00.0[A] -> GSI 17 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:03:00.0 to 64
iwl4965: Detected Intel Wireless WiFi Link 4965AGN
usb 5-4: new high speed USB device using ehci_hcd and address 3
usb 5-4: configuration #1 chosen from 1 choice
hub 5-4:1.0: USB hub found
hub 5-4:1.0: 4 ports detected
iwl4965: Tunable channels: 13 802.11bg, 19 802.11a channels
phy0: Selected rate control algorithm 'iwl-4965-rs'
usb 1-1: USB disconnect, address 2
usb 1-1: new full speed USB device using uhci_hcd and address 3
usb 1-1: configuration #1 chosen from 1 choice
XFS mounting filesystem sda3
Ending clean XFS mount for filesystem: sda3
Adding 4882396k swap on /dev/sda4. Priority:1 extents:1 across:4882396k
Clocksource tsc unstable (delta = -72484678 ns)
iwl4965: Radio Frequency Kill Switch is On:
Kill switch must be turned off for wireless networking to work.
Syncing filesystems ... done.
PM: Preparing system for mem sleep
Freezing user space processes ... (elapsed 0.00 seconds) done.
Freezing remaining freezable tasks ... (elapsed 0.00 seconds) done.
PM: Entering mem sleep
Suspending console(s)
sd 0:0:0:0: [sda] Synchronizing SCSI cache
sd 0:0:0:0: [sda] Stopping disk
serial 00:0c: disabled
serial 00:0a: disabled
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
Disabling non-boot CPUs ...
CPU 1 is now offline
SMP alternatives: switching to UP code
CPU1 is down
Extended CMOS year: 2000
Back to C!
Extended CMOS year: 2000
Enabling non-boot CPUs ...
SMP alternatives: switching to SMP code
Booting processor 1/2 APIC 0x1
Initializing CPU#1
Calibrating delay using timer specific routine.. 3192.20 BogoMIPS (lpj=1596101)
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 1
Intel(R) Core(TM)2 Duo CPU L7500 @ 1.60GHz stepping 0b
CPU1 is up
Switched to high resolution mode on CPU 1
ACPI: EC: missing write data confirmation, don't expect it any longer.
PM: Writing back config space on device 0000:00:02.1 at offset 1 (was 900000, writing 900007)
ACPI: PCI Interrupt 0000:00:19.0[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:19.0 to 64
ACPI: PCI Interrupt 0000:00:1a.0[A] -> GSI 20 (level, low) -> IRQ 20
PCI: Setting latency timer of device 0000:00:1a.0 to 64
usb usb1: root hub lost power or was reset
ACPI: PCI Interrupt 0000:00:1a.1[B] -> GSI 21 (level, low) -> IRQ 21
PCI: Setting latency timer of device 0000:00:1a.1 to 64
usb usb2: root hub lost power or was reset
ACPI: PCI Interrupt 0000:00:1a.7[C] -> GSI 22 (level, low) -> IRQ 22
PCI: Setting latency timer of device 0000:00:1a.7 to 64
PM: Writing back config space on device 0000:00:1b.0 at offset 1 (was 100106, writing 100102)
ACPI: PCI Interrupt 0000:00:1b.0[B] -> GSI 17 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:00:1b.0 to 64
PM: Writing back config space on device 0000:00:1c.0 at offset 7 (was 20002020, writing 2020)
PM: Writing back config space on device 0000:00:1c.0 at offset 1 (was 100107, writing 100507)
PCI: Setting latency timer of device 0000:00:1c.0 to 64
PM: Writing back config space on device 0000:00:1c.1 at offset 1 (was 100107, writing 100507)
PCI: Setting latency timer of device 0000:00:1c.1 to 64
ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:00:1d.0 to 64
usb usb3: root hub lost power or was reset
ACPI: PCI Interrupt 0000:00:1d.1[B] -> GSI 17 (level, low) -> IRQ 17
PCI: Setting latency timer of device 0000:00:1d.1 to 64
usb usb4: root hub lost power or was reset
ACPI: PCI Interrupt 0000:00:1d.7[D] -> GSI 19 (level, low) -> IRQ 19
PCI: Setting latency timer of device 0000:00:1d.7 to 64
PM: Writing back config space on device 0000:00:1e.0 at offset 1 (was 100005, writing 100007)
PCI: Setting latency timer of device 0000:00:1e.0 to 64
PM: Writing back config space on device 0000:00:1f.1 at offset 1 (was 2800005, writing 2880005)
ACPI: PCI Interrupt 0000:00:1f.1[C] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:00:1f.1 to 64
ata5: port disabled. ignoring.
PM: Writing back config space on device 0000:00:1f.2 at offset 1 (was 2b00007, writing 2b00407)
PCI: Setting latency timer of device 0000:00:1f.2 to 64
ata4.00: configured for UDMA/33
Coming out of suspend...
PM: Writing back config space on device 0000:03:00.0 at offset 1 (was 100106, writing 40100506)
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
ata3: SATA link down (SStatus 0 SControl 0)
ata2: SATA link down (SStatus 0 SControl 0)
ACPI: PCI Interrupt 0000:05:00.0[A] -> GSI 16 (level, low) -> IRQ 16
i8042 kbd 00:08: activation not supported
i8042 aux 00:09: activation not supported
pnp: Res cnt 2
pnp: res cnt 2
pnp: Encode io
pnp: Encode irq
serial 00:0a: activated
pnp: Res cnt 2
pnp: res cnt 2
pnp: Encode io
pnp: Encode irq
serial 00:0c: activated
sd 0:0:0:0: [sda] Starting disk
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
ata1.00: configured for UDMA/100
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
ata1.00: configured for UDMA/100
ata1: EH complete
sd 0:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 156301488 512-byte hardware sectors (80026 MB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: Radio disabled by HW RF Kill switch
PM: Finishing wakeup.
Restarting tasks ... <6>usb 1-1: USB disconnect, address 3
done.
usb 1-1: new full speed USB device using uhci_hcd and address 4
irq 19: nobody cared (try booting with the "irqpoll" option)
Pid: 0, comm: swapper Not tainted 2.6.24-rc3-gdea7d55d #60

Call Trace:
<IRQ> [<ffffffff80269d3e>] __report_bad_irq+0x1e/0x80
[<ffffffff8026a03c>] note_interrupt+0x29c/0x2e0
[<ffffffff8026a8ad>] handle_fasteoi_irq+0xdd/0x110
[<ffffffff8020f2cb>] do_IRQ+0x7b/0x100
[<ffffffff8020c1d1>] ret_from_intr+0x0/0xa
<EOI> [<ffffffff80474755>] acpi_idle_enter_bm+0x26a/0x2d4
[<ffffffff8047474b>] acpi_idle_enter_bm+0x260/0x2d4
[<ffffffff8055a552>] cpuidle_idle_call+0xa2/0xe0
[<ffffffff8055a4b0>] cpuidle_idle_call+0x0/0xe0
[<ffffffff8020aa55>] cpu_idle+0x75/0xf0
[<ffffffff8084bb5a>] start_kernel+0x26a/0x2b0
[<ffffffff8084b117>] _sinittext+0x117/0x120

handlers:
[<ffffffff8051e900>] (usb_hcd_irq+0x0/0x60)
Disabling IRQ #19
usb 1-1: configuration #1 chosen from 1 choice
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: WARNING: Requesting MAC access during RFKILL wakes up NIC
iwl4965: Radio disabled by HW RF Kill switch
e1000: eth0: e1000_watchdog: NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
[drm] Initialized drm 1.1.0 20060810
ACPI: PCI Interrupt 0000:00:02.0[A] -> GSI 16 (level, low) -> IRQ 16
[drm] Initialized i915 1.6.0 20060119 on minor 0


Attachments:
config (38.48 kB)
dmesg (44.25 kB)
Download all attachments

2007-12-01 16:49:53

by Arjan van de Ven

[permalink] [raw]
Subject: Re: WARNING: smp_call_function_single() and smp_call_function_mask()

On Sun, 02 Dec 2007 09:43:39 +0100
Tomas Carnecky <[email protected]> wrote:

> WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
> WARNING: at arch/x86/kernel/smp_64.c:397 smp_call_function_mask()
>
> dmesg and config attached.
>
> I'm getting about three of each at boot. I'm running:
> commit e1cca7e8d484390169777b423a7fe46c7021fec1
> Date: Thu Nov 29 16:25:29 2007 -0800
> which is the latest git as of yesterday plus a one (unrelated) debug
> statement patch in usb uhci.
>
> There was a similar bug report after 2.6.23-rc8-mm was released.
> Though there seems to be a fundamental problem with how people use
> smp_call_function*() [1]. And this can just as well be another
> incarnation of it.
>
> Is that easy enough to fix or do I need to bisect (it didn't happen in
> 2.6.24-rc3)?
>

this appears to be a bug in the acpi code, to be exact in
processor_throttling.c file, function
acpi_processor_set_throttling_ptc(); it disables interrupts and then
appears to do a cross-cpu IPI to set the state. Well... we can't do
that due to deadlock reasons (you can't do IPI's with interrupts off or
you can get a very nice deadlock with the cpu that you IPI trying to
do the same thing to you).

2007-12-03 20:14:30

by Tomas Carnecky

[permalink] [raw]
Subject: Re: WARNING: smp_call_function_single() and smp_call_function_mask()

Arjan van de Ven wrote:
> On Sun, 02 Dec 2007 09:43:39 +0100
> Tomas Carnecky <[email protected]> wrote:
>
>> WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
>> WARNING: at arch/x86/kernel/smp_64.c:397 smp_call_function_mask()
>>
>> dmesg and config attached.
>>
>> I'm getting about three of each at boot. I'm running:
>> commit e1cca7e8d484390169777b423a7fe46c7021fec1
>> Date: Thu Nov 29 16:25:29 2007 -0800
>> which is the latest git as of yesterday plus a one (unrelated) debug
>> statement patch in usb uhci.
>>
>> There was a similar bug report after 2.6.23-rc8-mm was released.
>> Though there seems to be a fundamental problem with how people use
>> smp_call_function*() [1]. And this can just as well be another
>> incarnation of it.
>>
>> Is that easy enough to fix or do I need to bisect (it didn't happen in
>> 2.6.24-rc3)?
>>
>
> this appears to be a bug in the acpi code, to be exact in
> processor_throttling.c file, function
> acpi_processor_set_throttling_ptc(); it disables interrupts and then
> appears to do a cross-cpu IPI to set the state. Well... we can't do
> that due to deadlock reasons (you can't do IPI's with interrupts off or
> you can get a very nice deadlock with the cpu that you IPI trying to
> do the same thing to you).
>

I updated the kernel today (to 1a2edea9aff48...) and the warnings are gone.

tom

2007-12-03 20:46:17

by Pallipadi, Venkatesh

[permalink] [raw]
Subject: RE: WARNING: smp_call_function_single() and smp_call_function_mask()



>-----Original Message-----
>From: [email protected]
>[mailto:[email protected]] On Behalf Of Tomas Carnecky
>Sent: Monday, December 03, 2007 12:14 PM
>To: Arjan van de Ven
>Cc: [email protected]; [email protected]
>Subject: Re: WARNING: smp_call_function_single() and
>smp_call_function_mask()
>
>Arjan van de Ven wrote:
>> On Sun, 02 Dec 2007 09:43:39 +0100
>> Tomas Carnecky <[email protected]> wrote:
>>
>>> WARNING: at arch/x86/kernel/smp_64.c:427 smp_call_function_single()
>>> WARNING: at arch/x86/kernel/smp_64.c:397 smp_call_function_mask()
>>>
>>> dmesg and config attached.
>>>
>>> I'm getting about three of each at boot. I'm running:
>>> commit e1cca7e8d484390169777b423a7fe46c7021fec1
>>> Date: Thu Nov 29 16:25:29 2007 -0800
>>> which is the latest git as of yesterday plus a one (unrelated) debug
>>> statement patch in usb uhci.
>>>
>>> There was a similar bug report after 2.6.23-rc8-mm was released.
>>> Though there seems to be a fundamental problem with how people use
>>> smp_call_function*() [1]. And this can just as well be another
>>> incarnation of it.
>>>
>>> Is that easy enough to fix or do I need to bisect (it
>didn't happen in
>>> 2.6.24-rc3)?
>>>
>>
>> this appears to be a bug in the acpi code, to be exact in
>> processor_throttling.c file, function
>> acpi_processor_set_throttling_ptc(); it disables interrupts and then
>> appears to do a cross-cpu IPI to set the state. Well... we can't do
>> that due to deadlock reasons (you can't do IPI's with
>interrupts off or
>> you can get a very nice deadlock with the cpu that you IPI trying to
>> do the same thing to you).
>>
>
>I updated the kernel today (to 1a2edea9aff48...) and the
>warnings are gone.

Yes. This was reported here earlier and fixed by this patch from Yakui.
http://www.ussg.iu.edu/hypermail/linux/kernel/0711.3/1596.html
which should now be merged upstream.

Thanks,
Venki