[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#584881: Lockups under heavy disk IO; md (RAID) resync/check implicated



Package: linux-image-2.6.26-2-686-bigmem
Version: 2.6.26-21lenny4

I keep getting soft lockups; the symptoms appear to be that user
processes become deadlocked when they try to access the disk, but the
kernel doesn't notice that anything is wrong.

It appears that the lockups happen when:
 (a) my software (mdadm) RAID mirror is resyncing or checking
 (b) some other program does heavy disk IO

I'm currently trying to work around the problem by disabling the
system's backups (which are a prime trigger in category (b)) until the
post-crash mirror resync is complete, combined with setting the sysctl
dev.raid.speed_limit_max to 1000.  Just disabling the backups wasn't
sufficient because, it seems, various recovery tasks in the most
recent crash are sufficient to trigger the bug.

I observe that the message from the md driver, and the presence of the
sysctls dev.raid.speed_limit_{min,max}, suggest that the md driver is
using a fundamentally incorrect algorithm which depends on guessing
the available IO bandwidth.


Actual hard data:

* chiark locked up at 0355 on the 2nd of May.  It did so shortly after
  the backups start.  chiark's backups are done with LVM snapshots and
  rsync.  I don't any more have information about exactly at what
  stage the backups were at.

* chiark locked up again at 0355 on Sunday morning the 6th of June.
  In this case I was able to see that the system had successfully
  created and mounted the LVM snapshot as the rsync process on the
  backup master system was still present.

* Note that both these two crashes happened on the 1st Sunday of the
  month.  Investigating the kernel logs for the 2nd crash show this:
    Jun  6 00:57:01 chiark kernel: [3250794.079478] md: data-check of RAID array md127
    Jun  6 00:57:01 chiark kernel: [3250794.079479] md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
    Jun  6 00:57:01 chiark kernel: [3250794.079479] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
    Jun  6 00:57:01 chiark kernel: [3250794.079479] md: using 128k window, over a total of 222297980 blocks.
  However there is no sign of it completing.

* Shortly after I power cycled the system to get it back up, it locked
  up again.  At that point, the RAID was doing a post-crash resync,
  and the crash happened at the point where the backup master
  attempted to start on the next partition.

* Some research dug up some reports of first-Sunday-of-the-month
  crashes associated with RAID integrity checks.[1] So I tried setting
  the max IO bandwidth sysctl to the lowest reasonable value (by hand)
  and left the system running.  However, it locked up again as the
  backups started.

* I power cycled the machine again and disabled the backups and made
  sure they were truly stopped.  However chiark locked up again mere
  minutes after coming back up.

* I have now power cycled chiark once more and this time I set the
  max IO bandwidth sysctl.  So far it seems to have stayed up for
  about half an hour.

If nothing more goes wrong I intend to leave the backups disabled
until the RAID finishes its resync, which we can expect to be some
time on Wednesday night.


chiark is running LVM-on-MD-on-LVM.  So the two "disks" which form the
mirror which is resyncing are actually LVM LVs, and that mirror is
itself an LVM PV.  The underlying hardware is a Dell R210 with two
WD SATA disks (WD7500AYPS-0).


[1] https://bugs.launchpad.net/ubuntu/+source/linux/+bug/212684
  seems relevant for example.


Ian.


lvs:

  LV                VG               Attr   LSize   Origin Snap%  Move Log Copy%  Convert
  mirror-base       chiark-early-a   -wi-ao 400.00G
  stripe-base       chiark-early-a   -wi-ao  52.00G
  swap              chiark-early-a   -wi-ao   4.00G
  mirror-base       chiark-early-b   -wi-ao 400.00G
  stripe-base       chiark-early-b   -wi-ao  52.00G
  swap              chiark-early-b   -wi-ao   4.00G
  lv-quicksand      vg-chiark-stripe -wi-ao  40.00G
  twomack-relations vg-chiark-stripe -wi-ao  60.00G
  lv-log            vg-main          -wi-ao   3.00G
  lv-mail           vg-main          -wi-ao   3.00G
  lv-news           vg-main          -wi-ao  15.94G
  lv-root           vg-main          -wi-ao   1.00G
  lv-u              vg-main          -wi-ao   9.75G
  lv-u2             vg-main          -wi-ao  12.25G
  lv-u3             vg-main          -wi-ao   7.06G
  lv-usr            vg-main          -wi-ao   4.12G
  lv-var            vg-main          -wi-ao   5.94G
  lv-volt           vg-main          -wi-ao  77.44G


pvs:

  PV                    VG               Fmt  Attr PSize   PFree 
  /dev/md_chiark-mirror vg-main          lvm2 a-   211.94G 72.44G
  /dev/md_chiark-stripe vg-chiark-stripe lvm2 a-   103.94G  3.94G
  /dev/sdb2             chiark-early-a   lvm2 a-   464.00G  8.00G
  /dev/sdc2             chiark-early-b   lvm2 a-   464.00G  8.00G


/proc/mdstat:

Personalities : [raid0] [raid1] 
md126 : active raid0 dm-2[0] dm-5[1]
      109051776 blocks super 1.1 64k chunks
      
md127 : active raid1 dm-0[3] dm-3[2]
      222297980 blocks super 1.1 [2/2] [UU]
      [>....................]  resync =  0.9% (2014848/222297980) finish=3659.9min speed=1000K/sec


mdadm -D -vv --scan:

/dev/md127:
        Version : 01.01
  Creation Time : Sat Mar  6 20:06:57 2010
     Raid Level : raid1
     Array Size : 222297980 (212.00 GiB 227.63 GB)
  Used Dev Size : 444595960 (424.00 GiB 455.27 GB)
   Raid Devices : 2
  Total Devices : 2
Preferred Minor : 127
    Persistence : Superblock is persistent

    Update Time : Mon Jun  7 10:13:05 2010
          State : active, resyncing
 Active Devices : 2
Working Devices : 2
 Failed Devices : 0
  Spare Devices : 0

 Rebuild Status : 0% complete

           Name : chiark:chiark-mirror  (local to host chiark)
           UUID : [***]
         Events : 9033

    Number   Major   Minor   RaidDevice State
       3     254        0        0      active sync   /dev/dm-0
       2     254        3        1      active sync   /dev/dm-3
/dev/md126:
        Version : 01.01
  Creation Time : Thu Mar 11 13:52:05 2010
     Raid Level : raid0
     Array Size : 109051776 (104.00 GiB 111.67 GB)
   Raid Devices : 2
  Total Devices : 2
Preferred Minor : 126
    Persistence : Superblock is persistent

    Update Time : Mon Jun  7 10:47:15 2010
          State : active
 Active Devices : 2
Working Devices : 2
 Failed Devices : 0
  Spare Devices : 0

     Chunk Size : 64K

           Name : chiark:chiark-stripe  (local to host chiark)
           UUID : [***]
         Events : 5

    Number   Major   Minor   RaidDevice State
       0     254        2        0      active sync   /dev/dm-2
       1     254        5        1      active sync   /dev/dm-5

brw-r----- 1 root disk 254, 0 Jun  7 10:13 /dev/dm-0
brw-r----- 1 root disk 254, 1 Jun  7 10:13 /dev/dm-1
brw-r----- 1 root disk 254, 2 Jun  7 10:13 /dev/dm-2
brw-r----- 1 root disk 254, 3 Jun  7 10:13 /dev/dm-3
brw-r----- 1 root disk 254, 4 Jun  7 10:13 /dev/dm-4
brw-r----- 1 root disk 254, 5 Jun  7 10:13 /dev/dm-5
brw-r----- 1 root disk 254, 6 Jun  7 10:13 /dev/dm-6
brw-r----- 1 root disk 254, 7 Jun  7 10:13 /dev/dm-7
brw-r----- 1 root disk 254, 8 Jun  7 10:13 /dev/dm-8

/dev/mapper/:
total 0
drwxr-xr-x  2 root root     420 Jun  7 10:43 ./
drwxr-xr-x 19 root root    3840 Jun  7 10:43 ../
brw-rw----  1 root disk 254,  0 Jun  7 10:13 chiark--early--a-mirror--base
brw-rw----  1 root disk 254,  2 Jun  7 10:13 chiark--early--a-stripe--base
brw-rw----  1 root disk 254,  1 Jun  7 10:13 chiark--early--a-swap
brw-rw----  1 root disk 254,  3 Jun  7 10:13 chiark--early--b-mirror--base
brw-rw----  1 root disk 254,  5 Jun  7 10:13 chiark--early--b-stripe--base
brw-rw----  1 root disk 254,  4 Jun  7 10:13 chiark--early--b-swap
crw-rw----  1 root root  10, 60 Jun  7 10:13 control
brw-rw----  1 root disk 254, 20 Jun  7 10:13 vg--chiark--stripe-lv--quicksand
brw-rw----  1 root disk 254, 19 Jun  7 10:13 vg--chiark--stripe-twomack--relations
brw-rw----  1 root disk 254,  6 Jun  7 10:13 vg--main-lv--log
brw-rw----  1 root disk 254,  7 Jun  7 10:13 vg--main-lv--mail
brw-rw----  1 root disk 254,  8 Jun  7 10:13 vg--main-lv--news
brw-rw----  1 root disk 254, 18 Jun  7 10:13 vg--main-lv--root
brw-rw----  1 root disk 254, 10 Jun  7 10:13 vg--main-lv--u
brw-rw----  1 root disk 254, 13 Jun  7 10:13 vg--main-lv--u2
brw-rw----  1 root disk 254, 14 Jun  7 10:13 vg--main-lv--u3
brw-rw----  1 root disk 254, 15 Jun  7 10:13 vg--main-lv--usr
brw-rw----  1 root disk 254, 16 Jun  7 10:13 vg--main-lv--var
brw-rw----  1 root disk 254, 17 Jun  7 10:13 vg--main-lv--volt

[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Linux version 2.6.26-2-686-bigmem (Debian 2.6.26-21lenny4) (dannf@debian.org) (gcc version 4.1.3 20080704 (prerelease) (Debian 4.1.2-25)) #1 SMP Tue Mar 9 18:01:52 UTC 2010
[    0.000000] BIOS-provided physical RAM map:
[    0.000000]  BIOS-e820: 0000000000000000 - 000000000009d000 (usable)
[    0.000000]  BIOS-e820: 0000000000100000 - 00000000bf699000 (usable)
[    0.000000]  BIOS-e820: 00000000bf699000 - 00000000bf6af000 (reserved)
[    0.000000]  BIOS-e820: 00000000bf6af000 - 00000000bf6ce000 (ACPI data)
[    0.000000]  BIOS-e820: 00000000bf6ce000 - 00000000c0000000 (reserved)
[    0.000000]  BIOS-e820: 00000000e0000000 - 00000000f0000000 (reserved)
[    0.000000]  BIOS-e820: 00000000fe000000 - 0000000100000000 (reserved)
[    0.000000]  BIOS-e820: 0000000100000000 - 0000000140000000 (usable)
[    0.000000] 4224MB HIGHMEM available.
[    0.000000] 896MB LOWMEM available.
[    0.000000] found SMP MP-table at [c00fe710] 000fe710
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] Entering add_active_range(0, 0, 1310720) 0 entries of 256 used
[    0.000000] Zone PFN ranges:
[    0.000000]   DMA             0 ->     4096
[    0.000000]   Normal       4096 ->   229376
[    0.000000]   HighMem    229376 ->  1310720
[    0.000000] Movable zone start PFN for each node
[    0.000000] early_node_map[1] active PFN ranges
[    0.000000]     0:        0 ->  1310720
[    0.000000] On node 0 totalpages: 1310720
[    0.000000]   DMA zone: 32 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 4064 pages, LIFO batch:0
[    0.000000]   Normal zone: 1760 pages used for memmap
[    0.000000]   Normal zone: 223520 pages, LIFO batch:31
[    0.000000]   HighMem zone: 8448 pages used for memmap
[    0.000000]   HighMem zone: 1072896 pages, LIFO batch:31
[    0.000000]   Movable zone: 0 pages used for memmap
[    0.000000] DMI 2.6 present.
[    0.000000] Using APIC driver default
[    0.000000] ACPI: RSDP 000F0B40, 0024 (r2 DELL  )
[    0.000000] ACPI: XSDT 000F0C40, 0094 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: FACP BF6C3BB4, 00F4 (r3 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: DSDT BF6AF000, 398C (r1 DELL   PE_SC3          1 INTL 20050624)
[    0.000000] ACPI: FACS BF6C6000, 0040
[    0.000000] ACPI: APIC BF6C3478, 0152 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: SPCR BF6C35CC, 0050 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: HPET BF6C3620, 0038 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: DM__ BF6C365C, 00A8 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: MCFG BF6C3850, 003C (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: WD__ BF6C3890, 0134 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: SLIC BF6C39C8, 0024 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: ERST BF6B2B0C, 0270 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: HEST BF6B2D7C, 03A8 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: BERT BF6B298C, 0030 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: EINJ BF6B29BC, 0150 (r1 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: TCPA BF6C3B4C, 0064 (r2 DELL   PE_SC3          1 DELL        1)
[    0.000000] ACPI: SSDT BF6C7000, 2164 (r1  INTEL PPM RCM  80000001 INTL 20061109)
[    0.000000] ACPI: PM-Timer IO Port: 0x808
[    0.000000] ACPI: Local APIC address 0xfee00000
[    0.000000] ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x02] lapic_id[0x02] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x03] lapic_id[0x04] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x04] lapic_id[0x06] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x05] lapic_id[0x01] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x06] lapic_id[0x03] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x07] lapic_id[0x05] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x08] lapic_id[0x07] enabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x09] lapic_id[0x28] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0a] lapic_id[0x29] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0b] lapic_id[0x2a] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0c] lapic_id[0x2b] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0d] lapic_id[0x2c] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0e] lapic_id[0x2d] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x0f] lapic_id[0x2e] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x10] lapic_id[0x2f] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x11] lapic_id[0x30] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x12] lapic_id[0x31] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x13] lapic_id[0x32] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x14] lapic_id[0x33] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x15] lapic_id[0x34] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x16] lapic_id[0x35] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x17] lapic_id[0x36] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x18] lapic_id[0x37] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x19] lapic_id[0x38] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x1a] lapic_id[0x39] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x1b] lapic_id[0x3a] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x1c] lapic_id[0x3b] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x1d] lapic_id[0x3c] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x1e] lapic_id[0x3d] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x1f] lapic_id[0x3e] disabled)
[    0.000000] ACPI: LAPIC (acpi_id[0x20] lapic_id[0x3f] disabled)
[    0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] high edge lint[0x1])
[    0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0])
[    0.000000] IOAPIC[0]: apic_id 0, version 32, address 0xfec00000, GSI 0-23
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[    0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[    0.000000] ACPI: IRQ0 used by override.
[    0.000000] ACPI: IRQ2 used by override.
[    0.000000] ACPI: IRQ9 used by override.
[    0.000000] Enabling APIC mode:  Flat.  Using 1 I/O APICs
[    0.000000] ACPI: HPET id: 0x8086a701 base: 0xfed00000
[    0.000000] Using ACPI (MADT) for SMP configuration information
[    0.000000] Allocating PCI resources starting at c2000000 (gap: c0000000:20000000)
[    0.000000] PM: Registered nosave memory: 000000000009d000 - 0000000000100000
[    0.000000] SMP: Allowing 32 CPUs, 24 hotplug CPUs
[    0.000000] PERCPU: Allocating 42184 bytes of per cpu data
[    0.000000] NR_CPUS: 32, nr_cpu_ids: 32
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 1300480
[    0.000000] Kernel command line: ro root=/dev/vg-main/lv-root console=tty0 console=ttyS0,9600n8 TERM=dumb reboot=bios,smp,warm 
[    0.000000] mapped APIC to ffffb000 (fee00000)
[    0.000000] mapped IOAPIC to ffffa000 (fec00000)
[    0.000000] Enabling fast FPU save and restore... done.
[    0.000000] Enabling unmasked SIMD FPU exception support... done.
[    0.000000] Initializing CPU#0
[    0.000000] PID hash table entries: 4096 (order: 12, 16384 bytes)
[    0.000000] Extended CMOS year: 2000
[    0.000000] Detected 1862.111 MHz processor.
[    0.004000] Console: colour VGA+ 80x25
[    0.004000] console [tty0] enabled
[    0.004000] console [ttyS0] enabled
[    0.004000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.004000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.004000] Memory: 4130168k/5242880k available (1836k kernel code, 53248k reserved, 790k data, 256k init, 3267172k highmem)
[    0.004000] virtual kernel memory layout:
[    0.004000]     fixmap  : 0xffe13000 - 0xfffff000   (1968 kB)
[    0.004000]     pkmap   : 0xffa00000 - 0xffc00000   (2048 kB)
[    0.004000]     vmalloc : 0xf8800000 - 0xff9fe000   ( 113 MB)
[    0.004000]     lowmem  : 0xc0000000 - 0xf8000000   ( 896 MB)
[    0.004000]       .init : 0xc0399000 - 0xc03d9000   ( 256 kB)
[    0.004000]       .data : 0xc02cb06d - 0xc0390ac0   ( 790 kB)
[    0.004000]       .text : 0xc0100000 - 0xc02cb06d   (1836 kB)
[    0.004000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[    0.004000] CPA: page pool initialized 1 of 1 pages preallocated
[    0.004000] hpet clockevent registered
[    0.083864] Calibrating delay using timer specific routine.. 3727.45 BogoMIPS (lpj=7454918)
[    0.092005] Security Framework initialized
[    0.096006] SELinux:  Disabled at boot.
[    0.100006] Capability LSM initialized
[    0.104006] Mount-cache hash table entries: 512
[    0.108006] Initializing cgroup subsys ns
[    0.112007] Initializing cgroup subsys cpuacct
[    0.116007] Initializing cgroup subsys devices
[    0.120007] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.128008] CPU: L2 cache: 256K
[    0.132008] CPU: L3 cache: 8192K
[    0.136008] CPU: Physical Processor ID: 0
[    0.140008] CPU: Processor Core ID: 0
[    0.144009] Intel machine check architecture supported.
[    0.148009] Intel machine check reporting enabled on CPU#0.
[    0.152009] using mwait in idle threads.
[    0.156009] Checking 'hlt' instruction... OK.
[    0.180011] ACPI: Core revision 20080321
[    0.188011] ENABLING IO-APIC IRQs
[    0.192012] ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.235662] CPU0: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.248015] Booting processor 1/2 ip 6000
[    0.260016] Initializing CPU#1
[    0.260016] Calibrating delay using timer specific routine.. 3723.81 BogoMIPS (lpj=7447620)
[    0.260016] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.260016] CPU: L2 cache: 256K
[    0.260016] CPU: L3 cache: 8192K
[    0.260016] CPU: Physical Processor ID: 0
[    0.260016] CPU: Processor Core ID: 1
[    0.260016] Intel machine check architecture supported.
[    0.260016] Intel machine check reporting enabled on CPU#1.
[    0.340021] CPU1: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.352022] checking TSC synchronization [CPU#0 -> CPU#1]: passed.
[    0.356022] Booting processor 2/4 ip 6000
[    0.372023] Initializing CPU#2
[    0.372023] Calibrating delay using timer specific routine.. 3723.81 BogoMIPS (lpj=7447631)
[    0.372023] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.372023] CPU: L2 cache: 256K
[    0.372023] CPU: L3 cache: 8192K
[    0.372023] CPU: Physical Processor ID: 0
[    0.372023] CPU: Processor Core ID: 2
[    0.372023] Intel machine check architecture supported.
[    0.372023] Intel machine check reporting enabled on CPU#2.
[    0.448857] CPU2: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.464029] checking TSC synchronization [CPU#0 -> CPU#2]: passed.
[    0.468029] Booting processor 3/6 ip 6000
[    0.484030] Initializing CPU#3
[    0.484030] Calibrating delay using timer specific routine.. 3723.81 BogoMIPS (lpj=7447636)
[    0.484030] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.484030] CPU: L2 cache: 256K
[    0.484030] CPU: L3 cache: 8192K
[    0.484030] CPU: Physical Processor ID: 0
[    0.484030] CPU: Processor Core ID: 3
[    0.484030] Intel machine check architecture supported.
[    0.484030] Intel machine check reporting enabled on CPU#3.
[    0.560779] CPU3: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.576031] checking TSC synchronization [CPU#0 -> CPU#3]: passed.
[    0.580031] Booting processor 4/1 ip 6000
[    0.596037] Initializing CPU#4
[    0.596037] Calibrating delay using timer specific routine.. 3723.80 BogoMIPS (lpj=7447615)
[    0.596037] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.596037] CPU: L2 cache: 256K
[    0.596037] CPU: L3 cache: 8192K
[    0.596037] CPU: Physical Processor ID: 0
[    0.596037] CPU: Processor Core ID: 0
[    0.596037] Intel machine check architecture supported.
[    0.596037] Intel machine check reporting enabled on CPU#4.
[    0.672947] CPU4: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.688031] checking TSC synchronization [CPU#0 -> CPU#4]: passed.
[    0.692031] Booting processor 5/3 ip 6000
[    0.708044] Initializing CPU#5
[    0.708044] Calibrating delay using timer specific routine.. 3723.81 BogoMIPS (lpj=7447627)
[    0.708044] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.708044] CPU: L2 cache: 256K
[    0.708044] CPU: L3 cache: 8192K
[    0.708044] CPU: Physical Processor ID: 0
[    0.708044] CPU: Processor Core ID: 1
[    0.708044] Intel machine check architecture supported.
[    0.708044] Intel machine check reporting enabled on CPU#5.
[    0.784980] CPU5: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.800038] checking TSC synchronization [CPU#0 -> CPU#5]: passed.
[    0.804038] Booting processor 6/5 ip 6000
[    0.820051] Initializing CPU#6
[    0.820051] Calibrating delay using timer specific routine.. 3723.81 BogoMIPS (lpj=7447636)
[    0.820051] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.820051] CPU: L2 cache: 256K
[    0.820051] CPU: L3 cache: 8192K
[    0.820051] CPU: Physical Processor ID: 0
[    0.820051] CPU: Processor Core ID: 2
[    0.820051] Intel machine check architecture supported.
[    0.820051] Intel machine check reporting enabled on CPU#6.
[    0.896887] CPU6: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    0.912044] checking TSC synchronization [CPU#0 -> CPU#6]: passed.
[    0.916044] Booting processor 7/7 ip 6000
[    0.932058] Initializing CPU#7
[    0.932058] Calibrating delay using timer specific routine.. 3723.81 BogoMIPS (lpj=7447631)
[    0.932058] CPU: L1 I cache: 32K, L1 D cache: 32K
[    0.932058] CPU: L2 cache: 256K
[    0.932058] CPU: L3 cache: 8192K
[    0.932058] CPU: Physical Processor ID: 0
[    0.932058] CPU: Processor Core ID: 3
[    0.932058] Intel machine check architecture supported.
[    0.932058] Intel machine check reporting enabled on CPU#7.
[    1.008795] CPU7: Intel(R) Xeon(R) CPU           L3426  @ 1.87GHz stepping 05
[    1.024052] checking TSC synchronization [CPU#0 -> CPU#7]: passed.
[    1.028052] Brought up 8 CPUs
[    1.032052] Total of 8 processors activated (29794.15 BogoMIPS).
[    1.036052] CPU0 attaching sched-domain:
[    1.036052]  domain 0: span 0,4
[    1.036052]   groups: 0 4
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 0,4 1,5 2,6 3,7
[    1.036052] CPU1 attaching sched-domain:
[    1.036052]  domain 0: span 1,5
[    1.036052]   groups: 1 5
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 1,5 2,6 3,7 0,4
[    1.036052] CPU2 attaching sched-domain:
[    1.036052]  domain 0: span 2,6
[    1.036052]   groups: 2 6
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 2,6 3,7 0,4 1,5
[    1.036052] CPU3 attaching sched-domain:
[    1.036052]  domain 0: span 3,7
[    1.036052]   groups: 3 7
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 3,7 0,4 1,5 2,6
[    1.036052] CPU4 attaching sched-domain:
[    1.036052]  domain 0: span 0,4
[    1.036052]   groups: 4 0
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 0,4 1,5 2,6 3,7
[    1.036052] CPU5 attaching sched-domain:
[    1.036052]  domain 0: span 1,5
[    1.036052]   groups: 5 1
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 1,5 2,6 3,7 0,4
[    1.036052] CPU6 attaching sched-domain:
[    1.036052]  domain 0: span 2,6
[    1.036052]   groups: 6 2
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 2,6 3,7 0,4 1,5
[    1.036052] CPU7 attaching sched-domain:
[    1.036052]  domain 0: span 3,7
[    1.036052]   groups: 7 3
[    1.036052]   domain 1: span 0-7
[    1.036052]    groups: 3,7 0,4 1,5 2,6
[    1.036052] net_namespace: 660 bytes
[    1.040060] Booting paravirtualized kernel on bare hardware
[    1.044060] NET: Registered protocol family 16
[    1.048060] ACPI FADT declares the system doesn't support PCIe ASPM, so disable it
[    1.055393] ACPI: bus type pci registered
[    1.059393] PCI: MCFG configuration 0: base e0000000 segment 0 buses 0 - 255
[    1.063393] PCI: MCFG area at e0000000 reserved in E820
[    1.067393] PCI: Using MMCONFIG for extended config space
[    1.071393] PCI: Using configuration type 1 for base access
[    1.075393] Setting up standard PCI resources
[    1.079393] ACPI: EC: Look up EC in DSDT
[    1.084794] ACPI: BIOS _OSI(Linux) query ignored
[    1.091030] ACPI: DMI System Vendor: Dell Inc.
[    1.095030] ACPI: DMI Product Name: PowerEdge R210
[    1.099030] ACPI: DMI Product Version: 
[    1.103030] ACPI: DMI Board Name: 0M877N
[    1.107030] ACPI: DMI BIOS Vendor: Dell Inc.
[    1.111032] ACPI: DMI BIOS Date: 10/30/2009
[    1.115032] ACPI: Please send DMI info above to linux-acpi@vger.kernel.org
[    1.119032] ACPI: If "acpi_osi=Linux" works better, please notify linux-acpi@vger.kernel.org
[    1.123033] ACPI: Interpreter enabled
[    1.127033] ACPI: (supports S0 S4 S5)
[    1.139034] ACPI: Using IOAPIC for interrupt routing
[    1.150844] ACPI: PCI Root Bridge [PCI0] (0000:00)
[    1.158836] PCI: Transparent bridge - 0000:00:1e.0
[    1.166131] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0._PRT]
[    1.166131] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.LYD0._PRT]
[    1.166131] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.PEX0._PRT]
[    1.166131] ACPI: PCI Interrupt Routing Table [\_SB_.PCI0.COMP._PRT]
[    1.170131] ACPI: PCI Interrupt Link [LK00] (IRQs 3 4 5 6 7 10 11 14 *15)
[    1.200049] ACPI: PCI Interrupt Link [LK01] (IRQs 3 4 5 6 7 10 11 14 15) *0, disabled.
[    1.239241] ACPI: PCI Interrupt Link [LK02] (IRQs 3 4 5 6 7 10 11 14 15) *0, disabled.
[    1.281507] ACPI: PCI Interrupt Link [LK03] (IRQs 3 4 5 6 7 *10 11 14 15)
[    1.313679] ACPI: PCI Interrupt Link [LK04] (IRQs 3 4 5 6 7 10 *11 14 15)
[    1.345937] ACPI: PCI Interrupt Link [LK05] (IRQs 3 4 5 6 7 10 11 14 15) *0, disabled.
[    1.384679] ACPI: PCI Interrupt Link [LK06] (IRQs 3 4 5 6 7 10 11 *14 15)
[    1.420582] ACPI: PCI Interrupt Link [LK07] (IRQs 3 4 5 6 7 10 11 14 15) *0, disabled.
[    1.463236] Linux Plug and Play Support v0.97 (c) Adam Belay
[    1.467236] pnp: PnP ACPI init
[    1.471236] ACPI: bus type pnp registered
[    1.481343] pnp: PnP ACPI: found 13 devices
[    1.485344] ACPI: ACPI bus type pnp unregistered
[    1.489344] PnPBIOS: Disabled by ACPI PNP
[    1.493344] PCI: Using ACPI for IRQ routing
[    1.505352] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0, 0, 0, 0, 0, 0
[    1.581606] hpet0: 8 64-bit timers, 14318180 Hz
[    1.636850] ACPI: RTC can wake from S4
[    1.637508] Switched to high resolution mode on CPU 0
[    1.639335] Switched to high resolution mode on CPU 7
[    1.641058] Switched to high resolution mode on CPU 3
[    1.641096] Switched to high resolution mode on CPU 1
[    1.641096] Switched to high resolution mode on CPU 2
[    1.644899] Switched to high resolution mode on CPU 5
[    1.646400] Switched to high resolution mode on CPU 6
[    1.686592] Switched to high resolution mode on CPU 4
[    1.690619] system 00:07: ioport range 0x800-0x87f has been reserved
[    1.766671] system 00:07: ioport range 0x880-0x8ff has been reserved
[    1.842794] system 00:07: ioport range 0x900-0x91f has been reserved
[    1.918917] system 00:07: ioport range 0x920-0x923 has been reserved
[    1.995040] system 00:07: ioport range 0x924-0x924 has been reserved
[    2.071165] system 00:07: ioport range 0xca0-0xca7 has been reserved
[    2.147289] system 00:07: ioport range 0xca9-0xcab has been reserved
[    2.223411] system 00:07: ioport range 0xcad-0xcaf has been reserved
[    2.299538] system 00:08: ioport range 0xca8-0xca8 has been reserved
[    2.375656] system 00:08: ioport range 0xcac-0xcac has been reserved
[    2.451787] system 00:0a: iomem range 0xe0000000-0xefffffff could not be reserved
[    2.541442] system 00:0c: iomem range 0xfed50000-0xfed53fff could not be reserved
[    2.749565] PCI: Bridge: 0000:00:03.0
[    2.793561]   IO window: f000-ffff
[    2.837572]   MEM window: 0xdf900000-0xdf9fffff
[    2.892592]   PREFETCH window: disabled.
[    2.945573] PCI: Bridge: 0000:00:1c.0
[    2.989382]   IO window: disabled.
[    3.030080]   MEM window: disabled.
[    3.071815]   PREFETCH window: disabled.
[    3.118746] PCI: Bridge: 0000:00:1e.0
[    3.162554]   IO window: disabled.
[    3.203254]   MEM window: 0xde800000-0xdf7fffff
[    3.258049]   PREFETCH window: 0x00000000de000000-0x00000000de7fffff
[    3.334064] ACPI: PCI Interrupt 0000:00:03.0[A] -> GSI 16 (level, low) -> IRQ 16
[    3.437572] PCI: Setting latency timer of device 0000:00:03.0 to 64
[    3.437590] PCI: Setting latency timer of device 0000:00:1c.0 to 64
[    3.437600] PCI: Setting latency timer of device 0000:00:1e.0 to 64
[    3.437653] NET: Registered protocol family 2
[    3.529659] IP route cache hash table entries: 32768 (order: 5, 131072 bytes)
[    3.615173] TCP established hash table entries: 131072 (order: 8, 1048576 bytes)
[    3.704445] TCP bind hash table entries: 65536 (order: 7, 524288 bytes)
[    3.783971] TCP: Hash tables configured (established 131072 bind 65536)
[    3.863107] TCP reno registered
[    3.918800] NET: Registered protocol family 1
[    3.970943] checking if image is initramfs... it is
[    4.596694] Freeing initrd memory: 6602k freed
[    5.358462] audit: initializing netlink socket (disabled)
[    5.658791] type=2000 audit(1275901948.528:1): initialized
[    5.728510] highmem bounce pool size: 64 pages
[    5.780517] Total HugeTLB memory allocated, 0
[    5.834268] VFS: Disk quotas dquot_6.5.1
[    5.905506] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    5.999711] msgmni has been set to 1700
[    6.045670] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    6.237671] io scheduler noop registered
[    6.285670] io scheduler anticipatory registered
[    6.341670] io scheduler deadline registered
[    7.306212] io scheduler cfq registered (default)
[    7.377656] pci 0000:03:03.0: Boot video device
[    7.378704] PCI: Setting latency timer of device 0000:00:03.0 to 64
[    7.378704] assign_interrupt_mode Found MSI capability
[    7.438735] Allocate Port Service[0000:00:03.0:pcie00]
[    7.440386] Allocate Port Service[0000:00:03.0:pcie01]
[    7.440386] PCI: Setting latency timer of device 0000:00:1c.0 to 64
[    7.440386] assign_interrupt_mode Found MSI capability
[    7.926210] Allocate Port Service[0000:00:1c.0:pcie00]
[    7.930302] Load service driver aer on pcie device 0000:00:03.0:pcie01
[    7.930302] isapnp: Scanning for PnP cards...
[    9.103921] isapnp: No Plug & Play device found
[    9.913339] hpet_resources: 0xfed00000 is busy
[    9.913339] Serial: 8250/16550 driver $Revision: 1.90 $ 4 ports, IRQ sharing enabled
[   11.529239] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[   11.601288] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[   11.702619] 00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[   11.776850] 00:06: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[   11.843718] brd: module loaded
[   11.881567] PNP: No PS/2 controller found. Probing ports directly.
[   12.138037] i8042.c: No controller found.
[   12.186909] mice: PS/2 mouse device common for all mice
[   12.251095] rtc_cmos 00:04: rtc core: registered rtc_cmos as rtc0
[   12.324317] rtc0: alarms up to one day, y3k
[   12.377396] cpuidle: using governor ladder
[   12.425401] cpuidle: using governor menu
[   12.473063] No iBFT detected.
[   12.509084] TCP cubic registered
[   12.546220] NET: Registered protocol family 17
[   12.600954] Using IPI No-Shortcut mode
[   12.647114] registered taskstats version 1
[   12.695376] rtc_cmos 00:04: setting system clock to 2010-06-07 09:12:48 UTC (1275901968)
[   12.788310] Freeing unused kernel memory: 256k freed
[   14.538145] Monitor-Mwait will be used to enter C-1 state
[   14.538145] Monitor-Mwait will be used to enter C-2 state
[   14.538145] Monitor-Mwait will be used to enter C-3 state
[   14.538145] ACPI: CPU0 (power states: C1[C1] C2[C2] C3[C3])
[   15.286040] ACPI: ACPI0007:00 is registered as cooling_device0
[   15.356073] ------------[ cut here ]------------
[   15.356073] ACPI: CPU1 (power states: C1[C1] C2[C2] C3[C3])
[   15.356073] ACPI: ACPI0007:01 is registered as cooling_device1
[   15.356073] WARNING: at arch/x86/kernel/hpet.c:299 hpet_legacy_next_event+0x38/0x5a()
[   15.881774] Modules linked in: processor(+) fan thermal_sys
[   15.881774] Pid: 0, comm: swapper Not tainted 2.6.26-2-686-bigmem #1
[   15.881774]  [<c0129147>] warn_on_slowpath+0x40/0x66
[   15.881774]  [<c01e7782>] __next_cpu+0x12/0x21
[   16.081772]  [<c01201f9>] find_busiest_group+0x21e/0x623
[   16.081772]  [<c01192bb>] hpet_legacy_next_event+0x38/0x5a
[   16.081772]  [<c013f68c>] clockevents_program_event+0xc4/0xd2
[   16.081772]  [<c014038e>] tick_dev_program_event+0x1e/0x82
[   16.081772]  [<c013fe14>] tick_broadcast_set_event+0xf/0x11
[   16.081772]  [<c014009e>] tick_broadcast_oneshot_control+0x8a/0xda
[   16.081772]  [<c013fae8>] tick_notify+0x1cd/0x2e3
[   16.081772]  [<c013acaa>] enqueue_hrtimer+0xc9/0xd4
[   16.081772]  [<c013bdd0>] notifier_call_chain+0x2a/0x47
[   16.081772]  [<c013be14>] raw_notifier_call_chain+0x9/0xc
[   16.081772]  [<c013f58c>] clockevents_notify+0x19/0x55
[   16.081772]  [<f8848f1b>] acpi_idle_enter_bm+0x12f/0x315 [processor]
[   16.081772]  [<c025b435>] cpuidle_idle_call+0x5b/0x86
[   16.081772]  [<c025b3da>] cpuidle_idle_call+0x0/0x86
[   16.081772]  [<c01075d3>] cpu_idle+0xb0/0xd0
[   16.081772]  =======================
[   18.026131] ---[ end trace 180ccccd85916810 ]---
[   18.026131] Marking TSC unstable due to: TSC halts in idle.
[   18.026131] ACPI: CPU2 (power states: C1[C1] C2[C2] C3[C3])
[   18.026131] ACPI: ACPI0007:02 is registered as cooling_device2
[   18.033904] ACPI: CPU3 (power states: C1[C1] C2[C2] C3[C3])
[   18.033904] ACPI: ACPI0007:03 is registered as cooling_device3
[   18.033904] ACPI: CPU4 (power states: C1[C1] C2[C2] C3[C3])
[   18.033904] ACPI: ACPI0007:04 is registered as cooling_device4
[   18.033904] ACPI: CPU5 (power states: C1[C1] C2[C2] C3[C3])
[   18.033904] ACPI: ACPI0007:05 is registered as cooling_device5
[   18.033904] ACPI: CPU6 (power states: C1[C1] C2[C2] C3[C3])
[   18.033904] ACPI: ACPI0007:06 is registered as cooling_device6
[   18.035674] ACPI: CPU7 (power states: C1[C1] C2[C2] C3[C3])
[   18.035674] ACPI: ACPI0007:07 is registered as cooling_device7
[   19.910306] e1000e: Intel(R) PRO/1000 Network Driver - 0.3.3.3-k2
[   19.984585] e1000e: Copyright (c) 1999-2008 Intel Corporation.
[   20.056632] ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
[   20.145363] PCI: Setting latency timer of device 0000:01:00.0 to 64
[   20.148015] usbcore: registered new interface driver usbfs
[   20.218805] usbcore: registered new interface driver hub
[   20.282794] usbcore: registered new device driver usb
[   20.348926] No dock devices found.
[   20.434205] SCSI subsystem initialized
[   20.491095] libata version 3.00 loaded.
[   20.515513] eth0: (PCI Express:2.5GB/s:Width x1) 00:1b:21:51:a5:06
[   20.634158] eth0: Intel(R) PRO/1000 Network Connection
[   20.717939] eth0: MAC: 3, PHY: 8, PBA No: e46981-003
[   20.772268] ACPI: PCI Interrupt 0000:00:1a.0[A] -> GSI 22 (level, low) -> IRQ 22
[   20.876293] PCI: Setting latency timer of device 0000:00:1a.0 to 64
[   20.876297] ehci_hcd 0000:00:1a.0: EHCI Host Controller
[   20.940363] ehci_hcd 0000:00:1a.0: new USB bus registered, assigned bus number 1
[   21.096163] ehci_hcd 0000:00:1a.0: debug port 2
[   21.182164] PCI: cache line size of 32 is not supported by device 0000:00:1a.0
[   21.182174] ehci_hcd 0000:00:1a.0: irq 22, io mem 0xdf8fa000
[   21.297066] ehci_hcd 0000:00:1a.0: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
[   21.385254] usb usb1: configuration #1 chosen from 1 choice
[   21.475578] hub 1-0:1.0: USB hub found
[   21.520485] hub 1-0:1.0: 2 ports detected
[   21.674646] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[   21.996465] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[   22.084470] usb usb1: Product: EHCI Host Controller
[   22.142842] usb usb1: Manufacturer: Linux 2.6.26-2-686-bigmem ehci_hcd
[   22.154728] usb 1-1: new high speed USB device using ehci_hcd and address 2
[   22.287166] usb 1-1: configuration #1 chosen from 1 choice
[   22.287166] hub 1-1:1.0: USB hub found
[   22.287229] hub 1-1:1.0: 6 ports detected
[   22.390367] usb 1-1: New USB device found, idVendor=8087, idProduct=0020
[   22.390370] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[   22.630390] usb usb1: SerialNumber: 0000:00:1a.0
[   22.682406] ACPI: PCI Interrupt 0000:00:1d.0[A] -> GSI 22 (level, low) -> IRQ 22
[   23.127469] PCI: Setting latency timer of device 0000:00:1d.0 to 64
[   23.127472] ehci_hcd 0000:00:1d.0: EHCI Host Controller
[   23.187971] ehci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
[   23.287989] ehci_hcd 0000:00:1d.0: debug port 2
[   23.340171] PCI: cache line size of 32 is not supported by device 0000:00:1d.0
[   23.340176] ehci_hcd 0000:00:1d.0: irq 22, io mem 0xdf8fc000
[   23.424255] ehci_hcd 0000:00:1d.0: USB 2.0 started, EHCI 1.00, driver 10 Dec 2004
[   23.513222] usb usb2: configuration #1 chosen from 1 choice
[   23.583141] hub 2-0:1.0: USB hub found
[   23.628706] hub 2-0:1.0: 2 ports detected
[   24.272184] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002
[   24.354065] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[   24.442070] usb usb2: Product: EHCI Host Controller
[   24.500409] usb usb2: Manufacturer: Linux 2.6.26-2-686-bigmem ehci_hcd
[   24.514102] usb 2-1: new high speed USB device using ehci_hcd and address 2
[   24.646523] usb 2-1: configuration #1 chosen from 1 choice
[   24.646523] hub 2-1:1.0: USB hub found
[   24.646589] hub 2-1:1.0: 6 ports detected
[   24.750137] usb 2-1: New USB device found, idVendor=8087, idProduct=0020
[   24.750140] usb 2-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[   24.950222] usb 2-1.5: new high speed USB device using ehci_hcd and address 3
[   25.042490] usb 2-1.5: configuration #1 chosen from 1 choice
[   25.042490] hub 2-1.5:1.0: USB hub found
[   25.042559] hub 2-1.5:1.0: 4 ports detected
[   25.446601] usb 2-1.5: New USB device found, idVendor=0424, idProduct=2514
[   25.446603] usb 2-1.5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[   25.646809] usb 2-1.5.3: new high speed USB device using ehci_hcd and address 4
[   25.742051] usb 2-1.5.3: configuration #1 chosen from 1 choice
[   25.745999] usb 2-1.5.3: New USB device found, idVendor=0951, idProduct=1624
[   25.745999] usb 2-1.5.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[   25.745999] usb 2-1.5.3: Product: DataTraveler G2
[   25.745999] usb 2-1.5.3: Manufacturer: Kingston
[   25.745999] usb 2-1.5.3: SerialNumber: 0014780F9955A9A085EC00BE
[   26.238512] usb usb2: SerialNumber: 0000:00:1d.0
[   26.295652] ahci 0000:00:1f.2: version 3.0
[   26.295652] ACPI: PCI Interrupt 0000:00:1f.2[A] -> GSI 20 (level, low) -> IRQ 20
[   26.685567] Initializing USB Mass Storage driver...
[   26.759632] scsi0 : SCSI emulation for USB Mass Storage devices
[   26.830422] usbcore: registered new interface driver usb-storage
[   26.830422] usb-storage: device found at 4
[   26.830424] usb-storage: waiting for device to settle before scanning
[   26.910949] USB Mass Storage support registered.
[   27.711754] ahci 0000:00:1f.2: AHCI 0001.0300 32 slots 6 ports 3 Gbps 0x3f impl SATA mode
[   27.882626] ahci 0000:00:1f.2: flags: 64bit ncq sntf pm led clo pmp pio slum part 
[   28.059553] PCI: Setting latency timer of device 0000:00:1f.2 to 64
[   28.061471] scsi1 : ahci
[   28.094211] scsi2 : ahci
[   28.125334] scsi3 : ahci
[   28.157198] scsi4 : ahci
[   28.188218] scsi5 : ahci
[   28.236327] scsi6 : ahci
[   28.267975] ata1: SATA max UDMA/133 abar m2048@0xdf8fe000 port 0xdf8fe100 irq 218
[   28.361466] ata2: SATA max UDMA/133 abar m2048@0xdf8fe000 port 0xdf8fe180 irq 218
[   28.451112] ata3: SATA max UDMA/133 abar m2048@0xdf8fe000 port 0xdf8fe200 irq 218
[   28.543119] ata4: SATA max UDMA/133 abar m2048@0xdf8fe000 port 0xdf8fe280 irq 218
[   28.632613] ata5: SATA max UDMA/133 abar m2048@0xdf8fe000 port 0xdf8fe300 irq 218
[   28.722415] ata6: SATA max UDMA/133 abar m2048@0xdf8fe000 port 0xdf8fe380 irq 218
[   29.399603] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[   29.484570] ata1.00: ATA-8: WDC WD7500AYPS-01ZKB1, 02.01B02, max UDMA/133
[   29.565992] ata1.00: 1465149168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   29.652465] ata1.00: configured for UDMA/133
[   30.201114] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[   30.313461] ata2.00: ATA-8: WDC WD7500AYPS-01ZKB1, 02.01B02, max UDMA/133
[   30.405207] ata2.00: 1465149168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[   30.495436] ata2.00: configured for UDMA/133
[   30.874691] ata3: SATA link down (SStatus 0 SControl 300)
[   31.274925] ata4: SATA link down (SStatus 0 SControl 300)
[   31.675161] ata5: SATA link down (SStatus 0 SControl 300)
[   32.285148] ata6: SATA link down (SStatus 0 SControl 300)
[   32.364921] scsi 1:0:0:0: Direct-Access     ATA      WDC WD7500AYPS-0 02.0 PQ: 0 ANSI: 5
[   32.390095] usb-storage: device scan complete
[   32.390095] scsi 0:0:0:0: Direct-Access     Kingston DataTraveler G2  1.00 PQ: 0 ANSI: 2
[   32.901856] Driver 'sd' needs updating - please use bus_type methods
[   32.901856] scsi 2:0:0:0: Direct-Access     ATA      WDC WD7500AYPS-0 02.0 PQ: 0 ANSI: 5
[   33.077904] sd 0:0:0:0: [sda] 7831552 512-byte hardware sectors (4010 MB)
[   33.161033] sd 0:0:0:0: [sda] Write Protect is off
[   33.261524] sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00
[   33.261526] sd 0:0:0:0: [sda] Assuming drive cache: write through
[   33.337817] sd 0:0:0:0: [sda] 7831552 512-byte hardware sectors (4010 MB)
[   33.422891] sd 0:0:0:0: [sda] Write Protect is off
[   33.506633] sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00
[   33.506635] sd 0:0:0:0: [sda] Assuming drive cache: write through
[   33.578786]  sda: sda1
[   33.608932] sd 0:0:0:0: [sda] Attached SCSI removable disk
[   33.677442] sd 1:0:0:0: [sdb] 1465149168 512-byte hardware sectors (750156 MB)
[   33.768455] sd 1:0:0:0: [sdb] Write Protect is off
[   33.825721] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[   33.828492] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   34.037780] sd 1:0:0:0: [sdb] 1465149168 512-byte hardware sectors (750156 MB)
[   34.121780] sd 1:0:0:0: [sdb] Write Protect is off
[   34.121780] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[   34.177781] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   34.285778]  sdb: sdb1 sdb2
[   34.331956] sd 1:0:0:0: [sdb] Attached SCSI disk
[   34.391358] sd 2:0:0:0: [sdc] 1465149168 512-byte hardware sectors (750156 MB)
[   34.486374] sd 2:0:0:0: [sdc] Write Protect is off
[   34.543212] sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
[   34.545753] sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   34.654258] sd 2:0:0:0: [sdc] 1465149168 512-byte hardware sectors (750156 MB)
[   34.837987] sd 2:0:0:0: [sdc] Write Protect is off
[   34.894175] sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
[   34.895577] sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   35.003896]  sdc: sdc1 sdc2
[   35.050156] sd 2:0:0:0: [sdc] Attached SCSI disk
[   35.307708] device-mapper: uevent: version 1.0.3
[   35.383401] device-mapper: ioctl: 4.13.0-ioctl (2007-10-18) initialised: dm-devel@redhat.com
[   35.530895] md: raid0 personality registered for level 0
[   35.609576] md: raid1 personality registered for level 1
[   35.873259] md: md127 stopped.
[   35.991805] md: bind<dm-3>
[   36.030565] md: bind<dm-0>
[   36.079520] md: md127: raid array is not clean -- starting background reconstruction
[   36.204275] raid1: raid set md127 active with 2 out of 2 mirrors
[   36.742716] EXT3-fs: INFO: recovery required on readonly filesystem.
[   36.834254] EXT3-fs: write access will be enabled during recovery.
[   37.375441] md: resync of RAID array md127
[   37.393581] kjournald starting.  Commit interval 5 seconds
[   37.393581] EXT3-fs: recovery complete.
[   37.393778] EXT3-fs: mounted filesystem with ordered data mode.
[   37.763446] md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
[   37.901838] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for resync.
[   37.901843] md: using 128k window, over a total of 222297980 blocks.
[   39.318926] udevd version 125 started
[   39.526894] dcdbas dcdbas: Dell Systems Management Base Driver (version 5.6.0-3.2)
[   39.768006] input: PC Speaker as /class/input/input0
[   39.850320] input: Power Button (FF) as /class/input/input1
[   39.984597] ACPI: Power Button (FF) [PWRF]
[   41.212396] EXT3 FS on dm-18, internal journal
[   41.831114] md: md126 stopped.
[   42.046012] md: bind<dm-5>
[   42.089787] md: bind<dm-2>
[   42.215263] md126: setting max_sectors to 128, segment boundary to 32767
[   42.295225] raid0: looking at dm-2
[   42.335916] raid0:   comparing dm-2(54525888) with dm-2(54525888)
[   42.407836] raid0:   END
[   42.438153] raid0:   ==> UNIQUE
[   42.475739] raid0: 1 zones
[   42.528213] raid0: looking at dm-5
[   42.581001] raid0:   comparing dm-5(54525888) with dm-2(54525888)
[   42.678343] raid0:   EQUAL
[   42.711182] raid0: FINAL 1 zones
[   42.751186] raid0: done.
[   42.781448] raid0 : md_size is 109051776 blocks.
[   42.836906] raid0 : conf->hash_spacing is 109051776 blocks.
[   42.904911] raid0 : nb_zone is 1.
[   42.961486] raid0 : Allocating 4 bytes for hash.
[   73.273813] kjournald starting.  Commit interval 5 seconds
[   73.275108] EXT3 FS on dm-15, internal journal
[   73.275108] EXT3-fs: mounted filesystem with ordered data mode.
[   73.315332] kjournald starting.  Commit interval 5 seconds
[   73.315332] EXT3 FS on dm-16, internal journal
[   73.315332] EXT3-fs: mounted filesystem with ordered data mode.
[   73.379532] kjournald starting.  Commit interval 5 seconds
[   73.380685] EXT3 FS on dm-6, internal journal
[   73.380685] EXT3-fs: mounted filesystem with ordered data mode.
[   73.449358] kjournald starting.  Commit interval 5 seconds
[   73.449358] EXT3 FS on dm-7, internal journal
[   73.449358] EXT3-fs: mounted filesystem with ordered data mode.
[   73.479249] kjournald starting.  Commit interval 5 seconds
[   73.480447] EXT3 FS on dm-8, internal journal
[   73.480447] EXT3-fs: mounted filesystem with ordered data mode.
[   73.525190] kjournald starting.  Commit interval 5 seconds
[   73.525190] EXT3 FS on dm-17, internal journal
[   73.525190] EXT3-fs: mounted filesystem with ordered data mode.
[   73.566757] kjournald starting.  Commit interval 5 seconds
[   73.568562] EXT3 FS on dm-10, internal journal
[   73.568562] EXT3-fs: mounted filesystem with ordered data mode.
[   73.574051] kjournald starting.  Commit interval 5 seconds
[   73.574051] EXT3 FS on dm-13, internal journal
[   73.574051] EXT3-fs: mounted filesystem with ordered data mode.
[   73.611615] kjournald starting.  Commit interval 5 seconds
[   73.611684] EXT3 FS on dm-14, internal journal
[   73.611684] EXT3-fs: mounted filesystem with ordered data mode.
[   73.690197] kjournald starting.  Commit interval 5 seconds
[   73.690197] EXT3 FS on dm-19, internal journal
[   73.690197] EXT3-fs: mounted filesystem with ordered data mode.
[   73.738732] kjournald starting.  Commit interval 5 seconds
[   73.739828] EXT3 FS on dm-20, internal journal
[   73.739828] EXT3-fs: mounted filesystem with ordered data mode.
[   73.786859] Adding 4194296k swap on /dev/mapper/chiark--early--a-swap.  Priority:10 extents:1 across:4194296k
[   73.847214] Adding 4194296k swap on /dev/mapper/chiark--early--b-swap.  Priority:10 extents:1 across:4194296k
[   75.677263] ip_tables: (C) 2000-2006 Netfilter Core Team
[   75.744291] NET: Registered protocol family 10
[   75.744291] lo: Disabled Privacy Extensions
[   75.765697] ip6_tables: (C) 2000-2006 Netfilter Core Team
[   78.125485] ADDRCONF(NETDEV_UP): eth0: link is not ready

Reply to: