Bug 620955

Summary: Fedora 12 kernels since 2.6.32.16-141 cause performance problems
Product: [Fedora] Fedora Reporter: John Fitzgibbon <john_fitzgibbon>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: medium Docs Contact:
Priority: low    
Version: 12CC: anton, dougsland, gansalmon, itamar, jonathan, kernel-maint, madhu.chinakonda, Marc.Herbert+rhzilla, roebela
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: kernel-2.6.32.19-163.fc12 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2010-08-23 22:02:03 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description John Fitzgibbon 2010-08-03 20:39:17 UTC
Description of problem:
Current and previous releases of the kernel in fedora 12 severely degrade performance in certain circumstances.


Version-Release number of selected component (if applicable):
Problem started with 2.6.32.16-141.fc12.i686. Now experiencing it with 2.6.32.16-150.fc12.i686. No problem with 2.6.32.14-127.fc12.i686 and earlier.


How reproducible:
In my environment, (thinkpad T43 laptop, running fedora 12 + kde), happens fairly consistently.


Steps to Reproduce:
1. Start a suite of compute-intensive tasks. These are software unit tests, each executed via a loopback command interface, about 600 tests in total. Each test restarts the test program, (with a new set of commands executed via the command interface).
2. Start messing about in firefox while waiting for the tests to complete.

  
Actual results:
The full test suite would normally complete in 40-50 seconds. Instead, it goes to about 10 times that value, (400+ seconds). Looking at "top" while the tests are running, the kernel, (I'm guessing), seems to spend an inordinate amount of time spinning it's wheels -- the "%sy" value frequently jumps from <10%, (fairly typical), to >80% and can stay there for a second or two before allowing the unit tests to resume. Needless to say, everything can get a bit sluggish while this is going on, but it's most noticeable in the unit tests.

Note that even if I quit firefox, etc., once the problem has started, it seems to happen consistently from that point forward. However, I can usually boot clean and not see the problem -- as long as I do nothing other than run the test suite.


Expected results:
On "working" kernels, these tests complete consistently in <1 minute.

Note that I can downgrade my kernel to 2.6.32.14-127.fc12.i686 without downgrading anything else and everything works fine, which is why I suspect the kernel.


Additional info:
/proc/sched_debug, (cat'ed mid test cycle), and dmesg:

#cat /proc/sched_debug 
Sched Debug Version: v0.09, 2.6.32.16-150.fc12.i686 #1
now at 17029464.472933 msecs
  .jiffies                                 : 16729464
  .sysctl_sched_latency                    : 5.000000
  .sysctl_sched_min_granularity            : 1.000000
  .sysctl_sched_wakeup_granularity         : 1.000000
  .sysctl_sched_child_runs_first           : 0.000000
  .sysctl_sched_features                   : 15834235

cpu#0, 1862.163 MHz
  .nr_running                    : 4
  .load                          : 4096
  .nr_switches                   : 7870454
  .nr_load_updates               : 3366229
  .nr_uninterruptible            : 0
  .next_balance                  : 16.503236
  .curr->pid                     : 14148
  .clock                         : 17029464.006513
  .cpu_load[0]                   : 4096
  .cpu_load[1]                   : 4832
  .cpu_load[2]                   : 5944
  .cpu_load[3]                   : 6576
  .cpu_load[4]                   : 6080
  .yld_count                     : 6367671
  .sched_switch                  : 0
  .sched_count                   : 14213726
  .sched_goidle                  : 1065214
  .avg_idle                      : 1000000
  .ttwu_count                    : 4537989
  .ttwu_local                    : 4537989
  .bkl_count                     : 223751

cfs_rq[0]:/
  .exec_clock                    : 3059742.525802
  .MIN_vruntime                  : 2707007.390148
  .min_vruntime                  : 2707007.390148
  .max_vruntime                  : 2707034.206818
  .spread                        : 26.816670
  .spread0                       : 0.000000
  .nr_running                    : 4
  .load                          : 4096
  .nr_spread_over                : 3657
  .shares                        : 0

rt_rq[0]:/
  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 0.000000
  .rt_runtime                    : 950.000000

runnable tasks:
            task   PID         tree-key  switches  prio     exec-runtime         sum-exec        sum-sleep
----------------------------------------------------------------------------------------------------------
              sh 12118   2707007.390148      6018   120   2707007.390148     12907.766572    199087.179542 /
           utest 14145   2707034.206818       175   120   2707034.206818       755.190624         0.000000 /
              sh 14147   2707007.469760         0   120   2707007.469760         0.000000         0.000000 /
R            cat 14148   2707008.506921         0   120   2707008.506921         1.234097         0.000000 /




# dmesg
Initializing cgroup subsys cpuset
Initializing cgroup subsys cpu
Linux version 2.6.32.16-150.fc12.i686 (mockbuild.fedoraproject.org) (gcc version 4.4.4 20100630 (Red Hat 4.4.4-10) (GCC) ) #1 SMP Sat Jul 24 05:31:53 UTC 2010
KERNEL supported cpus:
  Intel GenuineIntel
  AMD AuthenticAMD
  NSC Geode by NSC
  Cyrix CyrixInstead
  Centaur CentaurHauls
  Transmeta GenuineTMx86
  Transmeta TransmetaCPU
  UMC UMC UMC UMC
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 - 000000003fee0000 (usable)
 BIOS-e820: 000000003fee0000 - 000000003fef5000 (ACPI data)
 BIOS-e820: 000000003fef5000 - 000000003ff00000 (ACPI NVS)
 BIOS-e820: 000000003ff00000 - 0000000040000000 (reserved)
 BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
 BIOS-e820: 00000000f0008000 - 00000000f000c000 (reserved)
 BIOS-e820: 00000000fec00000 - 00000000fec10000 (reserved)
 BIOS-e820: 00000000fed14000 - 00000000fed1a000 (reserved)
 BIOS-e820: 00000000fed20000 - 00000000fed90000 (reserved)
 BIOS-e820: 00000000fee00000 - 00000000fee01000 (reserved)
 BIOS-e820: 00000000ff000000 - 0000000100000000 (reserved)
DMI present.
last_pfn = 0x3fee0 max_arch_pfn = 0x100000
MTRR default type: uncachable
MTRR fixed ranges enabled:
  00000-9FFFF write-back
  A0000-BFFFF uncachable
  C0000-CFFFF write-protect
  D0000-DBFFF uncachable
  DC000-DFFFF write-back
  E0000-FFFFF write-protect
MTRR variable ranges enabled:
  0 base 000000000 mask FC0000000 write-back
  1 base 03FF00000 mask FFFF00000 uncachable
  2 disabled
  3 disabled
  4 disabled
  5 disabled
  6 disabled
  7 disabled
PAT not supported by CPU.
original variable MTRRs
reg 0, base: 0GB, range: 1GB, type WB
reg 1, base: 1023MB, range: 1MB, type UC
total RAM covered: 1023M
Found optimal setting for mtrr clean up
 gran_size: 64K         chunk_size: 2M  num_reg: 2      lose cover RAM: 0G
New variable MTRRs
reg 0, base: 0GB, range: 1GB, type WB
reg 1, base: 1023MB, range: 1MB, type UC
initial memory mapped : 0 - 01000000
init_memory_mapping: 0000000000000000-00000000373fe000
Using x86 segment limits to approximate NX protection
 0000000000 - 0000400000 page 4k
 0000400000 - 0037000000 page 2M
 0037000000 - 00373fe000 page 4k
kernel direct mapping tables up to 373fe000 @ 7000-d000
RAMDISK: 3751d000 - 37fef19c
Allocated new RAMDISK: 00b38000 - 0160a19c
Move RAMDISK from 000000003751d000 - 0000000037fef19b to 00b38000 - 0160a19b
ACPI: RSDP 000f6c00 00024 (v02 IBM   )
ACPI: XSDT 3fee6ff2 0005C (v01 IBM    TP-1Y    00001240  LTP 00000000)
ACPI: FACP 3fee7100 000F4 (v03 IBM    TP-1Y    00001240 IBM  00000001)
ACPI Warning: 32/64X length mismatch in Gpe1Block: 0/32 (20090903/tbfadt-526)
ACPI Warning: Optional field Gpe1Block has zero address or length: 000000000000102C/0 (20090903/tbfadt-557)
ACPI: DSDT 3fee72e7 0DB08 (v01 IBM    TP-1Y    00001240 MSFT 0100000E)
ACPI: FACS 3fef6000 00040
ACPI: SSDT 3fee72b4 00033 (v01 IBM    TP-1Y    00001240 MSFT 0100000E)
ACPI: ECDT 3fef4def 00052 (v01 IBM    TP-1Y    00001240 IBM  00000001)
ACPI: TCPA 3fef4e41 00032 (v01 IBM    TP-1Y    00001240 PTL  00000001)
ACPI: APIC 3fef4e73 0005A (v01 IBM    TP-1Y    00001240 IBM  00000001)
ACPI: MCFG 3fef4ecd 0003E (v01 IBM    TP-1Y    00001240 IBM  00000001)
ACPI: BOOT 3fef4fd8 00028 (v01 IBM    TP-1Y    00001240  LTP 00000001)
ACPI: Local APIC address 0xfee00000
138MB HIGHMEM available.
883MB LOWMEM available.
  mapped low ram: 0 - 373fe000
  low ram: 0 - 373fe000
  node 0 low ram: 00000000 - 373fe000
  node 0 bootmap 0000a000 - 00010e80
(9 early reservations) ==> bootmem [0000000000 - 00373fe000]
  #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
  #1 [0000001000 - 0000002000]    EX TRAMPOLINE ==> [0000001000 - 0000002000]
  #2 [0000006000 - 0000007000]       TRAMPOLINE ==> [0000006000 - 0000007000]
  #3 [0000400000 - 0000b328d8]    TEXT DATA BSS ==> [0000400000 - 0000b328d8]
  #4 [000009f000 - 0000100000]    BIOS reserved ==> [000009f000 - 0000100000]
  #5 [0000b33000 - 0000b37128]              BRK ==> [0000b33000 - 0000b37128]
  #6 [0000007000 - 000000a000]          PGTABLE ==> [0000007000 - 000000a000]
  #7 [0000b38000 - 000160a19c]      NEW RAMDISK ==> [0000b38000 - 000160a19c]
  #8 [000000a000 - 0000011000]          BOOTMAP ==> [000000a000 - 0000011000]
Zone PFN ranges:
  DMA      0x00000000 -> 0x00001000
  Normal   0x00001000 -> 0x000373fe
  HighMem  0x000373fe -> 0x0003fee0
Movable zone start PFN for each node
early_node_map[2] active PFN ranges
    0: 0x00000000 -> 0x0000009f
    0: 0x00000100 -> 0x0003fee0
On node 0 totalpages: 261759
free_area_init_node: node 0, pgdat c09b9280, node_mem_map c160c000
  DMA zone: 32 pages used for memmap
  DMA zone: 0 pages reserved
  DMA zone: 3967 pages, LIFO batch:0
  Normal zone: 1736 pages used for memmap
  Normal zone: 220470 pages, LIFO batch:31
  HighMem zone: 278 pages used for memmap
  HighMem zone: 35276 pages, LIFO batch:7
Using APIC driver default
ACPI: PM-Timer IO Port: 0x1008
ACPI: Local APIC address 0xfee00000
ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
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 32, address 0xfec00000, GSI 0-23
ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
ACPI: IRQ0 used by override.
ACPI: IRQ2 used by override.
ACPI: IRQ9 used by override.
Using ACPI (MADT) for SMP configuration information
SMP: Allowing 1 CPUs, 0 hotplug CPUs
nr_irqs_gsi: 24
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 40000000 (gap: 40000000:a0000000)
Booting paravirtualized kernel on bare hardware
NR_CPUS:32 nr_cpumask_bits:32 nr_cpu_ids:1 nr_node_ids:1
PERCPU: Embedded 14 pages/cpu @c2000000 s34488 r0 d22856 u4194304
pcpu-alloc: s34488 r0 d22856 u4194304 alloc=1*4194304
pcpu-alloc: [0] 0 
Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 259713
Kernel command line: ro root=/dev/mapper/vg_fitzltw-lv_root noiswmd LANG=en_US.UTF-8 SYSFONT=latarcyrheb-sun16 KEYBOARDTYPE=pc KEYTABLE=us rhgb quiet
PID hash table entries: 4096 (order: 2, 16384 bytes)
Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
Enabling fast FPU save and restore... done.
Enabling unmasked SIMD FPU exception support... done.
Initializing CPU#0
allocated 5237120 bytes of page_cgroup
please try 'cgroup_disable=memory' option if you don't want memory cgroups
Initializing HighMem for node 0 (000373fe:0003fee0)
Memory: 1013964k/1047424k available (3684k kernel code, 32696k reserved, 2305k data, 552k init, 142216k highmem)
virtual kernel memory layout:
    fixmap  : 0xffad5000 - 0xfffff000   (5288 kB)
    pkmap   : 0xff400000 - 0xff800000   (4096 kB)
    vmalloc : 0xf7bfe000 - 0xff3fe000   ( 120 MB)
    lowmem  : 0xc0000000 - 0xf73fe000   ( 883 MB)
      .init : 0xc09da000 - 0xc0a64000   ( 552 kB)
      .data : 0xc0799130 - 0xc09d9710   (2305 kB)
      .text : 0xc0400000 - 0xc0799130   (3684 kB)
Checking if this processor honours the WP bit even in supervisor mode...Ok.
SLUB: Genslabs=13, HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Hierarchical RCU implementation.
NR_IRQS:1280
Extended CMOS year: 2000
Console: colour VGA+ 80x25
console [tty0] enabled
Fast TSC calibration using PIT
Detected 1862.163 MHz processor.
Calibrating delay loop (skipped), value calculated using timer frequency.. 3724.32 BogoMIPS (lpj=1862163)
Security Framework initialized
SELinux:  Initializing.
SELinux:  Starting in permissive mode
Mount-cache hash table entries: 512
Initializing cgroup subsys ns
Initializing cgroup subsys cpuacct
Initializing cgroup subsys memory
Initializing cgroup subsys devices
Initializing cgroup subsys freezer
Initializing cgroup subsys net_cls
CPU: L1 I cache: 32K, L1 D cache: 32K
CPU: L2 cache: 2048K
mce: CPU supports 5 MCE banks
CPU0: Thermal monitoring enabled (TM2)
Performance Events: p6 PMU driver.
... version:                0
... bit width:              32
... generic registers:      2
... value mask:             00000000ffffffff
... max period:             000000007fffffff
... fixed-purpose events:   0
... event mask:             0000000000000003
Checking 'hlt' instruction... OK.
SMP alternatives: switching to UP code
Freeing SMP alternatives: 26k freed
ACPI: Core revision 20090903
ftrace: converting mcount calls to 0f 1f 44 00 00
ftrace: allocating 22347 entries in 44 pages
Enabling APIC mode:  Flat.  Using 1 I/O APICs
..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
CPU0: Intel(R) Pentium(R) M processor 1.86GHz stepping 08
Brought up 1 CPUs
Total of 1 processors activated (3724.32 BogoMIPS).
sizeof(vma)=84 bytes
sizeof(page)=32 bytes
sizeof(inode)=352 bytes
sizeof(dentry)=132 bytes
sizeof(ext3inode)=508 bytes
sizeof(buffer_head)=56 bytes
sizeof(skbuff)=184 bytes
sizeof(task_struct)=3252 bytes
CPU0 attaching NULL sched-domain.
devtmpfs: initialized
regulator: core version 0.5
Time: 15:44:57  Date: 08/03/10
NET: Registered protocol family 16
ACPI: bus type pci registered
PCI: MCFG configuration 0: base e0000000 segment 0 buses 0 - 255
PCI: MCFG area at e0000000 reserved in E820
PCI: Using MMCONFIG for extended config space
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: 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: Power Resource [PUBS] (on)
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:1c.0: PME# supported from D0 D3hot D3cold
pci 0000:00:1c.0: PME# disabled
pci 0000:00:1c.2: PME# supported from D0 D3hot D3cold
pci 0000:00:1c.2: PME# disabled
pci 0000:00:1d.0: reg 20 io port: [0x1800-0x181f]
pci 0000:00:1d.1: reg 20 io port: [0x1820-0x183f]
pci 0000:00:1d.2: reg 20 io port: [0x1840-0x185f]
pci 0000:00:1d.3: reg 20 io port: [0x1860-0x187f]
pci 0000:00:1d.7: reg 10 32bit mmio: [0xa8000000-0xa80003ff]
pci 0000:00:1d.7: PME# supported from D0 D3hot D3cold
pci 0000:00:1d.7: PME# disabled
pci 0000:00:1e.2: reg 10 io port: [0x1c00-0x1cff]
pci 0000:00:1e.2: reg 14 io port: [0x1880-0x18bf]
pci 0000:00:1e.2: reg 18 32bit mmio: [0xa8000800-0xa80009ff]
pci 0000:00:1e.2: reg 1c 32bit mmio: [0xa8000400-0xa80004ff]
pci 0000:00:1e.2: PME# supported from D0 D3hot D3cold
pci 0000:00:1e.2: PME# disabled
pci 0000:00:1e.3: reg 10 io port: [0x2400-0x24ff]
pci 0000:00:1e.3: reg 14 io port: [0x2000-0x207f]
pci 0000:00:1e.3: PME# supported from D0 D3hot D3cold
pci 0000:00:1e.3: PME# disabled
pci 0000:00:1f.0: Force enabled HPET at 0xfed00000
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: LPC Generic IO decode 1 PIO at 1600-167f
pci 0000:00:1f.0: LPC Generic IO decode 2 PIO at 15e0-15ef
pci 0000:00:1f.2: reg 10 io port: [0x00-0x07]
pci 0000:00:1f.2: reg 14 io port: [0x00-0x03]
pci 0000:00:1f.2: reg 18 io port: [0x00-0x07]
pci 0000:00:1f.2: reg 1c io port: [0x00-0x03]
pci 0000:00:1f.2: reg 20 io port: [0x18c0-0x18cf]
pci 0000:00:1f.2: PME# supported from D3hot
pci 0000:00:1f.2: PME# disabled
pci 0000:00:1f.3: reg 20 io port: [0x18e0-0x18ff]
pci 0000:01:00.0: reg 10 32bit mmio pref: [0xc0000000-0xc7ffffff]
pci 0000:01:00.0: reg 14 io port: [0x3000-0x30ff]
pci 0000:01:00.0: reg 18 32bit mmio: [0xa8100000-0xa810ffff]
pci 0000:01:00.0: reg 30 32bit mmio pref: [0x000000-0x01ffff]
pci 0000:01:00.0: supports D1 D2
pci 0000:01:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
pci 0000:00:01.0: bridge io port: [0x3000-0x3fff]
pci 0000:00:01.0: bridge 32bit mmio: [0xa8100000-0xa81fffff]
pci 0000:00:01.0: bridge 32bit mmio pref: [0xc0000000-0xc7ffffff]
pci 0000:02:00.0: reg 10 64bit mmio: [0xa8200000-0xa820ffff]
pci 0000:02:00.0: PME# supported from D3hot D3cold
pci 0000:02:00.0: PME# disabled
pci 0000:02:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
pci 0000:00:1c.0: bridge 32bit mmio: [0xa8200000-0xa82fffff]
pci 0000:00:1c.2: bridge io port: [0x4000-0x4fff]
pci 0000:00:1c.2: bridge 32bit mmio: [0xa8300000-0xa83fffff]
pci 0000:00:1c.2: bridge 64bit mmio pref: [0xc8000000-0xc80fffff]
pci 0000:04:00.0: reg 10 32bit mmio: [0xa8400000-0xa8400fff]
pci 0000:04:00.0: supports D1 D2
pci 0000:04:00.0: PME# supported from D0 D1 D2 D3hot D3cold
pci 0000:04:00.0: PME# disabled
pci 0000:04:02.0: reg 10 32bit mmio: [0xa8401000-0xa8401fff]
pci 0000:04:02.0: PME# supported from D0 D3hot D3cold
pci 0000:04:02.0: PME# disabled
pci 0000:00:1e.0: transparent bridge
pci 0000:00:1e.0: bridge io port: [0x5000-0x8fff]
pci 0000:00:1e.0: bridge 32bit mmio: [0xa8400000-0xb7ffffff]
pci 0000:00:1e.0: bridge 64bit mmio pref: [0xd0000000-0xd7ffffff]
pci_bus 0000:00: on NUMA node 0
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.AGP_._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP0._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.EXP2._PRT]
ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PCI1._PRT]
ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKC] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKF] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 6 7 9 10 *11)
ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 6 7 9 10 *11)
vgaarb: device added: PCI:0000:01:00.0,decodes=io+mem,owns=io+mem,locks=none
vgaarb: loaded
SCSI subsystem initialized
libata version 3.00 loaded.
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
PCI: Using ACPI for IRQ routing
PCI: old code would have set cacheline size to 32 bytes, but clflush_size = 64
PCI: pci_cache_line_size set to 64 bytes
Expanded resource reserved due to conflict with Adapter ROM
NetLabel: Initializing
NetLabel:  domain hash size = 128
NetLabel:  protocols = UNLABELED CIPSOv4
NetLabel:  unlabeled traffic allowed by default
hpet clockevent registered
HPET: 3 timers in total, 0 timers will be used for per-cpu timer
hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
hpet0: 3 comparators, 64-bit 14.318180 MHz counter
Switching to clocksource tsc
pnp: PnP ACPI init
ACPI: bus type pnp registered
pnp: PnP ACPI: found 14 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 could not be reserved
system 00:00: iomem range 0xc4000-0xc7fff could not be reserved
system 00:00: iomem range 0xc8000-0xcbfff could not be reserved
system 00:00: iomem range 0xcc000-0xcffff could not be 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-0x3fffffff could not be reserved
system 00:00: iomem range 0xfec00000-0xffffffff could not be 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 0x15e0-0x15ef has been reserved
system 00:02: ioport range 0x1600-0x1641 has been reserved
system 00:02: ioport range 0x1644-0x167f has been reserved
system 00:02: iomem range 0xe0000000-0xefffffff has been reserved
system 00:02: iomem range 0xf0008000-0xf000bfff 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: 0x3000-0x3fff
pci 0000:00:01.0:   MEM window: 0xa8100000-0xa81fffff
pci 0000:00:01.0:   PREFETCH window: 0xc0000000-0xc7ffffff
pci 0000:00:1c.0: PCI bridge, secondary bus 0000:02
pci 0000:00:1c.0:   IO window: 0x9000-0x9fff
pci 0000:00:1c.0:   MEM window: 0xa8200000-0xa82fffff
pci 0000:00:1c.0:   PREFETCH window: 0x00000040000000-0x000000401fffff
pci 0000:00:1c.2: PCI bridge, secondary bus 0000:03
pci 0000:00:1c.2:   IO window: 0x4000-0x4fff
pci 0000:00:1c.2:   MEM window: 0xa8300000-0xa83fffff
pci 0000:00:1c.2:   PREFETCH window: 0x000000c8000000-0x000000c80fffff
pci 0000:04:00.0: CardBus bridge, secondary bus 0000:05
pci 0000:04:00.0:   IO window: 0x005000-0x0050ff
pci 0000:04:00.0:   IO window: 0x005400-0x0054ff
pci 0000:04:00.0:   PREFETCH window: 0xd0000000-0xd3ffffff
pci 0000:04:00.0:   MEM window: 0xac000000-0xafffffff
pci 0000:00:1e.0: PCI bridge, secondary bus 0000:04
pci 0000:00:1e.0:   IO window: 0x5000-0x8fff
pci 0000:00:1e.0:   MEM window: 0xa8400000-0xb7ffffff
pci 0000:00:1e.0:   PREFETCH window: 0x000000d0000000-0x000000d7ffffff
pci 0000:00:01.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
pci 0000:00:01.0: setting latency timer to 64
pci 0000:00:1c.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
pci 0000:00:1c.0: setting latency timer to 64
pci 0000:00:1c.2: PCI INT C -> GSI 22 (level, low) -> IRQ 22
pci 0000:00:1c.2: setting latency timer to 64
pci 0000:00:1e.0: setting latency timer to 64
pci 0000:04:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
pci_bus 0000:00: resource 0 io:  [0x00-0xffff]
pci_bus 0000:00: resource 1 mem: [0x000000-0xffffffff]
pci_bus 0000:01: resource 0 io:  [0x3000-0x3fff]
pci_bus 0000:01: resource 1 mem: [0xa8100000-0xa81fffff]
pci_bus 0000:01: resource 2 pref mem [0xc0000000-0xc7ffffff]
pci_bus 0000:02: resource 0 io:  [0x9000-0x9fff]
pci_bus 0000:02: resource 1 mem: [0xa8200000-0xa82fffff]
pci_bus 0000:02: resource 2 pref mem [0x40000000-0x401fffff]
pci_bus 0000:03: resource 0 io:  [0x4000-0x4fff]
pci_bus 0000:03: resource 1 mem: [0xa8300000-0xa83fffff]
pci_bus 0000:03: resource 2 pref mem [0xc8000000-0xc80fffff]
pci_bus 0000:04: resource 0 io:  [0x5000-0x8fff]
pci_bus 0000:04: resource 1 mem: [0xa8400000-0xb7ffffff]
pci_bus 0000:04: resource 2 pref mem [0xd0000000-0xd7ffffff]
pci_bus 0000:04: resource 3 io:  [0x00-0xffff]
pci_bus 0000:04: resource 4 mem: [0x000000-0xffffffff]
pci_bus 0000:05: resource 0 io:  [0x5000-0x50ff]
pci_bus 0000:05: resource 1 io:  [0x5400-0x54ff]
pci_bus 0000:05: resource 2 pref mem [0xd0000000-0xd3ffffff]
pci_bus 0000:05: resource 3 mem: [0xac000000-0xafffffff]
NET: Registered protocol family 2
IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
TCP bind hash table entries: 65536 (order: 7, 524288 bytes)
TCP: Hash tables configured (established 131072 bind 65536)
TCP reno registered
NET: Registered protocol family 1
pci 0000:01:00.0: Boot video device
Trying to unpack rootfs image as initramfs...
Freeing initrd memory: 11080k freed
Simple Boot Flag at 0x35 set to 0x1
IBM machine detected. Enabling interrupts during APM calls.
apm: BIOS version 1.2 Flags 0x03 (Driver version 1.16ac)
apm: overridden by ACPI.
audit: initializing netlink socket (disabled)
type=2000 audit(1280850297.547:1): initialized
highmem bounce pool size: 64 pages
HugeTLB registered 4 MB page size, pre-allocated 0 pages
VFS: Disk quotas dquot_6.5.2
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
msgmni has been set to 1725
SELinux:  Registering netfilter hooks
alg: No test for stdrng (krng)
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
io scheduler noop registered
io scheduler anticipatory registered
io scheduler deadline registered
io scheduler cfq registered (default)
pcieport 0000:00:01.0: irq 24 for MSI/MSI-X
pcieport 0000:00:01.0: setting latency timer to 64
pcieport 0000:00:1c.0: irq 25 for MSI/MSI-X
pcieport 0000:00:1c.0: setting latency timer to 64
pcieport 0000:00:1c.2: irq 26 for MSI/MSI-X
pcieport 0000:00:1c.2: setting latency timer to 64
pci_hotplug: PCI Hot Plug PCI Core version: 0.5
pciehp: PCI Express Hot Plug Controller Driver version: 0.4
acpiphp: ACPI Hot Plug PCI Controller Driver version: 0.5
acpiphp: Slot [1] registered
acpiphp: Slot [1-1] registered
pci-stub: invalid id string ""
ACPI: AC Adapter [AC] (on-line)
input: Lid Switch as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0D:00/input/input0
ACPI: Lid Switch [LID]
input: Sleep Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0E:00/input/input1
ACPI: Sleep Button [SLPB]
input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input2
ACPI: Power Button [PWRF]
Marking TSC unstable due to TSC halts in idle
processor LNXCPU:00: registered as cooling_device0
Switching to clocksource hpet
thermal LNXTHERM:01: registered as thermal_zone0
ACPI: Thermal Zone [THM0] (37 C)
isapnp: Scanning for PnP cards...
isapnp: No Plug & Play device found
Non-volatile memory driver v1.3
Linux agpgart interface v0.103
Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
serial 00:0a: activated
00:0a: ttyS0 at I/O 0x3f8 (irq = 4) is a NS16550A
serial 0000:00:1e.3: PCI INT B -> GSI 23 (level, low) -> IRQ 23
serial 0000:00:1e.3: PCI INT B disabled
brd: module loaded
loop: module loaded
input: Macintosh mouse button emulation as /devices/virtual/input/input3
ahci 0000:00:1f.2: version 3.0
ahci: probe of 0000:00:1f.2 failed with error -22
ata_piix 0000:00:1f.2: version 2.13
ata_piix 0000:00:1f.2: MAP [ P0 P2 IDE IDE ]
ata_piix 0000:00:1f.2: setting latency timer to 64
scsi0 : ata_piix
scsi1 : ata_piix
ata1: SATA max UDMA/133 cmd 0x1f0 ctl 0x3f6 bmdma 0x18c0 irq 14
ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x18c8 irq 15
Fixed MDIO Bus: probed
ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
ACPI: Battery Slot [BAT0] (battery present)
ehci_hcd 0000:00:1d.7: power state changed by ACPI to D0
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: setting latency timer to 64
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: cache line size of 64 is not supported
ehci_hcd 0000:00:1d.7: irq 19, io mem 0xa8000000
ehci_hcd 0000:00:1d.7: USB 2.0 started, EHCI 1.00
usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: Product: EHCI Host Controller
usb usb1: Manufacturer: Linux 2.6.32.16-150.fc12.i686 ehci_hcd
usb usb1: SerialNumber: 0000:00:1d.7
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: 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: setting latency timer to 64
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: New USB device found, idVendor=1d6b, idProduct=0001
usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb2: Product: UHCI Host Controller
usb usb2: Manufacturer: Linux 2.6.32.16-150.fc12.i686 uhci_hcd
usb usb2: SerialNumber: 0000:00:1d.0
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: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.1: power state changed by ACPI to D0
uhci_hcd 0000:00:1d.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
uhci_hcd 0000:00:1d.1: setting latency timer to 64
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: New USB device found, idVendor=1d6b, idProduct=0001
usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb3: Product: UHCI Host Controller
usb usb3: Manufacturer: Linux 2.6.32.16-150.fc12.i686 uhci_hcd
usb usb3: SerialNumber: 0000:00:1d.1
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: PCI INT C -> GSI 18 (level, low) -> IRQ 18
uhci_hcd 0000:00:1d.2: setting latency timer to 64
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: New USB device found, idVendor=1d6b, idProduct=0001
usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb4: Product: UHCI Host Controller
usb usb4: Manufacturer: Linux 2.6.32.16-150.fc12.i686 uhci_hcd
usb usb4: SerialNumber: 0000:00:1d.2
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: setting latency timer to 64
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: New USB device found, idVendor=1d6b, idProduct=0001
usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb5: Product: UHCI Host Controller
usb usb5: Manufacturer: Linux 2.6.32.16-150.fc12.i686 uhci_hcd
usb usb5: SerialNumber: 0000:00:1d.3
usb usb5: configuration #1 chosen from 1 choice
hub 5-0:1.0: USB hub found
hub 5-0:1.0: 2 ports detected
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
rtc_cmos 00:06: RTC can wake from S4
rtc_cmos 00:06: rtc core: registered rtc_cmos as rtc0
rtc0: alarms up to one month, y3k, 114 bytes nvram, hpet irqs
device-mapper: uevent: version 1.0.3
device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel
cpuidle: using governor ladder
cpuidle: using governor menu
usbcore: registered new interface driver hiddev
usbcore: registered new interface driver usbhid
usbhid: v2.6:USB HID core driver
nf_conntrack version 0.5.0 (16022 buckets, 64088 max)
CONFIG_NF_CT_ACCT is deprecated and will be removed soon. Please use
nf_conntrack.acct=1 kernel parameter, acct=1 nf_conntrack module option or
sysctl net.netfilter.nf_conntrack_acct=1 to enable it.
ip_tables: (C) 2000-2006 Netfilter Core Team
TCP cubic registered
Initializing XFRM netlink socket
NET: Registered protocol family 17
Using IPI No-Shortcut mode
PM: Resume from disk failed.
registered taskstats version 1
No TPM chip found, activating TPM-bypass!
  Magic number: 6:511:739
rtc_cmos 00:06: setting system clock to 2010-08-03 15:44:59 UTC (1280850299)
Initalizing network drop monitor service
input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input4
ata2.00: ATAPI: HL-DT-STCD-RW/DVD DRIVE GCC-4242N, 0J05, max UDMA/33
ata1.00: ATA-6: HTS541040G9AT00, MB2IA60A, max UDMA/100
ata1.00: 78140160 sectors, multi 16: LBA 
ata1.00: applying bridge limits
ata2.00: configured for UDMA/33
ata1.00: configured for UDMA/100
scsi 0:0:0:0: Direct-Access     ATA      HTS541040G9AT00  MB2I PQ: 0 ANSI: 5
sd 0:0:0:0: Attached scsi generic sg0 type 0
sd 0:0:0:0: [sda] 78140160 512-byte logical blocks: (40.0 GB/37.2 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
 sda:
scsi 1:0:0:0: CD-ROM            HL-DT-ST RW/DVD GCC-4242N 0J05 PQ: 0 ANSI: 5
sr0: scsi3-mmc drive: 24x/24x writer cd/rw xa/form2 cdda tray
Uniform CD-ROM driver Revision: 3.20
sr 1:0:0:0: Attached scsi CD-ROM sr0
sr 1:0:0:0: Attached scsi generic sg1 type 5
 sda1 sda2
sd 0:0:0:0: [sda] Attached SCSI disk
Freeing unused kernel memory: 552k freed
Write protecting the kernel text: 3688k
Write protecting the kernel read-only data: 1744k
dracut: dracut-005-2.fc12
udev: starting version 145
[drm] Initialized drm 1.1.0 20060810
[drm] radeon defaulting to kernel modesetting.
[drm] radeon kernel modesetting enabled.
radeon 0000:01:00.0: power state changed by ACPI to D0
radeon 0000:01:00.0: power state changed by ACPI to D0
radeon 0000:01:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
radeon 0000:01:00.0: setting latency timer to 64
[drm] radeon: Initializing kernel modesetting.
[drm] register mmio base: 0xA8100000
[drm] register mmio size: 65536
[drm] GPU reset succeed (RBBM_STATUS=0x00000140)
[drm] Generation 2 PCI interface, using max accessible memory
[drm] radeon: VRAM 64M
[drm] radeon: VRAM from 0x00000000 to 0x03FFFFFF
[drm] radeon: GTT 512M
[drm] radeon: GTT from 0x20000000 to 0x3FFFFFFF
radeon 0000:01:00.0: irq 27 for MSI/MSI-X
[drm] radeon: using MSI.
[drm] radeon: irq initialized.
[drm] Detected VRAM RAM=64M, BAR=128M
[drm] RAM width 64bits DDR
[TTM] Zone  kernel: Available graphics memory: 441892 kiB.
[TTM] Zone highmem: Available graphics memory: 513000 kiB.
[drm] radeon: 64M of VRAM memory ready
[drm] radeon: 512M of GTT memory ready.
[drm] GART: num cpu pages 131072, num gpu pages 131072
[drm] radeon: 1 quad pipes, 1 Z pipes initialized.
[drm] PCIE GART of 512M enabled (table at 0x00040000).
[drm] radeon: cp idle (0x10000C03)
[drm] Loading R300 Microcode
platform radeon_cp.0: firmware: requesting radeon/R300_cp.bin
[drm] radeon: ring at 0x0000000020000000
[drm] ring test succeeded in 1 usecs
[drm] radeon: ib pool ready.
[drm] ib test succeeded in 0 usecs
[drm] DFP table revision: 4
[drm] Panel ID String: Samsung LTN150P1-L02    
[drm] Panel Size 1400x1050
[drm] Default TV standard: NTSC
[drm] 27.000000000 MHz TV ref clk
[drm] Default TV standard: NTSC
[drm] 27.000000000 MHz TV ref clk
[drm] Radeon Display Connectors
[drm] Connector 0:
[drm]   VGA
[drm]   DDC: 0x60 0x60 0x60 0x60 0x60 0x60 0x60 0x60
[drm]   Encoders:
[drm]     CRT1: INTERNAL_DAC1
[drm] Connector 1:
[drm]   DVI-D
[drm]   HPD1
[drm]   DDC: 0x64 0x64 0x64 0x64 0x64 0x64 0x64 0x64
[drm]   Encoders:
[drm]     DFP1: INTERNAL_TMDS1
[drm] Connector 2:
[drm]   LVDS
[drm]   Encoders:
[drm]     LCD1: INTERNAL_LVDS
[drm] Connector 3:
[drm]   S-video
[drm]   Encoders:
[drm]     TV1: INTERNAL_DAC2
[drm] fb mappable at 0xC00C0000
[drm] vram apper at 0xC0000000
[drm] size 5913600
[drm] fb depth is 24
[drm]    pitch is 5632
fbcon: radeondrmfb (fb0) is primary device
Console: switching to colour frame buffer device 175x65
fb0: radeondrmfb frame buffer device
registered panic notifier
[drm] Initialized radeon 2.0.0 20080528 for 0000:01:00.0 on minor 0
dracut: Starting plymouth daemon
usb 3-1: new low speed USB device using uhci_hcd and address 2
Synaptics Touchpad, model: 1, fw: 5.9, id: 0x2c6ab1, caps: 0x884793/0x0
serio: Synaptics pass-through port at isa0060/serio1/input0
usb 3-1: New USB device found, idVendor=047d, idProduct=1029
usb 3-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
usb 3-1: Product: USB/PS2 Wheel Mouse
usb 3-1: Manufacturer: Kensington     
usb 3-1: configuration #1 chosen from 1 choice
dracut: rd_NO_MDIMSM: no MD RAID for imsm/isw raids
input: Kensington      USB/PS2 Wheel Mouse as /devices/pci0000:00/0000:00:1d.1/usb3/3-1/3-1:1.0/input/input5
generic-usb 0003:047D:1029.0001: input,hidraw0: USB HID v1.10 Mouse [Kensington      USB/PS2 Wheel Mouse] on usb-0000:00:1d.1-1/input0
input: SynPS/2 Synaptics TouchPad as /devices/platform/i8042/serio1/input/input6
yenta_cardbus 0000:04:00.0: CardBus bridge found [1014:056c]
input: Video Bus as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/device:02/LNXVIDEO:00/input/input7
ACPI: Video Device [VID] (multi-head: yes  rom: no  post: no)
yenta_cardbus 0000:04:00.0: ISA IRQ mask 0x0cb8, PCI irq 16
yenta_cardbus 0000:04:00.0: Socket status: 30000006
yenta_cardbus 0000:04:00.0: pcmcia: parent PCI bridge I/O window: 0x5000 - 0x8fff
pcmcia_socket pcmcia_socket0: cs: IO port probe 0x5000-0x8fff: clean.
yenta_cardbus 0000:04:00.0: pcmcia: parent PCI bridge Memory window: 0xa8400000 - 0xb7ffffff
yenta_cardbus 0000:04:00.0: pcmcia: parent PCI bridge Memory window: 0xd0000000 - 0xd7ffffff
psmouse serio2: ID: 10 00 64
IBM TrackPoint firmware: 0x0e, buttons: 3/3
input: TPPS/2 IBM TrackPoint as /devices/platform/i8042/serio1/serio2/input/input8
dracut: Scanning devices sda2  for LVM volume groups 
dracut: Reading all physical volumes. This may take a while...
dracut: Found volume group "vg_fitzltw" using metadata type lvm2
dracut: 2 logical volume(s) in volume group "vg_fitzltw" now active
EXT4-fs (dm-0): mounted filesystem with ordered data mode
dracut: Mounted root filesystem /dev/mapper/vg_fitzltw-lv_root
dracut: Loading SELinux policy
type=1404 audit(1280850307.115:2): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295
SELinux: 8192 avtab hash slots, 164920 rules.
SELinux: 8192 avtab hash slots, 164920 rules.
SELinux:  8 users, 12 roles, 3129 types, 154 bools, 1 sens, 1024 cats
SELinux:  77 classes, 164920 rules
SELinux:  Completing initialization.
SELinux:  Setting up existing superblocks.
SELinux: initialized (dev dm-0, type ext4), uses xattr
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
SELinux: initialized (dev securityfs, type securityfs), uses genfs_contexts
SELinux: initialized (dev usbfs, type usbfs), uses genfs_contexts
SELinux: initialized (dev selinuxfs, type selinuxfs), uses genfs_contexts
SELinux: initialized (dev mqueue, type mqueue), uses transition SIDs
SELinux: initialized (dev hugetlbfs, type hugetlbfs), uses transition SIDs
SELinux: initialized (dev devpts, type devpts), uses transition SIDs
SELinux: initialized (dev inotifyfs, type inotifyfs), uses genfs_contexts
SELinux: initialized (dev anon_inodefs, type anon_inodefs), uses genfs_contexts
SELinux: initialized (dev pipefs, type pipefs), uses task SIDs
SELinux: initialized (dev debugfs, type debugfs), uses genfs_contexts
SELinux: initialized (dev sockfs, type sockfs), uses task SIDs
SELinux: initialized (dev devtmpfs, type devtmpfs), uses transition SIDs
SELinux: initialized (dev tmpfs, type tmpfs), uses transition SIDs
SELinux: initialized (dev proc, type proc), uses genfs_contexts
SELinux: initialized (dev bdev, type bdev), uses genfs_contexts
SELinux: initialized (dev rootfs, type rootfs), uses genfs_contexts
SELinux: initialized (dev sysfs, type sysfs), uses genfs_contexts
type=1403 audit(1280850307.518:3): policy loaded auid=4294967295 ses=4294967295
dracut: Switching root
udev: starting version 145
type=1400 audit(1280850311.482:4): avc:  denied  { mmap_zero } for  pid=477 comm="vbetool" scontext=system_u:system_r:vbetool_t:s0-s0:c0.c1023 tcontext=system_u:system_r:vbetool_t:s0-s0:c0.c1023 tclass=memprotect
lib80211: common routines for IEEE802.11 drivers
lib80211_crypt: registered algorithm 'NULL'
pcmcia_socket pcmcia_socket0: cs: IO port probe 0x100-0x3af: clean.
pcmcia_socket pcmcia_socket0: cs: IO port probe 0x3e0-0x4ff: excluding 0x4d0-0x4d7
pcmcia_socket pcmcia_socket0: cs: IO port probe 0x820-0x8ff: clean.
pcmcia_socket pcmcia_socket0: cs: IO port probe 0xc00-0xcf7: clean.
pcmcia_socket pcmcia_socket0: cs: IO port probe 0xa00-0xaff: clean.
ieee80211: 802.11 data/management/control stack, git-1.1.13
ieee80211: Copyright (C) 2004-2005 Intel Corporation <jketreno.com>
i801_smbus 0000:00:1f.3: PCI INT A -> GSI 23 (level, low) -> IRQ 23
NET: Registered protocol family 23
intel_rng: FWH not detected
tg3.c:v3.102 (September 1, 2009)
tg3 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
tg3 0000:02:00.0: setting latency timer to 64
nsc-ircc 00:0c: activated
nsc-ircc, chip->init
nsc-ircc, Found chip at base=0x02e
nsc-ircc, driver loaded (Dag Brattli)
IrDA: Registered device irda0
nsc-ircc, Using dongle: IBM31T1100 or Temic TFDS6000/TFDS6500
eth0: Tigon3 [partno(BCM95751M) rev 4101] (PCI Express) MAC address 00:16:41:12:88:36
eth0: attached PHY is 5750 (10/100/1000Base-T Ethernet) (WireSpeed[1])
eth0: RXcsums[1] LinkChgREG[0] MIirq[0] ASF[0] TSOcap[1]
eth0: dma_rwctrl[76180000] dma_mask[64-bit]
ipw2200: Intel(R) PRO/Wireless 2200/2915 Network Driver, 1.2.2kmprq
ipw2200: Copyright(c) 2003-2006 Intel Corporation
ipw2200 0000:04:02.0: PCI INT A -> GSI 21 (level, low) -> IRQ 21
ipw2200: Detected Intel PRO/Wireless 2915ABG Network Connection
ipw2200 0000:04:02.0: firmware: requesting ipw2200-bss.fw
iTCO_vendor_support: vendor-support=0
thinkpad_acpi: ThinkPad ACPI Extras v0.23
thinkpad_acpi: http://ibm-acpi.sf.net/
thinkpad_acpi: ThinkPad BIOS 1YET59WW (1.24 ), EC 1YHT27WW-1.04
thinkpad_acpi: IBM ThinkPad T43, model 2687D4U
thinkpad_acpi: WARNING: Outdated ThinkPad BIOS/EC firmware
thinkpad_acpi: WARNING: This firmware may be missing critical bug fixes and/or important features
Registered led device: tpacpi::thinklight
Registered led device: tpacpi::power
Registered led device: tpacpi::standby
thinkpad_acpi: Standard ACPI backlight interface not available, thinkpad_acpi native brightness control enabled
thinkpad_acpi: fan_init: initial fan status is unknown, assuming it is in auto mode
input: ThinkPad Extra Buttons as /devices/platform/thinkpad_acpi/input/input9
parport_pc 00:0b: reported by Plug and Play ACPI
parport0: PC-style at 0x3bc, irq 7 [PCSPP,TRISTATE]
iTCO_wdt: Intel TCO WatchDog Timer Driver v1.05
iTCO_wdt: Found a ICH6-M TCO device (Version=2, TCOBASE=0x1060)
iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
ppdev: user-space parallel port driver
ipw2200: Detected geography ZZA (11 802.11bg channels, 13 802.11a channels)
Intel ICH Modem 0000:00:1e.3: PCI INT B -> GSI 23 (level, low) -> IRQ 23
Intel ICH Modem 0000:00:1e.3: setting latency timer to 64
ALSA sound/pci/ac97/ac97_codec.c:2163: MC'97 1 converters and GPIO not ready (0xff00)
Intel ICH 0000:00:1e.2: PCI INT A -> GSI 22 (level, low) -> IRQ 22
Intel ICH 0000:00:1e.2: setting latency timer to 64
intel8x0_measure_ac97_clock: measured 50470 usecs (2432 samples)
intel8x0: clocking to 48000
device-mapper: multipath: version 1.1.0 loaded
EXT4-fs (sda1): mounted filesystem with ordered data mode
SELinux: initialized (dev sda1, type ext4), uses xattr
Adding 2064376k swap on /dev/mapper/vg_fitzltw-lv_swap.  Priority:-1 extents:1 across:2064376k 
SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses genfs_contexts
microcode: CPU0 sig=0x6d8, pf=0x20, revision=0x20
platform microcode: firmware: requesting intel-ucode/06-0d-08
Microcode Update Driver: v2.00 <tigran.co.uk>, Peter Oruba
Microcode Update Driver: v2.00 removed.
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
ip6_tables: (C) 2000-2006 Netfilter Core Team
P-state transition latency capped at 20 uS
tun: Universal TUN/TAP device driver, 1.6
tun: (C) 1999-2004 Max Krasnyansky <maxk>
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
SELinux: initialized (dev rpc_pipefs, type rpc_pipefs), uses genfs_contexts
ADDRCONF(NETDEV_UP): eth0: link is not ready
eth1: no IPv6 routers present
fuse init (API version 7.13)
SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
lib80211_crypt: registered algorithm 'CCMP'
padlock: VIA PadLock not detected.
tun0: Disabled Privacy Extensions
dumpcap uses obsolete (PF_INET,SOCK_PACKET)
Bluetooth: Core ver 2.15
NET: Registered protocol family 31
Bluetooth: HCI device and connection manager initialized
Bluetooth: HCI socket layer initialized

Comment 1 Chuck Ebbert 2010-08-03 23:01:29 UTC
Can you run oprofile and see where the kernel is using that time?

http://docs.fedoraproject.org/en-US/Fedora/12/html/Deployment_Guide/ch-oprofile.html

Comment 2 John Fitzgibbon 2010-08-05 02:26:39 UTC
(In reply to comment #1)
> Can you run oprofile and see where the kernel is using that time?
> 
> http://docs.fedoraproject.org/en-US/Fedora/12/html/Deployment_Guide/ch-oprofile.html    

Would like to help, but it'll be a while before I've time to RTFM... any chance you could help me out with a quick cheat sheet on what *exactly* you'd like me to run/collect/post?

Comment 3 Chuck Ebbert 2010-08-05 22:49:22 UTC
You need the kernel-debuginfo and oprofile packages installed to profile the kernel.

Load the kernel module and start the daemon:

  opcontrol --init

Run a profiling session:

  opcontrol --reset
  opcontrol --start --vmlinux=/usr/lib/debug/lib/modules/$(uname -r)/vmlinux
  [ run workload ]
  opcontrol --stop
  opreport --threshold 1 -l /usr/lib/debug/lib/modules/$(uname -r)/vmlinux

Stop the daemon when done:

  opcontrol --shutdown

Comment 4 John Fitzgibbon 2010-08-09 09:05:40 UTC
Chuck, thanks for the mini-howto.

I profiled one good run of the tests for comparison, then happened to catch a particularly bad test run after messing about in firefox for a bit, (though I exited firefox before the test run).


Good test run, (elapsed = 33 seconds):

# opreport --threshold 1 -l /usr/lib/debug/lib/modules/$(uname -r)/vmlinux
Overflow stats not available
CPU: Pentium M (P6 core), speed 1866 MHz (estimated)
Counted CPU_CLK_UNHALTED events (clocks processor is not halted, and not in a thermal trip) with a unit mask of 0x00 (No unit mask) count 100000
samples  %        symbol name
74472    20.7922  get_page_from_freelist
15532     4.3365  read_hpet
14791     4.1296  page_fault
8733      2.4382  mls_compute_sid
7680      2.1442  system_call
6429      1.7949  __might_sleep
6363      1.7765  do_select
6217      1.7358  list_del
4737      1.3225  mem_cgroup_charge_common
4708      1.3144  copy_user_highpage
4541      1.2678  copy_from_user
3807      1.0629  handle_mm_fault


Bad test run, (elapsed = 1450 seconds):

# opreport --threshold 1 -l /usr/lib/debug/lib/modules/$(uname -r)/vmlinux
Overflow stats not available
CPU: Pentium M (P6 core), speed 1866 MHz (estimated)
Counted CPU_CLK_UNHALTED events (clocks processor is not halted, and not in a thermal trip) with a unit mask of 0x00 (No unit mask) count 100000
samples  %        symbol name
747550    4.4549  do_select
588017    3.5042  get_page_from_freelist
464146    2.7660  __might_sleep
391223    2.3315  read_hpet
326714    1.9470  sched_clock_local
257557    1.5349  handle_mm_fault
251698    1.5000  softlockup_tick
243364    1.4503  core_sys_select
238071    1.4188  do_page_fault
233153    1.3895  test_ti_thread_flag
217087    1.2937  syscall_trace_enter
212461    1.2661  unmap_vmas
209578    1.2490  ktime_get
205824    1.2266  hrtimer_interrupt
201451    1.2005  restore_nocheck
193820    1.1550  __rcu_pending
186830    1.1134  kmap_atomic_prot
185022    1.1026  rb_get_reader_page
183781    1.0952  page_address
177655    1.0587  update_curr
174139    1.0378  copy_from_user

Comment 5 John Fitzgibbon 2010-08-10 02:41:51 UTC
FYI: Looking through other bugs, I came across bug #619396 -- sounds like a very similar problem, (slow performance, in X in that bug), with the same kernels, (2.6.32.16-141 and later), on the same h/w, (Thinkpad T43). Maybe something specific to the h/w, (graphics, maybe)?

Comment 6 Chuck Ebbert 2010-08-10 03:46:30 UTC
Can you add "nomodeset" to the kernel boot options and boot to runlevel 3 to run your tests and see if the problem goes away?

Comment 7 Chuck Ebbert 2010-08-10 03:48:38 UTC
(In reply to comment #5)
> FYI: Looking through other bugs, I came across bug #619396 -- sounds like a
> very similar problem, (slow performance, in X in that bug), with the same
> kernels, (2.6.32.16-141 and later), on the same h/w, (Thinkpad T43). Maybe
> something specific to the h/w, (graphics, maybe)?    

That problem only happens after a suspend/resume cycle.

Comment 8 John Fitzgibbon 2010-08-10 06:11:29 UTC
(In reply to comment #6)
> Can you add "nomodeset" to the kernel boot options and boot to runlevel 3 to
> run your tests and see if the problem goes away?    

Yes, left the tests running in a loop at runlevel 3 with nomodeset and performance is steady.

Comment 9 Chuck Ebbert 2010-08-10 13:25:51 UTC
I missed one step in the directions for profiling. You need to boot the machine with kernel option "idle=poll" to get accurate profiles. This will cause the machine to run hotter, so don't leave it that way.

Also, are there a large number of interrupts happening? Check /proc/interrupts and see if anything looks unusual.

Comment 10 Chuck Ebbert 2010-08-10 15:11:38 UTC
It looks like I dropped some DRM fixes in 2.6.34.16-141 . Can you try 2.6.32.18-158.rc1.fc12 when it finishes building in koji?

Comment 11 John Fitzgibbon 2010-08-11 01:38:24 UTC
(In reply to comment #10)
> It looks like I dropped some DRM fixes in 2.6.34.16-141 . Can you try
> 2.6.32.18-158.rc1.fc12 when it finishes building in koji?    

I'll need to test for a day or two to be 100% sure, but that seems to do the trick. Thanks.

Comment 12 John Fitzgibbon 2010-08-12 06:42:58 UTC
(In reply to comment #11)
> I'll need to test for a day or two to be 100% sure.    

Fix looks good. Feel free to close. Thanks again.

Comment 13 Fedora Update System 2010-08-18 10:35:26 UTC
kernel-2.6.32.19-162.fc12 has been submitted as an update for Fedora 12.
http://admin.fedoraproject.org/updates/kernel-2.6.32.19-162.fc12

Comment 14 Fedora Update System 2010-08-18 20:45:37 UTC
kernel-2.6.32.19-163.fc12 has been submitted as an update for Fedora 12.
http://admin.fedoraproject.org/updates/kernel-2.6.32.19-163.fc12

Comment 15 Chuck Ebbert 2010-08-19 10:49:39 UTC
*** Bug 625215 has been marked as a duplicate of this bug. ***

Comment 16 Fedora Update System 2010-08-20 01:59:49 UTC
kernel-2.6.32.19-163.fc12 has been pushed to the Fedora 12 testing repository.  If problems still persist, please make note of it in this bug report.
 If you want to test the update, you can install it with 
 su -c 'yum --enablerepo=updates-testing update kernel'.  You can provide feedback for this update here: http://admin.fedoraproject.org/updates/kernel-2.6.32.19-163.fc12

Comment 17 John Fitzgibbon 2010-08-22 19:21:07 UTC
(In reply to comment #16)
>  If you want to test the update, you can install it with 
>  su -c 'yum --enablerepo=updates-testing update kernel'.

Done:- no problems with this version either.

> You can provide feedback for this update here:
> http://admin.fedoraproject.org/updates/kernel-2.6.32.19-163.fc12

Done.

Comment 18 Fedora Update System 2010-08-23 22:01:34 UTC
kernel-2.6.32.19-163.fc12 has been pushed to the Fedora 12 stable repository.  If problems still persist, please make note of it in this bug report.