LinuxLists.cc - 2.6.29-rc1 does not boot

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Dieter Ries <[email protected]> wrote:

> Hi,
>
> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
> When I try to boot it, that kind of works until init should start. Then
> nothing happens. I tried with init=/bin/bash, which sometimes works, and
> sometimes gets me a bash without the prompt flashing.
>
> I captured the output with netconsole, but I cannot see a problem there.
> It is attached.
>
> My config is also attached.
>
> The machine:
>
> Lenovo Thinkpad T60
> Core2Duo 2GHz
>
> Gentoo 64bit
>
> Everything worked fine with 83bc66f, which was my last pull.
>
> What else should I provide for debugging that?

hm, there's no 83bc66f in Linus's tree.

Ingo

2009-01-11 15:30:27

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Ingo Molnar schrieb:
> * Dieter Ries <[email protected]> wrote:
>
>> Hi,
>>
>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
>> When I try to boot it, that kind of works until init should start. Then
>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
>> sometimes gets me a bash without the prompt flashing.
>>
>> I captured the output with netconsole, but I cannot see a problem there.
>> It is attached.
>>
>> My config is also attached.
>>
>> The machine:
>>
>> Lenovo Thinkpad T60
>> Core2Duo 2GHz
>>
>> Gentoo 64bit
>>
>> Everything worked fine with 83bc66f, which was my last pull.
>>
>> What else should I provide for debugging that?
>
> hm, there's no 83bc66f in Linus's tree.

Sorry, thats because I applied Timo Hoenigs patch for the fingerprint
reader. So the right commit where it worked is 6680598.

Before pulling today, I reverted that patch, to avoid conflicts, so I
guess it should not matter.

>
> Ingo
>

cu
Dieter

--
3rd Law of Computing:
Anything that can go wr
fortune: Segmentation violation -- Core dumped

Attachments:

signature.asc (260.00 B)
OpenPGP digital signature

2009-01-11 15:36:04

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Dieter Ries <[email protected]> wrote:

> Ingo Molnar schrieb:
> > * Dieter Ries <[email protected]> wrote:
> >
> >> Hi,
> >>
> >> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
> >> When I try to boot it, that kind of works until init should start. Then
> >> nothing happens. I tried with init=/bin/bash, which sometimes works, and
> >> sometimes gets me a bash without the prompt flashing.
> >>
> >> I captured the output with netconsole, but I cannot see a problem there.
> >> It is attached.
> >>
> >> My config is also attached.
> >>
> >> The machine:
> >>
> >> Lenovo Thinkpad T60
> >> Core2Duo 2GHz
> >>
> >> Gentoo 64bit
> >>
> >> Everything worked fine with 83bc66f, which was my last pull.
> >>
> >> What else should I provide for debugging that?
> >
> > hm, there's no 83bc66f in Linus's tree.
>
> Sorry, thats because I applied Timo Hoenigs patch for the fingerprint
> reader. So the right commit where it worked is 6680598.
>
> Before pulling today, I reverted that patch, to avoid conflicts, so I
> guess it should not matter.

in the 6680598..v2.6.29-rc1 window there's more than 3000 commits: there
were libata and IDE changes, x86 changes, cpumask changes, ACPI changes
and more. Any of those categories could produce such error symptoms as
your box is showing.

Unless you can see some particular badness in the kernel messages
(something that changed to the last working version) that narrows it down
to some subsystem, i suspect this would have to be bisected ...

Ingo

2009-01-11 15:42:21

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Ingo Molnar schrieb:
> * Dieter Ries <[email protected]> wrote:
>
>> Ingo Molnar schrieb:
>>> * Dieter Ries <[email protected]> wrote:
>>>
>>>> Hi,
>>>>
>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
>>>> When I try to boot it, that kind of works until init should start. Then
>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
>>>> sometimes gets me a bash without the prompt flashing.
>>>>
>>>> I captured the output with netconsole, but I cannot see a problem there.
>>>> It is attached.
>>>>
>>>> My config is also attached.
>>>>
>>>> The machine:
>>>>
>>>> Lenovo Thinkpad T60
>>>> Core2Duo 2GHz
>>>>
>>>> Gentoo 64bit
>>>>
>>>> Everything worked fine with 83bc66f, which was my last pull.
>>>>
>>>> What else should I provide for debugging that?
>>> hm, there's no 83bc66f in Linus's tree.
>> Sorry, thats because I applied Timo Hoenigs patch for the fingerprint
>> reader. So the right commit where it worked is 6680598.
>>
>> Before pulling today, I reverted that patch, to avoid conflicts, so I
>> guess it should not matter.
>
> in the 6680598..v2.6.29-rc1 window there's more than 3000 commits: there
> were libata and IDE changes, x86 changes, cpumask changes, ACPI changes
> and more. Any of those categories could produce such error symptoms as
> your box is showing.
>
> Unless you can see some particular badness in the kernel messages
> (something that changed to the last working version) that narrows it down
> to some subsystem, i suspect this would have to be bisected ...

I am starting to bisect now, will report back when I found something.

>
> Ingo
>

cu
Dieter

--
3rd Law of Computing:
Anything that can go wr
fortune: Segmentation violation -- Core dumped

Attachments:

signature.asc (260.00 B)
OpenPGP digital signature

2009-01-11 18:50:27

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Hi,

Ingo Molnar schrieb:
>>> * Dieter Ries <[email protected]> wrote:
>>>
>>>> Hi,
>>>>
>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
>>>> When I try to boot it, that kind of works until init should start. Then
>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
>>>> sometimes gets me a bash without the prompt flashing.
>>>>
>>>> I captured the output with netconsole, but I cannot see a problem there.
>>>> It is attached.
>>>>
>>>> My config is also attached.
>>>>
>>>> The machine:
>>>>
>>>> Lenovo Thinkpad T60
>>>> Core2Duo 2GHz
>>>>
>>>> Gentoo 64bit
>>>>
>>>>
>>>> What else should I provide for debugging that?
>
> Unless you can see some particular badness in the kernel messages
> (something that changed to the last working version) that narrows it down
> to some subsystem, i suspect this would have to be bisected ...

Bisected it:

####################################################################
7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
Author: Mike Travis <[email protected]>
Date: Sun Jan 4 05:18:09 2009 -0800

cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write

Impact: use new cpumask API to reduce stack usage

Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr()
with a work_on_cpu function for drv_read() and drv_write().

Basically converts do_drv_{read,write} into "work_on_cpu" functions that
are now called by drv_read and drv_write.

Signed-off-by: Mike Travis <[email protected]>
Acked-by: Rusty Russell <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
####################################################################

I reverted that patch, which makes my machine boot again. So I guess
theres something wrong here. Please tell me which information you need
to fix the problem, I will help as I can.

>
> Ingo
>

cu
Dieter

--
3rd Law of Computing:
Anything that can go wr
fortune: Segmentation violation -- Core dumped

Attachments:

signature.asc (260.00 B)
OpenPGP digital signature

2009-01-11 19:02:48

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Dieter Ries wrote:
> Hi,
>
> Ingo Molnar schrieb:
>>>> * Dieter Ries <[email protected]> wrote:
>>>>
>>>>> Hi,
>>>>>
>>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
>>>>> When I try to boot it, that kind of works until init should start. Then
>>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
>>>>> sometimes gets me a bash without the prompt flashing.
>>>>>
>>>>> I captured the output with netconsole, but I cannot see a problem there.
>>>>> It is attached.
>>>>>
>>>>> My config is also attached.
>>>>>
>>>>> The machine:
>>>>>
>>>>> Lenovo Thinkpad T60
>>>>> Core2Duo 2GHz
>>>>>
>>>>> Gentoo 64bit
>>>>>
>>>>>
>>>>> What else should I provide for debugging that?
>> Unless you can see some particular badness in the kernel messages
>> (something that changed to the last working version) that narrows it down
>> to some subsystem, i suspect this would have to be bisected ...
>
> Bisected it:
>
> ####################################################################
> 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
> commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
> Author: Mike Travis <[email protected]>
> Date: Sun Jan 4 05:18:09 2009 -0800
>
> cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
>
> Impact: use new cpumask API to reduce stack usage
>
> Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr()
> with a work_on_cpu function for drv_read() and drv_write().
>
> Basically converts do_drv_{read,write} into "work_on_cpu" functions that
> are now called by drv_read and drv_write.
>
> Signed-off-by: Mike Travis <[email protected]>
> Acked-by: Rusty Russell <[email protected]>
> Signed-off-by: Ingo Molnar <[email protected]>
> ####################################################################
>
> I reverted that patch, which makes my machine boot again. So I guess
> theres something wrong here. Please tell me which information you need
> to fix the problem, I will help as I can.
>
>
>> Ingo
>>
>
> cu
> Dieter
>

Thanks for catching this.

The work_on_cpu approach seems to create more problems than it solves. And
testing it has proven difficult without the right combination of hardware.

Could you send me the console log and config file?

Rusty - any ideas on how to avoid these clashes with the get_online_cpus()
call in work_on_cpu()? Or something else to indicate to lockdep that
the circular lock dependency is ok (as you mentioned before)?

Thanks,
Mike

2009-01-11 19:03:08

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Dieter Ries <[email protected]> wrote:

> Bisected it:
>
> ####################################################################
> 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
> commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
> Author: Mike Travis <[email protected]>
> Date: Sun Jan 4 05:18:09 2009 -0800
>
> cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
>
> Impact: use new cpumask API to reduce stack usage

thanks, this is very helpful!

Mike, most of the work_on_cpu() patches you did so far were rather
problematic. Especially something like cpufreq can run rather early during
bootup or during suspend/resume, so i'm not sure it's correct to rely on
keventd for it.

I dont see anything particularly wrong in the commit itself - but
obviously it causes this boot hang - if the bug is not found we'll revert
it .

Also, this bit in get_cur_val():

+ if (unlikely(!alloc_cpumask_var(&cmd.mask, GFP_KERNEL)))
+ return 0;

how is that supposed to work? If we fail to allocate a cpumask we just
ignore the call silently? That cannot be right. (but has no connection to
this boot problem)

Ingo

2009-01-11 19:14:59

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Ingo Molnar wrote:
> * Dieter Ries <[email protected]> wrote:
>
>> Bisected it:
>>
>> ####################################################################
>> 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
>> commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
>> Author: Mike Travis <[email protected]>
>> Date: Sun Jan 4 05:18:09 2009 -0800
>>
>> cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
>>
>> Impact: use new cpumask API to reduce stack usage
>
> thanks, this is very helpful!
>
> Mike, most of the work_on_cpu() patches you did so far were rather
> problematic. Especially something like cpufreq can run rather early during
> bootup or during suspend/resume, so i'm not sure it's correct to rely on
> keventd for it.
>
> I dont see anything particularly wrong in the commit itself - but
> obviously it causes this boot hang - if the bug is not found we'll revert
> it .

All of these are low use functions, primarily used when bringing up
cpus. So reverting the patches does not have a big effect on the stack
size problem.
>
> Also, this bit in get_cur_val():
>
> + if (unlikely(!alloc_cpumask_var(&cmd.mask, GFP_KERNEL)))
> + return 0;
>
> how is that supposed to work? If we fail to allocate a cpumask we just
> ignore the call silently? That cannot be right. (but has no connection to
> this boot problem)
>
> Ingo

Well I did have a different approach but Rusty seemed to really be
attached to work_on_cpu. (The alternate was to add a 2nd cpumask to the
task struct to hold current->cpus_allowed while setting it to a special
cpus_allowed mask.)

In any case, except for the get_online_cpus() call, work_on_cpu is a
fairly straight forward approach. But I'm just not familiar enough
with the whole locking scheme to determine whether the cpu hotplug lock
has already been taken, which is causing this weird lockdep warning.
And I don't know of an adaptive way to do it (figure out in work_on_cpu()
if get_online_cpus() should be called or not.)

About the return 0, it was the default return for another error case.
Should the function panic because it can't read a cpu reg? That seems
wrong too.

Thanks,
Mike

2009-01-11 19:30:53

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Linux version 2.6.29-rc1-00039-gc48f9c5 (root@Mobilehorst) (gcc version 4.1.2 (Gentoo 4.1.2 p1.1)) #129 SMP Sun Jan 11 15:36:19 CET 2009
Command line: root=/dev/sda5 resume2=swap:/dev/sda7 vga=0x31A elevator=noop [email protected]/eth0,[email protected]/00:14:2A:26:F9:57 init=/bin/bash
KERNEL supported cpus:
Intel GenuineIntel
AMD AuthenticAMD
Centaur CentaurHauls
BIOS-provided physical RAM map:
BIOS-e820: 0000000000000000 - 000000000009f000 (usable)
BIOS-e820: 000000000009f000 - 00000000000a0000 (reserved)
BIOS-e820: 00000000000d2000 - 00000000000d4000 (reserved)
BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved)
BIOS-e820: 0000000000100000 - 000000007fed0000 (usable)
BIOS-e820: 000000007fed0000 - 000000007fedf000 (ACPI data)
BIOS-e820: 000000007fedf000 - 000000007ff00000 (ACPI NVS)
BIOS-e820: 000000007ff00000 - 0000000080000000 (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: 00000000ff800000 - 0000000100000000 (reserved)
DMI present.
last_pfn = 0x7fed0 max_arch_pfn = 0x100000000
init_memory_mapping: 0000000000000000-000000007fed0000
last_map_addr: 7fed0000 end: 7fed0000
ACPI: RSDP 000F67E0, 0024 (r2 LENOVO)
ACPI: XSDT 7FED13C7, 008C (r1 LENOVO TP-79 2160 LTP 0)
ACPI: FACP 7FED1500, 00F4 (r3 LENOVO TP-79 2160 LNVO 1)
ACPI Warning (tbfadt-0568): 32/64X length mismatch in Gpe0Block: 64/32 [20081204]
ACPI Warning (tbfadt-0568): 32/64X length mismatch in Gpe1Block: 0/32 [20081204]
ACPI Warning (tbfadt-0596): Optional field Gpe1Block has zero address or length: 000000000000102C/0 [20081204]
FADT: X_PM1a_EVT_BLK.bit_width (16) does not match PM1_EVT_LEN (4)
ACPI: DSDT 7FED185E, D3C2 (r1 LENOVO TP-79 2160 MSFT 100000E)
ACPI: FACS 7FEF4000, 0040
ACPI: SSDT 7FED16B4, 01AA (r1 LENOVO TP-79 2160 MSFT 100000E)
ACPI: ECDT 7FEDEC20, 0052 (r1 LENOVO TP-79 2160 LNVO 1)
ACPI: TCPA 7FEDEC72, 0032 (r2 LENOVO TP-79 2160 LNVO 1)
ACPI: APIC 7FEDECA4, 0068 (r1 LENOVO TP-79 2160 LNVO 1)
ACPI: MCFG 7FEDED0C, 003C (r1 LENOVO TP-79 2160 LNVO 1)
ACPI: HPET 7FEDED48, 0038 (r1 LENOVO TP-79 2160 LNVO 1)
ACPI: SLIC 7FEDEE62, 0176 (r1 LENOVO TP-79 2160 LTP 0)
ACPI: BOOT 7FEDEFD8, 0028 (r1 LENOVO TP-79 2160 LTP 1)
ACPI: SSDT 7FEF2697, 025F (r1 LENOVO TP-79 2160 INTL 20050513)
ACPI: SSDT 7FEF28F6, 00A6 (r1 LENOVO TP-79 2160 INTL 20050513)
ACPI: SSDT 7FEF299C, 04F7 (r1 LENOVO TP-79 2160 INTL 20050513)
ACPI: SSDT 7FEF2E93, 01D8 (r1 LENOVO TP-79 2160 INTL 20050513)
(5 early reservations) ==> bootmem [0000000000 - 007fed0000]
#0 [0000000000 - 0000001000] BIOS data page ==> [0000000000 - 0000001000]
#1 [0000006000 - 0000008000] TRAMPOLINE ==> [0000006000 - 0000008000]
#2 [0000200000 - 00009d3738] TEXT DATA BSS ==> [0000200000 - 00009d3738]
#3 [000009f000 - 0000100000] BIOS reserved ==> [000009f000 - 0000100000]
#4 [0000008000 - 000000a000] PGTABLE ==> [0000008000 - 000000a000]
found SMP MP-table at [ffff8800000f6810] 000f6810
Zone PFN ranges:
DMA 0x00000000 -> 0x00001000
DMA32 0x00001000 -> 0x00100000
Normal 0x00100000 -> 0x00100000
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
0: 0x00000000 -> 0x0000009f
0: 0x00000100 -> 0x0007fed0
ACPI: PM-Timer IO Port: 0x1008
ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x01] enabled)
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, version 0, 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)
Using ACPI (MADT) for SMP configuration information
ACPI: HPET id: 0x8086a201 base: 0xfed00000
SMP: Allowing 2 CPUs, 0 hotplug CPUs
PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
PM: Registered nosave memory: 00000000000a0000 - 00000000000d2000
PM: Registered nosave memory: 00000000000d2000 - 00000000000d4000
PM: Registered nosave memory: 00000000000d4000 - 00000000000dc000
PM: Registered nosave memory: 00000000000dc000 - 0000000000100000
Allocating PCI resources starting at 88000000 (gap: 80000000:70000000)
NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:2 nr_node_ids:1
PERCPU: Allocating 53248 bytes of per cpu data
Built 1 zonelists in Zone order, mobility grouping on. Total pages: 514616
Kernel command line: root=/dev/sda5 resume2=swap:/dev/sda7 vga=0x31A elevator=noop [email protected]/eth0,[email protected]/00:14:2A:26:F9:57 init=/bin/bash
Initializing CPU#0
PID hash table entries: 4096 (order: 12, 32768 bytes)
Extended CMOS year: 2000
Fast TSC calibration using PIT
Detected 1995.109 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...
No AGP bridge found
Memory: 2055176k/2095936k available (4622k kernel code, 388k absent, 40016k reserved, 2056k data, 408k init)
SLUB: Genslabs=12, HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
HPET: 3 timers in total, 0 timers will be used for per-cpu timer
Calibrating delay loop (skipped), value calculated using timer frequency.. 3990.21 BogoMIPS (lpj=1995109)
Mount-cache hash table entries: 256
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
[ds] using core 2 configuration
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 0
CPU0: Thermal monitoring enabled (TM2)
using mwait in idle threads.
ACPI: Core revision 20081204
Setting APIC routing to flat
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
CPU0: Intel(R) Core(TM)2 CPU T7200 @ 2.00GHz stepping 06
Booting processor 1 APIC 0x1 ip 0x6000
Initializing CPU#1
Calibrating delay using timer specific routine.. 3989.82 BogoMIPS (lpj=1994910)
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 4096K
[ds] using core 2 configuration
CPU: Physical Processor ID: 0
CPU: Processor Core ID: 1
CPU1: Thermal monitoring enabled (TM2)
CPU1: Intel(R) Core(TM)2 CPU T7200 @ 2.00GHz stepping 06
checking TSC synchronization [CPU#0 -> CPU#1]:
Measured 617508 cycles TSC warp between CPUs, turning off TSC clock.
Marking TSC unstable due to check_tsc_sync_source failed
Brought up 2 CPUs
Total of 2 processors activated (7980.03 BogoMIPS).
net_namespace: 1312 bytes
NET: Registered protocol family 16
ACPI FADT declares the system doesn't support PCIe ASPM, so disable it
ACPI: bus type pci registered
PCI: MCFG configuration 0: base f0000000 segment 0 buses 0 - 63
PCI: MCFG area at f0000000 reserved in E820
PCI: Using MMCONFIG at f0000000 - f3ffffff
PCI: Using configuration type 1 for base access
bio: create slab <bio-0> at 0
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 = 0x1c, I/O: command/status = 0x66, data = 0x62
ACPI: EC: driver started in interrupt mode
ACPI: ACPI Dock Station Driver: 3 docks/bays found
ACPI: PCI Root Bridge [PCI0] (0000:00)
pci 0000:00:01.0: PME# supported from D0 D3hot D3cold
pci 0000:00:01.0: PME# disabled
pci 0000:00:1b.0: PME# supported from D0 D3hot D3cold
pci 0000:00:1b.0: PME# disabled
pci 0000:00:1c.0: PME# supported from D0 D3hot D3cold
pci 0000:00:1c.0: PME# disabled
pci 0000:00:1c.1: PME# supported from D0 D3hot D3cold
pci 0000:00:1c.1: PME# disabled
pci 0000:00:1c.2: PME# supported from D0 D3hot D3cold
pci 0000:00:1c.2: PME# disabled
pci 0000:00:1c.3: PME# supported from D0 D3hot D3cold
pci 0000:00:1c.3: PME# disabled
pci 0000:00:1d.7: PME# supported from D0 D3hot D3cold
pci 0000:00:1d.7: PME# disabled
pci 0000:00:1f.0: quirk: region 1000-107f claimed by ICH6 ACPI/GPIO/TCO
pci 0000:00:1f.0: quirk: region 1180-11bf claimed by ICH6 GPIO
pci 0000:00:1f.0: ICH7 LPC Generic IO decode 1 PIO at 1600 (mask 007f)
pci 0000:00:1f.0: ICH7 LPC Generic IO decode 2 PIO at 15e0 (mask 000f)
pci 0000:00:1f.0: ICH7 LPC Generic IO decode 3 PIO at 1680 (mask 001f)
pci 0000:00:1f.2: PME# supported from D3hot
pci 0000:00:1f.2: PME# disabled
pci 0000:02:00.0: PME# supported from D0 D3hot D3cold
pci 0000:02:00.0: PME# disabled
pci 0000:03:00.0: PME# supported from D0 D3hot
pci 0000:03:00.0: PME# disabled
pci 0000:15:00.0: PME# supported from D0 D1 D2 D3hot D3cold
pci 0000:15:00.0: PME# disabled
pci 0000:00:1e.0: transparent bridge
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: Power Resource [PUBS] (on)
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
Bluetooth: Core ver 2.14
NET: Registered protocol family 31
Bluetooth: HCI device and connection manager initialized
Bluetooth: HCI socket layer initialized
cfg80211: Using static regulatory domain info
cfg80211: Regulatory domain: US
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
(2402000 KHz - 2472000 KHz @ 40000 KHz), (600 mBi, 2700 mBm)
(5170000 KHz - 5190000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
(5190000 KHz - 5210000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
(5210000 KHz - 5230000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
(5230000 KHz - 5330000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
(5735000 KHz - 5835000 KHz @ 40000 KHz), (600 mBi, 3000 mBm)
cfg80211: Calling CRDA for country: US
hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
hpet0: 3 comparators, 64-bit 14.318180 MHz counter
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 11 devices
ACPI: ACPI bus type pnp unregistered
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 0xd0000-0xd3fff could not be reserved
system 00:00: iomem range 0xdc000-0xdffff 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: iomem range 0xec000-0xeffff could not be reserved
system 00:00: iomem range 0xf0000-0xfffff could not be reserved
system 00:00: iomem range 0x100000-0x7fffffff could not be reserved
system 00:00: iomem range 0xfec00000-0xfed3ffff could not be reserved
system 00:00: iomem range 0xfed41000-0xffffffff could not be reserved
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 has been reserved
system 00:02: iomem range 0xfed1c000-0xfed1ffff has been reserved
system 00:02: iomem range 0xfed14000-0xfed17fff has been reserved
system 00:02: iomem range 0xfed18000-0xfed18fff has been reserved
system 00:02: iomem range 0xfed19000-0xfed19fff has been reserved
pci 0000:00:01.0: PCI bridge, secondary bus 0000:01
pci 0000:00:01.0: IO window: 0x2000-0x2fff
pci 0000:00:01.0: MEM window: 0xee100000-0xee1fffff
pci 0000:00:01.0: PREFETCH window: 0x000000d8000000-0x000000dfffffff
pci 0000:00:1c.0: PCI bridge, secondary bus 0000:02
pci 0000:00:1c.0: IO window: 0x3000-0x3fff
pci 0000:00:1c.0: MEM window: 0xee000000-0xee0fffff
pci 0000:00:1c.0: PREFETCH window: disabled
pci 0000:00:1c.1: PCI bridge, secondary bus 0000:03
pci 0000:00:1c.1: IO window: 0x4000-0x5fff
pci 0000:00:1c.1: MEM window: 0xec000000-0xedffffff
pci 0000:00:1c.1: PREFETCH window: 0x000000e4000000-0x000000e40fffff
pci 0000:00:1c.2: PCI bridge, secondary bus 0000:04
pci 0000:00:1c.2: IO window: 0x6000-0x7fff
pci 0000:00:1c.2: MEM window: 0xe8000000-0xe9ffffff
pci 0000:00:1c.2: PREFETCH window: 0x000000e4100000-0x000000e41fffff
pci 0000:00:1c.3: PCI bridge, secondary bus 0000:0c
pci 0000:00:1c.3: IO window: 0x8000-0x9fff
pci 0000:00:1c.3: MEM window: 0xea000000-0xebffffff
pci 0000:00:1c.3: PREFETCH window: 0x000000e4200000-0x000000e42fffff
pci 0000:15:00.0: CardBus bridge, secondary bus 0000:16
pci 0000:15:00.0: IO window: 0x00a000-0x00a0ff
pci 0000:15:00.0: IO window: 0x00a400-0x00a4ff
pci 0000:15:00.0: PREFETCH window: 0xe0000000-0xe3ffffff
pci 0000:15:00.0: MEM window: 0x88000000-0x8bffffff
pci 0000:00:1e.0: PCI bridge, secondary bus 0000:15
pci 0000:00:1e.0: IO window: 0xa000-0xdfff
pci 0000:00:1e.0: MEM window: 0xe4300000-0xe7ffffff
pci 0000:00:1e.0: PREFETCH window: 0x000000e0000000-0x000000e3ffffff
pci 0000:00:01.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
pci 0000:00:1c.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
pci 0000:00:1c.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
pci 0000:00:1c.2: PCI INT C -> GSI 22 (level, low) -> IRQ 22
pci 0000:00:1c.3: PCI INT D -> GSI 23 (level, low) -> IRQ 23
pci 0000:00:1e.0: enabling device (0005 -> 0007)
pci 0000:15:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
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
NET: Registered protocol family 1
Simple Boot Flag at 0x35 set to 0x1
HugeTLB registered 2 MB page size, pre-allocated 0 pages
NTFS driver 2.1.29 [Flags: R/W DEBUG].
SGI XFS with security attributes, large block/inode numbers, no debug enabled
msgmni has been set to 4014
alg: No test for stdrng (krng)
io scheduler noop registered (default)
io scheduler deadline registered
io scheduler cfq registered
vesafb: framebuffer at 0xd8000000, mapped to 0xffffc20004100000, using 5120k, total 16384k
vesafb: mode is 1280x1024x16, linelength=2560, pages=5
vesafb: scrolling: redraw
vesafb: Truecolor: size=0:5:6:5, shift=0:11:5: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 present)
input: Power Button (FF) as /class/input/input0
ACPI: Power Button (FF) [PWRF]
input: Lid Switch as /class/input/input1
ACPI: Lid Switch [LID]
input: Sleep Button (CM) as /class/input/input2
ACPI: Sleep Button (CM) [SLPB]
acpi device:08: registered as cooling_device0
input: Video Bus as /class/input/input3
ACPI: Video Device [VID1] (multi-head: yes rom: no post: no)
ACPI: SSDT 7FEF1D36, 0282 (r1 PmRef Cpu0Ist 100 INTL 20050513)
ACPI: SSDT 7FEF203D, 065A (r1 PmRef Cpu0Cst 100 INTL 20050513)
ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
processor ACPI_CPU:00: registered as cooling_device1
ACPI: Processor [CPU0] (supports 8 throttling states)
ACPI: SSDT 7FEF1C6E, 00C8 (r1 PmRef Cpu1Ist 100 INTL 20050513)
ACPI: SSDT 7FEF1FB8, 0085 (r1 PmRef Cpu1Cst 100 INTL 20050513)
ACPI: CPU1 (power states: C1[C1] C2[C2] C3[C3])
processor ACPI_CPU:01: registered as cooling_device2
ACPI: Processor [CPU1] (supports 8 throttling states)
thermal LNXTHERM:01: registered as thermal_zone0
ACPI: Thermal Zone [THM0] (60 C)
thermal LNXTHERM:02: registered as thermal_zone1
ACPI: Thermal Zone [THM1] (61 C)
Real Time Clock Driver v1.12b
Non-volatile memory driver v1.3
intel_rng: FWH not detected
Linux agpgart interface v0.103
Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
brd: module loaded
loop: module loaded
e1000e: Intel(R) PRO/1000 Network Driver - 0.3.3.3-k6
e1000e: Copyright (c) 1999-2008 Intel Corporation.
e1000e 0000:02:00.0: Disabling L1 ASPM
e1000e 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
e1000e 0000:02:00.0: Warning: detected ASPM enabled in EEPROM
0000:02:00.0: eth0: (PCI Express:2.5GB/s:Width x1) 00:15:58:83:77:77
0000:02:00.0: eth0: Intel(R) PRO/1000 Network Connection
0000:02:00.0: eth0: MAC: 2, PHY: 2, PBA No: 005301-003
tun: Universal TUN/TAP device driver, 1.6
tun: (C) 1999-2004 Max Krasnyansky <[email protected]>
netconsole: local port 4444
netconsole: local IP 172.17.10.49
netconsole: interface eth0
netconsole: remote port 6666
netconsole: remote IP 172.17.10.46
netconsole: remote ethernet address 00:14:2a:26:f9:57
netconsole: device eth0 not up yet, forcing it
e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
console [netcon0] enabled
Clocksource tsc unstable (delta = 4398046201417 ns)
netconsole: network logging started
Uniform Multi-Platform E-IDE driver
ide-gd driver 1.18
Driver 'sd' needs updating - please use bus_type methods
ahci 0000:00:1f.2: PCI INT B -> GSI 16 (level, low) -> IRQ 16
ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 1.5 Gbps 0x1 impl SATA mode
ahci 0000:00:1f.2: flags: 64bit ncq pm led clo pio slum part
scsi0 : ahci
scsi1 : ahci
scsi2 : ahci
scsi3 : ahci
ata1: SATA max UDMA/133 irq_stat 0x00400040, conq 30
ata2: DUMMY
ata3: DUMMY
ata4: DUMMY
ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
ata1.00: ATA-8: OCZ CORE_SSD, 02.10104, max UDMA/100
ata1.00: 250445824 sectors, multi 0: LBA
ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
ata1.00: configured for UDMA/100
ata1.00: configured for UDMA/100
ata1: EH complete
scsi 0:0:0:0: Direct-Access ATA OCZ CORE_SSD 02.1 PQ: 0 ANSI: 5
sd 0:0:0:0: [sda] 250445824 512-byte hardware sectors: (128 GB/119 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sd 0:0:0:0: [sda] 250445824 512-byte hardware sectors: (128 GB/119 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sda: sda1 sda2 sda3 < sda5 sda6 sda7 sda8 > sda4
sd 0:0:0:0: [sda] Attached SCSI disk
ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
scsi4 : ata_piix
scsi5 : ata_piix
ata5: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x1880 irq 14
ata6: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x1888 irq 15
ata5.00: ATAPI: HL-DT-ST DVDRAM GSA-4083N, 1.08, max UDMA/33
ata5.00: configured for UDMA/33
isa bounce pool size: 16 pages
scsi 4:0:0:0: CD-ROM HL-DT-ST DVDRAM GSA-4083N 1.08 PQ: 0 ANSI: 5
ieee1394: raw1394: /dev/raw1394 device initialized
yenta_cardbus 0000:15:00.0: CardBus bridge found [17aa:2012]
yenta_cardbus 0000:15:00.0: Using INTVAL to route CSC interrupts to PCI
yenta_cardbus 0000:15:00.0: Routing CardBus interrupts to PCI
yenta_cardbus 0000:15:00.0: TI: mfunc 0x01d01002, devctl 0x64
yenta_cardbus 0000:15:00.0: ISA IRQ mask 0x0cf8, PCI irq 16
yenta_cardbus 0000:15:00.0: Socket status: 30000007
yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge I/O window: 0xa000 - 0xdfff
yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge Memory window: 0xe4300000 - 0xe7ffffff
yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge Memory window: 0xe0000000 - 0xe3ffffff
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
ehci_hcd 0000:00:1d.7: EHCI Host Controller
ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1
ehci_hcd 0000:00:1d.7: debug port 1
ehci_hcd 0000:00:1d.7: irq 19, io mem 0xee404000
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 8 ports detected
ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
uhci_hcd: USB Universal Host Controller Interface driver
uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
uhci_hcd 0000:00:1d.0: UHCI Host Controller
uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
uhci_hcd 0000:00:1d.0: irq 16, io base 0x00001800
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
uhci_hcd 0000:00:1d.1: UHCI Host Controller
uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
uhci_hcd 0000:00:1d.1: irq 17, io base 0x00001820
usb usb3: configuration #1 chosen from 1 choice
hub 3-0:1.0: USB hub found
hub 3-0:1.0: 2 ports detected
uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
uhci_hcd 0000:00:1d.2: UHCI Host Controller
uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
uhci_hcd 0000:00:1d.2: irq 18, io base 0x00001840
usb usb4: configuration #1 chosen from 1 choice
hub 4-0:1.0: USB hub found
hub 4-0:1.0: 2 ports detected
uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 19 (level, low) -> IRQ 19
uhci_hcd 0000:00:1d.3: UHCI Host Controller
uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 5
uhci_hcd 0000:00:1d.3: irq 19, io base 0x00001860
usb usb5: configuration #1 chosen from 1 choice
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 2 ports detected
Initializing USB Mass Storage driver...
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
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: PC Speaker as /class/input/input4
input: AT Translated Set 2 keyboard as /class/input/input5
i2c /dev entries driver
i801_smbus 0000:00:1f.3: PCI INT A -> GSI 23 (level, low) -> IRQ 23
Bluetooth: HCI UART driver ver 2.2
Bluetooth: HCI H4 protocol initialized
Bluetooth: HCI BCSP protocol initialized
Bluetooth: HCILL protocol initialized
Bluetooth: Broadcom Blutonium firmware driver ver 1.2
usbcore: registered new interface driver bcm203x
Bluetooth: Generic Bluetooth USB driver ver 0.4
usbcore: registered new interface driver btusb
cpuidle: using governor ladder
cpuidle: using governor menu
usbcore: registered new interface driver usbhid
usbhid: v2.6:USB HID core driver
thinkpad_acpi: ThinkPad ACPI Extras v0.21
thinkpad_acpi: http://ibm-acpi.sf.net/
thinkpad_acpi: ThinkPad BIOS 79ETD6WW (2.16 ), EC 79HT50WW-1.07
thinkpad_acpi: Lenovo ThinkPad T60, model 2007ZE1
thinkpad_acpi: radio switch found; radios are enabled
thinkpad_acpi: This ThinkPad has standard ACPI backlight brightness control, supported by the ACPI video driver
thinkpad_acpi: Disabling thinkpad-acpi brightness events by default...
Registered led device: tpacpi::thinklight
usb 5-1: new full speed USB device using uhci_hcd and address 2
Registered led device: tpacpi::power
Registered led device: tpacpi:orange:batt
Registered led device: tpacpi:green:batt
Registered led device: tpacpi::dock_active
Registered led device: tpacpi::bay_active
Registered led device: tpacpi::dock_batt
Registered led device: tpacpi::unknown_led
Registered led device: tpacpi::standby
thinkpad_acpi: Standard ACPI backlight interface available, not loading native one.
input: ThinkPad Extra Buttons as /class/input/input6
oprofile: using NMI interrupt.
Netfilter messages via NETLINK v0.30.
nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use
nf_conntrack.acct=1 kernel paramater, acct=1 nf_conntrack module option or
sysctl net.netfilter.nf_conntrack_acct=1 to enable it.
ctnetlink v0.93: registering with nfnetlink.
ip_tables: (C) 2000-2006 Netfilter Core Team
arp_tables: (C) 2002 David S. Miller
TCP cubic registered
NET: Registered protocol family 10
ip6_tables: (C) 2000-2006 Netfilter Core Team
IPv6 over IPv4 tunneling driver
NET: Registered protocol family 17
Bluetooth: L2CAP ver 2.11
Bluetooth: L2CAP socket layer initialized
Bluetooth: SCO (Voice Link) ver 0.6
Bluetooth: SCO socket layer initialized
Bluetooth: RFCOMM socket layer initialized
usb 5-1: configuration #1 chosen from 1 choice
Bluetooth: RFCOMM TTY layer initialized
Bluetooth: RFCOMM ver 1.10
Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Bluetooth: BNEP filters: protocol multicast
Bluetooth: HIDP (Human Interface Emulation) ver 1.2
usb 5-2: new full speed USB device using uhci_hcd and address 3
Synaptics Touchpad, model: 1, fw: 6.2, id: 0x81a0b1, caps: 0xa04793/0x300000
serio: Synaptics pass-through port at isa0060/serio1/input0
usb 5-2: configuration #1 chosen from 1 choice
input: SynPS/2 Synaptics TouchPad as /class/input/input7
IBM TrackPoint firmware: 0x0e, buttons: 3/3
input: TPPS/2 IBM TrackPoint as /class/input/input8
kjournald starting. Commit interval 5 seconds
EXT3-fs: mounted filesystem with journal data mode.
VFS: Mounted root (ext3 filesystem) readonly on device 8:5.
Freeing unused kernel memory: 408k freed

Attachments:

kernelconfig (57.29 kB)
kerneloutput (41.32 kB)
signature.asc (260.00 B)
OpenPGP digital signature Download all attachments

2009-01-11 23:19:40

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Mike Travis wrote:
> Ingo Molnar wrote:
...
>> Mike, most of the work_on_cpu() patches you did so far were rather
>> problematic. Especially something like cpufreq can run rather early during
>> bootup or during suspend/resume, so i'm not sure it's correct to rely on
>> keventd for it.
>>
>> I dont see anything particularly wrong in the commit itself - but
>> obviously it causes this boot hang - if the bug is not found we'll revert
>> it .
>
> All of these are low use functions, primarily used when bringing up
> cpus. So reverting the patches does not have a big effect on the stack
> size problem.

Btw, we're looking great with stack space. This is using the 'allyesconfig'
config with NR_CPUS=4096, MAX_NUMNODES=512, and 128-allyesconfig having
NR_CPUS=128, MAX_NUMNODES=64.

====== Stack (-l 500)

1 - 128-allyesconfig
2 - allyesconfig

.1. .2. .delta.
0 600 600 . shmem_getpage
0 600 600 . powernowk8_target
0 584 584 . powernowk8_cpu_init
0 584 584 . __percpu_alloc_mask
0 552 552 . smp_call_function_many
0 536 536 . reload_store
0 528 528 . get_cur_freq
0 528 528 . check_supported_cpu
0 520 520 . powernowk8_get
0 520 520 . microcode_write
0 520 520 . microcode_init_cpu

In Data space we've still got a couple of memory hogs:

====== Data (-l 500)

1 - 128-allyesconfig
2 - allyesconfig

.1. .2. .delta.
16384 524288 +507904 +3100% boot_pageset(.bss) [1]
23816 483080 +459264 +1928% kmalloc_caches(.data.cacheline_aligned) [2]
17408 132096 +114688 +658% irq_info(.bss) [3]
17408 132096 +114688 +658% irq_bindcount(.bss) [3]
1020 131072 +130052 +12750% apic_version(.bss) [4]
3072 98304 +95232 +3100% ucode_cpu_info(.bss) [5]
2048 65536 +63488 +3100% kgdb_info(.bss) [5]
5120 40960 +35840 +700% node_devices(.bss) [6]
5216 36952 +31736 +608% iter(.bss) [???]
6404 33284 +26880 +419% e820_saved(.bss) [7]
6404 33284 +26880 +419% e820(.bss) [7]
1040 33280 +32240 +3100% cpu_bit_bitmap(.rodata) [8]
1064 32808 +31744 +2983% max_tr(.bss) [9]
1064 32808 +31744 +2983% global_trace(.bss) [9]
1024 32768 +31744 +3100% fcoe_percpu(.bss) [10]

[1]: very hard to fix, might be able to use early per_cpu_alloc when available
[2]: can be fixed when early per_cpu_alloc available
[3]: sized by NR_IRQS which can be fixed now
[4]: currently apic_version[MAX_APICS] which is a very sparsely filled array
[5]: sized by NR_CPUS, can be dynamically allocated
[6]: sized by MAX_NUMNODES, also can be dynamically allocated
[7]: sized by MAX_NUMNODES, not so easily modified
[8]: will fix when cpumask_size() is sized by nr_cpu_ids instead of NR_CPUS
[9]: struct trace_array has an NR_CPUS array component
[10]: pointer list sized by NR_CPUS

Overall, the percentages are good:

====== Text/Data ()

1 - 128-allyesconfig
2 - allyesconfig

.1. .2. .delta.
33490944 33499136 +8192 +0.02% TextSize
45527040 45598720 +71680 +0.16% DataSize
11315200 12685312 +1370112 +12% BssSize
3436544 4231168 +794624 +23% InitSize [1]
1904640 1910784 +6144 +0.32% PerCPU
333824 794624 +460800 +138% OtherSize

[1]: remember, this space is "given back" after system initializes.

Here the section detail:

====== Sections (-l 500)

1 - 128-allyesconfig
2 - allyesconfig

.1. .2. .delta.
11316152 12685496 +1369344 +12% .bss
32384 491648 +459264 +1418% .data.cacheline_aligned
370195151 370555424 +360273 +0.10% .debug_info
7358485 7445195 +86710 +1.18% .debug_abbrev
23003987 23045427 +41440 +0.18% .rodata
21248744 21281904 +33160 +0.16% .data
43877348 43890141 +12793 +0.03% .debug_loc
66728 76984 +10256 +15% .data.read_mostly
33491529 33498553 +7024 +0.02% .text
26088048 26094032 +5984 +0.02% .debug_ranges
1904288 1910176 +5888 +0.31% .data.percpu
19530974 19532151 +1177 +0.01% .debug_line
153072 152432 -640 -0.42% __param
836911 837706 +795 +0.09% .init.text

2009-01-12 01:02:18

by H. Peter Anvin

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Mike Travis wrote:
>
> About the return 0, it was the default return for another error case.
> Should the function panic because it can't read a cpu reg? That seems
> wrong too.
>

The only other error case I see is when the value simply is zero by
definition. This is a memory allocation failure, which is quite a bit
different -- the former is that the query *can't* be answered, the
latter that the query *won't* be answered...

-hpa

--
H. Peter Anvin, Intel Open Source Technology Center
I work for Intel. I don't speak on their behalf.

2009-01-12 10:01:22

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Mike Travis <[email protected]> wrote:

> Dieter Ries wrote:
> > Hi,
> >
> > Ingo Molnar schrieb:
> >>>> * Dieter Ries <[email protected]> wrote:
> >>>>
> >>>>> Hi,
> >>>>>
> >>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
> >>>>> When I try to boot it, that kind of works until init should start. Then
> >>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
> >>>>> sometimes gets me a bash without the prompt flashing.
> >>>>>
> >>>>> I captured the output with netconsole, but I cannot see a problem there.
> >>>>> It is attached.
> >>>>>
> >>>>> My config is also attached.
> >>>>>
> >>>>> The machine:
> >>>>>
> >>>>> Lenovo Thinkpad T60
> >>>>> Core2Duo 2GHz
> >>>>>
> >>>>> Gentoo 64bit
> >>>>>
> >>>>>
> >>>>> What else should I provide for debugging that?
> >> Unless you can see some particular badness in the kernel messages
> >> (something that changed to the last working version) that narrows it down
> >> to some subsystem, i suspect this would have to be bisected ...
> >
> > Bisected it:
> >
> > ####################################################################
> > 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
> > commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
> > Author: Mike Travis <[email protected]>
> > Date: Sun Jan 4 05:18:09 2009 -0800
> >
> > cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
> >
> > Impact: use new cpumask API to reduce stack usage
> >
> > Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr()
> > with a work_on_cpu function for drv_read() and drv_write().
> >
> > Basically converts do_drv_{read,write} into "work_on_cpu" functions that
> > are now called by drv_read and drv_write.
> >
> > Signed-off-by: Mike Travis <[email protected]>
> > Acked-by: Rusty Russell <[email protected]>
> > Signed-off-by: Ingo Molnar <[email protected]>
> > ####################################################################
> >
> > I reverted that patch, which makes my machine boot again. So I guess
> > theres something wrong here. Please tell me which information you need
> > to fix the problem, I will help as I can.
> >
> >
> >> Ingo
> >>
> >
> > cu
> > Dieter
> >
>
> Thanks for catching this.
>
> The work_on_cpu approach seems to create more problems than it solves.
> And testing it has proven difficult without the right combination of
> hardware.
>
> Could you send me the console log and config file?
>
> Rusty - any ideas on how to avoid these clashes with the
> get_online_cpus() call in work_on_cpu()? Or something else to indicate
> to lockdep that the circular lock dependency is ok (as you mentioned
> before)?

I've queued up the revert below, please check the commit message whether
you agree with the analysis.

Mike, could you also check any other patches where you add work_on_cpu()
usage to make sure we dont have similar mishaps? work_on_cpu() seems
completely unsuited for any sort of set_cpus_allowed() replacement ...

Ingo

---------------->
>From e0b7a3bea054249b27ca3c843bf6eefcb509d1c2 Mon Sep 17 00:00:00 2001
From: Ingo Molnar <[email protected]>
Date: Mon, 12 Jan 2009 10:49:53 +0100
Subject: [PATCH] Revert "cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write"

This reverts commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d.

Dieter Ries reported bootup soft-hangs and bisected it back to
this commit, and reverting this commit gave him a working system.

The commit introduces work_on_cpu() use into the cpufreq code,
but that is subtly problematic from a lock hierarchy POV: the
hotplug-cpu lock is an highlevel lock that is taken before
lowlevel locks, and in this codepath we are called with the
policy lock taken.

Dieter did not have lockdep enabled so we dont have a nice stack
trace proof for this, but using work_on_cpu() in such a lowlevel
place certainly looks wrong, so we revert the patch.

work_on_cpu() needs to be reworked to be more generally usable.

Reported-by: Dieter Ries <[email protected]>
Tested-by: Dieter Ries <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c | 25 ++++++++++++-------------
1 files changed, 12 insertions(+), 13 deletions(-)

diff --git a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
index 06fcd8f..6f11e02 100644
--- a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
+++ b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
@@ -150,9 +150,8 @@ struct drv_cmd {
u32 val;
};

-static long do_drv_read(void *_cmd)
+static void do_drv_read(struct drv_cmd *cmd)
{
- struct drv_cmd *cmd = _cmd;
u32 h;

switch (cmd->type) {
@@ -167,12 +166,10 @@ static long do_drv_read(void *_cmd)
default:
break;
}
- return 0;
}

-static long do_drv_write(void *_cmd)
+static void do_drv_write(struct drv_cmd *cmd)
{
- struct drv_cmd *cmd = _cmd;
u32 lo, hi;

switch (cmd->type) {
@@ -189,23 +186,30 @@ static long do_drv_write(void *_cmd)
default:
break;
}
- return 0;
}

static void drv_read(struct drv_cmd *cmd)
{
+ cpumask_t saved_mask = current->cpus_allowed;
cmd->val = 0;

- work_on_cpu(cpumask_any(cmd->mask), do_drv_read, cmd);
+ set_cpus_allowed_ptr(current, cmd->mask);
+ do_drv_read(cmd);
+ set_cpus_allowed_ptr(current, &saved_mask);
}

static void drv_write(struct drv_cmd *cmd)
{
+ cpumask_t saved_mask = current->cpus_allowed;
unsigned int i;

for_each_cpu(i, cmd->mask) {
- work_on_cpu(i, do_drv_write, cmd);
+ set_cpus_allowed_ptr(current, cpumask_of(i));
+ do_drv_write(cmd);
}
+
+ set_cpus_allowed_ptr(current, &saved_mask);
+ return;
}

static u32 get_cur_val(const struct cpumask *mask)
@@ -231,15 +235,10 @@ static u32 get_cur_val(const struct cpumask *mask)
return 0;
}

- if (unlikely(!alloc_cpumask_var(&cmd.mask, GFP_KERNEL)))
- return 0;
-
cpumask_copy(cmd.mask, mask);

drv_read(&cmd);

- free_cpumask_var(cmd.mask);
-
dprintk("get_cur_val = %u\n", cmd.val);

return cmd.val;

2009-01-12 11:23:10

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

2009/1/11 Dieter Ries <[email protected]>:
> Hi,
>
> Ingo Molnar schrieb:
>>>> * Dieter Ries <[email protected]> wrote:
>>>>
>>>>> Hi,
>>>>>
>>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
>>>>> When I try to boot it, that kind of works until init should start. Then
>>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
>>>>> sometimes gets me a bash without the prompt flashing.
>>>>>

Simmilar issue, described:
http://lkml.indiana.edu/hypermail/linux/kernel/0901.1/01701.html

[...]
####################################################################
> 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
> commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
> Author: Mike Travis <[email protected]>
> Date: Sun Jan 4 05:18:09 2009 -0800
>
> cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
>
> Impact: use new cpumask API to reduce stack usage
>
> Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr()
> with a work_on_cpu function for drv_read() and drv_write().
>
> Basically converts do_drv_{read,write} into "work_on_cpu" functions that
> are now called by drv_read and drv_write.
>
> Signed-off-by: Mike Travis <[email protected]>
> Acked-by: Rusty Russell <[email protected]>
> Signed-off-by: Ingo Molnar <[email protected]>

Revert this commit also solves problem on my laptoop.

--
Maciej Rutecki
http://www.maciek.unixy.pl

2009-01-12 11:26:28

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Maciej Rutecki <[email protected]> wrote:

> 2009/1/11 Dieter Ries <[email protected]>:
> > Hi,
> >
> > Ingo Molnar schrieb:
> >>>> * Dieter Ries <[email protected]> wrote:
> >>>>
> >>>>> Hi,
> >>>>>
> >>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
> >>>>> When I try to boot it, that kind of works until init should start. Then
> >>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
> >>>>> sometimes gets me a bash without the prompt flashing.
> >>>>>
>
> Simmilar issue, described:
> http://lkml.indiana.edu/hypermail/linux/kernel/0901.1/01701.html
>
> [...]
> ####################################################################
> > 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
> > commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
> > Author: Mike Travis <[email protected]>
> > Date: Sun Jan 4 05:18:09 2009 -0800
> >
> > cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
> >
> > Impact: use new cpumask API to reduce stack usage
> >
> > Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr()
> > with a work_on_cpu function for drv_read() and drv_write().
> >
> > Basically converts do_drv_{read,write} into "work_on_cpu" functions that
> > are now called by drv_read and drv_write.
> >
> > Signed-off-by: Mike Travis <[email protected]>
> > Acked-by: Rusty Russell <[email protected]>
> > Signed-off-by: Ingo Molnar <[email protected]>
>
> Revert this commit also solves problem on my laptoop.

yes - the revert patch can be found below.

Ingo

------------------->
>From e0b7a3bea054249b27ca3c843bf6eefcb509d1c2 Mon Sep 17 00:00:00 2001
From: Ingo Molnar <[email protected]>
Date: Mon, 12 Jan 2009 10:49:53 +0100
Subject: [PATCH] Revert "cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write"

This reverts commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d.

Dieter Ries reported bootup soft-hangs and bisected it back to
this commit, and reverting this commit gave him a working system.

The commit introduces work_on_cpu() use into the cpufreq code,
but that is subtly problematic from a lock hierarchy POV: the
hotplug-cpu lock is an highlevel lock that is taken before
lowlevel locks, and in this codepath we are called with the
policy lock taken.

Dieter did not have lockdep enabled so we dont have a nice stack
trace proof for this, but using work_on_cpu() in such a lowlevel
place certainly looks wrong, so we revert the patch.

work_on_cpu() needs to be reworked to be more generally usable.

Reported-by: Dieter Ries <[email protected]>
Tested-by: Dieter Ries <[email protected]>
Signed-off-by: Ingo Molnar <[email protected]>
---
arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c | 25 ++++++++++++-------------
1 files changed, 12 insertions(+), 13 deletions(-)

diff --git a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
index 06fcd8f..6f11e02 100644
--- a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
+++ b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
@@ -150,9 +150,8 @@ struct drv_cmd {
u32 val;
};

-static long do_drv_read(void *_cmd)
+static void do_drv_read(struct drv_cmd *cmd)
{
- struct drv_cmd *cmd = _cmd;
u32 h;

switch (cmd->type) {
@@ -167,12 +166,10 @@ static long do_drv_read(void *_cmd)
default:
break;
}
- return 0;
}

-static long do_drv_write(void *_cmd)
+static void do_drv_write(struct drv_cmd *cmd)
{
- struct drv_cmd *cmd = _cmd;
u32 lo, hi;

switch (cmd->type) {
@@ -189,23 +186,30 @@ static long do_drv_write(void *_cmd)
default:
break;
}
- return 0;
}

static void drv_read(struct drv_cmd *cmd)
{
+ cpumask_t saved_mask = current->cpus_allowed;
cmd->val = 0;

- work_on_cpu(cpumask_any(cmd->mask), do_drv_read, cmd);
+ set_cpus_allowed_ptr(current, cmd->mask);
+ do_drv_read(cmd);
+ set_cpus_allowed_ptr(current, &saved_mask);
}

static void drv_write(struct drv_cmd *cmd)
{
+ cpumask_t saved_mask = current->cpus_allowed;
unsigned int i;

for_each_cpu(i, cmd->mask) {
- work_on_cpu(i, do_drv_write, cmd);
+ set_cpus_allowed_ptr(current, cpumask_of(i));
+ do_drv_write(cmd);
}
+
+ set_cpus_allowed_ptr(current, &saved_mask);
+ return;
}

static u32 get_cur_val(const struct cpumask *mask)
@@ -231,15 +235,10 @@ static u32 get_cur_val(const struct cpumask *mask)
return 0;
}

- if (unlikely(!alloc_cpumask_var(&cmd.mask, GFP_KERNEL)))
- return 0;
-
cpumask_copy(cmd.mask, mask);

drv_read(&cmd);

- free_cpumask_var(cmd.mask);
-
dprintk("get_cur_val = %u\n", cmd.val);

return cmd.val;

2009-01-12 11:28:59

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

2009/1/12 Ingo Molnar <[email protected]>:

> yes - the revert patch can be found below.

I will test it in this evening.

--
Maciej Rutecki
http://www.maciek.unixy.pl

2009-01-12 12:10:12

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Ingo Molnar schrieb:
> Dieter did not have lockdep enabled so we dont have a nice stack
> trace proof for this, but using work_on_cpu() in such a lowlevel
> place certainly looks wrong, so we revert the patch.

I can send a stack trace in the evening, when I have access to my other
machine for getting the netconsole output. Would that help?

cu
Dieter

2009-01-12 12:22:07

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Dieter Ries <[email protected]> wrote:

> Ingo Molnar schrieb:
> > Dieter did not have lockdep enabled so we dont have a nice stack
> > trace proof for this, but using work_on_cpu() in such a lowlevel
> > place certainly looks wrong, so we revert the patch.
>
> I can send a stack trace in the evening, when I have access to my other
> machine for getting the netconsole output. Would that help?

sure, that would confirm the theory and would avoid this bug being
reintroduced later.

So you did get stacktraces? You might want to boot with
CONFIG_PROVE_LOCKING=y, that could also catch and report the lockup
scenario.

Ingo

2009-01-12 16:38:19

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

[ 0.000000] Command line: root=/dev/sda5 resume2=swap:/dev/sda7 vga=0x31A elevator=noop [email protected]/eth0,[email protected]/00:14:2A:26:F9:57
[ 0.000000] KERNEL supported cpus:
[ 0.000000] Intel GenuineIntel
[ 0.000000] AMD AuthenticAMD
[ 0.000000] Centaur CentaurHauls
[ 0.000000] BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: 0000000000000000 - 000000000009f000 (usable)
[ 0.000000] BIOS-e820: 000000000009f000 - 00000000000a0000 (reserved)
[ 0.000000] BIOS-e820: 00000000000d2000 - 00000000000d4000 (reserved)
[ 0.000000] BIOS-e820: 00000000000dc000 - 0000000000100000 (reserved)
[ 0.000000] BIOS-e820: 0000000000100000 - 000000007fed0000 (usable)
[ 0.000000] BIOS-e820: 000000007fed0000 - 000000007fedf000 (ACPI data)
[ 0.000000] BIOS-e820: 000000007fedf000 - 000000007ff00000 (ACPI NVS)
[ 0.000000] BIOS-e820: 000000007ff00000 - 0000000080000000 (reserved)
[ 0.000000] BIOS-e820: 00000000f0000000 - 00000000f4000000 (reserved)
[ 0.000000] BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
[ 0.000000] BIOS-e820: 00000000fed00000 - 00000000fed00400 (reserved)
[ 0.000000] BIOS-e820: 00000000fed14000 - 00000000fed1a000 (reserved)
[ 0.000000] BIOS-e820: 00000000fed1c000 - 00000000fed90000 (reserved)
[ 0.000000] BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
[ 0.000000] BIOS-e820: 00000000ff800000 - 0000000100000000 (reserved)
[ 0.000000] DMI present.
[ 0.000000] last_pfn = 0x7fed0 max_arch_pfn = 0x100000000
[ 0.000000] init_memory_mapping: 0000000000000000-000000007fed0000
[ 0.000000] last_map_addr: 7fed0000 end: 7fed0000
[ 0.000000] ACPI: RSDP 000F67E0, 0024 (r2 LENOVO)
[ 0.000000] ACPI: XSDT 7FED13C7, 008C (r1 LENOVO TP-79 2160 LTP 0)
[ 0.000000] ACPI: FACP 7FED1500, 00F4 (r3 LENOVO TP-79 2160 LNVO 1)
[ 0.000000] ACPI Warning (tbfadt-0568): 32/64X length mismatch in Gpe0Block: 64/32 [20081204]
[ 0.000000] ACPI Warning (tbfadt-0568): 32/64X length mismatch in Gpe1Block: 0/32 [20081204]
[ 0.000000] ACPI Warning (tbfadt-0596): Optional field Gpe1Block has zero address or length: 000000000000102C/0 [20081204]
[ 0.000000] FADT: X_PM1a_EVT_BLK.bit_width (16) does not match PM1_EVT_LEN (4)
[ 0.000000] ACPI: DSDT 7FED185E, D3C2 (r1 LENOVO TP-79 2160 MSFT 100000E)
[ 0.000000] ACPI: FACS 7FEF4000, 0040
[ 0.000000] ACPI: SSDT 7FED16B4, 01AA (r1 LENOVO TP-79 2160 MSFT 100000E)
[ 0.000000] ACPI: ECDT 7FEDEC20, 0052 (r1 LENOVO TP-79 2160 LNVO 1)
[ 0.000000] ACPI: TCPA 7FEDEC72, 0032 (r2 LENOVO TP-79 2160 LNVO 1)
[ 0.000000] ACPI: APIC 7FEDECA4, 0068 (r1 LENOVO TP-79 2160 LNVO 1)
[ 0.000000] ACPI: MCFG 7FEDED0C, 003C (r1 LENOVO TP-79 2160 LNVO 1)
[ 0.000000] ACPI: HPET 7FEDED48, 0038 (r1 LENOVO TP-79 2160 LNVO 1)
[ 0.000000] ACPI: SLIC 7FEDEE62, 0176 (r1 LENOVO TP-79 2160 LTP 0)
[ 0.000000] ACPI: BOOT 7FEDEFD8, 0028 (r1 LENOVO TP-79 2160 LTP 1)
[ 0.000000] ACPI: SSDT 7FEF2697, 025F (r1 LENOVO TP-79 2160 INTL 20050513)
[ 0.000000] ACPI: SSDT 7FEF28F6, 00A6 (r1 LENOVO TP-79 2160 INTL 20050513)
[ 0.000000] ACPI: SSDT 7FEF299C, 04F7 (r1 LENOVO TP-79 2160 INTL 20050513)
[ 0.000000] ACPI: SSDT 7FEF2E93, 01D8 (r1 LENOVO TP-79 2160 INTL 20050513)
[ 0.000000] (5 early reservations) ==> bootmem [0000000000 - 007fed0000]
[ 0.000000] #0 [0000000000 - 0000001000] BIOS data page ==> [0000000000 - 0000001000]
[ 0.000000] #1 [0000006000 - 0000008000] TRAMPOLINE ==> [0000006000 - 0000008000]
[ 0.000000] #2 [0000200000 - 000100dd7c] TEXT DATA BSS ==> [0000200000 - 000100dd7c]
[ 0.000000] #3 [000009f000 - 0000100000] BIOS reserved ==> [000009f000 - 0000100000]
[ 0.000000] #4 [0000008000 - 000000a000] PGTABLE ==> [0000008000 - 000000a000]
[ 0.000000] found SMP MP-table at [ffff8800000f6810] 000f6810
[ 0.000000] Zone PFN ranges:
[ 0.000000] DMA 0x00000000 -> 0x00001000
[ 0.000000] DMA32 0x00001000 -> 0x00100000
[ 0.000000] Normal 0x00100000 -> 0x00100000
[ 0.000000] Movable zone start PFN for each node
[ 0.000000] early_node_map[2] active PFN ranges
[ 0.000000] 0: 0x00000000 -> 0x0000009f
[ 0.000000] 0: 0x00000100 -> 0x0007fed0
[ 0.000000] ACPI: PM-Timer IO Port: 0x1008
[ 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_NMI (acpi_id[0x00] high edge lint[0x1])
[ 0.000000] ACPI: LAPIC_NMI (acpi_id[0x01] high edge lint[0x1])
[ 0.000000] ACPI: IOAPIC (id[0x01] address[0xfec00000] gsi_base[0])
[ 0.000000] IOAPIC[0]: apic_id 1, version 0, 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] Using ACPI (MADT) for SMP configuration information
[ 0.000000] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[ 0.000000] SMP: Allowing 2 CPUs, 0 hotplug CPUs
[ 0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
[ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000d2000
[ 0.000000] PM: Registered nosave memory: 00000000000d2000 - 00000000000d4000
[ 0.000000] PM: Registered nosave memory: 00000000000d4000 - 00000000000dc000
[ 0.000000] PM: Registered nosave memory: 00000000000dc000 - 0000000000100000
[ 0.000000] Allocating PCI resources starting at 88000000 (gap: 80000000:70000000)
[ 0.000000] NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:2 nr_node_ids:1
[ 0.000000] PERCPU: Allocating 53248 bytes of per cpu data
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 512525
[ 0.000000] Kernel command line: root=/dev/sda5 resume2=swap:/dev/sda7 vga=0x31A elevator=noop [email protected]/eth0,[email protected]/00:14:2A:26:F9:57
[ 0.000000] Initializing CPU#0
[ 0.000000] PID hash table entries: 4096 (order: 12, 32768 bytes)
[ 0.000000] Extended CMOS year: 2000
[ 0.000000] Fast TSC calibration using PIT
[ 0.000000] Detected 1995.246 MHz processor.
[ 0.000999] Console: colour dummy device 80x25
[ 0.000999] console [tty0] enabled
[ 0.000999] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 0.000999] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.000999] ... MAX_LOCK_DEPTH: 48
[ 0.000999] ... MAX_LOCKDEP_KEYS: 8191
[ 0.000999] ... CLASSHASH_SIZE: 4096
[ 0.000999] ... MAX_LOCKDEP_ENTRIES: 8192
[ 0.000999] ... MAX_LOCKDEP_CHAINS: 16384
[ 0.000999] ... CHAINHASH_SIZE: 8192
[ 0.000999] memory used by lock dependency info: 3839 kB
[ 0.000999] per task-struct memory footprint: 1920 bytes
[ 0.000999] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
[ 0.000999] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
[ 0.000999] Checking aperture...
[ 0.000999] No AGP bridge found
[ 0.000999] Memory: 2032216k/2095936k available (4747k kernel code, 388k absent, 62856k reserved, 2139k data, 412k init)
[ 0.000999] SLUB: Genslabs=12, HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000999] HPET: 3 timers in total, 0 timers will be used for per-cpu timer
[ 0.000999] Calibrating delay loop (skipped), value calculated using timer frequency.. 3990.49 BogoMIPS (lpj=1995246)
[ 0.000999] Mount-cache hash table entries: 256
[ 0.000999] CPU: L1 I cache: 32K, L1 D cache: 32K
[ 0.000999] CPU: L2 cache: 4096K
[ 0.000999] [ds] using core 2 configuration
[ 0.000999] CPU: Physical Processor ID: 0
[ 0.000999] CPU: Processor Core ID: 0
[ 0.000999] CPU0: Thermal monitoring enabled (TM2)
[ 0.000999] using mwait in idle threads.
[ 0.000999] ACPI: Core revision 20081204
[ 0.029129] Setting APIC routing to flat
[ 0.029643] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 0.040015] CPU0: Intel(R) Core(TM)2 CPU T7200 @ 2.00GHz stepping 06
[ 0.040993] lockdep: fixing up alternatives.
[ 0.040993] Booting processor 1 APIC 0x1 ip 0x6000
[ 0.000999] Initializing CPU#1
[ 0.000999] Calibrating delay using timer specific routine.. 3989.82 BogoMIPS (lpj=1994912)
[ 0.000999] CPU: L1 I cache: 32K, L1 D cache: 32K
[ 0.000999] CPU: L2 cache: 4096K
[ 0.000999] [ds] using core 2 configuration
[ 0.000999] CPU: Physical Processor ID: 0
[ 0.000999] CPU: Processor Core ID: 1
[ 0.000999] CPU1: Thermal monitoring enabled (TM2)
[ 0.111611] CPU1: Intel(R) Core(TM)2 CPU T7200 @ 2.00GHz stepping 06
[ 0.111665] checking TSC synchronization [CPU#0 -> CPU#1]:
[ 0.111982] Measured 617568 cycles TSC warp between CPUs, turning off TSC clock.
[ 0.111982] Marking TSC unstable due to check_tsc_sync_source failed
[ 0.112086] Brought up 2 CPUs
[ 0.112092] Total of 2 processors activated (7980.31 BogoMIPS).
[ 0.113251] net_namespace: 1416 bytes
[ 0.114148] NET: Registered protocol family 16
[ 0.115044] ACPI FADT declares the system doesn't support PCIe ASPM, so disable it
[ 0.115073] ACPI: bus type pci registered
[ 0.115117] PCI: MCFG configuration 0: base f0000000 segment 0 buses 0 - 63
[ 0.115124] PCI: MCFG area at f0000000 reserved in E820
[ 0.120386] PCI: Using MMCONFIG at f0000000 - f3ffffff
[ 0.120392] PCI: Using configuration type 1 for base access
[ 0.131159] bio: create slab <bio-0> at 0
[ 0.135889] ACPI: EC: EC description table is found, configuring boot EC
[ 0.150706] ACPI: EC: non-query interrupt received, switching to interrupt mode
[ 0.157274] ACPI: Interpreter enabled
[ 0.157280] ACPI: (supports S0 S3 S4 S5)
[ 0.157292] ACPI: Using IOAPIC for interrupt routing
[ 0.179439] ACPI: EC: GPE = 0x1c, I/O: command/status = 0x66, data = 0x62
[ 0.179447] ACPI: EC: driver started in interrupt mode
[ 0.183968] ACPI: ACPI Dock Station Driver: 3 docks/bays found
[ 0.184654] ACPI: PCI Root Bridge [PCI0] (0000:00)
[ 0.185002] pci 0000:00:01.0: PME# supported from D0 D3hot D3cold
[ 0.185011] pci 0000:00:01.0: PME# disabled
[ 0.185208] pci 0000:00:1b.0: PME# supported from D0 D3hot D3cold
[ 0.185217] pci 0000:00:1b.0: PME# disabled
[ 0.185328] pci 0000:00:1c.0: PME# supported from D0 D3hot D3cold
[ 0.185337] pci 0000:00:1c.0: PME# disabled
[ 0.185451] pci 0000:00:1c.1: PME# supported from D0 D3hot D3cold
[ 0.185461] pci 0000:00:1c.1: PME# disabled
[ 0.185575] pci 0000:00:1c.2: PME# supported from D0 D3hot D3cold
[ 0.185584] pci 0000:00:1c.2: PME# disabled
[ 0.185699] pci 0000:00:1c.3: PME# supported from D0 D3hot D3cold
[ 0.185709] pci 0000:00:1c.3: PME# disabled
[ 0.186216] pci 0000:00:1d.7: PME# supported from D0 D3hot D3cold
[ 0.186227] pci 0000:00:1d.7: PME# disabled
[ 0.186439] pci 0000:00:1f.0: quirk: region 1000-107f claimed by ICH6 ACPI/GPIO/TCO
[ 0.186449] pci 0000:00:1f.0: quirk: region 1180-11bf claimed by ICH6 GPIO
[ 0.186458] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 1 PIO at 1600 (mask 007f)
[ 0.186467] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 2 PIO at 15e0 (mask 000f)
[ 0.186477] pci 0000:00:1f.0: ICH7 LPC Generic IO decode 3 PIO at 1680 (mask 001f)
[ 0.186758] pci 0000:00:1f.2: PME# supported from D3hot
[ 0.186766] pci 0000:00:1f.2: PME# disabled
[ 0.187689] pci 0000:02:00.0: PME# supported from D0 D3hot D3cold
[ 0.187701] pci 0000:02:00.0: PME# disabled
[ 0.188276] pci 0000:03:00.0: PME# supported from D0 D3hot
[ 0.188293] pci 0000:03:00.0: PME# disabled
[ 0.188723] pci 0000:15:00.0: PME# supported from D0 D1 D2 D3hot D3cold
[ 0.188733] pci 0000:15:00.0: PME# disabled
[ 0.188823] pci 0000:00:1e.0: transparent bridge
[ 0.198253] ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.198546] ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.199085] ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.199375] ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.199663] ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.199952] ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.200266] ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.200555] ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 9 10 *11)
[ 0.201065] ACPI: Power Resource [PUBS] (on)
[ 0.202012] SCSI subsystem initialized
[ 0.202013] usbcore: registered new interface driver usbfs
[ 0.202013] usbcore: registered new interface driver hub
[ 0.202013] usbcore: registered new device driver usb
[ 0.203017] PCI: Using ACPI for IRQ routing
[ 0.207994] Bluetooth: Core ver 2.14
[ 0.208016] NET: Registered protocol family 31
[ 0.208016] Bluetooth: HCI device and connection manager initialized
[ 0.208029] Bluetooth: HCI socket layer initialized
[ 0.208051] cfg80211: Using static regulatory domain info
[ 0.208051] cfg80211: Regulatory domain: US
[ 0.208051] (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[ 0.208051] (2402000 KHz - 2472000 KHz @ 40000 KHz), (600 mBi, 2700 mBm)
[ 0.208051] (5170000 KHz - 5190000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
[ 0.208051] (5190000 KHz - 5210000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
[ 0.208051] (5210000 KHz - 5230000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
[ 0.208051] (5230000 KHz - 5330000 KHz @ 40000 KHz), (600 mBi, 2300 mBm)
[ 0.208051] (5735000 KHz - 5835000 KHz @ 40000 KHz), (600 mBi, 3000 mBm)
[ 0.208055] cfg80211: Calling CRDA for country: US
[ 0.208072] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[ 0.208072] hpet0: 3 comparators, 64-bit 14.318180 MHz counter
[ 0.215024] pnp: PnP ACPI init
[ 0.215053] ACPI: bus type pnp registered
[ 0.222961] pnp: PnP ACPI: found 11 devices
[ 0.222968] ACPI: ACPI bus type pnp unregistered
[ 0.222989] system 00:00: iomem range 0x0-0x9ffff could not be reserved
[ 0.222996] system 00:00: iomem range 0xc0000-0xc3fff has been reserved
[ 0.223014] system 00:00: iomem range 0xc4000-0xc7fff has been reserved
[ 0.223021] system 00:00: iomem range 0xc8000-0xcbfff has been reserved
[ 0.223028] system 00:00: iomem range 0xcc000-0xcffff has been reserved
[ 0.223035] system 00:00: iomem range 0xd0000-0xd3fff could not be reserved
[ 0.223042] system 00:00: iomem range 0xdc000-0xdffff could not be reserved
[ 0.223049] system 00:00: iomem range 0xe0000-0xe3fff could not be reserved
[ 0.223056] system 00:00: iomem range 0xe4000-0xe7fff could not be reserved
[ 0.223064] system 00:00: iomem range 0xe8000-0xebfff could not be reserved
[ 0.223071] system 00:00: iomem range 0xec000-0xeffff could not be reserved
[ 0.223078] system 00:00: iomem range 0xf0000-0xfffff could not be reserved
[ 0.223085] system 00:00: iomem range 0x100000-0x7fffffff could not be reserved
[ 0.223093] system 00:00: iomem range 0xfec00000-0xfed3ffff could not be reserved
[ 0.223102] system 00:00: iomem range 0xfed41000-0xffffffff could not be reserved
[ 0.223119] system 00:02: ioport range 0x164e-0x164f has been reserved
[ 0.223126] system 00:02: ioport range 0x1000-0x107f has been reserved
[ 0.223133] system 00:02: ioport range 0x1180-0x11bf has been reserved
[ 0.223139] system 00:02: ioport range 0x800-0x80f has been reserved
[ 0.223146] system 00:02: ioport range 0x15e0-0x15ef has been reserved
[ 0.223153] system 00:02: ioport range 0x1600-0x165f could not be reserved
[ 0.223160] system 00:02: iomem range 0xf0000000-0xf3ffffff has been reserved
[ 0.223168] system 00:02: iomem range 0xfed1c000-0xfed1ffff has been reserved
[ 0.223175] system 00:02: iomem range 0xfed14000-0xfed17fff has been reserved
[ 0.223182] system 00:02: iomem range 0xfed18000-0xfed18fff has been reserved
[ 0.223189] system 00:02: iomem range 0xfed19000-0xfed19fff has been reserved
[ 0.228870] pci 0000:00:01.0: PCI bridge, secondary bus 0000:01
[ 0.228878] pci 0000:00:01.0: IO window: 0x2000-0x2fff
[ 0.228887] pci 0000:00:01.0: MEM window: 0xee100000-0xee1fffff
[ 0.228895] pci 0000:00:01.0: PREFETCH window: 0x000000d8000000-0x000000dfffffff
[ 0.228906] pci 0000:00:1c.0: PCI bridge, secondary bus 0000:02
[ 0.228914] pci 0000:00:1c.0: IO window: 0x3000-0x3fff
[ 0.228924] pci 0000:00:1c.0: MEM window: 0xee000000-0xee0fffff
[ 0.228933] pci 0000:00:1c.0: PREFETCH window: disabled
[ 0.228945] pci 0000:00:1c.1: PCI bridge, secondary bus 0000:03
[ 0.228953] pci 0000:00:1c.1: IO window: 0x4000-0x5fff
[ 0.228963] pci 0000:00:1c.1: MEM window: 0xec000000-0xedffffff
[ 0.228972] pci 0000:00:1c.1: PREFETCH window: 0x000000e4000000-0x000000e40fffff
[ 0.228986] pci 0000:00:1c.2: PCI bridge, secondary bus 0000:04
[ 0.228994] pci 0000:00:1c.2: IO window: 0x6000-0x7fff
[ 0.229015] pci 0000:00:1c.2: MEM window: 0xe8000000-0xe9ffffff
[ 0.229024] pci 0000:00:1c.2: PREFETCH window: 0x000000e4100000-0x000000e41fffff
[ 0.229038] pci 0000:00:1c.3: PCI bridge, secondary bus 0000:0c
[ 0.229045] pci 0000:00:1c.3: IO window: 0x8000-0x9fff
[ 0.229056] pci 0000:00:1c.3: MEM window: 0xea000000-0xebffffff
[ 0.229065] pci 0000:00:1c.3: PREFETCH window: 0x000000e4200000-0x000000e42fffff
[ 0.229083] pci 0000:15:00.0: CardBus bridge, secondary bus 0000:16
[ 0.229089] pci 0000:15:00.0: IO window: 0x00a000-0x00a0ff
[ 0.229099] pci 0000:15:00.0: IO window: 0x00a400-0x00a4ff
[ 0.229109] pci 0000:15:00.0: PREFETCH window: 0xe0000000-0xe3ffffff
[ 0.229119] pci 0000:15:00.0: MEM window: 0x88000000-0x8bffffff
[ 0.229130] pci 0000:00:1e.0: PCI bridge, secondary bus 0000:15
[ 0.229137] pci 0000:00:1e.0: IO window: 0xa000-0xdfff
[ 0.229147] pci 0000:00:1e.0: MEM window: 0xe4300000-0xe7ffffff
[ 0.229156] pci 0000:00:1e.0: PREFETCH window: 0x000000e0000000-0x000000e3ffffff
[ 0.229179] pci 0000:00:01.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 0.229197] pci 0000:00:1c.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
[ 0.229216] pci 0000:00:1c.1: PCI INT B -> GSI 21 (level, low) -> IRQ 21
[ 0.229235] pci 0000:00:1c.2: PCI INT C -> GSI 22 (level, low) -> IRQ 22
[ 0.229255] pci 0000:00:1c.3: PCI INT D -> GSI 23 (level, low) -> IRQ 23
[ 0.229272] pci 0000:00:1e.0: enabling device (0005 -> 0007)
[ 0.229291] pci 0000:15:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 0.229430] NET: Registered protocol family 2
[ 0.240157] IP route cache hash table entries: 65536 (order: 7, 524288 bytes)
[ 0.240862] TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
[ 0.243050] TCP bind hash table entries: 65536 (order: 9, 3670016 bytes)
[ 0.248770] TCP: Hash tables configured (established 262144 bind 65536)
[ 0.248827] TCP reno registered
[ 0.251189] NET: Registered protocol family 1
[ 0.251552] Simple Boot Flag at 0x35 set to 0x1
[ 0.259902] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[ 0.266900] NTFS driver 2.1.29 [Flags: R/W DEBUG].
[ 0.267307] SGI XFS with security attributes, large block/inode numbers, no debug enabled
[ 0.268374] msgmni has been set to 3970
[ 0.269929] alg: No test for stdrng (krng)
[ 0.269966] io scheduler noop registered (default)
[ 0.269972] io scheduler deadline registered
[ 0.270114] io scheduler cfq registered
[ 0.273549] vesafb: framebuffer at 0xd8000000, mapped to 0xffffc20004100000, using 5120k, total 16384k
[ 0.273559] vesafb: mode is 1280x1024x16, linelength=2560, pages=5
[ 0.273565] vesafb: scrolling: redraw
[ 0.273570] vesafb: Truecolor: size=0:5:6:5, shift=0:11:5:0
[ 0.315044] Console: switching to colour frame buffer device 160x64
[ 0.353455] fb0: VESA VGA frame buffer device
[ 0.354489] ACPI: AC Adapter [AC] (on-line)
[ 0.396835] ACPI: Battery Slot [BAT0] (battery present)
[ 0.397471] input: Power Button (FF) as /class/input/input0
[ 0.397764] ACPI: Power Button (FF) [PWRF]
[ 0.398118] input: Lid Switch as /class/input/input1
[ 0.403155] ACPI: Lid Switch [LID]
[ 0.403463] input: Sleep Button (CM) as /class/input/input2
[ 0.403728] ACPI: Sleep Button (CM) [SLPB]
[ 0.406383] acpi device:08: registered as cooling_device0
[ 0.407208] input: Video Bus as /class/input/input3
[ 0.407450] ACPI: Video Device [VID1] (multi-head: yes rom: no post: no)
[ 0.408574] ACPI: SSDT 7FEF1D36, 0282 (r1 PmRef Cpu0Ist 100 INTL 20050513)
[ 0.410323] ACPI: SSDT 7FEF203D, 065A (r1 PmRef Cpu0Cst 100 INTL 20050513)
[ 0.416185] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[ 0.416585] processor ACPI_CPU:00: registered as cooling_device1
[ 0.416868] ACPI: Processor [CPU0] (supports 8 throttling states)
[ 0.417678] ACPI: SSDT 7FEF1C6E, 00C8 (r1 PmRef Cpu1Ist 100 INTL 20050513)
[ 0.419291] ACPI: SSDT 7FEF1FB8, 0085 (r1 PmRef Cpu1Cst 100 INTL 20050513)
[ 0.422405] ACPI: CPU1 (power states: C1[C1] C2[C2] C3[C3])
[ 0.422804] processor ACPI_CPU:01: registered as cooling_device2
[ 0.423098] ACPI: Processor [CPU1] (supports 8 throttling states)
[ 0.431952] thermal LNXTHERM:01: registered as thermal_zone0
[ 0.436103] ACPI: Thermal Zone [THM0] (58 C)
[ 0.437625] thermal LNXTHERM:02: registered as thermal_zone1
[ 0.439301] ACPI: Thermal Zone [THM1] (59 C)
[ 0.501228] Real Time Clock Driver v1.12b
[ 0.501799] Non-volatile memory driver v1.3
[ 0.502346] intel_rng: FWH not detected
[ 0.502655] Linux agpgart interface v0.103
[ 0.502977] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 0.507442] brd: module loaded
[ 0.509065] loop: module loaded
[ 0.509434] e1000e: Intel(R) PRO/1000 Network Driver - 0.3.3.3-k6
[ 0.516734] e1000e: Copyright (c) 1999-2008 Intel Corporation.
[ 0.524315] e1000e 0000:02:00.0: Disabling L1 ASPM
[ 0.531986] e1000e 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 0.581448] e1000e 0000:02:00.0: Warning: detected ASPM enabled in EEPROM
[ 0.631859] 0000:02:00.0: eth0: (PCI Express:2.5GB/s:Width x1) 00:15:58:83:77:77
[ 0.640202] 0000:02:00.0: eth0: Intel(R) PRO/1000 Network Connection
[ 0.648773] 0000:02:00.0: eth0: MAC: 2, PHY: 2, PBA No: 005301-003
[ 0.657683] tun: Universal TUN/TAP device driver, 1.6
[ 0.666503] tun: (C) 1999-2004 Max Krasnyansky <[email protected]>
[ 0.675730] netconsole: local port 4444
[ 0.684946] netconsole: local IP 172.17.10.49
[ 0.694281] netconsole: interface eth0
[ 0.703680] netconsole: remote port 6666
[ 0.713163] netconsole: remote IP 172.17.10.46
[ 0.722761] netconsole: remote ethernet address 00:14:2a:26:f9:57
[ 0.732598] netconsole: device eth0 not up yet, forcing it
[ 3.997967] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX/TX
[ 4.011277] console [netcon0] enabled
[ 7.350838] netconsole: network logging started
[ 7.362493] Uniform Multi-Platform E-IDE driver
[ 7.374012] Clocksource tsc unstable (delta = 4398046201563 ns)
[ 7.385995] ide-gd driver 1.18
[ 7.397783] Driver 'sd' needs updating - please use bus_type methods
[ 7.409429] ahci 0000:00:1f.2: PCI INT B -> GSI 16 (level, low) -> IRQ 16
[ 7.421866] ahci 0000:00:1f.2: AHCI 0001.0100 32 slots 4 ports 1.5 Gbps 0x1 impl SATA mode
[ 7.433498] ahci 0000:00:1f.2: flags: 64bit ncq pm led clo pio slum part
[ 7.445353] scsi0 : ahci
[ 7.457190] scsi1 : ahci
[ 7.468712] scsi2 : ahci
[ 7.480053] scsi3 : ahci
[ 7.491305] ata1: SATA max UDMA/133 irq_stat 0x00400040, connection status changed irq 30
[ 7.502678] ata2: DUMMY
[ 7.513887] ata3: DUMMY
[ 7.524929] ata4: DUMMY
[ 8.258039] ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 8.270201] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 8.283014] ata1.00: ATA-8: OCZ CORE_SSD, 02.10104, max UDMA/100
[ 8.293883] ata1.00: 250445824 sectors, multi 0: LBA
[ 8.306462] ata1.00: ACPI cmd f5/00:00:00:00:00:a0 filtered out
[ 8.318135] ata1.00: configured for UDMA/100
[ 8.340808] ata1.00: configured for UDMA/100
[ 8.351452] ata1: EH complete
[ 8.372418] scsi 0:0:0:0: Direct-Access ATA OCZ CORE_SSD 02.1 PQ: 0 ANSI: 5
[ 8.384003] sd 0:0:0:0: [sda] 250445824 512-byte hardware sectors: (128 GB/119 GiB)
[ 8.395000] sd 0:0:0:0: [sda] Write Protect is off
[ 8.405874] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 8.417391] sd 0:0:0:0: [sda] 250445824 512-byte hardware sectors: (128 GB/119 GiB)
[ 8.428447] sd 0:0:0:0: [sda] Write Protect is off
[ 8.439419] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 8.450595] sda: sda1 sda2 sda3 < sda5 sda6 sda7 sda8 > sda4
[ 10.021574] sd 0:0:0:0: [sda] Attached SCSI disk
[ 10.033061] ata_piix 0000:00:1f.1: PCI INT C -> GSI 16 (level, low) -> IRQ 16
[ 10.044600] scsi4 : ata_piix
[ 10.056022] scsi5 : ata_piix
[ 10.068240] ata5: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x1880 irq 14
[ 10.079591] ata6: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x1888 irq 15
[ 10.260425] ata5.00: ATAPI: HL-DT-ST DVDRAM GSA-4083N, 1.08, max UDMA/33
[ 10.277297] ata5.00: configured for UDMA/33
[ 10.289780] isa bounce pool size: 16 pages
[ 10.304394] scsi 4:0:0:0: CD-ROM HL-DT-ST DVDRAM GSA-4083N 1.08 PQ: 0 ANSI: 5
[ 10.316835] ieee1394: raw1394: /dev/raw1394 device initialized
[ 10.328533] yenta_cardbus 0000:15:00.0: CardBus bridge found [17aa:2012]
[ 10.340170] yenta_cardbus 0000:15:00.0: Using INTVAL to route CSC interrupts to PCI
[ 10.351746] yenta_cardbus 0000:15:00.0: Routing CardBus interrupts to PCI
[ 10.363258] yenta_cardbus 0000:15:00.0: TI: mfunc 0x01d01002, devctl 0x64
[ 10.598604] yenta_cardbus 0000:15:00.0: ISA IRQ mask 0x0cf8, PCI irq 16
[ 10.609972] yenta_cardbus 0000:15:00.0: Socket status: 30000007
[ 10.621295] yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge I/O window: 0xa000 - 0xdfff
[ 10.632680] yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge Memory window: 0xe4300000 - 0xe7ffffff
[ 10.644160] yenta_cardbus 0000:15:00.0: pcmcia: parent PCI bridge Memory window: 0xe0000000 - 0xe3ffffff
[ 10.906216] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 10.918419] ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
[ 10.930116] ehci_hcd 0000:00:1d.7: PCI INT D -> GSI 19 (level, low) -> IRQ 19
[ 10.941898] ehci_hcd 0000:00:1d.7: EHCI Host Controller
[ 10.954355] ehci_hcd 0000:00:1d.7: new USB bus registered, assigned bus number 1
[ 10.969964] ehci_hcd 0000:00:1d.7: debug port 1
[ 10.981462] ehci_hcd 0000:00:1d.7: irq 19, io mem 0xee404000
[ 11.002025] ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[ 11.013731] usb usb1: configuration #1 chosen from 1 choice
[ 11.026139] hub 1-0:1.0: USB hub found
[ 11.037478] hub 1-0:1.0: 8 ports detected
[ 11.049406] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 11.060725] uhci_hcd: USB Universal Host Controller Interface driver
[ 11.072515] uhci_hcd 0000:00:1d.0: power state changed by ACPI to D0
[ 11.083674] uhci_hcd 0000:00:1d.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 11.094831] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[ 11.106149] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
[ 11.117662] uhci_hcd 0000:00:1d.0: irq 16, io base 0x00001800
[ 11.129419] usb usb2: configuration #1 chosen from 1 choice
[ 11.140976] hub 2-0:1.0: USB hub found
[ 11.152316] hub 2-0:1.0: 2 ports detected
[ 11.164103] uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[ 11.175805] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[ 11.187507] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
[ 11.199167] uhci_hcd 0000:00:1d.1: irq 17, io base 0x00001820
[ 11.210954] usb usb3: configuration #1 chosen from 1 choice
[ 11.222638] hub 3-0:1.0: USB hub found
[ 11.234117] hub 3-0:1.0: 2 ports detected
[ 11.246413] uhci_hcd 0000:00:1d.2: power state changed by ACPI to D0
[ 11.258129] uhci_hcd 0000:00:1d.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[ 11.269956] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[ 11.281716] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 4
[ 11.293340] uhci_hcd 0000:00:1d.2: irq 18, io base 0x00001840
[ 11.305151] usb usb4: configuration #1 chosen from 1 choice
[ 11.316743] hub 4-0:1.0: USB hub found
[ 11.328062] hub 4-0:1.0: 2 ports detected
[ 11.339542] uhci_hcd 0000:00:1d.3: PCI INT D -> GSI 19 (level, low) -> IRQ 19
[ 11.350890] uhci_hcd 0000:00:1d.3: UHCI Host Controller
[ 11.362116] uhci_hcd 0000:00:1d.3: new USB bus registered, assigned bus number 5
[ 11.373412] uhci_hcd 0000:00:1d.3: irq 19, io base 0x00001860
[ 11.384669] usb usb5: configuration #1 chosen from 1 choice
[ 11.395751] hub 5-0:1.0: USB hub found
[ 11.406792] hub 5-0:1.0: 2 ports detected
[ 11.418057] Initializing USB Mass Storage driver...
[ 11.429238] usbcore: registered new interface driver usb-storage
[ 11.440292] USB Mass Storage support registered.
[ 11.451486] PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 11.472221] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 11.483405] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 11.494603] mice: PS/2 mouse device common for all mice
[ 11.519845] input: PC Speaker as /class/input/input4
[ 11.530943] input: AT Translated Set 2 keyboard as /class/input/input5
[ 11.546429] i2c /dev entries driver
[ 11.557470] i801_smbus 0000:00:1f.3: PCI INT A -> GSI 23 (level, low) -> IRQ 23
[ 11.569648] Bluetooth: HCI UART driver ver 2.2
[ 11.580769] Bluetooth: HCI H4 protocol initialized
[ 11.580772] Bluetooth: HCI BCSP protocol initialized
[ 11.580773] Bluetooth: HCILL protocol initialized
[ 11.580775] Bluetooth: Broadcom Blutonium firmware driver ver 1.2
[ 11.580855] usbcore: registered new interface driver bcm203x
[ 11.580859] Bluetooth: Generic Bluetooth USB driver ver 0.4
[ 11.580939] usbcore: registered new interface driver btusb
[ 11.658013] cpuidle: using governor ladder
[ 11.670304] cpuidle: using governor menu
[ 11.683287] usbcore: registered new interface driver usbhid
[ 11.694460] usbhid: v2.6:USB HID core driver
[ 11.706407] thinkpad_acpi: ThinkPad ACPI Extras v0.21
[ 11.717656] thinkpad_acpi: http://ibm-acpi.sf.net/
[ 11.728903] thinkpad_acpi: ThinkPad BIOS 79ETD6WW (2.16 ), EC 79HT50WW-1.07
[ 11.740350] thinkpad_acpi: Lenovo ThinkPad T60, model 2007ZE1
[ 11.752922] thinkpad_acpi: radio switch found; radios are enabled
[ 11.763958] thinkpad_acpi: This ThinkPad has standard ACPI backlight brightness control, supported by the ACPI video driver
[ 11.775207] thinkpad_acpi: Disabling thinkpad-acpi brightness events by default...
[ 11.790090] usb 5-1: new full speed USB device using uhci_hcd and address 2
[ 11.809717] Registered led device: tpacpi::thinklight
[ 11.821244] Registered led device: tpacpi::power
[ 11.832596] Registered led device: tpacpi:orange:batt
[ 11.844320] Registered led device: tpacpi:green:batt
[ 11.855846] Registered led device: tpacpi::dock_active
[ 11.867356] Registered led device: tpacpi::bay_active
[ 11.878543] Registered led device: tpacpi::dock_batt
[ 11.889621] Registered led device: tpacpi::unknown_led
[ 11.900607] Registered led device: tpacpi::standby
[ 11.914399] thinkpad_acpi: Standard ACPI backlight interface available, not loading native one.
[ 11.925778] input: ThinkPad Extra Buttons as /class/input/input6
[ 11.945627] oprofile: using NMI interrupt.
[ 11.956536] Netfilter messages via NETLINK v0.30.
[ 11.967388] nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
[ 11.978739] CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use
[ 11.989847] nf_conntrack.acct=1 kernel paramater, acct=1 nf_conntrack module option or
[ 12.001112] sysctl net.netfilter.nf_conntrack_acct=1 to enable it.
[ 12.012808] ctnetlink v0.93: registering with nfnetlink.
[ 12.025980] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 12.037353] arp_tables: (C) 2002 David S. Miller
[ 12.048770] TCP cubic registered
[ 12.060746] NET: Registered protocol family 10
[ 12.076357] ip6_tables: (C) 2000-2006 Netfilter Core Team
[ 12.087700] IPv6 over IPv4 tunneling driver
[ 12.100658] usb 5-1: configuration #1 chosen from 1 choice
[ 12.100778] NET: Registered protocol family 17
[ 12.100820] Bluetooth: L2CAP ver 2.11
[ 12.100822] Bluetooth: L2CAP socket layer initialized
[ 12.100826] Bluetooth: SCO (Voice Link) ver 0.6
[ 12.100828] Bluetooth: SCO socket layer initialized
[ 12.100877] Bluetooth: RFCOMM socket layer initialized
[ 12.100888] Bluetooth: RFCOMM TTY layer initialized
[ 12.100889] Bluetooth: RFCOMM ver 1.10
[ 12.100890] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 12.100892] Bluetooth: BNEP filters: protocol multicast
[ 12.100894] Bluetooth: HIDP (Human Interface Emulation) ver 1.2
[ 12.340121]
[ 12.340122] =============================================
[ 12.341044] [ INFO: possible recursive locking detected ]
[ 12.341044] 2.6.29-rc1-00041-gacd1e11 #143
[ 12.341044] ---------------------------------------------
[ 12.341044] events/0/9 is trying to acquire lock:
[ 12.341044] (events){--..}, at: [<ffffffff80254783>] flush_work+0x33/0x100
[ 12.341044]
[ 12.341044] but task is already holding lock:
[ 12.341044] (events){--..}, at: [<ffffffff80253ef7>] run_workqueue+0x107/0x230
[ 12.341044]
[ 12.341044] other info that might help us debug this:
[ 12.341044] 3 locks held by events/0/9:
[ 12.341044] #0: (events){--..}, at: [<ffffffff80253ef7>] run_workqueue+0x107/0x230
[ 12.341044] #1: ((dbs_work).work){--..}, at: [<ffffffff80253ef7>] run_workqueue+0x107/0x230
[ 12.341044] #2: (dbs_mutex){--..}, at: [<ffffffff805692f5>] do_dbs_timer+0x25/0x250
[ 12.341044]
[ 12.341044] stack backtrace:
[ 12.341044] Pid: 9, comm: events/0 Not tainted 2.6.29-rc1-00041-gacd1e11 #143
[ 12.341044] Call Trace:
[ 12.341044] [<ffffffff80269e69>] validate_chain+0xb69/0x1200
[ 12.341044] [<ffffffff8026a93e>] __lock_acquire+0x43e/0xa50
[ 12.341044] [<ffffffff8026afa8>] lock_acquire+0x58/0x80
[ 12.341044] [<ffffffff80254783>] ? flush_work+0x33/0x100
[ 12.341044] [<ffffffff802547a8>] flush_work+0x58/0x100
[ 12.341044] [<ffffffff80254783>] ? flush_work+0x33/0x100
[ 12.341044] [<ffffffff80268b7d>] ? trace_hardirqs_on+0xd/0x10
[ 12.341044] [<ffffffff80254a3c>] ? __queue_work+0x3c/0x50
[ 12.341044] [<ffffffff80254ad4>] ? queue_work_on+0x44/0x60
[ 12.341044] [<ffffffff8021bd20>] ? do_drv_write+0x0/0x60
[ 12.341044] [<ffffffff8021bd20>] ? do_drv_write+0x0/0x60
[ 12.341044] [<ffffffff80254ba3>] work_on_cpu+0x93/0xc0
[ 12.341044] [<ffffffff80253cc0>] ? do_work_for_cpu+0x0/0x20
[ 12.341044] [<ffffffff8021bd20>] ? do_drv_write+0x0/0x60
[ 12.341044] [<ffffffff8025cba1>] ? srcu_notifier_call_chain+0x11/0x20
[ 12.341044] [<ffffffff8021c5c9>] acpi_cpufreq_target+0x239/0x350
[ 12.341044] [<ffffffff80268af2>] ? trace_hardirqs_on_caller+0x112/0x190
[ 12.341044] [<ffffffff80699ac8>] ? mutex_lock_nested+0x228/0x2f0
[ 12.341044] [<ffffffff80565731>] __cpufreq_driver_target+0x81/0x90
[ 12.341044] [<ffffffff8056940e>] do_dbs_timer+0x13e/0x250
[ 12.341044] [<ffffffff805692d0>] ? do_dbs_timer+0x0/0x250
[ 12.341044] [<ffffffff80253f49>] run_workqueue+0x159/0x230
[ 12.341044] [<ffffffff80253ef7>] ? run_workqueue+0x107/0x230
[ 12.341044] [<ffffffff80254d1f>] worker_thread+0xbf/0x120
[ 12.341044] [<ffffffff80258550>] ? autoremove_wake_function+0x0/0x40
[ 12.341044] [<ffffffff80254c60>] ? worker_thread+0x0/0x120
[ 12.341044] [<ffffffff8025811d>] kthread+0x4d/0x80
[ 12.341044] [<ffffffff8020c87a>] child_rip+0xa/0x20
[ 12.341044] [<ffffffff8020c27c>] ? restore_args+0x0/0x30
[ 12.341044] [<ffffffff802580d0>] ? kthread+0x0/0x80
[ 12.341044] [<ffffffff8020c870>] ? child_rip+0x0/0x20
[ 12.867818] usb 5-2: new full speed USB device using uhci_hcd and address 3
[ 12.867878] Synaptics claims to have extended capabilities, but I'm not ableto read them.<6>Synaptics Touchpad, model: 1, fw: 6.2, id: 0x81a0b1, caps: 0xa04793/0x0
[ 12.929049] serio: Synaptics pass-through port at isa0060/serio1/input0
[ 12.984978] input: SynPS/2 Synaptics TouchPad as /class/input/input7
[ 13.051634] usb 5-2: configuration #1 chosen from 1 choice
[ 18.671935] IBM TrackPoint firmware: 0x0e, buttons: 3/3
[ 18.919622] input: TPPS/2 IBM TrackPoint as /class/input/input8
[ 19.032728] kjournald starting. Commit interval 5 seconds
[ 19.032753] EXT3-fs: mounted filesystem with journal data mode.
[ 19.032764] VFS: Mounted root (ext3 filesystem) readonly on device 8:5.
[ 19.032783] Freeing unused kernel memory: 412k freed
[ 19.032995] Write protecting the kernel read-only data: 6400k
[ 22.867059] eth0: no IPv6 routers present

Attachments:

kernelconfig2 (59.20 kB)
kerneloutput2 (52.25 kB)
signature.asc (260.00 B)
OpenPGP digital signature Download all attachments

2009-01-12 17:22:42

by Rafael J. Wysocki

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot and fails to resume

On Monday 12 January 2009, Ingo Molnar wrote:
>
> * Maciej Rutecki <[email protected]> wrote:
>
> > 2009/1/11 Dieter Ries <[email protected]>:
> > > Hi,
> > >
> > > Ingo Molnar schrieb:
> > >>>> * Dieter Ries <[email protected]> wrote:
> > >>>>
> > >>>>> Hi,
> > >>>>>
> > >>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
> > >>>>> When I try to boot it, that kind of works until init should start. Then
> > >>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
> > >>>>> sometimes gets me a bash without the prompt flashing.
> > >>>>>
> >
> > Simmilar issue, described:
> > http://lkml.indiana.edu/hypermail/linux/kernel/0901.1/01701.html
> >
> > [...]
> > ####################################################################
> > > 7503bfbae89eba07b46441a5d1594647f6b8ab7d is first bad commit
> > > commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d
> > > Author: Mike Travis <[email protected]>
> > > Date: Sun Jan 4 05:18:09 2009 -0800
> > >
> > > cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write
> > >
> > > Impact: use new cpumask API to reduce stack usage
> > >
> > > Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr()
> > > with a work_on_cpu function for drv_read() and drv_write().
> > >
> > > Basically converts do_drv_{read,write} into "work_on_cpu" functions that
> > > are now called by drv_read and drv_write.
> > >
> > > Signed-off-by: Mike Travis <[email protected]>
> > > Acked-by: Rusty Russell <[email protected]>
> > > Signed-off-by: Ingo Molnar <[email protected]>
> >
> > Revert this commit also solves problem on my laptoop.
>
> yes - the revert patch can be found below.

Just for the record, apart from the boot problems the commit the patch below
reverts is also causing a suspend-resume regression for people.

Thanks,
Rafael

> ------------------->
> From e0b7a3bea054249b27ca3c843bf6eefcb509d1c2 Mon Sep 17 00:00:00 2001
> From: Ingo Molnar <[email protected]>
> Date: Mon, 12 Jan 2009 10:49:53 +0100
> Subject: [PATCH] Revert "cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write"
>
> This reverts commit 7503bfbae89eba07b46441a5d1594647f6b8ab7d.
>
> Dieter Ries reported bootup soft-hangs and bisected it back to
> this commit, and reverting this commit gave him a working system.
>
> The commit introduces work_on_cpu() use into the cpufreq code,
> but that is subtly problematic from a lock hierarchy POV: the
> hotplug-cpu lock is an highlevel lock that is taken before
> lowlevel locks, and in this codepath we are called with the
> policy lock taken.
>
> Dieter did not have lockdep enabled so we dont have a nice stack
> trace proof for this, but using work_on_cpu() in such a lowlevel
> place certainly looks wrong, so we revert the patch.
>
> work_on_cpu() needs to be reworked to be more generally usable.
>
> Reported-by: Dieter Ries <[email protected]>
> Tested-by: Dieter Ries <[email protected]>
> Signed-off-by: Ingo Molnar <[email protected]>
> ---
> arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c | 25 ++++++++++++-------------
> 1 files changed, 12 insertions(+), 13 deletions(-)
>
> diff --git a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
> index 06fcd8f..6f11e02 100644
> --- a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
> +++ b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
> @@ -150,9 +150,8 @@ struct drv_cmd {
> u32 val;
> };
>
> -static long do_drv_read(void *_cmd)
> +static void do_drv_read(struct drv_cmd *cmd)
> {
> - struct drv_cmd *cmd = _cmd;
> u32 h;
>
> switch (cmd->type) {
> @@ -167,12 +166,10 @@ static long do_drv_read(void *_cmd)
> default:
> break;
> }
> - return 0;
> }
>
> -static long do_drv_write(void *_cmd)
> +static void do_drv_write(struct drv_cmd *cmd)
> {
> - struct drv_cmd *cmd = _cmd;
> u32 lo, hi;
>
> switch (cmd->type) {
> @@ -189,23 +186,30 @@ static long do_drv_write(void *_cmd)
> default:
> break;
> }
> - return 0;
> }
>
> static void drv_read(struct drv_cmd *cmd)
> {
> + cpumask_t saved_mask = current->cpus_allowed;
> cmd->val = 0;
>
> - work_on_cpu(cpumask_any(cmd->mask), do_drv_read, cmd);
> + set_cpus_allowed_ptr(current, cmd->mask);
> + do_drv_read(cmd);
> + set_cpus_allowed_ptr(current, &saved_mask);
> }
>
> static void drv_write(struct drv_cmd *cmd)
> {
> + cpumask_t saved_mask = current->cpus_allowed;
> unsigned int i;
>
> for_each_cpu(i, cmd->mask) {
> - work_on_cpu(i, do_drv_write, cmd);
> + set_cpus_allowed_ptr(current, cpumask_of(i));
> + do_drv_write(cmd);
> }
> +
> + set_cpus_allowed_ptr(current, &saved_mask);
> + return;
> }
>
> static u32 get_cur_val(const struct cpumask *mask)
> @@ -231,15 +235,10 @@ static u32 get_cur_val(const struct cpumask *mask)
> return 0;
> }
>
> - if (unlikely(!alloc_cpumask_var(&cmd.mask, GFP_KERNEL)))
> - return 0;
> -
> cpumask_copy(cmd.mask, mask);
>
> drv_read(&cmd);
>
> - free_cpumask_var(cmd.mask);
> -
> dprintk("get_cur_val = %u\n", cmd.val);
>
> return cmd.val;
> --

2009-01-12 17:53:20

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Ingo Molnar wrote:
> * Mike Travis <[email protected]> wrote:
...
>> Rusty - any ideas on how to avoid these clashes with the
>> get_online_cpus() call in work_on_cpu()? Or something else to indicate
>> to lockdep that the circular lock dependency is ok (as you mentioned
>> before)?
>
> I've queued up the revert below, please check the commit message whether
> you agree with the analysis.
>
> Mike, could you also check any other patches where you add work_on_cpu()
> usage to make sure we dont have similar mishaps? work_on_cpu() seems
> completely unsuited for any sort of set_cpus_allowed() replacement ...
>
> Ingo

Yes, I'll do that now. With the resume feature also calling these functions,
I'm even less comfortable with it.

Shall I resurrect the 2nd cpumask in the task struct from my original patches,
(and one that akpm also suggested more than a year ago)?

Basically, it looks like this:

--- linux-2.6-for-ingo.orig/include/linux/sched.h 2009-01-11 10:43:19.000000000 -0800
+++ linux-2.6-for-ingo/include/linux/sched.h 2009-01-12 09:45:02.871247038 -0800
@@ -1132,6 +1132,7 @@ struct task_struct {

unsigned int policy;
cpumask_t cpus_allowed;
+ cpumask_t save_cpus_allowed;

--- linux-2.6-for-ingo.orig/arch/x86/kernel/microcode_core.c 2009-01-12 09:05:36.000000000 -0800
+++ linux-2.6-for-ingo/arch/x86/kernel/microcode_core.c 2009-01-12 09:49:19.315276144 -0800
@@ -110,11 +110,10 @@ EXPORT_SYMBOL_GPL(ucode_cpu_info);
#ifdef CONFIG_MICROCODE_OLD_INTERFACE
static int do_microcode_update(const void __user *buf, size_t size)
{
- cpumask_t old;
int error = 0;
int cpu;

- old = current->cpus_allowed;
+ cpumask_copy(&current->save_cpus_allowed, &current->cpus_allowed);

for_each_online_cpu(cpu) {
struct ucode_cpu_info *uci = ucode_cpu_info + cpu;
@@ -122,7 +121,7 @@ static int do_microcode_update(const voi
if (!uci->valid)
continue;

- set_cpus_allowed_ptr(current, &cpumask_of_cpu(cpu));
+ set_cpus_allowed_ptr(current, cpumask_of(cpu));
error = microcode_ops->request_microcode_user(cpu, buf, size);
if (error < 0)
goto out;
@@ -130,7 +129,7 @@ static int do_microcode_update(const voi
microcode_ops->apply_microcode(cpu);
}
out:
- set_cpus_allowed_ptr(current, &old);
+ set_cpus_allowed_ptr(current, &current->save_cpus_allowed);
return error;
}

The primary concern is that there is only one temp, so I had also put in a warning
if it was already in use. But the scope of where it's used is very short-lived,
so I don't know if a preempt_disable() is required, but it seems the safe thing
to do.

THanks,
MIke

2009-01-12 18:56:19

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Mike Travis <[email protected]> wrote:

> Ingo Molnar wrote:
> > * Mike Travis <[email protected]> wrote:
> ...
> >> Rusty - any ideas on how to avoid these clashes with the
> >> get_online_cpus() call in work_on_cpu()? Or something else to indicate
> >> to lockdep that the circular lock dependency is ok (as you mentioned
> >> before)?
> >
> > I've queued up the revert below, please check the commit message whether
> > you agree with the analysis.
> >
> > Mike, could you also check any other patches where you add work_on_cpu()
> > usage to make sure we dont have similar mishaps? work_on_cpu() seems
> > completely unsuited for any sort of set_cpus_allowed() replacement ...
> >
> > Ingo
>
> Yes, I'll do that now. With the resume feature also calling these functions,
> I'm even less comfortable with it.
>
> Shall I resurrect the 2nd cpumask in the task struct from my original patches,
> (and one that akpm also suggested more than a year ago)?
>
> Basically, it looks like this:
>
> --- linux-2.6-for-ingo.orig/include/linux/sched.h 2009-01-11 10:43:19.000000000 -0800
> +++ linux-2.6-for-ingo/include/linux/sched.h 2009-01-12 09:45:02.871247038 -0800
> @@ -1132,6 +1132,7 @@ struct task_struct {
>
> unsigned int policy;
> cpumask_t cpus_allowed;
> + cpumask_t save_cpus_allowed;
>
> --- linux-2.6-for-ingo.orig/arch/x86/kernel/microcode_core.c 2009-01-12 09:05:36.000000000 -0800
> +++ linux-2.6-for-ingo/arch/x86/kernel/microcode_core.c 2009-01-12 09:49:19.315276144 -0800
> @@ -110,11 +110,10 @@ EXPORT_SYMBOL_GPL(ucode_cpu_info);
> #ifdef CONFIG_MICROCODE_OLD_INTERFACE
> static int do_microcode_update(const void __user *buf, size_t size)
> {
> - cpumask_t old;
> int error = 0;
> int cpu;
>
> - old = current->cpus_allowed;
> + cpumask_copy(&current->save_cpus_allowed, &current->cpus_allowed);
>
> for_each_online_cpu(cpu) {
> struct ucode_cpu_info *uci = ucode_cpu_info + cpu;
> @@ -122,7 +121,7 @@ static int do_microcode_update(const voi
> if (!uci->valid)
> continue;
>
> - set_cpus_allowed_ptr(current, &cpumask_of_cpu(cpu));
> + set_cpus_allowed_ptr(current, cpumask_of(cpu));
> error = microcode_ops->request_microcode_user(cpu, buf, size);
> if (error < 0)
> goto out;
> @@ -130,7 +129,7 @@ static int do_microcode_update(const voi
> microcode_ops->apply_microcode(cpu);
> }
> out:
> - set_cpus_allowed_ptr(current, &old);
> + set_cpus_allowed_ptr(current, &current->save_cpus_allowed);
> return error;
> }
>
> The primary concern is that there is only one temp, so I had also put in
> a warning if it was already in use. But the scope of where it's used is
> very short-lived, so I don't know if a preempt_disable() is required,
> but it seems the safe thing to do.

that's rather fragile. Fix work_on_cpu() instead? Why does it need to take
the CPU-hotplug lock?

Ingo

2009-01-12 19:00:22

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Dieter Ries <[email protected]> wrote:

> Hi,
>
> Ingo Molnar schrieb:
> >
> > So you did get stacktraces? You might want to boot with
> > CONFIG_PROVE_LOCKING=y, that could also catch and report the lockup
> > scenario.
>
> This is what I have got:
>
> [ 12.340122] =============================================
> [ 12.341044] [ INFO: possible recursive locking detected ]
> [ 12.341044] 2.6.29-rc1-00041-gacd1e11 #143
> [ 12.341044] ---------------------------------------------
> [ 12.341044] events/0/9 is trying to acquire lock:
> [ 12.341044] (events){--..}, at: [<ffffffff80254783>]
> flush_work+0x33/0x100
> [ 12.341044]
>
> [ 12.341044] but task is already holding lock:
>
> [ 12.341044] (events){--..}, at: [<ffffffff80253ef7>]
> run_workqueue+0x107/0x230
>
> [ 12.341044]
>
> [ 12.341044] other info that might help us debug this:
>
> [ 12.341044] 3 locks held by events/0/9:
>
> [ 12.341044] #0: (events){--..}, at: [<ffffffff80253ef7>]
> run_workqueue+0x107/0x230
>
> [ 12.341044] #1: ((dbs_work).work){--..}, at: [<ffffffff80253ef7>]
> run_workqueue+0x107/0x230
>
> [ 12.341044] #2: (dbs_mutex){--..}, at: [<ffffffff805692f5>]
> do_dbs_timer+0x25/0x250
>
> [ 12.341044]
>
> [ 12.341044] stack backtrace:
>
> [ 12.341044] Pid: 9, comm: events/0 Not tainted
> 2.6.29-rc1-00041-gacd1e11 #143
> [ 12.341044] Call Trace:
>
> [ 12.341044] [<ffffffff80269e69>] validate_chain+0xb69/0x1200
>
> [ 12.341044] [<ffffffff8026a93e>] __lock_acquire+0x43e/0xa50
>
> [ 12.341044] [<ffffffff8026afa8>] lock_acquire+0x58/0x80
>
> [ 12.341044] [<ffffffff80254783>] ? flush_work+0x33/0x100
>
> [ 12.341044] [<ffffffff802547a8>] flush_work+0x58/0x100
>
> [ 12.341044] [<ffffffff80254783>] ? flush_work+0x33/0x100
>
> [ 12.341044] [<ffffffff80268b7d>] ? trace_hardirqs_on+0xd/0x10
>
> [ 12.341044] [<ffffffff80254a3c>] ? __queue_work+0x3c/0x50
>
> [ 12.341044] [<ffffffff80254ad4>] ? queue_work_on+0x44/0x60
>
> [ 12.341044] [<ffffffff8021bd20>] ? do_drv_write+0x0/0x60
>
> [ 12.341044] [<ffffffff8021bd20>] ? do_drv_write+0x0/0x60
>
> [ 12.341044] [<ffffffff80254ba3>] work_on_cpu+0x93/0xc0
>
> [ 12.341044] [<ffffffff80253cc0>] ? do_work_for_cpu+0x0/0x20
>
> [ 12.341044] [<ffffffff8021bd20>] ? do_drv_write+0x0/0x60
>
> [ 12.341044] [<ffffffff8025cba1>] ?
> srcu_notifier_call_chain+0x11/0x20
> [ 12.341044] [<ffffffff8021c5c9>] acpi_cpufreq_target+0x239/0x350
>
> [ 12.341044] [<ffffffff80268af2>] ?
> trace_hardirqs_on_caller+0x112/0x190
> [ 12.341044] [<ffffffff80699ac8>] ? mutex_lock_nested+0x228/0x2f0
>
> [ 12.341044] [<ffffffff80565731>] __cpufreq_driver_target+0x81/0x90
>
> [ 12.341044] [<ffffffff8056940e>] do_dbs_timer+0x13e/0x250
>
> [ 12.341044] [<ffffffff805692d0>] ? do_dbs_timer+0x0/0x250
>
> [ 12.341044] [<ffffffff80253f49>] run_workqueue+0x159/0x230
>
> [ 12.341044] [<ffffffff80253ef7>] ? run_workqueue+0x107/0x230
>
> [ 12.341044] [<ffffffff80254d1f>] worker_thread+0xbf/0x120
>
> [ 12.341044] [<ffffffff80258550>] ? autoremove_wake_function+0x0/0x40
>
> [ 12.341044] [<ffffffff80254c60>] ? worker_thread+0x0/0x120
>
> [ 12.341044] [<ffffffff8025811d>] kthread+0x4d/0x80
>
> [ 12.341044] [<ffffffff8020c87a>] child_rip+0xa/0x20
>
> [ 12.341044] [<ffffffff8020c27c>] ? restore_args+0x0/0x30
> [ 12.341044] [<ffffffff802580d0>] ? kthread+0x0/0x80
> [ 12.341044] [<ffffffff8020c870>] ? child_rip+0x0/0x20
>
>
> complete log and config are attached.
>
> The different git hash is because I reverted that revert patch. It is
> exactly the same like the kernel on which I first found the problem,
> only with some debugging enabled now. Maybe I should make more use of
> gits capabilities...
>
> Hope that helps,

thanks, it helps!

the problem isnt even the hotplug lock, but that work_on_cpu() uses the
normal generic kevent workqueue - which workqueue can already contain
items related to the cpufreq code hence it's not safe to call it with any
cpufreq mutex held.

so Mike, i think we could solve this by work_on_cpu() getting its own
workqueue?

Ingo

2009-01-13 04:46:19

by Michal Jaegermann

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

On Mon, Jan 12, 2009 at 07:59:54PM +0100, Ingo Molnar wrote:
> * Dieter Ries <[email protected]> wrote:
>
> >
> > This is what I have got:
> >
> > [ 12.340122] =============================================
> > [ 12.341044] [ INFO: possible recursive locking detected ]
> > [ 12.341044] 2.6.29-rc1-00041-gacd1e11 #143
> > [ 12.341044] ---------------------------------------------
> > [ 12.341044] events/0/9 is trying to acquire lock:
> > [ 12.341044] (events){--..}, at: [<ffffffff80254783>]
....
> > Hope that helps,
>
> thanks, it helps!

I bumped into something pretty similar, although not precisely the
same, with 2.6.29-0.28.rc1.fc11.x86_64 Fedora rawhide kernel.

=============================================
[ INFO: possible recursive locking detected ]
2.6.29-0.28.rc1.fc11.x86_64 #1
---------------------------------------------
events/0/6 is trying to acquire lock:
(events){--..}, at: [<ffffffff8105b843>] flush_workqueue+0x0/0xa4

but task is already holding lock:
(events){--..}, at: [<ffffffff8105ae26>] run_workqueue+0xb1/0x20a

It appears that this during an initialization of AC97 sound system.
What I got is at https://bugzilla.redhat.com/show_bug.cgi?id=479778
and close to the bottom of
https://bugzilla.redhat.com/attachment.cgi?id=328808

It is a throw of a dice if this kernel will boot or not.

Michal

2009-01-14 01:16:20

by Rusty Russell

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

On Monday 12 January 2009 21:56:08 Ingo Molnar wrote:
> work_on_cpu() needs to be reworked to be more generally usable.

Yes, but how? If we don't take the hotplug lock, we are relying on the
callers to "prove" the cpu can't go away. But we've already shown that
we can't find this by inspection :(

> The commit introduces work_on_cpu() use into the cpufreq code,
> but that is subtly problematic from a lock hierarchy POV: the
> hotplug-cpu lock is an highlevel lock that is taken before
> lowlevel locks, and in this codepath we are called with the
> policy lock taken.

The easiest thing to do in this case is to use smp_call_function_single(),
since the thing we want to do is just rdmsr and wrmsr.

How about this instead of reverting?
Rusty.

fix: use smp_call_function_single() not work_on_cpu in acpi-cpufreq.c

get_measured_perf() gets called through twisty chains, and
work_on_cpu() has issues being called here as it takes the cpu hotplug
lock.

So we just use smp_call_function_single() which should work fine for
this case.

Signed-off-by: Rusty Russell <[email protected]>

diff --git a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
--- a/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
+++ b/arch/x86/kernel/cpu/cpufreq/acpi-cpufreq.c
@@ -255,7 +255,7 @@ struct perf_cur {
};

-static long read_measured_perf_ctrs(void *_cur)
+static void read_measured_perf_ctrs(void *_cur)
{
struct perf_cur *cur = _cur;

@@ -264,8 +264,6 @@ static long read_measured_perf_ctrs(void

wrmsr(MSR_IA32_APERF, 0, 0);
wrmsr(MSR_IA32_MPERF, 0, 0);
-
- return 0;
}

/*
@@ -288,7 +286,7 @@ static unsigned int get_measured_perf(st
unsigned int perf_percent;
unsigned int retval;

- if (!work_on_cpu(cpu, read_measured_perf_ctrs, &cur))
+ if (smp_call_function_single(cpu, read_measured_perf_ctrs, &cur, 1))
return 0;

#ifdef __i386__

2009-01-14 11:30:32

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Rusty Russell <[email protected]> wrote:

> On Monday 12 January 2009 21:56:08 Ingo Molnar wrote:
> > work_on_cpu() needs to be reworked to be more generally usable.
>
> Yes, but how? If we don't take the hotplug lock, we are relying on the
> callers to "prove" the cpu can't go away. But we've already shown that
> we can't find this by inspection :(

it appears the problem wasnt even the hotplug lock, but the fact that
work_on_cpu() uses the generic schedule_work() method, which goes into a
queue with all other keventsd worklets.

and keventd is used by other aspects of cpufreq as well -> creating
workqueue-driven lock inversion scenarios - see Dieter's lockdep dump
earlier in this thread. ( I'm amazed lockdep sees through that dependency
:-)

Ingo

2009-01-14 12:46:53

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Hi,

Rusty Russell schrieb:
> How about this instead of reverting?
> Rusty.
>
> fix: use smp_call_function_single() not work_on_cpu in acpi-cpufreq.c
>
> get_measured_perf() gets called through twisty chains, and
> work_on_cpu() has issues being called here as it takes the cpu hotplug
> lock.
>
> So we just use smp_call_function_single() which should work fine for
> this case.
>
> Signed-off-by: Rusty Russell <[email protected]>
>

I just applied that patch and tried it, but it does not work. The
stacktrace seems to be the same as before, but I cannot say it 100% for
sure, as I dont have my netconsole machine here.

I can send the trace in the late afternoon, when I am home.

cu

Dieter

2009-01-15 00:54:36

by Rusty Russell

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

On Monday 12 January 2009 20:30:53 Ingo Molnar wrote:
> work_on_cpu() seems
> completely unsuited for any sort of set_cpus_allowed() replacement ...

That's harsh. set_cpus_allowed is *always* questionable in these cases. Sometimes it's harmless, and sometimes there was a risk that we could run on the wrong cpu.

The mistake was that work_on_cpu() should rely on the caller to ensure the CPU doesn't go away. It's a worse interface, but this reduces the number of *new* bugs, at least.

Subject: cpumask: don't try to get_online_cpus() in work_on_cpu.

This has caused more problems than it solved, with a pile of cpu
hotplug locking issues.

Followup patches will get_online_cpus() in callers that need it, but
if they don't do it they're no worse than before when they were using
set_cpus_allowed without locking.

Signed-off-by: Rusty Russell <[email protected]>

diff --git a/kernel/workqueue.c b/kernel/workqueue.c
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -991,8 +991,7 @@ static void do_work_for_cpu(struct work_
* @fn: the function to run
* @arg: the function arg
*
- * This will return -EINVAL in the cpu is not online, or the return value
- * of @fn otherwise.
+ * It is up to the caller to ensure that the cpu doesn't go offline.
*/
long work_on_cpu(unsigned int cpu, long (*fn)(void *), void *arg)
{
@@ -1001,14 +1000,12 @@ long work_on_cpu(unsigned int cpu, long
INIT_WORK(&wfc.work, do_work_for_cpu);
wfc.fn = fn;
wfc.arg = arg;
- get_online_cpus();
if (unlikely(!cpu_online(cpu)))
wfc.ret = -EINVAL;
else {
schedule_work_on(cpu, &wfc.work);
flush_work(&wfc.work);
}
- put_online_cpus();

return wfc.ret;
}

2009-01-15 20:32:31

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

* Dieter Ries wrote:
> Hi,
>
> Ingo Molnar schrieb:
>>>> * Dieter Ries <[email protected]> wrote:
>>>>
>>>>> Hi,
>>>>>
>>>>> I just pulled 2.6.29-rc1, ran oldconfig with defaults and built it.
>>>>> When I try to boot it, that kind of works until init should start. Then
>>>>> nothing happens. I tried with init=/bin/bash, which sometimes works, and
>>>>> sometimes gets me a bash without the prompt flashing.
...

* Maciej Rutecki <[email protected]> wrote:
> Revert this commit also solves problem on my laptoop.

Hi Dieter and Maciej,

Can you try the attached patches on your system? It boots on my system fine
now, but wasn't there a problem with resume as well? (My test systems are
remote so suspending/resuming over the network is iffy.)

The patches apply to the latest tip/cpus4096 branch:

http://people.redhat.com/mingo/tip.git/README

(They may apply to linux-next as well, I'm not sure.)

Thanks!
Mike

========================
Subject: cpumask: don't try to get_online_cpus() in work_on_cpu.

From: Rusty Russell <[email protected]>

Impact: remove potential circular lock dependency with cpu hotplug lock

This has caused more problems than it solved, with a pile of cpu
hotplug locking issues.

Followup patches will get_online_cpus() in callers that need it, but
if they don't do it they're no worse than before when they were using
set_cpus_allowed without locking.
========================
Subject: work_on_cpu: Use our own workqueue.

From: Rusty Russell <[email protected]>

Impact: remove potential circular lock dependency with generic kevent workqueue

Annoyingly, some places we want to use work_on_cpu are already in
workqueues. As per Ingo's suggestion, we create a different workqueue
for work_on_cpu.

========================
Subject: cpumask: use work_on_cpu in acpi-cpufreq.c for drv_read and drv_write

Impact: use new work_on_cpu function to reduce stack usage

Replace the saving of current->cpus_allowed and set_cpus_allowed_ptr() with
a work_on_cpu function for drv_read() and drv_write().

Basically converts do_drv_{read,write} into "work_on_cpu" functions that
are now called by drv_read and drv_write.
========================

Attachments:

fix-work_on_cpu-in-acpi-cpufreq.tar.bz2 (2.14 kB)

2009-01-15 21:11:06

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Mike Travis schrieb:
> Hi Dieter and Maciej,

Hi Mike,

>
> Can you try the attached patches on your system? It boots on my system fine
> now, but wasn't there a problem with resume as well? (My test systems are
> remote so suspending/resuming over the network is iffy.)

I just tested it. The kernel does boot up, suspending to ram works
perfectly, hibernating did also work, but I found an inconsistent lock
state in dmesg afterwards. System is still fully functional

May or may not be related, I don't know.

But the original problem is solved by your patches. Thank you!

[ 97.475165] =================================
[ 97.475165] [ INFO: inconsistent lock state ]
[ 97.475165] 2.6.29-rc1-00256-g0f0f4af #147
[ 97.475165] ---------------------------------
[ 97.475165] inconsistent {in-hardirq-W} -> {hardirq-on-W} usage.
[ 97.475165] echo/5817 [HC0[0]:SC0[0]:HE1:SE1] takes:
[ 97.475165] (&cpu_base->lock){++..}, at: [<ffffffff8025b4fd>]
retrigger_next_event+0x7d/0xd0
[ 97.475165] {in-hardirq-W} state was registered at:
[ 97.475165] [<ffffffffffffffff>] 0xffffffffffffffff
[ 97.475165] irq event stamp: 88679
[ 97.475165] hardirqs last enabled at (88679): [<ffffffff8069be05>]
_spin_unlock_irqrestore+0x55/0x60
[ 97.475165] hardirqs last disabled at (88678): [<ffffffff8069bcac>]
_spin_lock_irqsave+0x1c/0x60
[ 97.475165] softirqs last enabled at (88466): [<ffffffff802478c2>]
__do_softirq+0x132/0x190
[ 97.475165] softirqs last disabled at (88461): [<ffffffff8020c97c>]
call_softirq+0x1c/0x40
[ 97.475165]
[ 97.475165] other info that might help us debug this:
[ 97.475165] 3 locks held by echo/5817:
[ 97.475165] #0: (&buffer->mutex){--..}, at: [<ffffffff8030dff3>]
sysfs_write_file+0x43/0x140
[ 97.475165] #1: (pm_mutex){--..}, at: [<ffffffff802755a5>]
enter_state+0x55/0x190
[ 97.475165] #2: (dpm_list_mtx){--..}, at: [<ffffffff80499212>]
device_pm_lock+0x12/0x20
[ 97.475165]
[ 97.475165] stack backtrace:
[ 97.475165] Pid: 5817, comm: echo Not tainted
2.6.29-rc1-00256-g0f0f4af #147
[ 97.475165] Call Trace:
[ 97.475165] [<ffffffff80266f86>] print_usage_bug+0x1a6/0x200
[ 97.475165] [<ffffffff80268647>] mark_lock+0xab7/0xe90
[ 97.475165] [<ffffffff8026ae8a>] __lock_acquire+0x80a/0xa50
[ 97.475165] [<ffffffff8026b128>] lock_acquire+0x58/0x80
[ 97.475165] [<ffffffff8025b4fd>] ? retrigger_next_event+0x7d/0xd0
[ 97.475165] [<ffffffff8069b8bc>] _spin_lock+0x2c/0x40
[ 97.475165] [<ffffffff8025b4fd>] ? retrigger_next_event+0x7d/0xd0
[ 97.475165] [<ffffffff8025b4fd>] retrigger_next_event+0x7d/0xd0
[ 97.475165] [<ffffffff8025b55b>] hres_timers_resume+0xb/0x10
[ 97.475165] [<ffffffff80260973>] timekeeping_resume+0xc3/0x100
[ 97.475165] [<ffffffff80493730>] __sysdev_resume+0x20/0x60
[ 97.475165] [<ffffffff804937ba>] sysdev_resume+0x4a/0x80
[ 97.475165] [<ffffffff80499db0>] device_power_up+0x10/0x20
[ 97.475165] [<ffffffff802754c8>] suspend_devices_and_enter+0x158/0x170
[ 97.475165] [<ffffffff802756a5>] enter_state+0x155/0x190
[ 97.475165] [<ffffffff8027578e>] state_store+0xae/0xe0
[ 97.475165] [<ffffffff804009e7>] kobj_attr_store+0x17/0x20
[ 97.475165] [<ffffffff8030e07e>] sysfs_write_file+0xce/0x140
[ 97.475165] [<ffffffff802bd4d7>] vfs_write+0xc7/0x170
[ 97.475165] [<ffffffff802bda90>] sys_write+0x50/0x90
[ 97.475165] [<ffffffff8020b81b>] system_call_fastpath+0x16/0x1b

>
> The patches apply to the latest tip/cpus4096 branch:
>
> http://people.redhat.com/mingo/tip.git/README

Thanks for that link. Could one of you hint me to some documentation
about what tip is? I searched a bit, but didn't find it.

>
> (They may apply to linux-next as well, I'm not sure.)
>
> Thanks!
> Mike
>

cu

Dieter

2009-01-15 21:48:28

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

2009/1/15 Dieter Ries <[email protected]>:
> Mike Travis schrieb:
>> Hi Dieter and Maciej,

>> Can you try the attached patches on your system? It boots on my system fine
>> now, but wasn't there a problem with resume as well? (My test systems are
>> remote so suspending/resuming over the network is iffy.)
>
> I just tested it. The kernel does boot up, suspending to ram works
> perfectly, hibernating did also work, but I found an inconsistent lock
> state in dmesg afterwards. System is still fully functional
>

Suspend to disk works OK (unlike latest 2.6.29-rc1-git5). But suspend
to ram still doesn't work: resume immediately and hangs.

--
Maciej Rutecki
http://www.maciek.unixy.pl

2009-01-15 21:54:43

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Dieter Ries wrote:
> Mike Travis schrieb:
>> Hi Dieter and Maciej,
>
> Hi Mike,
>
>> Can you try the attached patches on your system? It boots on my system fine
>> now, but wasn't there a problem with resume as well? (My test systems are
>> remote so suspending/resuming over the network is iffy.)
>
> I just tested it. The kernel does boot up, suspending to ram works
> perfectly, hibernating did also work, but I found an inconsistent lock
> state in dmesg afterwards. System is still fully functional
>
> May or may not be related, I don't know.

If it doesn't happen before my patch, then it's probably related.

>
> But the original problem is solved by your patches. Thank you!
>
...
>
>> The patches apply to the latest tip/cpus4096 branch:
>>
>> http://people.redhat.com/mingo/tip.git/README
>
> Thanks for that link. Could one of you hint me to some documentation
> about what tip is? I searched a bit, but didn't find it.

Ingo can probably explain it more fully, I just think of it as the
"tip of the iceberg" (that sank the Titanic... ;-)

>
>> (They may apply to linux-next as well, I'm not sure.)
>>
>> Thanks!
>> Mike
>>
>
> cu
>
> Dieter

2009-01-15 21:55:15

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Maciej Rutecki wrote:
> 2009/1/15 Dieter Ries <[email protected]>:
>> Mike Travis schrieb:
>>> Hi Dieter and Maciej,
>
>>> Can you try the attached patches on your system? It boots on my system fine
>>> now, but wasn't there a problem with resume as well? (My test systems are
>>> remote so suspending/resuming over the network is iffy.)
>> I just tested it. The kernel does boot up, suspending to ram works
>> perfectly, hibernating did also work, but I found an inconsistent lock
>> state in dmesg afterwards. System is still fully functional
>>
>
> Suspend to disk works OK (unlike latest 2.6.29-rc1-git5). But suspend
> to ram still doesn't work: resume immediately and hangs.
>
>

And it works ok without my patch? Drats! ;-)

I'll see if I can't figure out how to debug it here.

Thanks!
Mike

2009-01-15 23:05:00

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

2009/1/15 Mike Travis <[email protected]>:

>
> And it works ok without my patch? Drats! ;-)
>
> I'll see if I can't figure out how to debug it here.
>
> Thanks!
> Mike
>

To be clear:
2.6.29-rc1-git5:
s2disk: hang
s2ram: resume immediately and hangs

2.6.29-rc1-git5+ Your patches (3):
s2disk: works OK
s2ram: resume immediately and hangs
--
Maciej Rutecki
http://www.maciek.unixy.pl

2009-01-15 23:18:17

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Mike Travis schrieb:
> Dieter Ries wrote:
>> I just tested it. The kernel does boot up, suspending to ram works
>> perfectly, hibernating did also work, but I found an inconsistent lock
>> state in dmesg afterwards. System is still fully functional
>>
>> May or may not be related, I don't know.
>
> If it doesn't happen before my patch, then it's probably related.
>

I just tried it without your patches, and the inconsistent lock state
message is also there after suspending to ram.

So they dont seem to be related.

cu
Dieter

2009-01-15 23:30:40

[permalink] [raw]

Subject: Re: 2.6.29-rc1 does not boot

Dieter Ries wrote:
> Mike Travis schrieb:
>> Dieter Ries wrote:
>>> I just tested it. The kernel does boot up, suspending to ram works
>>> perfectly, hibernating did also work, but I found an inconsistent lock
>>> state in dmesg afterwards. System is still fully functional
>>>
>>> May or may not be related, I don't know.
>> If it doesn't happen before my patch, then it's probably related.
>>
>
>
> I just tried it without your patches, and the inconsistent lock state
> message is also there after suspending to ram.
>
> So they dont seem to be related.
>
> cu
> Dieter

Thanks for the feedback!

Mike

2009-01-15 23:31:30