Bug 19642 - 2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
Status: CLOSED CODE_FIX
Product: IO/Storage
Classification: Unclassified
Component: MD
All Linux
: P1 normal
Assigned To: io_md
:
Depends on:
Blocks: 16444
  Show dependency treegraph
 
Reported: 2010-10-03 18:37 UTC by Maciej Rutecki
Modified: 2010-10-10 17:27 UTC (History)
9 users (show)

See Also:
Kernel Version: 2.6.36-rc6
Tree: Mainline
Regression: Yes


Attachments

Description Maciej Rutecki 2010-10-03 18:37:01 UTC
Subject    : 2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
Submitter  : "George Spelvin" <linux@horizon.com>
Date       : 2010-09-30 21:10
Message-ID : 20100930211006.27449.qmail@science.horizon.com
References : http://marc.info/?l=linux-kernel&m=128588102620299&w=2

This entry is being used for tracking a regression from 2.6.35. Please don't
close it until the problem is fixed in the mainline.
Comment 1 Anonymous Emailer 2010-10-03 18:53:57 UTC
Reply-To: James.Bottomley@suse.de

On Sun, 2010-10-03 at 18:37 +0000, bugzilla-daemon@bugzilla.kernel.org
wrote:
> https://bugzilla.kernel.org/show_bug.cgi?id=19642
> 
>            Summary: 2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
>            Product: IO/Storage
>            Version: 2.5
>     Kernel Version: 2.6.36-rc6
>           Platform: All
>         OS/Version: Linux
>               Tree: Mainline
>             Status: NEW
>           Severity: normal
>           Priority: P1
>          Component: SCSI
>         AssignedTo: linux-scsi@vger.kernel.org

I think this is wrong.

>         ReportedBy: maciej.rutecki@gmail.com
>                 CC: rjw@sisk.pl, maciej.rutecki@gmail.com,
>                     linux@horizon.com
>         Regression: Yes
> 
> 
> Subject    : 2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
> Submitter  : "George Spelvin" <linux@horizon.com>
> Date       : 2010-09-30 21:10
> Message-ID : 20100930211006.27449.qmail@science.horizon.com
> References : http://marc.info/?l=linux-kernel&m=128588102620299&w=2

That looks like a zero length barrier send down to SCSI with the RW flag
set (hence we try to map a buffer that has nothing to map).  I cc'd
dm-devel to see what their opinion is.

James
Comment 2 Mike Snitzer 2010-10-03 22:12:53 UTC
On Sun, Oct 03 2010 at  2:53pm -0400,
James Bottomley <James.Bottomley@suse.de> wrote:

> On Sun, 2010-10-03 at 18:37 +0000, bugzilla-daemon@bugzilla.kernel.org
> wrote:
> > https://bugzilla.kernel.org/show_bug.cgi?id=19642
> > 
> >            Summary: 2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
> >            Product: IO/Storage
> >            Version: 2.5
> >     Kernel Version: 2.6.36-rc6
> >           Platform: All
> >         OS/Version: Linux
> >               Tree: Mainline
> >             Status: NEW
> >           Severity: normal
> >           Priority: P1
> >          Component: SCSI
> >         AssignedTo: linux-scsi@vger.kernel.org
> 
> I think this is wrong.
> 
> >         ReportedBy: maciej.rutecki@gmail.com
> >                 CC: rjw@sisk.pl, maciej.rutecki@gmail.com,
> >                     linux@horizon.com
> >         Regression: Yes
> > 
> > 
> > Subject    : 2.6.36-rc6 BUG at drivers/scsi/scsi_lib.c:1113
> > Submitter  : "George Spelvin" <linux@horizon.com>
> > Date       : 2010-09-30 21:10
> > Message-ID : 20100930211006.27449.qmail@science.horizon.com
> > References : http://marc.info/?l=linux-kernel&m=128588102620299&w=2
> 
> That looks like a zero length barrier send down to SCSI with the RW flag
> set (hence we try to map a buffer that has nothing to map).  I cc'd
> dm-devel to see what their opinion is.

Given that the referenced LKML report is MD focused it seems linux-raid
should be cc'd instead (doing so now).

Mike
Comment 3 Nicholas A. Bellinger 2010-10-04 06:38:15 UTC
Hi guys,

So what appears to be happening is:

drivers/md/md.c:submit_barriers() uses bio_submit(WRITE_BARRIER, bh)
to signal an explict underlying libata-scsi.c SYNCHRONIZE_CACHE -> ATA_CMD_FLUSH
translation for a ULP write barrier op.  For the specific case of SATA hw and MD backstores with libata.fua=1 using WRITE_BARRIER and struct request which should call:

           *) drivers/scsi/sd.c:sd_prep_fn() w/ (rq->cmd_flags & REQ_FLUSH) to 
              setup the SYNCHRONIZE_CACHE struct scsi_cmd
           *) call scsi_setup_flush_cmnd() -> scsi_setup_blk_pc_cmnd()

which instead in .36-rc6 is calling:


           *) drivers/scsi/sd.c:sd_prep_fn() -> scsi_setup_fs_cmnd() with a zero struct request->nr_phys_segments

to trigger the BUG_ON() reported by George here.  The original bogus DMA_TO_DEVICE assignment for struct scsi_cmd w/ SYNCHRONIZE_CACHE to be set in sd_pred_fn() with the following code:

       <SNIP>

       if (rq_data_dir(rq) == WRITE) {
                if (!sdp->writeable) {
                        goto out;
                }
                SCpnt->cmnd[0] = WRITE_6;
                SCpnt->sc_data_direction = DMA_TO_DEVICE;

                if (blk_integrity_rq(rq) &&
                    sd_dif_prepare(rq, block, sdp->sector_size) == -EIO)
                        goto out;

        } else if (rq_data_dir(rq) == READ) {

        <SNIP>

From there the DMA_TO_DEVICE with (rd_data_dir(rq) == WRITE) and causing libata scsi.c:__ata_scsi_queuecmd() to incorrectly call ata_scsi_translate() instead of ata_scsi_simulate() for a WRITE_BARRIER bio.

So the main issue appears to be that sd_pref_fn() -> (rq->cmd_flags & REQ_FLUSH)
conditional is not returning TRUE from the original drivers/md/md.c:
submit_barrier() -> submit_bio(WRITE_BARRIER, bh) code to call a properscsi_setup_flush_cmnd() -> scsi_setup_blk_pc_cmnd().  So that seems to indicate the main issue being that WRITE_BARRIER bios needs to ensure that  sd_prep_fn() -> scsi_setup_flush_cmnd() always gets called, yes..?
Comment 4 Tejun Heo 2010-10-04 08:55:28 UTC
Hello, sorry about the delay.  I was off the last week.  I'm still not quite sure what's going on.  The problem here seems to be in the barrier code rather than libata or scsi.  It shouldn't be sending down an empty write request w/o REQ_FLUSH set for a barrier request but I don't seem to recall any change which could have caused this behavior difference.

* Is this a regression?

* Does this always happen with libata.fua=1?  Does it go away w/o it?

Thanks.
Comment 5 linux 2010-10-04 17:52:52 UTC
Tejun Heo <tj@kernel.org> wrote:
> Just in case, can you please do "make mrproper" and then rebuild the
> kernel?  The only thing I can think of now is mismatching flag bits
> due to partial rebuild (unfortunately those flag bits have been hard
> coded duplicately in different places, they're being cleaned up).

Done.  No change (kernel log attached).  I've also attached the
(non-comment part of) .config in case that's of any use.

15:55:08: klogd 1.5.0#6, log source = /proc/kmsg started.
15:55:08: Linux version 2.6.36-rc6-00070-g44c064a ($USER@$HOST) (gcc version 4.4.5 (Debian 4.4.4-17) ) #1 SMP Mon Oct 4 11:27:16 EDT 2010
15:55:08: Command line: BOOT_IMAGE=Single-user ro root=907 libata.fua=0 tsc_khz=2500210 amd64_edac_mod.ecc_enable_override=1 acpi_enforce_resources=lax k10temp.force=1 single libata.fua=1
15:55:08: BIOS-provided physical RAM map:
15:55:08:  BIOS-e820: 0000000000000000 - 0000000000093800 (usable)
15:55:08:  BIOS-e820: 0000000000093800 - 00000000000a0000 (reserved)
15:55:08:  BIOS-e820: 00000000000e4000 - 0000000000100000 (reserved)
15:55:08:  BIOS-e820: 0000000000100000 - 00000000dffa0000 (usable)
15:55:08:  BIOS-e820: 00000000dffc0000 - 00000000dffce000 (ACPI data)
15:55:08:  BIOS-e820: 00000000dffce000 - 00000000dfff0000 (ACPI NVS)
15:55:08:  BIOS-e820: 00000000dfff0000 - 00000000dfffe000 (reserved)
15:55:08:  BIOS-e820: 00000000fff00000 - 0000000100000000 (reserved)
15:55:08:  BIOS-e820: 0000000100000000 - 0000000220000000 (usable)
15:55:08: NX (Execute Disable) protection: active
15:55:08: DMI present.
15:55:08: No AGP bridge found
15:55:08: last_pfn = 0x220000 max_arch_pfn = 0x400000000
15:55:08: x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
15:55:08: last_pfn = 0xdffa0 max_arch_pfn = 0x400000000
15:55:08: found SMP MP-table at [ffff8800000ff780] ff780
15:55:08: Using GB pages for direct mapping
15:55:08: init_memory_mapping: 0000000000000000-00000000dffa0000
15:55:08: init_memory_mapping: 0000000100000000-0000000220000000
15:55:08: ACPI: RSDP 00000000000f9e30 00014 (v00 ACPIAM)
15:55:08: ACPI: RSDT 00000000dffc0000 00038 (v01 011309 RSDT1044 20090113 MSFT 00000097)
15:55:08: ACPI: FACP 00000000dffc0200 00084 (v02 011309 FACP1044 20090113 MSFT 00000097)
15:55:08: ACPI: DSDT 00000000dffc0440 06E9B (v01  1ADNC 1ADNC001 00000001 INTL 20051117)
15:55:08: ACPI: FACS 00000000dffce000 00040
15:55:08: ACPI: APIC 00000000dffc0390 0006C (v01 011309 APIC1044 20090113 MSFT 00000097)
15:55:08: ACPI: MCFG 00000000dffc0400 0003C (v01 011309 OEMMCFG  20090113 MSFT 00000097)
15:55:08: ACPI: OEMB 00000000dffce040 00071 (v01 011309 OEMB1044 20090113 MSFT 00000097)
15:55:08: ACPI: HPET 00000000dffc72e0 00038 (v01 011309 OEMHPET  20090113 MSFT 00000097)
15:55:08: (11/32 early reservations) ==> bootmem [0000000000 - 0220000000]
15:55:08:   #0 [0001000000 - 0001798334]    TEXT DATA BSS ==> [0001000000 - 0001798334]
15:55:08:   #1 [0001799000 - 00017991b8]              BRK ==> [0001799000 - 00017991b8]
15:55:08:   #2 [00000ff790 - 0000100000]    BIOS reserved ==> [00000ff790 - 0000100000]
15:55:08:   #3 [00000ff780 - 00000ff790]     MP-table mpf ==> [00000ff780 - 00000ff790]
15:55:08:   #4 [0000093800 - 00000fd190]    BIOS reserved ==> [0000093800 - 00000fd190]
15:55:08:   #5 [00000fd334 - 00000ff780]    BIOS reserved ==> [00000fd334 - 00000ff780]
15:55:08:   #6 [00000fd190 - 00000fd334]     MP-table mpc ==> [00000fd190 - 00000fd334]
15:55:08:   #7 [0000001000 - 0000003000]       TRAMPOLINE ==> [0000001000 - 0000003000]
15:55:08:   #8 [0000008000 - 000000a000]          PGTABLE ==> [0000008000 - 000000a000]
15:55:08:   #9 [000000a000 - 000000b000]          PGTABLE ==> [000000a000 - 000000b000]
15:55:08:   #10 [000000b000 - 000004f000]          BOOTMAP ==> [000000b000 - 000004f000]
15:55:08: Zone PFN ranges:
15:55:08:   DMA      0x00000001 -> 0x00001000
15:55:08:   DMA32    0x00001000 -> 0x00100000
15:55:08:   Normal   0x00100000 -> 0x00220000
15:55:08: Movable zone start PFN for each node
15:55:08: early_node_map[3] active PFN ranges
15:55:08:     0: 0x00000001 -> 0x00000093
15:55:08:     0: 0x00000100 -> 0x000dffa0
15:55:08:     0: 0x00100000 -> 0x00220000
15:55:08: ACPI: PM-Timer IO Port: 0x808
15:55:08: ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
15:55:08: ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
15:55:08: ACPI: LAPIC (acpi_id[0x03] lapic_id[0x02] enabled)
15:55:08: ACPI: LAPIC (acpi_id[0x04] lapic_id[0x03] enabled)
15:55:08: ACPI: IOAPIC (id[0x04] address[0xfec00000] gsi_base[0])
15:55:08: IOAPIC[0]: apic_id 4, version 33, address 0xfec00000, GSI 0-23
15:55:08: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
15:55:08: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 low level)
15:55:08: Using ACPI (MADT) for SMP configuration information
15:55:08: ACPI: HPET id: 0x8300 base: 0xfed00000
15:55:08: SMP: Allowing 4 CPUs, 0 hotplug CPUs
15:55:08: Allocating PCI resources starting at dfffe000 (gap: dfffe000:1ff02000)
15:55:08: setup_percpu: NR_CPUS:4 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1
15:55:08: PERCPU: Embedded 26 pages/cpu @ffff880028200000 s77632 r8192 d20672 u524288
15:55:08: pcpu-alloc: s77632 r8192 d20672 u524288 alloc=1*2097152
15:55:08: pcpu-alloc: [0] 0 1 2 3 
15:55:08: Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 2066302
15:55:08: Kernel command line: BOOT_IMAGE=Single-user ro root=907 libata.fua=0 tsc_khz=2500210 amd64_edac_mod.ecc_enable_override=1 acpi_enforce_resources=lax k10temp.force=1 single libata.fua=1
15:55:08: PID hash table entries: 4096 (order: 3, 32768 bytes)
15:55:08: Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes)
15:55:08: Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes)
15:55:08: Checking aperture...
15:55:08: No AGP bridge found
15:55:08: Node 0: aperture @ 20000000 size 32 MB
15:55:08: Aperture pointing to e820 RAM. Ignoring.
15:55:08: Your BIOS doesn't leave a aperture memory hole
15:55:08: Please enable the IOMMU option in the BIOS setup
15:55:08: This costs you 64 MB of RAM
15:55:08: Mapping aperture over 65536 KB of RAM @ 20000000
15:55:08: Memory: 8118784k/8912896k available (4071k kernel code, 525112k absent, 269000k reserved, 2734k data, 492k init)
15:55:08: SLUB: Genslabs=13, HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
15:55:08: Hierarchical RCU implementation.
15:55:08: ^IRCU-based detection of stalled CPUs is disabled.
15:55:08: ^IVerbose stalled-CPUs detection is disabled.
15:55:08: NR_IRQS:384
15:55:08: Console: colour VGA+ 80x25
15:55:08: console [tty0] enabled
15:55:08: Fast TSC calibration failed
15:55:08: TSC: Unable to calibrate against PIT
15:55:08: TSC: using HPET reference calibration
15:55:08: Using user defined TSC freq: 2500.210 MHz
15:55:08: Detected 2500.213 MHz processor.
15:55:08: Calibrating delay loop (skipped), value calculated using timer frequency.. 5000.42 BogoMIPS (lpj=25002100)
15:55:08: pid_max: default: 32768 minimum: 301
15:55:08: Mount-cache hash table entries: 256
15:55:08: CPU: Physical Processor ID: 0
15:55:08: CPU: Processor Core ID: 0
15:55:08: mce: CPU supports 6 MCE banks
15:55:08: using C1E aware idle routine
15:55:08: Performance Events: AMD PMU driver.
15:55:08: ... version:                0
15:55:08: ... bit width:              48
15:55:08: ... generic registers:      4
15:55:08: ... value mask:             0000ffffffffffff
15:55:08: ... max period:             00007fffffffffff
15:55:08: ... fixed-purpose events:   0
15:55:08: ... event mask:             000000000000000f
15:55:08: Freeing SMP alternatives: 20k freed
15:55:08: ACPI: Core revision 20100702
15:55:08: Setting APIC routing to flat
15:55:08: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
15:55:08: CPU0: AMD Phenom(tm) 9850 Quad-Core Processor stepping 03
15:55:08: NMI watchdog enabled, takes one hw-pmu counter.
15:55:08: Booting Node   0, Processors  #1
15:55:08: NMI watchdog enabled, takes one hw-pmu counter.
15:55:08: System has AMD C1E enabled
15:55:08: Switch to broadcast mode on CPU1
15:55:08:  #2
15:55:08: NMI watchdog enabled, takes one hw-pmu counter.
15:55:08: Switch to broadcast mode on CPU2
15:55:08:  #3 Ok.
15:55:08: NMI watchdog enabled, takes one hw-pmu counter.
15:55:08: Switch to broadcast mode on CPU3
15:55:08: Brought up 4 CPUs
15:55:08: Total of 4 processors activated (20001.68 BogoMIPS).
15:55:08: Switch to broadcast mode on CPU0
15:55:08: xor: automatically using best checksumming function: generic_sse
15:55:08:    generic_sse:  9959.200 MB/sec
15:55:08: xor: using function: generic_sse (9959.200 MB/sec)
15:55:08: NET: Registered protocol family 16
15:55:08: TOM: 00000000e0000000 aka 3584M
15:55:08: TOM2: 0000000220000000 aka 8704M
15:55:08: ACPI: bus type pci registered
15:55:08: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xe0000000-0xefffffff] (base 0xe0000000)
15:55:08: PCI: not using MMCONFIG
15:55:08: PCI: Using configuration type 1 for base access
15:55:08: PCI: Using configuration type 1 for extended access
15:55:08: bio: create slab <bio-0> at 0
15:55:08: raid6: int64x1   2443 MB/s
15:55:08: raid6: int64x2   2760 MB/s
15:55:08: raid6: int64x4   2030 MB/s
15:55:08: raid6: int64x8   1760 MB/s
15:55:08: raid6: sse2x1    3376 MB/s
15:55:08: raid6: sse2x2    5731 MB/s
15:55:08: raid6: sse2x4    7039 MB/s
15:55:08: raid6: using algorithm sse2x4 (7039 MB/s)
15:55:08: ACPI: Executed 3 blocks of module-level executable AML code
15:55:08: ACPI: Interpreter enabled
15:55:08: ACPI: (supports S0 S5)
15:55:08: ACPI: Using IOAPIC for interrupt routing
15:55:08: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xe0000000-0xefffffff] (base 0xe0000000)
15:55:08: PCI: MMCONFIG at [mem 0xe0000000-0xefffffff] reserved in ACPI motherboard resources
15:55:08: ACPI Warning: Incorrect checksum in table [OEMB] - 0xDD, should be 0xD4 (20100702/tbutils-314)
15:55:08: ACPI: No dock devices found.
15:55:08: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
15:55:08: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
15:55:08: pci_root PNP0A03:00: host bridge window [io  0x0000-0x0cf7]
15:55:08: pci_root PNP0A03:00: host bridge window [io  0x0d00-0xffff]
15:55:08: pci_root PNP0A03:00: host bridge window [mem 0x000a0000-0x000bffff]
15:55:08: pci_root PNP0A03:00: host bridge window [mem 0x000d0000-0x000dffff]
15:55:08: pci_root PNP0A03:00: host bridge window [mem 0xf0000000-0xfebfffff]
15:55:08: pci 0000:01:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
15:55:08: pci 0000:00:03.0: PCI bridge to [bus 01-01]
15:55:08: pci 0000:02:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
15:55:08: pci 0000:00:04.0: PCI bridge to [bus 02-02]
15:55:08: pci 0000:03:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
15:55:08: pci 0000:00:05.0: PCI bridge to [bus 03-03]
15:55:08: pci 0000:04:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
15:55:08: pci 0000:00:09.0: PCI bridge to [bus 04-04]
15:55:08: pci 0000:05:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
15:55:08: pci 0000:00:0b.0: PCI bridge to [bus 05-05]
15:55:08: pci 0000:00:14.4: PCI bridge to [bus 06-06] (subtractive decode)
15:55:08: ACPI: PCI Interrupt Link [LNKA] (IRQs 3 4 5 7 10 *11 12 14 15)
15:55:08: ACPI: PCI Interrupt Link [LNKB] (IRQs 3 4 *5 7 10 11 12 14 15)
15:55:08: ACPI: PCI Interrupt Link [LNKC] (IRQs *3 4 5 7 10 11 12 14 15)
15:55:08: ACPI: PCI Interrupt Link [LNKD] (IRQs 3 4 5 7 *10 11 12 14 15)
15:55:08: ACPI: PCI Interrupt Link [LNKE] (IRQs 3 4 5 7 10 11 12 14 15) *0, disabled.
15:55:08: ACPI: PCI Interrupt Link [LNKF] (IRQs *9)
15:55:08: ACPI: PCI Interrupt Link [LNKG] (IRQs 3 4 5 7 10 11 12 14 *15)
15:55:08: ACPI: PCI Interrupt Link [LNKH] (IRQs 3 4 5 *7 10 11 12 14 15)
15:55:08: HEST: Table is not found!
15:55:08: vgaarb: device added: PCI:0000:05:00.0,decodes=io+mem,owns=io+mem,locks=none
15:55:08: vgaarb: loaded
15:55:08: SCSI subsystem initialized
15:55:08: usbcore: registered new interface driver usbfs
15:55:08: usbcore: registered new interface driver hub
15:55:08: usbcore: registered new device driver usb
15:55:08: PCI: Using ACPI for IRQ routing
15:55:08: pci 0000:00:00.0: no compatible bridge window for [mem 0xe0000000-0xffffffff 64bit]
15:55:08: hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0, 0
15:55:08: hpet0: 4 comparators, 32-bit 14.318180 MHz counter
15:55:08: Switching to clocksource tsc
15:55:08: pnp: PnP ACPI init
15:55:08: ACPI: bus type pnp registered
15:55:08: pnp 00:0e: disabling [mem 0x00000000-0x0009ffff] because it overlaps 0000:00:00.0 BAR 3 [mem 0x00000000-0x1fffffff 64bit]
15:55:08: pnp 00:0e: disabling [mem 0x000c0000-0x000cffff] because it overlaps 0000:00:00.0 BAR 3 [mem 0x00000000-0x1fffffff 64bit]
15:55:08: pnp 00:0e: disabling [mem 0x000e0000-0x000fffff] because it overlaps 0000:00:00.0 BAR 3 [mem 0x00000000-0x1fffffff 64bit]
15:55:08: pnp 00:0e: disabling [mem 0x00100000-0xdfffffff] because it overlaps 0000:00:00.0 BAR 3 [mem 0x00000000-0x1fffffff 64bit]
15:55:08: pnp: PnP ACPI: found 15 devices
15:55:08: ACPI: ACPI bus type pnp unregistered
15:55:08: system 00:08: [mem 0xfec00000-0xfec00fff] could not be reserved
15:55:08: system 00:08: [mem 0xfee00000-0xfee00fff] has been reserved
15:55:08: system 00:09: [io  0x04d0-0x04d1] has been reserved
15:55:08: system 00:09: [io  0x040b] has been reserved
15:55:08: system 00:09: [io  0x04d6] has been reserved
15:55:08: system 00:09: [io  0x0c00-0x0c01] has been reserved
15:55:08: system 00:09: [io  0x0c14] has been reserved
15:55:08: system 00:09: [io  0x0c50-0x0c51] has been reserved
15:55:08: system 00:09: [io  0x0c52] has been reserved
15:55:08: system 00:09: [io  0x0c6c] has been reserved
15:55:08: system 00:09: [io  0x0c6f] has been reserved
15:55:08: system 00:09: [io  0x0cd0-0x0cd1] has been reserved
15:55:08: system 00:09: [io  0x0cd2-0x0cd3] has been reserved
15:55:08: system 00:09: [io  0x0cd4-0x0cd5] has been reserved
15:55:08: system 00:09: [io  0x0cd6-0x0cd7] has been reserved
15:55:08: system 00:09: [io  0x0cd8-0x0cdf] has been reserved
15:55:08: system 00:09: [io  0x0800-0x089f] has been reserved
15:55:08: system 00:09: [io  0x0b10-0x0b1f] has been reserved
15:55:08: system 00:09: [io  0x0900-0x090f] has been reserved
15:55:08: system 00:09: [io  0x0910-0x091f] has been reserved
15:55:08: system 00:09: [io  0xfe00-0xfefe] has been reserved
15:55:08: system 00:09: [mem 0xffb80000-0xffbfffff] has been reserved
15:55:08: system 00:0c: [io  0x0600-0x06df] has been reserved
15:55:08: system 00:0c: [io  0x0ae0-0x0aef] has been reserved
15:55:08: system 00:0d: [mem 0xe0000000-0xefffffff] has been reserved
15:55:08: system 00:0e: [mem 0xfec00000-0xffffffff] could not be reserved
15:55:08: pci 0000:00:03.0: PCI bridge to [bus 01-01]
15:55:08: pci 0000:00:03.0:   bridge window [io  0x7000-0x7fff]
15:55:08: pci 0000:00:03.0:   bridge window [mem 0xfe600000-0xfe6fffff]
15:55:08: pci 0000:00:03.0:   bridge window [mem pref disabled]
15:55:08: pci 0000:00:04.0: PCI bridge to [bus 02-02]
15:55:08: pci 0000:00:04.0:   bridge window [io  0x8000-0x8fff]
15:55:08: pci 0000:00:04.0:   bridge window [mem 0xfe700000-0xfe7fffff]
15:55:08: pci 0000:00:04.0:   bridge window [mem pref disabled]
15:55:08: pci 0000:00:05.0: PCI bridge to [bus 03-03]
15:55:08: pci 0000:00:05.0:   bridge window [io  0x9000-0x9fff]
15:55:08: pci 0000:00:05.0:   bridge window [mem 0xfe800000-0xfe8fffff]
15:55:08: pci 0000:00:05.0:   bridge window [mem pref disabled]
15:55:08: pci 0000:00:09.0: PCI bridge to [bus 04-04]
15:55:08: pci 0000:00:09.0:   bridge window [io  0xa000-0xafff]
15:55:08: pci 0000:00:09.0:   bridge window [mem 0xfe900000-0xfe9fffff]
15:55:08: pci 0000:00:09.0:   bridge window [mem pref disabled]
15:55:08: pci 0000:00:0b.0: PCI bridge to [bus 05-05]
15:55:08: pci 0000:00:0b.0:   bridge window [io  0xb000-0xbfff]
15:55:08: pci 0000:00:0b.0:   bridge window [mem 0xfea00000-0xfeafffff]
15:55:08: pci 0000:00:0b.0:   bridge window [mem 0xfc000000-0xfdffffff 64bit pref]
15:55:08: pci 0000:00:14.4: PCI bridge to [bus 06-06]
15:55:08: pci 0000:00:14.4:   bridge window [io  0xc000-0xefff]
15:55:08: pci 0000:00:14.4:   bridge window [mem 0xfeb00000-0xfebfffff]
15:55:08: pci 0000:00:14.4:   bridge window [mem pref disabled]
15:55:08: pci 0000:00:03.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
15:55:08: pci 0000:00:04.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
15:55:08: pci 0000:00:05.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
15:55:08: pci 0000:00:09.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
15:55:08: pci 0000:00:0b.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
15:55:08: NET: Registered protocol family 2
15:55:08: IP route cache hash table entries: 262144 (order: 9, 2097152 bytes)
15:55:08: TCP established hash table entries: 262144 (order: 10, 4194304 bytes)
15:55:08: TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
15:55:08: TCP: Hash tables configured (established 262144 bind 65536)
15:55:08: TCP reno registered
15:55:08: UDP hash table entries: 4096 (order: 5, 131072 bytes)
15:55:08: UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes)
15:55:08: NET: Registered protocol family 1
15:55:08: RPC: Registered udp transport module.
15:55:08: RPC: Registered tcp transport module.
15:55:08: RPC: Registered tcp NFSv4.1 backchannel transport module.
15:55:08: PCI-DMA: Disabling AGP.
15:55:08: PCI-DMA: aperture base @ 20000000 size 65536 KB
15:55:08: PCI-DMA: using GART IOMMU.
15:55:08: PCI-DMA: Reserving 64MB of IOMMU area in the AGP aperture
15:55:08: Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
15:55:08: msgmni has been set to 15985
15:55:08: alg: No test for stdrng (krng)
15:55:08: io scheduler noop registered
15:55:08: io scheduler deadline registered
15:55:08: io scheduler cfq registered (default)
15:55:08: radeonfb 0000:05:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
15:55:08: radeonfb: Found Intel x86 BIOS ROM Image
15:55:08: radeonfb: Retrieved PLL infos from BIOS
15:55:08: radeonfb: Reference=27.00 MHz (RefDiv=12) Memory=325.00 Mhz, System=296.00 MHz
15:55:08: radeonfb: PLL min 20000 max 40000
15:55:08: i2c i2c-1: unable to read EDID block.
15:55:08: radeonfb: Monitor 1 type CRT found
15:55:08: radeonfb: EDID probed
15:55:08: radeonfb: Monitor 2 type no found
15:55:08: Console: switching to colour frame buffer device 128x48
15:55:08: radeonfb (0000:05:00.0): ATI Radeon 5b60 "[`"
15:55:08: input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input0
15:55:08: ACPI: Power Button [PWRB]
15:55:08: input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input1
15:55:08: ACPI: Power Button [PWRF]
15:55:08: ACPI: duty_cycle spans bit 4
15:55:08: ACPI: processor limited to max C-state 1
15:55:08: ERST: Table is not found!
15:55:08: Linux agpgart interface v0.103
15:55:08: Hangcheck: starting hangcheck timer 0.9.1 (tick is 180 seconds, margin is 60 seconds).
15:55:08: Hangcheck: Using getrawmonotonic().
15:55:08: [drm] Initialized drm 1.1.0 20060810
15:55:08: [drm] radeon defaulting to userspace modesetting.
15:55:08: [drm] Initialized radeon 1.33.0 20080528 for 0000:05:00.0 on minor 0
15:55:08: Floppy drive(s): fd0 is 1.44M
15:55:08: FDC 0 is a post-1991 82077
15:55:08: brd: module loaded
15:55:08: loop: module loaded
15:55:08: Uniform Multi-Platform E-IDE driver
15:55:08: atiixp 0000:00:14.1: IDE controller (0x1002:0x438c rev 0x00)
15:55:08: pci 0000:00:14.1: PCI INT A -> GSI 16 (level, low) -> IRQ 16
15:55:08: atiixp 0000:00:14.1: not 100% native mode: will probe irqs later
15:55:08:     ide0: BM-DMA at 0xff00-0xff07
15:55:08: hdb: _NEC DVD+/-RW ND-6650A, ATAPI CD/DVD-ROM drive
15:55:08: hdb: UDMA/33 mode selected
15:55:08: ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
15:55:08: ide_generic: please use "probe_mask=0x3f" module parameter for probing all legacy ISA IDE ports
15:55:08: ide-gd driver 1.18
15:55:08: ide-cd driver 5.00
15:55:08: ide-cd: hdb: ATAPI 24X DVD-ROM DVD-R CD-R/RW drive, 2048kB Cache
15:55:08: cdrom: Uniform CD-ROM driver Revision: 3.20
15:55:08: ahci 0000:00:12.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
15:55:08: ahci 0000:00:12.0: MSI K9A2 Platinum: enabling 64bit DMA
15:55:08: ahci 0000:00:12.0: AHCI 0001.0100 32 slots 4 ports 3 Gbps 0xf impl SATA mode
15:55:08: ahci 0000:00:12.0: flags: 64bit ncq sntf ilck pm led clo pmp pio slum part ccc 
15:55:08: scsi0 : ahci
15:55:08: scsi1 : ahci
15:55:08: scsi2 : ahci
15:55:08: scsi3 : ahci
15:55:08: ata1: SATA max UDMA/133 irq_stat 0x00400040, connection status changed irq 22
15:55:08: ata2: SATA max UDMA/133 irq_stat 0x00400040, connection status changed irq 22
15:55:08: ata3: SATA max UDMA/133 irq_stat 0x00400040, connection status changed irq 22
15:55:08: ata4: SATA max UDMA/133 abar m1024@0xfe5ff800 port 0xfe5ffa80 irq 22
15:55:08: ahci 0000:04:00.0: PDC42819 can only drive SATA devices with this driver
15:55:08: ahci 0000:04:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
15:55:08: ahci 0000:04:00.0: AHCI 0001.0100 32 slots 4 ports 3 Gbps 0xf impl RAID mode
15:55:08: ahci 0000:04:00.0: flags: 64bit ncq sntf ilck pm led clo pmp pio slum part ccc 
15:55:08: scsi4 : ahci
15:55:08: scsi5 : ahci
15:55:08: scsi6 : ahci
15:55:08: scsi7 : ahci
15:55:08: ata5: SATA max UDMA/133 abar m8192@0xfe9fc000 port 0xfe9fc100 irq 17
15:55:08: ata6: SATA max UDMA/133 abar m8192@0xfe9fc000 port 0xfe9fc180 irq 17
15:55:08: ata7: SATA max UDMA/133 abar m8192@0xfe9fc000 port 0xfe9fc200 irq 17
15:55:08: ata8: SATA max UDMA/133 abar m8192@0xfe9fc000 port 0xfe9fc280 irq 17
15:55:08: sata_sil24 0000:01:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
15:55:08: scsi8 : sata_sil24
15:55:08: scsi9 : sata_sil24
15:55:08: ata9: SATA max UDMA/100 host m128@0xfe6ffc00 port 0xfe6f8000 irq 19
15:55:08: ata10: SATA max UDMA/100 host m128@0xfe6ffc00 port 0xfe6fa000 irq 19
15:55:08: hub 1-0:1.0: 10 ports detected
15:55:08: ohci_hcd 0000:00:13.0: new USB bus registered, assigned bus number 2
15:55:08: ohci_hcd 0000:00:13.0: irq 16, io mem 0xfe5fe000
15:55:08: ohci_hcd 0000:00:13.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
15:55:08: ohci_hcd 0000:00:13.1: OHCI Host Controller
15:55:08: hub 3-0:1.0: USB hub found
15:55:08: hub 3-0:1.0: 2 ports detected
15:55:08: ohci_hcd 0000:00:13.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
15:55:08: ohci_hcd 0000:00:13.2: new USB bus registered, assigned bus number 4
15:55:08: ohci_hcd 0000:00:13.2: irq 18, io mem 0xfe5fc000
15:55:08: ohci_hcd 0000:00:13.3: PCI INT B -> GSI 17 (level, low) -> IRQ 17
15:55:08: ohci_hcd 0000:00:13.3: OHCI Host Controller
15:55:08: ata8: SATA link down (SStatus 0 SControl 300)
15:55:08: ata7: SATA link down (SStatus 0 SControl 300)
15:55:08: ohci_hcd 0000:00:13.4: PCI INT C -> GSI 18 (level, low) -> IRQ 18
15:55:08: ohci_hcd 0000:00:13.4: OHCI Host Controller
15:55:08: ohci_hcd 0000:00:13.4: new USB bus registered, assigned bus number 6
15:55:08: hub 6-0:1.0: USB hub found
15:55:08: hub 6-0:1.0: 2 ports detected
15:55:08: serio: i8042 AUX port at 0x60,0x64 irq 12
15:55:08: mice: PS/2 mouse device common for all mice
15:55:08: rtc_cmos 00:02: rtc core: registered rtc_cmos as rtc0
15:55:08: rtc0: alarms up to one month, y3k, 114 bytes nvram, hpet irqs
15:55:08: ACPI: This conflict may cause random problems and system instability
15:55:08: ACPI: If an ACPI driver is available for this device, you should use it instead of the native driver
15:55:08: piix4_smbus 0000:00:14.0: SMBus Host Controller at 0xb00, revision 0
15:55:08: f71882fg f71882fg.1536: Fan: 2 is in duty-cycle mode
15:55:08: input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input3
15:55:08: k10temp 0000:00:18.3: unreliable CPU thermal sensor; check erratum 319
15:55:08: md: raid0 personality registered for level 0
15:55:08: md: raid6 personality registered for level 6
15:55:08: md: raid5 personality registered for level 5
15:55:08: EDAC amd64_edac:  Ver: 3.3.0 Oct  4 2010
15:55:08: EDAC amd64: This node reports that Memory ECC is currently disabled, set F3x44[22] (0000:00:18.3).
15:55:08: EDAC amd64: using x4 syndromes.
15:55:08: EDAC MC0: Giving out device to 'amd64_edac' 'Family 10h': DEV 0000:00:18.2
15:55:08: usbcore: registered new interface driver hiddev
15:55:08: usbcore: registered new interface driver usbhid
15:55:08: usbhid: USB HID core driver
15:55:08: Simple TC action Loaded
15:55:08: netem: version 1.2
15:55:08: Netfilter messages via NETLINK v0.30.
15:55:08: ata4: softreset failed (device not ready)
15:55:08: ata4: applying SB600 PMP SRST workaround and retrying
15:55:08: TCP cubic registered
15:55:08: Initializing XFRM netlink socket
15:55:08: 802.1Q VLAN Support v1.8 Ben Greear <greearb@candelatech.com>
15:55:08: usb 3-1: new low speed USB device using ohci_hcd and address 2
15:55:08: ata5: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
15:55:08: ata6.00: ATA-8: Hitachi HDS722020ALA330, JKAOA3EA, max UDMA/133
15:55:08: ata6.00: 3907029168 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
15:55:08: ata5.00: configured for UDMA/133
15:55:08: ata6.00: configured for UDMA/133
15:55:08: [Firmware Bug]: powernow-k8: No compatible ACPI _PSS objects found.
15:55:08: [Firmware Bug]: powernow-k8: Try again with latest BIOS.
15:55:08: ata4: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
15:55:08: ata4.00: ATA-8: Hitachi HDS722020ALA330, JKAOA3EA, max UDMA/133
15:55:08: ata4.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata4.00: configured for UDMA/133
15:55:08: ata2: softreset failed (device not ready)
15:55:08: ata1: applying SB600 PMP SRST workaround and retrying
15:55:08: ata2: applying SB600 PMP SRST workaround and retrying
15:55:08: ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
15:55:08: ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
15:55:08: ata2.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata2.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata3.00: ATA-8: Hitachi HDS722020ALA330, JKAOA3EA, max UDMA/133
15:55:08: ata3.00: 3907029168 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
15:55:08: ata1.00: ATA-8: Hitachi HDS722020ALA330, JKAOA3EA, max UDMA/133
15:55:08: ata1.00: 3907029168 sectors, multi 16: LBA48 NCQ (depth 31/32), AA
15:55:08: ata1.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata1.00: configured for UDMA/133
15:55:08: sd 0:0:0:0: [sda] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
15:55:08: scsi 1:0:0:0: Direct-Access     ATA      Hitachi HDS72202 JKAO PQ: 0 ANSI: 5
15:55:08: sd 1:0:0:0: [sdb] Write Protect is off
15:55:08: scsi 3:0:0:0: Direct-Access     ATA      Hitachi HDS72202 JKAO PQ: 0 ANSI: 5
15:55:08: sd 2:0:0:0: [sdc] Write Protect is off
15:55:08: sd 3:0:0:0: [sdd] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
15:55:08: sd 3:0:0:0: [sdd] Write Protect is off
15:55:08: sd 4:0:0:0: [sde] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
15:55:08: sd 4:0:0:0: [sde] Write cache: enabled, read cache: enabled, supports DPO and FUA
15:55:08: scsi 5:0:0:0: Direct-Access     ATA      Hitachi HDS72202 JKAO PQ: 0 ANSI: 5
15:55:08: sd 5:0:0:0: [sdf] Write cache: enabled, read cache: enabled, supports DPO and FUA
15:55:08:  sdf: sdf1 sdf2 sdf3 sdf4
15:55:08:  sdb: sdb1 sdb2 sdb3 sdb4
15:55:08: sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
15:55:08: sd 3:0:0:0: [sdd] Attached SCSI disk
15:55:08: sd 2:0:0:0: [sdc] Attached SCSI disk
15:55:08: sd 4:0:0:0: [sde] Attached SCSI disk
15:55:08: sd 0:0:0:0: [sda] Attached SCSI disk
15:55:08: generic-usb 0003:051D:0002.0001: hiddev0,hidraw0: USB HID v1.10 Device [American Power Conversion Smart-UPS 1000 RM FW:618.3.D USB FW:1.5] on usb-0000:00:13.1-1/input0
15:55:08: ata9.00: 3907029168 sectors, multi 16: LBA48 NCQ (depth 31/32)
15:55:08: ata11: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
15:55:08: sd 8:0:0:0: [sdg] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
15:55:08: sd 8:0:0:0: [sdg] Write Protect is off
15:55:08:  sdg: sdg1 sdg2 sdg3 sdg4
15:55:08: sd 8:0:0:0: [sdg] Attached SCSI disk
15:55:08: ata11.00: configured for UDMA/100
15:55:08: ata10: SATA link up 3.0 Gbps (SStatus 123 SControl 0)
15:55:08: ata10.00: configured for UDMA/100
15:55:08: scsi 9:0:0:0: Direct-Access     ATA      Hitachi HDS72202 JKAO PQ: 0 ANSI: 5
15:55:08: sd 10:0:0:0: [sdi] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
15:55:08: sd 10:0:0:0: [sdi] Write Protect is off
15:55:08:  sdi: sdi1 sdi2 sdi3 sdi4
15:55:08: sd 9:0:0:0: [sdh] Write Protect is off
15:55:08: sd 9:0:0:0: [sdh] Write cache: enabled, read cache: enabled, supports DPO and FUA
15:55:08:  sdh: sdh1 sdh2 sdh3 sdh4
15:55:08: ata12.00: ATA-8: Hitachi HDS722020ALA330, JKAOA3EA, max UDMA/133
15:55:08: ata12.00: 3907029168 sectors, multi 16: LBA48 NCQ (depth 31/32)
15:55:08: sd 11:0:0:0: [sdj] 3907029168 512-byte logical blocks: (2.00 TB/1.81 TiB)
15:55:08: sd 11:0:0:0: [sdj] Write Protect is off
15:55:08:  sdj: sdj1 sdj2 sdj3 sdj4
15:55:08: sd 11:0:0:0: [sdj] Attached SCSI disk
15:55:08: md: Autodetecting RAID arrays.
15:55:08: md: invalid raid superblock magic on sdf3
15:55:08: md: sde3 does not have a valid v0.90 superblock, not importing!
15:55:08: md: invalid raid superblock magic on sdg3
15:55:08: md: sdh3 does not have a valid v0.90 superblock, not importing!
15:55:08: md: Scanned 40 and added 36 devices.
15:55:08: md:  adding sdj4 ...
15:55:08: md: sdj3 has different UUID to sdj4
15:55:08: md:  adding sdh4 ...
15:55:08: md: sdh2 has different UUID to sdj4
15:55:08: md: sdi3 has different UUID to sdj4
15:55:08: md: sdi2 has different UUID to sdj4
15:55:08: md: sdg2 has different UUID to sdj4
15:55:08: md: sdg1 has different UUID to sdj4
15:55:08: md: sda2 has different UUID to sdj4
15:55:08: md: sda1 has different UUID to sdj4
15:55:08: md: sdb2 has different UUID to sdj4
15:55:08: md: sdb1 has different UUID to sdj4
15:55:08: md: sde1 has different UUID to sdj4
15:55:08: md:  adding sdf4 ...
15:55:08: md:  adding sdd4 ...
15:55:08: md: sdd3 has different UUID to sdj4
15:55:08: md: sdd2 has different UUID to sdj4
15:55:08: md:  adding sdc4 ...
15:55:08: md: sdc3 has different UUID to sdj4
15:55:08: md: created md10
15:55:08: md: bind<sdi4>
15:55:08: md: bind<sdh4>
15:55:08: md/raid10:md10: active with 10 out of 10 devices
15:55:08: created bitmap (28 pages) for device md10
15:55:08: md: considering sdj3 ...
15:55:08: md:  adding sdj3 ...
15:55:08: md: sdh2 has different UUID to sdj3
15:55:08: md: sdh1 has different UUID to sdj3
15:55:08: md: sdi1 has different UUID to sdj3
15:55:08: md: sdg2 has different UUID to sdj3
15:55:08: md: sdg1 has different UUID to sdj3
15:55:08: md: sda2 has different UUID to sdj3
15:55:08: md: sda1 has different UUID to sdj3
15:55:08: md: sdb1 has different UUID to sdj3
15:55:08: md: sde2 has different UUID to sdj3
15:55:08: md: sdf1 has different UUID to sdj3
15:55:08: md:  adding sdd3 ...
15:55:08: md: sdc3 has different UUID to sdj3
15:55:08: md: sdc2 has different UUID to sdj3
15:55:08: md: bind<sdd3>
15:55:08: md: bind<sdb3>
15:55:08: md: bind<sdj3>
15:55:08: md/raid1:md9: active with 3 out of 3 mirrors
15:55:08: created bitmap (1 pages) for device md9
15:55:08: md: considering sdj2 ...
15:55:08: md:  adding sdj2 ...
15:55:08: md: sdj1 has different UUID to sdj2
15:55:08: md: sdh1 has different UUID to sdj2
15:55:08: md: sdi3 has different UUID to sdj2
15:55:08: md:  adding sdg2 ...
15:55:08: md: sdg1 has different UUID to sdj2
15:55:08: md: sda1 has different UUID to sdj2
15:55:08: md:  adding sdb2 ...
15:55:08: md: sde1 has different UUID to sdj2
15:55:08: md:  adding sdf2 ...
15:55:08: md: sdf1 has different UUID to sdj2
15:55:08: md: sdd1 has different UUID to sdj2
15:55:08: md: sdc3 has different UUID to sdj2
15:55:08: md: created md7
15:55:08: md: bind<sdc2>
15:55:08: md: bind<sde2>
15:55:08: md: bind<sdb2>
15:55:08: md: bind<sdi2>
15:55:08: md: bind<sdh2>
15:55:08: md: bind<sdj2>
15:55:08: md/raid10:md7: active with 10 out of 10 devices
15:55:08: created bitmap (2 pages) for device md7
15:55:08: md: considering sdj1 ...
15:55:08: md:  adding sdj1 ...
15:55:08: md:  adding sdi1 ...
15:55:08: md:  adding sdg1 ...
15:55:08: md:  adding sdb1 ...
15:55:08: md:  adding sde1 ...
15:55:08: md: sdc3 has different UUID to sdj1
15:55:08: md:  adding sdc1 ...
15:55:08: md: bind<sdd1>
15:55:08: md: bind<sdf1>
15:55:08: md: bind<sda1>
15:55:08: md: bind<sdg1>
15:55:08: md: bind<sdj1>
15:55:08: md: running: <sdj1><sdh1><sdi1><sdg1><sda1><sdb1><sde1><sdf1><sdd1><sdc1>
15:55:08: md6: bitmap initialized from disk: read 1/1 pages, set 0 bits
15:55:08: md6: detected capacity change from 0 to 1194917888
15:55:08: md:  adding sda3 ...
15:55:08: md:  adding sdc3 ...
15:55:08: md: bind<sda3>
15:55:08: md: bind<sdi3>
15:55:08: md: running: <sdi3><sda3><sdc3>
15:55:08: created bitmap (1 pages) for device md8
15:55:08: md8: bitmap initialized from disk: read 1/1 pages, set 0 bits
15:55:08: md7: detected capacity change from 0 to 140026839040
15:55:08:  md7: unknown partition table
15:55:08: VFS: Mounted root (ext4 filesystem) readonly on device 9:7.
15:55:08: Freeing unused kernel memory: 492k freed
15:55:08: md8: detected capacity change from 0 to 8159363072
15:55:08: md10: detected capacity change from 0 to 3842060058624
15:55:08:  md9: unknown partition table
15:55:08:  md8: unknown partition table
15:55:08: serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
15:55:08: 00:05: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
15:55:08: serial 0000:06:03.0: PCI INT A -> GSI 21 (level, low) -> IRQ 21
15:55:08: 0000:06:03.0: ttyS1 at I/O 0xe400 (irq = 21) is a 16550A
15:55:08:  md6:
15:55:08: md10: detected capacity change from 0 to 3842060058624
15:55:08: ata1.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata2.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata1.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata1: EH complete
15:55:08: ata2.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata3: EH complete
15:55:08: ata2.00: configured for UDMA/133
15:55:08: ata4.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata4.00: SB600 AHCI: limiting to 255 sectors per cmd
15:55:08: ata6.00: configured for UDMA/133
15:55:08: ata6: EH complete
15:55:08: Adding 7968124k swap on /dev/md8.  Priority:0 extents:1 across:7968124k 
15:55:08: Adding 7968124k swap on /dev/md9.  Priority:0 extents:1 across:7968124k 
15:55:08: EXT4-fs (md7): re-mounted. Opts: (null)
15:55:08: EXT4-fs (md10): mounted filesystem with ordered data mode. Opts: journal_checksum,journal_async_commit,delalloc,auto_da_alloc
15:55:08: alg: No test for cipher_null (cipher_null-generic)
15:55:08: alg: No test for compress_null (compress_null-generic)
15:55:08: alg: No test for authenc(digest_null,cbc(aes)) (authenc(digest_null-generic,cbc(aes-asm)))
15:55:08: r8169 0000:03:00.0: eth0: link up
15:55:38: r8169 0000:03:00.0: eth0: link up
15:56:20: md: data-check of RAID array md6
15:56:20: md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
15:56:20: md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
15:56:20: md: using 128k window, over a total of 1166912 blocks.
15:56:20: ata1.00: WARNING: zero len r/w req
15:56:20: ------------[ cut here ]------------
15:56:20: kernel BUG at drivers/scsi/scsi_lib.c:1113!
15:56:20: invalid opcode: 0000 [#1] SMP 
15:56:20: last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
15:56:20: CPU 2 
15:56:20: Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core
15:56:20: 
15:56:20: Pid: 5448, comm: md6_resync Not tainted 2.6.36-rc6-00070-g44c064a #1 MS-7376/MS-7376
15:56:20: RIP: 0010:[<ffffffff812ab746>]  [<ffffffff812ab746>] scsi_setup_fs_cmnd+0x4e/0xbb
15:56:20: RSP: 0018:ffff88021c89dad0  EFLAGS: 00010046
15:56:20: RAX: 0000000000000000 RBX: ffff88021f3a87b0 RCX: ffff88021f3e57d0
15:56:20: RDX: 0000000000000000 RSI: ffff88021f3a87b0 RDI: ffff88021ff6f000
15:56:20: RBP: ffff88021c89dae0 R08: 00000000000003e8 R09: ffff88021c89dae0
15:56:20: R10: 0000000000000000 R11: ffff88021c89dae0 R12: ffff88021ff6f000
15:56:20: R13: ffff88021c89db58 R14: 0000000000000000 R15: ffff88021ff6f400
15:56:20: FS:  00007fe5c3395720(0000) GS:ffff880028300000(0000) knlGS:0000000000000000
15:56:20: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
15:56:20: CR2: 00007fe5bd5d602c CR3: 000000021c810000 CR4: 00000000000006e0
15:56:20: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
15:56:20: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
15:56:20: Process md6_resync (pid: 5448, threadinfo ffff88021c89c000, task ffff88021c68c200)
15:56:20: Stack:
15:56:20:  ffff88021f3a87b0 ffff88021ff6f000 ffff88021c89db40 ffffffff812b171d
15:56:20: <0> ffff88021f3c8068 ffff88021f3c80b8 000000001f3c8158 ffff88021f3e57d0
15:56:20: <0> ffff88021c89db40 ffff88021f3a87b0 ffff88021f3e57d0 ffff88021c89db58
15:56:20: Call Trace:
15:56:20:  [<ffffffff812b171d>] sd_prep_fn+0x241/0x868
15:56:20:  [<ffffffff81160487>] blk_peek_request+0xb3/0x177
15:56:20:  [<ffffffff812aae96>] scsi_request_fn+0x84/0x424
15:56:20:  [<ffffffff8103f279>] ? del_timer+0x7f/0x89
15:56:20:  [<ffffffff81160d9c>] __generic_unplug_device+0x32/0x37
15:56:20:  [<ffffffff81160dcc>] generic_unplug_device+0x2b/0x3a
15:56:20:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
15:56:20:  [<ffffffff81306b31>] unplug_slaves+0x69/0x9f
15:56:20:  [<ffffffff81306b7f>] raid1_unplug+0x18/0x28
15:56:20:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
15:56:20:  [<ffffffff8131aa72>] md_unplug+0x1d/0x33
15:56:20:  [<ffffffff8131b3d4>] md_do_sync+0x94c/0xba6
15:56:20:  [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
15:56:20:  [<ffffffff8131ba3a>] md_thread+0xf6/0x114
15:56:20:  [<ffffffff8131b944>] ? md_thread+0x0/0x114
15:56:20:  [<ffffffff8131b944>] ? md_thread+0x0/0x114
15:56:20:  [<ffffffff81049e4f>] kthread+0x7d/0x85
15:56:20:  [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
15:56:20:  [<ffffffff81049dd2>] ? kthread+0x0/0x85
15:56:20:  [<ffffffff81002c90>] ? kernel_thread_helper+0x0/0x10
15:56:20: Code: 85 c0 74 1d 48 8b 00 48 85 c0 74 15 48 8b 40 48 48 85 c0 74 0c 48 89 de 4c 89 e7 ff d0 85 c0 75 72 66 83 bb c0 00 00 00 00 75 04 <0f> 0b eb fe 48 8b 93 c8 00 00 00 48 85 d2 75 21 be 20 00 00 00 
15:56:20: RIP  [<ffffffff812ab746>] scsi_setup_fs_cmnd+0x4e/0xbb
15:56:20:  RSP <ffff88021c89dad0>
15:56:20: ---[ end trace 1dccec85b302be98 ]---
15:56:20: ata1.00: WARNING: zero len r/w req
15:56:25: ------------[ cut here ]------------
15:56:25: kernel BUG at drivers/scsi/scsi_lib.c:1113!
15:56:25: invalid opcode: 0000 [#2] SMP 
15:56:25: last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
15:56:25: CPU 3 
15:56:25: Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core
15:56:25: 
15:56:25: Pid: 947, comm: md7_raid10 Tainted: G      D     2.6.36-rc6-00070-g44c064a #1 MS-7376/MS-7376
15:56:25: RIP: 0010:[<ffffffff812ab746>]  [<ffffffff812ab746>] scsi_setup_fs_cmnd+0x4e/0xbb
15:56:25: RSP: 0018:ffff88021f50f910  EFLAGS: 00010046
15:56:25: RAX: 0000000000000000 RBX: ffff88021f3a9d78 RCX: 0000000000000000
15:56:25: RDX: 0000000000000000 RSI: ffff88021f3a9d78 RDI: ffff88021f508400
15:56:25: RBP: ffff88021f50f920 R08: 0000000000035800 R09: 0000000000000000
15:56:25: R10: ffff88021f50f9b0 R11: 0000000000000001 R12: ffff88021f508400
15:56:25: R13: ffff88021f50f998 R14: 0000000000000000 R15: ffff88021f508800
15:56:25: FS:  00007f0327259700(0000) GS:ffff880028380000(0000) knlGS:0000000000000000
15:56:25: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
15:56:25: CR2: 0000003a10c6e5a0 CR3: 000000021d552000 CR4: 00000000000006e0
15:56:25: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
15:56:25: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
15:56:25: Process md7_raid10 (pid: 947, threadinfo ffff88021f50e000, task ffff88021f2bc200)
15:56:25: Stack:
15:56:25:  ffff88021f3a9d78 ffff88021f508400 ffff88021f50f980 ffffffff812b171d
15:56:25: <0> ffff88021f50f950 ffffffff8115eb7e 000000001f500008 ffff88021e822320
15:56:25: <0> ffff88021f50f970 ffff88021f3a9d78 ffff88021e822320 ffff88021f50f998
15:56:25: Call Trace:
15:56:25:  [<ffffffff812b171d>] sd_prep_fn+0x241/0x868
15:56:25:  [<ffffffff8115eb7e>] ? elv_rb_del+0x30/0x49
15:56:25:  [<ffffffff81160487>] blk_peek_request+0xb3/0x177
15:56:25:  [<ffffffff812aae96>] scsi_request_fn+0x84/0x424
15:56:25:  [<ffffffff81160c18>] __blk_run_queue+0x3f/0x72
15:56:25:  [<ffffffff8115e831>] elv_insert+0x80/0x1a8
15:56:25:  [<ffffffff8115e9f1>] __elv_add_request+0x98/0x9f
15:56:25:  [<ffffffff8116174e>] __make_request+0x34a/0x3cd
15:56:25:  [<ffffffff8115feda>] generic_make_request+0x19a/0x204
15:56:25:  [<ffffffff8116000b>] submit_bio+0xc7/0xd0
15:56:25:  [<ffffffff810bb519>] ? bio_clone+0x39/0x44
15:56:25:  [<ffffffff8131be2b>] md_super_write+0xab/0xba
15:56:25:  [<ffffffff81322c77>] write_page+0x161/0x2c9
15:56:25:  [<ffffffff81092dca>] ? __slab_free+0x1f/0x25e
15:56:25:  [<ffffffff813232d2>] bitmap_daemon_work+0x417/0x498
15:56:25:  [<ffffffff81000c98>] ? __switch_to+0xea/0x212
15:56:25:  [<ffffffff8131da82>] md_check_recovery+0x19/0x43f
15:56:25:  [<ffffffff8130af28>] raid10d+0x34/0x804
15:56:25:  [<ffffffff8103f1ce>] ? try_to_del_timer_sync+0x83/0x8f

CONFIG_64BIT=y
CONFIG_X86_64=y
CONFIG_X86=y
CONFIG_INSTRUCTION_DECODER=y
CONFIG_OUTPUT_FORMAT="elf64-x86-64"
CONFIG_ARCH_DEFCONFIG="arch/x86/configs/x86_64_defconfig"
CONFIG_GENERIC_CMOS_UPDATE=y
CONFIG_CLOCKSOURCE_WATCHDOG=y
CONFIG_GENERIC_CLOCKEVENTS=y
CONFIG_GENERIC_CLOCKEVENTS_BROADCAST=y
CONFIG_LOCKDEP_SUPPORT=y
CONFIG_STACKTRACE_SUPPORT=y
CONFIG_HAVE_LATENCYTOP_SUPPORT=y
CONFIG_MMU=y
CONFIG_ZONE_DMA=y
CONFIG_NEED_DMA_MAP_STATE=y
CONFIG_NEED_SG_DMA_LENGTH=y
CONFIG_GENERIC_ISA_DMA=y
CONFIG_GENERIC_IOMAP=y
CONFIG_GENERIC_BUG=y
CONFIG_GENERIC_BUG_RELATIVE_POINTERS=y
CONFIG_GENERIC_HWEIGHT=y
CONFIG_ARCH_MAY_HAVE_PC_FDC=y
CONFIG_RWSEM_XCHGADD_ALGORITHM=y
CONFIG_ARCH_HAS_CPU_IDLE_WAIT=y
CONFIG_GENERIC_CALIBRATE_DELAY=y
CONFIG_GENERIC_TIME_VSYSCALL=y
CONFIG_ARCH_HAS_CPU_RELAX=y
CONFIG_ARCH_HAS_DEFAULT_IDLE=y
CONFIG_ARCH_HAS_CACHE_LINE_SIZE=y
CONFIG_HAVE_SETUP_PER_CPU_AREA=y
CONFIG_NEED_PER_CPU_EMBED_FIRST_CHUNK=y
CONFIG_NEED_PER_CPU_PAGE_FIRST_CHUNK=y
CONFIG_HAVE_CPUMASK_OF_CPU_MAP=y
CONFIG_ARCH_HIBERNATION_POSSIBLE=y
CONFIG_ARCH_SUSPEND_POSSIBLE=y
CONFIG_ZONE_DMA32=y
CONFIG_ARCH_POPULATES_NODE_MAP=y
CONFIG_AUDIT_ARCH=y
CONFIG_ARCH_SUPPORTS_OPTIMIZED_INLINING=y
CONFIG_ARCH_SUPPORTS_DEBUG_PAGEALLOC=y
CONFIG_HAVE_EARLY_RES=y
CONFIG_GENERIC_HARDIRQS=y
CONFIG_GENERIC_HARDIRQS_NO__DO_IRQ=y
CONFIG_GENERIC_IRQ_PROBE=y
CONFIG_GENERIC_PENDING_IRQ=y
CONFIG_USE_GENERIC_SMP_HELPERS=y
CONFIG_X86_64_SMP=y
CONFIG_X86_HT=y
CONFIG_X86_TRAMPOLINE=y
CONFIG_ARCH_HWEIGHT_CFLAGS="-fcall-saved-rdi -fcall-saved-rsi -fcall-saved-rdx -fcall-saved-rcx -fcall-saved-r8 -fcall-saved-r9 -fcall-saved-r10 -fcall-saved-r11"
CONFIG_DEFCONFIG_LIST="/lib/modules/$UNAME_RELEASE/.config"
CONFIG_CONSTRUCTORS=y
CONFIG_EXPERIMENTAL=y
CONFIG_LOCK_KERNEL=y
CONFIG_INIT_ENV_ARG_LIMIT=32
CONFIG_CROSS_COMPILE=""
CONFIG_LOCALVERSION=""
CONFIG_LOCALVERSION_AUTO=y
CONFIG_HAVE_KERNEL_GZIP=y
CONFIG_HAVE_KERNEL_BZIP2=y
CONFIG_HAVE_KERNEL_LZMA=y
CONFIG_HAVE_KERNEL_LZO=y
CONFIG_KERNEL_GZIP=y
CONFIG_SWAP=y
CONFIG_SYSVIPC=y
CONFIG_SYSVIPC_SYSCTL=y
CONFIG_BSD_PROCESS_ACCT=y
CONFIG_BSD_PROCESS_ACCT_V3=y
CONFIG_TASKSTATS=y
CONFIG_TASK_DELAY_ACCT=y
CONFIG_TASK_XACCT=y
CONFIG_TASK_IO_ACCOUNTING=y
CONFIG_TREE_RCU=y
CONFIG_RCU_FANOUT=64
CONFIG_IKCONFIG=y
CONFIG_IKCONFIG_PROC=y
CONFIG_LOG_BUF_SHIFT=16
CONFIG_HAVE_UNSTABLE_SCHED_CLOCK=y
CONFIG_NAMESPACES=y
CONFIG_BLK_DEV_INITRD=y
CONFIG_INITRAMFS_SOURCE=""
CONFIG_RD_GZIP=y
CONFIG_RD_BZIP2=y
CONFIG_RD_LZMA=y
CONFIG_RD_LZO=y
CONFIG_CC_OPTIMIZE_FOR_SIZE=y
CONFIG_SYSCTL=y
CONFIG_ANON_INODES=y
CONFIG_UID16=y
CONFIG_SYSCTL_SYSCALL=y
CONFIG_KALLSYMS=y
CONFIG_KALLSYMS_ALL=y
CONFIG_HOTPLUG=y
CONFIG_PRINTK=y
CONFIG_BUG=y
CONFIG_ELF_CORE=y
CONFIG_PCSPKR_PLATFORM=y
CONFIG_BASE_FULL=y
CONFIG_FUTEX=y
CONFIG_EPOLL=y
CONFIG_SIGNALFD=y
CONFIG_TIMERFD=y
CONFIG_EVENTFD=y
CONFIG_SHMEM=y
CONFIG_AIO=y
CONFIG_HAVE_PERF_EVENTS=y
CONFIG_PERF_EVENTS=y
CONFIG_VM_EVENT_COUNTERS=y
CONFIG_PCI_QUIRKS=y
CONFIG_SLUB_DEBUG=y
CONFIG_SLUB=y
CONFIG_HAVE_OPROFILE=y
CONFIG_HAVE_EFFICIENT_UNALIGNED_ACCESS=y
CONFIG_HAVE_IOREMAP_PROT=y
CONFIG_HAVE_KPROBES=y
CONFIG_HAVE_KRETPROBES=y
CONFIG_HAVE_OPTPROBES=y
CONFIG_HAVE_ARCH_TRACEHOOK=y
CONFIG_HAVE_DMA_ATTRS=y
CONFIG_HAVE_REGS_AND_STACK_ACCESS_API=y
CONFIG_HAVE_DMA_API_DEBUG=y
CONFIG_HAVE_HW_BREAKPOINT=y
CONFIG_HAVE_MIXED_BREAKPOINTS_REGS=y
CONFIG_HAVE_USER_RETURN_NOTIFIER=y
CONFIG_HAVE_PERF_EVENTS_NMI=y
CONFIG_SLABINFO=y
CONFIG_RT_MUTEXES=y
CONFIG_BASE_SMALL=0
CONFIG_MODULES=y
CONFIG_MODULE_FORCE_LOAD=y
CONFIG_MODULE_UNLOAD=y
CONFIG_MODULE_FORCE_UNLOAD=y
CONFIG_MODVERSIONS=y
CONFIG_STOP_MACHINE=y
CONFIG_BLOCK=y
CONFIG_BLOCK_COMPAT=y
CONFIG_IOSCHED_NOOP=y
CONFIG_IOSCHED_DEADLINE=y
CONFIG_IOSCHED_CFQ=y
CONFIG_DEFAULT_CFQ=y
CONFIG_DEFAULT_IOSCHED="cfq"
CONFIG_INLINE_SPIN_UNLOCK=y
CONFIG_INLINE_SPIN_UNLOCK_IRQ=y
CONFIG_INLINE_READ_UNLOCK=y
CONFIG_INLINE_READ_UNLOCK_IRQ=y
CONFIG_INLINE_WRITE_UNLOCK=y
CONFIG_INLINE_WRITE_UNLOCK_IRQ=y
CONFIG_MUTEX_SPIN_ON_OWNER=y
CONFIG_TICK_ONESHOT=y
CONFIG_HIGH_RES_TIMERS=y
CONFIG_GENERIC_CLOCKEVENTS_BUILD=y
CONFIG_SMP=y
CONFIG_X86_MPPARSE=y
CONFIG_X86_SUPPORTS_MEMORY_FAILURE=y
CONFIG_SCHED_OMIT_FRAME_POINTER=y
CONFIG_MK8=y
CONFIG_X86_CPU=y
CONFIG_X86_INTERNODE_CACHE_SHIFT=6
CONFIG_X86_CMPXCHG=y
CONFIG_X86_L1_CACHE_SHIFT=6
CONFIG_X86_XADD=y
CONFIG_X86_WP_WORKS_OK=y
CONFIG_X86_INTEL_USERCOPY=y
CONFIG_X86_USE_PPRO_CHECKSUM=y
CONFIG_X86_TSC=y
CONFIG_X86_CMPXCHG64=y
CONFIG_X86_CMOV=y
CONFIG_X86_MINIMUM_CPU_FAMILY=64
CONFIG_X86_DEBUGCTLMSR=y
CONFIG_CPU_SUP_INTEL=y
CONFIG_CPU_SUP_AMD=y
CONFIG_CPU_SUP_CENTAUR=y
CONFIG_HPET_TIMER=y
CONFIG_HPET_EMULATE_RTC=y
CONFIG_DMI=y
CONFIG_GART_IOMMU=y
CONFIG_AMD_IOMMU=y
CONFIG_SWIOTLB=y
CONFIG_IOMMU_HELPER=y
CONFIG_IOMMU_API=y
CONFIG_NR_CPUS=4
CONFIG_SCHED_MC=y
CONFIG_PREEMPT_NONE=y
CONFIG_X86_LOCAL_APIC=y
CONFIG_X86_IO_APIC=y
CONFIG_X86_MCE=y
CONFIG_X86_MCE_AMD=y
CONFIG_X86_MCE_THRESHOLD=y
CONFIG_X86_MSR=y
CONFIG_X86_CPUID=y
CONFIG_ARCH_PHYS_ADDR_T_64BIT=y
CONFIG_DIRECT_GBPAGES=y
CONFIG_ARCH_PROC_KCORE_TEXT=y
CONFIG_ARCH_SPARSEMEM_DEFAULT=y
CONFIG_ARCH_SPARSEMEM_ENABLE=y
CONFIG_ARCH_SELECT_MEMORY_MODEL=y
CONFIG_ILLEGAL_POINTER_VALUE=0xdead000000000000
CONFIG_SELECT_MEMORY_MODEL=y
CONFIG_SPARSEMEM_MANUAL=y
CONFIG_SPARSEMEM=y
CONFIG_HAVE_MEMORY_PRESENT=y
CONFIG_SPARSEMEM_EXTREME=y
CONFIG_SPARSEMEM_VMEMMAP_ENABLE=y
CONFIG_SPARSEMEM_ALLOC_MEM_MAP_TOGETHER=y
CONFIG_SPARSEMEM_VMEMMAP=y
CONFIG_PAGEFLAGS_EXTENDED=y
CONFIG_SPLIT_PTLOCK_CPUS=4
CONFIG_PHYS_ADDR_T_64BIT=y
CONFIG_ZONE_DMA_FLAG=1
CONFIG_BOUNCE=y
CONFIG_VIRT_TO_BUS=y
CONFIG_DEFAULT_MMAP_MIN_ADDR=4096
CONFIG_ARCH_SUPPORTS_MEMORY_FAILURE=y
CONFIG_MEMORY_FAILURE=y
CONFIG_MTRR=y
CONFIG_MTRR_SANITIZER=y
CONFIG_MTRR_SANITIZER_ENABLE_DEFAULT=1
CONFIG_MTRR_SANITIZER_SPARE_REG_NR_DEFAULT=1
CONFIG_X86_PAT=y
CONFIG_ARCH_USES_PG_UNCACHED=y
CONFIG_SECCOMP=y
CONFIG_HZ_100=y
CONFIG_HZ=100
CONFIG_SCHED_HRTICK=y
CONFIG_PHYSICAL_START=0x1000000
CONFIG_PHYSICAL_ALIGN=0x1000000
CONFIG_ARCH_ENABLE_MEMORY_HOTPLUG=y
CONFIG_PM=y
CONFIG_ACPI=y
CONFIG_ACPI_POWER_METER=m
CONFIG_ACPI_SYSFS_POWER=y
CONFIG_ACPI_BUTTON=y
CONFIG_ACPI_FAN=y
CONFIG_ACPI_DOCK=y
CONFIG_ACPI_PROCESSOR=y
CONFIG_ACPI_THERMAL=y
CONFIG_ACPI_BLACKLIST_YEAR=0
CONFIG_X86_PM_TIMER=y
CONFIG_ACPI_APEI=y
CONFIG_CPU_FREQ=y
CONFIG_CPU_FREQ_TABLE=y
CONFIG_CPU_FREQ_STAT=y
CONFIG_CPU_FREQ_DEFAULT_GOV_PERFORMANCE=y
CONFIG_CPU_FREQ_GOV_PERFORMANCE=y
CONFIG_CPU_FREQ_GOV_POWERSAVE=y
CONFIG_CPU_FREQ_GOV_USERSPACE=y
CONFIG_X86_POWERNOW_K8=y
CONFIG_CPU_IDLE=y
CONFIG_CPU_IDLE_GOV_LADDER=y
CONFIG_PCI=y
CONFIG_PCI_DIRECT=y
CONFIG_PCI_MMCONFIG=y
CONFIG_PCI_DOMAINS=y
CONFIG_PCIEPORTBUS=y
CONFIG_PCIEAER=y
CONFIG_PCIEASPM=y
CONFIG_ARCH_SUPPORTS_MSI=y
CONFIG_PCI_MSI=y
CONFIG_HT_IRQ=y
CONFIG_PCI_IOAPIC=y
CONFIG_ISA_DMA_API=y
CONFIG_K8_NB=y
CONFIG_BINFMT_ELF=y
CONFIG_COMPAT_BINFMT_ELF=y
CONFIG_CORE_DUMP_DEFAULT_ELF_HEADERS=y
CONFIG_IA32_EMULATION=y
CONFIG_COMPAT=y
CONFIG_COMPAT_FOR_U64_ALIGNMENT=y
CONFIG_SYSVIPC_COMPAT=y
CONFIG_NET=y
CONFIG_PACKET=y
CONFIG_UNIX=y
CONFIG_XFRM=y
CONFIG_XFRM_USER=y
CONFIG_XFRM_IPCOMP=y
CONFIG_NET_KEY=y
CONFIG_INET=y
CONFIG_IP_MULTICAST=y
CONFIG_IP_ADVANCED_ROUTER=y
CONFIG_ASK_IP_FIB_HASH=y
CONFIG_IP_FIB_HASH=y
CONFIG_IP_MULTIPLE_TABLES=y
CONFIG_IP_ROUTE_MULTIPATH=y
CONFIG_IP_ROUTE_VERBOSE=y
CONFIG_IP_MROUTE=y
CONFIG_IP_PIMSM_V1=y
CONFIG_IP_PIMSM_V2=y
CONFIG_SYN_COOKIES=y
CONFIG_INET_AH=y
CONFIG_INET_ESP=y
CONFIG_INET_IPCOMP=y
CONFIG_INET_XFRM_TUNNEL=y
CONFIG_INET_TUNNEL=y
CONFIG_INET_XFRM_MODE_TRANSPORT=y
CONFIG_INET_XFRM_MODE_TUNNEL=y
CONFIG_INET_XFRM_MODE_BEET=y
CONFIG_INET_LRO=y
CONFIG_INET_DIAG=y
CONFIG_INET_TCP_DIAG=y
CONFIG_TCP_CONG_CUBIC=y
CONFIG_DEFAULT_TCP_CONG="cubic"
CONFIG_NETFILTER=y
CONFIG_NETFILTER_ADVANCED=y
CONFIG_NETFILTER_NETLINK=y
CONFIG_NETFILTER_NETLINK_LOG=y
CONFIG_NETFILTER_TPROXY=y
CONFIG_NETFILTER_XTABLES=y
CONFIG_NETFILTER_XT_MARK=y
CONFIG_NETFILTER_XT_TARGET_CLASSIFY=y
CONFIG_NETFILTER_XT_TARGET_HL=y
CONFIG_NETFILTER_XT_TARGET_MARK=y
CONFIG_NETFILTER_XT_TARGET_NFLOG=y
CONFIG_NETFILTER_XT_TARGET_NFQUEUE=y
CONFIG_NETFILTER_XT_TARGET_TPROXY=y
CONFIG_NETFILTER_XT_MATCH_HASHLIMIT=y
CONFIG_NETFILTER_XT_MATCH_HL=y
CONFIG_NETFILTER_XT_MATCH_LENGTH=y
CONFIG_NETFILTER_XT_MATCH_LIMIT=y
CONFIG_NETFILTER_XT_MATCH_MARK=y
CONFIG_NETFILTER_XT_MATCH_OSF=y
CONFIG_NETFILTER_XT_MATCH_PKTTYPE=y
CONFIG_NETFILTER_XT_MATCH_QUOTA=y
CONFIG_NETFILTER_XT_MATCH_RECENT=y
CONFIG_NETFILTER_XT_MATCH_STATISTIC=y
CONFIG_NETFILTER_XT_MATCH_TCPMSS=y
CONFIG_NF_DEFRAG_IPV4=y
CONFIG_IP_NF_QUEUE=m
CONFIG_IP_NF_IPTABLES=y
CONFIG_IP_NF_MATCH_ADDRTYPE=y
CONFIG_IP_NF_MATCH_ECN=y
CONFIG_IP_NF_FILTER=y
CONFIG_IP_NF_TARGET_REJECT=y
CONFIG_IP_NF_TARGET_ULOG=y
CONFIG_IP_NF_MANGLE=y
CONFIG_IP_NF_TARGET_ECN=y
CONFIG_IP_NF_TARGET_TTL=y
CONFIG_VLAN_8021Q=y
CONFIG_NET_SCHED=y
CONFIG_NET_SCH_CBQ=y
CONFIG_NET_SCH_HTB=y
CONFIG_NET_SCH_HFSC=y
CONFIG_NET_SCH_PRIO=y
CONFIG_NET_SCH_RED=y
CONFIG_NET_SCH_SFQ=y
CONFIG_NET_SCH_TEQL=y
CONFIG_NET_SCH_TBF=y
CONFIG_NET_SCH_GRED=y
CONFIG_NET_SCH_DSMARK=y
CONFIG_NET_SCH_NETEM=y
CONFIG_NET_SCH_INGRESS=y
CONFIG_NET_CLS=y
CONFIG_NET_CLS_TCINDEX=y
CONFIG_NET_CLS_ROUTE4=y
CONFIG_NET_CLS_ROUTE=y
CONFIG_NET_CLS_ACT=y
CONFIG_NET_ACT_POLICE=y
CONFIG_NET_ACT_MIRRED=y
CONFIG_NET_ACT_IPT=y
CONFIG_NET_ACT_PEDIT=y
CONFIG_NET_ACT_SIMP=y
CONFIG_NET_SCH_FIFO=y
CONFIG_RPS=y
CONFIG_FIB_RULES=y
CONFIG_UEVENT_HELPER_PATH="/sbin/hotplug"
CONFIG_STANDALONE=y
CONFIG_PREVENT_FIRMWARE_BUILD=y
CONFIG_FW_LOADER=y
CONFIG_FIRMWARE_IN_KERNEL=y
CONFIG_EXTRA_FIRMWARE=""
CONFIG_MTD=m
CONFIG_MTD_BLKDEVS=m
CONFIG_MTD_BLOCK=m
CONFIG_MTD_MAP_BANK_WIDTH_1=y
CONFIG_MTD_MAP_BANK_WIDTH_2=y
CONFIG_MTD_MAP_BANK_WIDTH_4=y
CONFIG_MTD_CFI_I1=y
CONFIG_MTD_CFI_I2=y
CONFIG_MTD_MTDRAM=m
CONFIG_MTDRAM_TOTAL_SIZE=8000
CONFIG_MTDRAM_ERASE_SIZE=128
CONFIG_MTD_BLOCK2MTD=m
CONFIG_PARPORT=y
CONFIG_PARPORT_PC=y
CONFIG_PARPORT_PC_FIFO=y
CONFIG_PARPORT_PC_SUPERIO=y
CONFIG_PARPORT_1284=y
CONFIG_PNP=y
CONFIG_PNP_DEBUG_MESSAGES=y
CONFIG_PNPACPI=y
CONFIG_BLK_DEV=y
CONFIG_BLK_DEV_FD=y
CONFIG_BLK_DEV_LOOP=y
CONFIG_BLK_DEV_CRYPTOLOOP=y
CONFIG_BLK_DEV_RAM=y
CONFIG_BLK_DEV_RAM_COUNT=16
CONFIG_BLK_DEV_RAM_SIZE=65536
CONFIG_CDROM_PKTCDVD=y
CONFIG_CDROM_PKTCDVD_BUFFERS=8
CONFIG_MISC_DEVICES=y
CONFIG_EEPROM_AT24=m
CONFIG_EEPROM_LEGACY=m
CONFIG_HAVE_IDE=y
CONFIG_IDE=y
CONFIG_IDE_XFER_MODE=y
CONFIG_IDE_TIMINGS=y
CONFIG_IDE_ATAPI=y
CONFIG_IDE_GD=y
CONFIG_IDE_GD_ATA=y
CONFIG_BLK_DEV_IDECD=y
CONFIG_BLK_DEV_IDECD_VERBOSE_ERRORS=y
CONFIG_BLK_DEV_IDEACPI=y
CONFIG_IDE_GENERIC=y
CONFIG_BLK_DEV_IDEDMA_SFF=y
CONFIG_BLK_DEV_IDEPCI=y
CONFIG_IDEPCI_PCIBUS_ORDER=y
CONFIG_BLK_DEV_GENERIC=y
CONFIG_BLK_DEV_IDEDMA_PCI=y
CONFIG_BLK_DEV_ATIIXP=y
CONFIG_BLK_DEV_VIA82CXXX=y
CONFIG_BLK_DEV_IDEDMA=y
CONFIG_SCSI_MOD=y
CONFIG_SCSI=y
CONFIG_SCSI_DMA=y
CONFIG_BLK_DEV_SD=y
CONFIG_SCSI_WAIT_SCAN=m
CONFIG_ATA=y
CONFIG_ATA_VERBOSE_ERROR=y
CONFIG_ATA_ACPI=y
CONFIG_SATA_PMP=y
CONFIG_SATA_AHCI=y
CONFIG_SATA_SIL24=y
CONFIG_MD=y
CONFIG_BLK_DEV_MD=y
CONFIG_MD_AUTODETECT=y
CONFIG_MD_RAID0=y
CONFIG_MD_RAID1=y
CONFIG_MD_RAID10=y
CONFIG_MD_RAID456=y
CONFIG_FIREWIRE=m
CONFIG_FIREWIRE_OHCI=m
CONFIG_FIREWIRE_OHCI_DEBUG=y
CONFIG_FIREWIRE_SBP2=m
CONFIG_NETDEVICES=y
CONFIG_DUMMY=y
CONFIG_TUN=y
CONFIG_MII=y
CONFIG_NETDEV_1000=y
CONFIG_IP1000=m
CONFIG_R8169=y
CONFIG_R8169_VLAN=y
CONFIG_INPUT=y
CONFIG_INPUT_MOUSEDEV=y
CONFIG_INPUT_MOUSEDEV_PSAUX=y
CONFIG_INPUT_MOUSEDEV_SCREEN_X=1024
CONFIG_INPUT_MOUSEDEV_SCREEN_Y=768
CONFIG_INPUT_EVDEV=y
CONFIG_INPUT_KEYBOARD=y
CONFIG_KEYBOARD_ATKBD=y
CONFIG_INPUT_MOUSE=y
CONFIG_MOUSE_PS2=y
CONFIG_MOUSE_PS2_ALPS=y
CONFIG_MOUSE_PS2_LOGIPS2PP=y
CONFIG_MOUSE_PS2_SYNAPTICS=y
CONFIG_MOUSE_PS2_LIFEBOOK=y
CONFIG_MOUSE_PS2_TRACKPOINT=y
CONFIG_INPUT_MISC=y
CONFIG_INPUT_PCSPKR=y
CONFIG_SERIO=y
CONFIG_SERIO_I8042=y
CONFIG_SERIO_LIBPS2=y
CONFIG_VT=y
CONFIG_CONSOLE_TRANSLATIONS=y
CONFIG_VT_CONSOLE=y
CONFIG_HW_CONSOLE=y
CONFIG_SERIAL_8250=m
CONFIG_FIX_EARLYCON_MEM=y
CONFIG_SERIAL_8250_PCI=m
CONFIG_SERIAL_8250_PNP=m
CONFIG_SERIAL_8250_NR_UARTS=4
CONFIG_SERIAL_8250_RUNTIME_UARTS=4
CONFIG_SERIAL_8250_EXTENDED=y
CONFIG_SERIAL_8250_SHARE_IRQ=y
CONFIG_SERIAL_8250_DETECT_IRQ=y
CONFIG_SERIAL_CORE=m
CONFIG_UNIX98_PTYS=y
CONFIG_PRINTER=m
CONFIG_HPET=y
CONFIG_HPET_MMAP=y
CONFIG_HANGCHECK_TIMER=y
CONFIG_DEVPORT=y
CONFIG_I2C=y
CONFIG_I2C_BOARDINFO=y
CONFIG_I2C_COMPAT=y
CONFIG_I2C_CHARDEV=y
CONFIG_I2C_HELPER_AUTO=y
CONFIG_I2C_ALGOBIT=y
CONFIG_I2C_PIIX4=y
CONFIG_I2C_NFORCE2=m
CONFIG_I2C_VIAPRO=m
CONFIG_PPS=m
CONFIG_PPS_CLIENT_LDISC=m
CONFIG_ARCH_WANT_OPTIONAL_GPIOLIB=y
CONFIG_POWER_SUPPLY=y
CONFIG_HWMON=y
CONFIG_SENSORS_K10TEMP=y
CONFIG_SENSORS_F71882FG=y
CONFIG_THERMAL=y
CONFIG_THERMAL_HWMON=y
CONFIG_SSB_POSSIBLE=y
CONFIG_AGP=y
CONFIG_AGP_AMD64=y
CONFIG_VGA_ARB=y
CONFIG_VGA_ARB_MAX_GPUS=2
CONFIG_DRM=y
CONFIG_DRM_KMS_HELPER=y
CONFIG_DRM_TTM=y
CONFIG_DRM_RADEON=y
CONFIG_FB=y
CONFIG_FB_DDC=y
CONFIG_FB_CFB_FILLRECT=y
CONFIG_FB_CFB_COPYAREA=y
CONFIG_FB_CFB_IMAGEBLIT=y
CONFIG_FB_BACKLIGHT=y
CONFIG_FB_MODE_HELPERS=y
CONFIG_FB_RADEON=y
CONFIG_FB_RADEON_I2C=y
CONFIG_FB_RADEON_BACKLIGHT=y
CONFIG_BACKLIGHT_LCD_SUPPORT=y
CONFIG_BACKLIGHT_CLASS_DEVICE=y
CONFIG_VGA_CONSOLE=y
CONFIG_DUMMY_CONSOLE=y
CONFIG_FRAMEBUFFER_CONSOLE=y
CONFIG_FONT_8x8=y
CONFIG_FONT_8x16=y
CONFIG_SOUND=m
CONFIG_SND=m
CONFIG_SND_TIMER=m
CONFIG_SND_PCM=m
CONFIG_SND_RAWMIDI=m
CONFIG_SND_VERBOSE_PROCFS=y
CONFIG_SND_VMASTER=y
CONFIG_SND_DMA_SGBUF=y
CONFIG_SND_MPU401_UART=m
CONFIG_SND_AC97_CODEC=m
CONFIG_SND_DRIVERS=y
CONFIG_SND_PCI=y
CONFIG_SND_VIA82XX=m
CONFIG_AC97_BUS=m
CONFIG_HID_SUPPORT=y
CONFIG_HID=y
CONFIG_HIDRAW=y
CONFIG_USB_HID=y
CONFIG_USB_HIDDEV=y
CONFIG_HID_A4TECH=y
CONFIG_HID_APPLE=y
CONFIG_HID_BELKIN=y
CONFIG_HID_CHERRY=y
CONFIG_HID_CHICONY=y
CONFIG_HID_CYPRESS=y
CONFIG_HID_DRAGONRISE=y
CONFIG_HID_EZKEY=y
CONFIG_HID_KYE=y
CONFIG_HID_GYRATION=y
CONFIG_HID_TWINHAN=y
CONFIG_HID_KENSINGTON=y
CONFIG_HID_LOGITECH=y
CONFIG_HID_MICROSOFT=y
CONFIG_HID_MONTEREY=y
CONFIG_HID_NTRIG=y
CONFIG_HID_ORTEK=y
CONFIG_HID_PANTHERLORD=y
CONFIG_HID_PETALYNX=y
CONFIG_HID_SAMSUNG=y
CONFIG_HID_SONY=y
CONFIG_HID_SUNPLUS=y
CONFIG_HID_GREENASIA=y
CONFIG_HID_SMARTJOYPLUS=y
CONFIG_HID_TOPSEED=y
CONFIG_HID_THRUSTMASTER=y
CONFIG_HID_ZEROPLUS=y
CONFIG_USB_SUPPORT=y
CONFIG_USB_ARCH_HAS_HCD=y
CONFIG_USB_ARCH_HAS_OHCI=y
CONFIG_USB_ARCH_HAS_EHCI=y
CONFIG_USB=y
CONFIG_USB_EHCI_HCD=y
CONFIG_USB_EHCI_ROOT_HUB_TT=y
CONFIG_USB_OHCI_HCD=y
CONFIG_USB_OHCI_LITTLE_ENDIAN=y
CONFIG_USB_PRINTER=m
CONFIG_USB_STORAGE=m
CONFIG_USB_SERIAL=m
CONFIG_USB_EZUSB=y
CONFIG_USB_SERIAL_GENERIC=y
CONFIG_USB_SERIAL_BELKIN=m
CONFIG_USB_SERIAL_WHITEHEAT=m
CONFIG_USB_SERIAL_DIGI_ACCELEPORT=m
CONFIG_USB_SERIAL_CYPRESS_M8=m
CONFIG_USB_SERIAL_FTDI_SIO=m
CONFIG_USB_SERIAL_MCT_U232=m
CONFIG_USB_SERIAL_MOS7720=m
CONFIG_USB_SERIAL_MOS7840=m
CONFIG_USB_SERIAL_PL2303=m
CONFIG_USB_SERIAL_TI=m
CONFIG_USB_SERIAL_XIRCOM=m
CONFIG_EDAC=y
CONFIG_EDAC_DECODE_MCE=y
CONFIG_EDAC_MM_EDAC=y
CONFIG_EDAC_AMD64=y
CONFIG_RTC_LIB=y
CONFIG_RTC_CLASS=y
CONFIG_RTC_HCTOSYS=y
CONFIG_RTC_HCTOSYS_DEVICE="rtc0"
CONFIG_RTC_INTF_SYSFS=y
CONFIG_RTC_INTF_PROC=y
CONFIG_RTC_INTF_DEV=y
CONFIG_RTC_DRV_CMOS=y
CONFIG_FIRMWARE_MEMMAP=y
CONFIG_DMIID=y
CONFIG_EXT2_FS=m
CONFIG_EXT3_FS=y
CONFIG_EXT3_DEFAULTS_TO_ORDERED=y
CONFIG_EXT4_FS=y
CONFIG_JBD=y
CONFIG_JBD2=y
CONFIG_XFS_FS=m
CONFIG_BTRFS_FS=m
CONFIG_FILE_LOCKING=y
CONFIG_FSNOTIFY=y
CONFIG_DNOTIFY=y
CONFIG_INOTIFY_USER=y
CONFIG_FANOTIFY=y
CONFIG_ISO9660_FS=y
CONFIG_JOLIET=y
CONFIG_ZISOFS=y
CONFIG_UDF_FS=y
CONFIG_UDF_NLS=y
CONFIG_FAT_FS=m
CONFIG_MSDOS_FS=m
CONFIG_VFAT_FS=m
CONFIG_FAT_DEFAULT_CODEPAGE=437
CONFIG_FAT_DEFAULT_IOCHARSET="iso8859-1"
CONFIG_PROC_FS=y
CONFIG_PROC_KCORE=y
CONFIG_PROC_SYSCTL=y
CONFIG_PROC_PAGE_MONITOR=y
CONFIG_SYSFS=y
CONFIG_TMPFS=y
CONFIG_MISC_FILESYSTEMS=y
CONFIG_JFFS2_FS=m
CONFIG_JFFS2_FS_DEBUG=0
CONFIG_JFFS2_FS_WRITEBUFFER=y
CONFIG_JFFS2_ZLIB=y
CONFIG_JFFS2_RTIME=y
CONFIG_NETWORK_FILESYSTEMS=y
CONFIG_NFSD=y
CONFIG_NFSD_V3=y
CONFIG_LOCKD=y
CONFIG_LOCKD_V4=y
CONFIG_EXPORTFS=y
CONFIG_NFS_COMMON=y
CONFIG_SUNRPC=y
CONFIG_MSDOS_PARTITION=y
CONFIG_NLS=y
CONFIG_NLS_DEFAULT="cp437"
CONFIG_NLS_CODEPAGE_437=y
CONFIG_NLS_ASCII=y
CONFIG_NLS_ISO8859_1=y
CONFIG_NLS_ISO8859_15=y
CONFIG_NLS_UTF8=y
CONFIG_TRACE_IRQFLAGS_SUPPORT=y
CONFIG_ENABLE_WARN_DEPRECATED=y
CONFIG_FRAME_WARN=2048
CONFIG_MAGIC_SYSRQ=y
CONFIG_STRIP_ASM_SYMS=y
CONFIG_DEBUG_KERNEL=y
CONFIG_LOCKUP_DETECTOR=y
CONFIG_HARDLOCKUP_DETECTOR=y
CONFIG_BOOTPARAM_SOFTLOCKUP_PANIC_VALUE=0
CONFIG_DETECT_HUNG_TASK=y
CONFIG_BOOTPARAM_HUNG_TASK_PANIC_VALUE=0
CONFIG_SCHED_DEBUG=y
CONFIG_SCHEDSTATS=y
CONFIG_TIMER_STATS=y
CONFIG_STACKTRACE=y
CONFIG_DEBUG_BUGVERBOSE=y
CONFIG_DEBUG_MEMORY_INIT=y
CONFIG_ARCH_WANT_FRAME_POINTERS=y
CONFIG_FRAME_POINTER=y
CONFIG_LATENCYTOP=y
CONFIG_SYSCTL_SYSCALL_CHECK=y
CONFIG_USER_STACKTRACE_SUPPORT=y
CONFIG_HAVE_FUNCTION_TRACER=y
CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y
CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST=y
CONFIG_HAVE_FUNCTION_TRACE_MCOUNT_TEST=y
CONFIG_HAVE_DYNAMIC_FTRACE=y
CONFIG_HAVE_FTRACE_MCOUNT_RECORD=y
CONFIG_HAVE_SYSCALL_TRACEPOINTS=y
CONFIG_TRACING_SUPPORT=y
CONFIG_HAVE_ARCH_KGDB=y
CONFIG_HAVE_ARCH_KMEMCHECK=y
CONFIG_STRICT_DEVMEM=y
CONFIG_X86_VERBOSE_BOOTUP=y
CONFIG_EARLY_PRINTK=y
CONFIG_DEBUG_STACKOVERFLOW=y
CONFIG_HAVE_MMIOTRACE_SUPPORT=y
CONFIG_IO_DELAY_TYPE_0X80=0
CONFIG_IO_DELAY_TYPE_0XED=1
CONFIG_IO_DELAY_TYPE_UDELAY=2
CONFIG_IO_DELAY_TYPE_NONE=3
CONFIG_IO_DELAY_NONE=y
CONFIG_DEFAULT_IO_DELAY_TYPE=3
CONFIG_OPTIMIZE_INLINING=y
CONFIG_DEFAULT_SECURITY_DAC=y
CONFIG_DEFAULT_SECURITY=""
CONFIG_XOR_BLOCKS=y
CONFIG_ASYNC_CORE=y
CONFIG_ASYNC_MEMCPY=y
CONFIG_ASYNC_XOR=y
CONFIG_ASYNC_PQ=y
CONFIG_ASYNC_RAID6_RECOV=y
CONFIG_CRYPTO=y
CONFIG_CRYPTO_ALGAPI=y
CONFIG_CRYPTO_ALGAPI2=y
CONFIG_CRYPTO_AEAD=y
CONFIG_CRYPTO_AEAD2=y
CONFIG_CRYPTO_BLKCIPHER=y
CONFIG_CRYPTO_BLKCIPHER2=y
CONFIG_CRYPTO_HASH=y
CONFIG_CRYPTO_HASH2=y
CONFIG_CRYPTO_RNG=m
CONFIG_CRYPTO_RNG2=y
CONFIG_CRYPTO_PCOMP2=y
CONFIG_CRYPTO_MANAGER=y
CONFIG_CRYPTO_MANAGER2=y
CONFIG_CRYPTO_GF128MUL=m
CONFIG_CRYPTO_NULL=m
CONFIG_CRYPTO_WORKQUEUE=y
CONFIG_CRYPTO_AUTHENC=y
CONFIG_CRYPTO_CCM=m
CONFIG_CRYPTO_GCM=m
CONFIG_CRYPTO_SEQIV=m
CONFIG_CRYPTO_CBC=y
CONFIG_CRYPTO_CTR=m
CONFIG_CRYPTO_ECB=m
CONFIG_CRYPTO_PCBC=m
CONFIG_CRYPTO_HMAC=y
CONFIG_CRYPTO_XCBC=m
CONFIG_CRYPTO_CRC32C=m
CONFIG_CRYPTO_GHASH=m
CONFIG_CRYPTO_MD5=y
CONFIG_CRYPTO_SHA1=y
CONFIG_CRYPTO_SHA256=m
CONFIG_CRYPTO_SHA512=m
CONFIG_CRYPTO_AES=y
CONFIG_CRYPTO_AES_X86_64=y
CONFIG_CRYPTO_DES=y
CONFIG_CRYPTO_SERPENT=m
CONFIG_CRYPTO_TEA=m
CONFIG_CRYPTO_TWOFISH=m
CONFIG_CRYPTO_TWOFISH_COMMON=m
CONFIG_CRYPTO_TWOFISH_X86_64=m
CONFIG_CRYPTO_DEFLATE=y
CONFIG_HAVE_KVM=y
CONFIG_RAID6_PQ=y
CONFIG_BITREVERSE=y
CONFIG_GENERIC_FIND_FIRST_BIT=y
CONFIG_GENERIC_FIND_NEXT_BIT=y
CONFIG_GENERIC_FIND_LAST_BIT=y
CONFIG_CRC16=y
CONFIG_CRC_ITU_T=y
CONFIG_CRC32=y
CONFIG_LIBCRC32C=m
CONFIG_ZLIB_INFLATE=y
CONFIG_ZLIB_DEFLATE=y
CONFIG_LZO_DECOMPRESS=y
CONFIG_DECOMPRESS_GZIP=y
CONFIG_DECOMPRESS_BZIP2=y
CONFIG_DECOMPRESS_LZMA=y
CONFIG_DECOMPRESS_LZO=y
CONFIG_HAS_IOMEM=y
CONFIG_HAS_IOPORT=y
CONFIG_HAS_DMA=y
CONFIG_NLATTR=y
Comment 6 linux 2010-10-04 18:11:29 UTC
> Rafael J. Wysocki <rjw@sisk.pl> wrote:
>> The following bug entry is on the current list of known regressions
>> from 2.6.35.  Please verify if it still should be listed and let the
>> tracking team know (either way).

It would help if the e-mail had specific instruction for letting the tracking
team know, but see below.

Tejun Heo <tj@kernel.org> wrote:
> * Is this a regression?

Yes, it is; at least, booting with a 2.6.35 kernel avoids
the problem entirely.

> * Does this always happen with libata.fua=1?  Does it go away w/o it?

I repeated it 3 times.  I can go for larger numbers if you like.

Booting twice with libata.fua=0 (once appending that to the command
line, which I think works to override the earlier, and once after editing
lilo.conf & re-running lilo), the problem turned into a panic.  The first
time, I got a lot of screen spew (that I couldn't scroll back through, nor
did I capture it on the remote syslog host).

The second time, it didn't manage to print anything... just started
blinking the keyboard LEDs.

Of course, it also paniced this weekend when the weekly RAID check that
I forgot to disable fired off.  That might be a data-dependent change.

Just checked... nope.  Rebooting with fua=1 makes it a less fatal
error again.


BTW, I'm by the machine and can try things today, but I'm leaving early
(around 20h UTC), so won't be responding after that.

Thank you all for your help!
Comment 7 Tejun Heo 2010-10-04 18:20:59 UTC
Hello,

On 10/04/2010 02:44 PM, George Spelvin wrote:
>> Rafael J. Wysocki <rjw@sisk.pl> wrote:
>> * Is this a regression?
> 
> Yes, it is; at least, booting with a 2.6.35 kernel avoids
> the problem entirely.

Hmmm... weird.  The thing is that empty barrier is now pretty wildly
used so if it is actually broken we should be getting a lot more
reports and the only change that I can recall which might be relevant
is req/bio flag bit reshuffling which in itself shouldn't cause
problems you're describing.

>> * Does this always happen with libata.fua=1?  Does it go away w/o it?
> 
> I repeated it 3 times.  I can go for larger numbers if you like.
> 
> Booting twice with libata.fua=0 (once appending that to the command
> line, which I think works to override the earlier, and once after editing
> lilo.conf & re-running lilo), the problem turned into a panic.  The first
> time, I got a lot of screen spew (that I couldn't scroll back through, nor
> did I capture it on the remote syslog host).
> 
> The second time, it didn't manage to print anything... just started
> blinking the keyboard LEDs.
> 
> Of course, it also paniced this weekend when the weekly RAID check that
> I forgot to disable fired off.  That might be a data-dependent change.
> 
> Just checked... nope.  Rebooting with fua=1 makes it a less fatal
> error again.
> 
> BTW, I'm by the machine and can try things today, but I'm leaving early
> (around 20h UTC), so won't be responding after that.

Just in case, can you please do "make mrproper" and then rebuild the
kernel?  The only thing I can think of now is mismatching flag bits
due to partial rebuild (unfortunately those flag bits have been hard
coded duplicately in different places, they're being cleaned up).

Thanks.
Comment 8 Tejun Heo 2010-10-04 18:21:08 UTC
On 10/04/2010 05:10 PM, James Bottomley wrote:
> An empty barrier isn't wrong.  An empty barrier sent down with the wrong
> flags (so we think it's a data request) is.  I suspect that's what's
> happening ... we're getting a zero size request marked as either read or
> write, so we trip the bug on when we try to map it.

I'm confused.  sd_prep_fn() tests REQ_FLUSH before
scsi_setup_fs_cmnd() is called.  sd_prep_fn() seems to be getting an
empty REQ_TYPE_FS request w/o any of REQ_DISCARD/FLUSH set.  Whether
REQ_WRITE is set or not doesn't make any difference.  The block layer
should never send down empty request unless it's one of the special
ones and the data direction shouldn't matter at all for REQ_FLUSH (and
I think REQ_WRITE makes more sense for flushes).

Another notable thing in the log is that libata "zero len r/w req"
warning is printed before the BUG_ON() in scsi_setup_fs_cmnd() trips.
I can't see how this can happen for the same request.

Will try to setup a test env but I think it's possible that this is
caused by incorrect build with mixed old and new flags.

Thanks.
Comment 9 Tejun Heo 2010-10-04 18:21:15 UTC
On 10/04/2010 06:05 PM, George Spelvin wrote:
> Tejun Heo <tj@kernel.org> wrote:
>> Just in case, can you please do "make mrproper" and then rebuild the
>> kernel?  The only thing I can think of now is mismatching flag bits
>> due to partial rebuild (unfortunately those flag bits have been hard
>> coded duplicately in different places, they're being cleaned up).
> 
> Done.  No change (kernel log attached).  I've also attached the
> (non-comment part of) .config in case that's of any use.

I see.  I'll try to reproduce the problem here tomorrow.  Thanks a lot
for verifying.
Comment 10 Anonymous Emailer 2010-10-04 18:37:55 UTC
Reply-To: James.Bottomley@suse.de

On Mon, 2010-10-04 at 17:04 +0200, Tejun Heo wrote:
> Hello,
> 
> On 10/04/2010 02:44 PM, George Spelvin wrote:
> >> Rafael J. Wysocki <rjw@sisk.pl> wrote:
> >> * Is this a regression?
> > 
> > Yes, it is; at least, booting with a 2.6.35 kernel avoids
> > the problem entirely.
> 
> Hmmm... weird.  The thing is that empty barrier is now pretty wildly
> used so if it is actually broken we should be getting a lot more
> reports and the only change that I can recall which might be relevant
> is req/bio flag bit reshuffling which in itself shouldn't cause
> problems you're describing.

An empty barrier isn't wrong.  An empty barrier sent down with the wrong
flags (so we think it's a data request) is.  I suspect that's what's
happening ... we're getting a zero size request marked as either read or
write, so we trip the bug on when we try to map it.

James
Comment 11 Anonymous Emailer 2010-10-04 18:37:55 UTC
Reply-To: James.Bottomley@suse.de

On Mon, 2010-10-04 at 17:33 +0200, Tejun Heo wrote:
> On 10/04/2010 05:10 PM, James Bottomley wrote:
> > An empty barrier isn't wrong.  An empty barrier sent down with the wrong
> > flags (so we think it's a data request) is.  I suspect that's what's
> > happening ... we're getting a zero size request marked as either read or
> > write, so we trip the bug on when we try to map it.
> 
> I'm confused.  sd_prep_fn() tests REQ_FLUSH before
> scsi_setup_fs_cmnd() is called.  sd_prep_fn() seems to be getting an
> empty REQ_TYPE_FS request w/o any of REQ_DISCARD/FLUSH set.  Whether
> REQ_WRITE is set or not doesn't make any difference.  The block layer
> should never send down empty request unless it's one of the special
> ones and the data direction shouldn't matter at all for REQ_FLUSH (and
> I think REQ_WRITE makes more sense for flushes).

It's not a SCSI problem, it's a dm/md problem.  What I think happened is
that a zero length barrier got translated into a zero length fs request
(possibly with or without the barrier).

> Another notable thing in the log is that libata "zero len r/w req"
> warning is printed before the BUG_ON() in scsi_setup_fs_cmnd() trips.
> I can't see how this can happen for the same request.

See above.

James

> Will try to setup a test env but I think it's possible that this is
> caused by incorrect build with mixed old and new flags.
> 
> Thanks.
>
Comment 12 Nicholas A. Bellinger 2010-10-04 23:12:09 UTC
Hi George,

Would you mind enabling CONFIG_SCSI_LOGGING=y in your kernel build and calling 

echo 0xffffffff > /proc/sys/dev/scsi/logging_level

so we can double check to see which CDBs are actually generating the issue..?

Thanks!
Comment 13 linux 2010-10-05 00:03:35 UTC
> Would you mind enabling CONFIG_SCSI_LOGGING=y in your kernel build and calling 
> 
> echo 0xffffffff > /proc/sys/dev/scsi/logging_level
> 
> so we can double check to see which CDBs are actually generating the issue..?
> 
> Thanks!

Here's a syslog starting at boot time for that (I also added verbose
SCSI errors, FWIW.)  I did
echo 0xffffffff > /proc/sys/dev/scsi/logging_level; echo check > /sys/block/md6/md/sync_action
to minimize time delay and resultany unrelated log spam.

Note that md6 is mirrored across *every* drive on the machine.  (It's the
emergency recovery /boot partition.)

23:55:16: Linux version 2.6.36-rc6-00070-g44c064a ($USER@$HOST) (gcc version 4.4.5 (Debian 4.4.4-17) ) #3 SMP Mon Oct 4 19:51:36 EDT 2010
23:55:16: Command line: auto BOOT_IMAGE=2.6 ro root=907 libata.fua=1 tsc_khz=2500210 amd64_edac_mod.ecc_enable_override=1 acpi_enforce_resources=lax k10temp.force=1
23:55:16: BIOS-provided physical RAM map:
23:55:16:  BIOS-e820: 0000000000000000 - 0000000000093800 (usable)
23:55:16:  BIOS-e820: 0000000000093800 - 00000000000a0000 (reserved)
23:55:16:  BIOS-e820: 00000000000e4000 - 0000000000100000 (reserved)
23:55:16:  BIOS-e820: 0000000000100000 - 00000000dffa0000 (usable)
23:55:16:  BIOS-e820: 00000000dffc0000 - 00000000dffce000 (ACPI data)
23:55:16:  BIOS-e820: 00000000dffce000 - 00000000dfff0000 (ACPI NVS)
23:55:16:  BIOS-e820: 00000000dfff0000 - 00000000dfffe000 (reserved)
23:55:16:  BIOS-e820: 00000000fff00000 - 0000000100000000 (reserved)
23:55:16:  BIOS-e820: 0000000100000000 - 0000000220000000 (usable)
23:55:16: NX (Execute Disable) protection: active
23:55:16: DMI present.
23:55:16: No AGP bridge found
23:55:16: last_pfn = 0x220000 max_arch_pfn = 0x400000000
23:55:16: x86 PAT enabled: cpu 0, old 0x7040600070406, new 0x7010600070106
23:55:16: last_pfn = 0xdffa0 max_arch_pfn = 0x400000000
23:55:16: found SMP MP-table at [ffff8800000ff780] ff780
23:55:16: Using GB pages for direct mapping
23:55:16: init_memory_mapping: 0000000000000000-00000000dffa0000
23:55:16: init_memory_mapping: 0000000100000000-0000000220000000
23:55:16: ACPI: RSDP 00000000000f9e30 00014 (v00 ACPIAM)
23:55:16: ACPI: RSDT 00000000dffc0000 00038 (v01 011309 RSDT1044 20090113 MSFT 00000097)
23:55:16: ACPI: FACP 00000000dffc0200 00084 (v02 011309 FACP1044 20090113 MSFT 00000097)
23:55:16: ACPI: DSDT 00000000dffc0440 06E9B (v01  1ADNC 1ADNC001 00000001 INTL 20051117)
23:55:16: ACPI: FACS 00000000dffce000 00040
23:55:16: ACPI: APIC 00000000dffc0390 0006C (v01 011309 APIC1044 20090113 MSFT 00000097)
23:55:16: ACPI: MCFG 00000000dffc0400 0003C (v01 011309 OEMMCFG  20090113 MSFT 00000097)
23:55:16: ACPI: OEMB 00000000dffce040 00071 (v01 011309 OEMB1044 20090113 MSFT 00000097)
23:55:16: ACPI: HPET 00000000dffc72e0 00038 (v01 011309 OEMHPET  20090113 MSFT 00000097)
23:55:16: (11/32 early reservations) ==> bootmem [0000000000 - 0220000000]
23:55:16:   #0 [0001000000 - 00017a4334]    TEXT DATA BSS ==> [0001000000 - 00017a4334]
23:55:16:   #1 [00017a5000 - 00017a51b8]              BRK ==> [00017a5000 - 00017a51b8]
23:55:16:   #2 [00000ff790 - 0000100000]    BIOS reserved ==> [00000ff790 - 0000100000]
23:55:16:   #3 [00000ff780 - 00000ff790]     MP-table mpf ==> [00000ff780 - 00000ff790]
23:55:16:   #4 [0000093800 - 00000fd190]    BIOS reserved ==> [0000093800 - 00000fd190]
23:55:16:   #5 [00000fd334 - 00000ff780]    BIOS reserved ==> [00000fd334 - 00000ff780]
23:55:16:   #6 [00000fd190 - 00000fd334]     MP-table mpc ==> [00000fd190 - 00000fd334]
23:55:16:   #7 [0000001000 - 0000003000]       TRAMPOLINE ==> [0000001000 - 0000003000]
23:55:16:   #8 [0000008000 - 000000a000]          PGTABLE ==> [0000008000 - 000000a000]
23:55:16:   #9 [000000a000 - 000000b000]          PGTABLE ==> [000000a000 - 000000b000]
23:55:16:   #10 [000000b000 - 000004f000]          BOOTMAP ==> [000000b000 - 000004f000]
23:55:16: Zone PFN ranges:
23:55:16:   DMA      0x00000001 -> 0x00001000
23:55:16:   DMA32    0x00001000 -> 0x00100000
23:55:16:   Normal   0x00100000 -> 0x00220000
23:55:16: Movable zone start PFN for each node
23:55:16: early_node_map[3] active PFN ranges
23:55:16:     0: 0x00000001 -> 0x00000093
23:55:16:     0: 0x00000100 -> 0x000dffa0
23:55:16:     0: 0x00100000 -> 0x00220000
23:55:16: ACPI: PM-Timer IO Port: 0x808
23:55:16: ACPI: LAPIC (acpi_id[0x01] lapic_id[0x00] enabled)
23:55:16: ACPI: LAPIC (acpi_id[0x02] lapic_id[0x01] enabled)
23:55:16: ACPI: LAPIC (acpi_id[0x03] lapic_id[0x02] enabled)
23:55:16: ACPI: LAPIC (acpi_id[0x04] lapic_id[0x03] enabled)
23:55:16: ACPI: IOAPIC (id[0x04] address[0xfec00000] gsi_base[0])
23:55:16: IOAPIC[0]: apic_id 4, version 33, address 0xfec00000, GSI 0-23
23:55:16: ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
23:55:16: ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 low level)
23:55:16: Using ACPI (MADT) for SMP configuration information
23:55:16: ACPI: HPET id: 0x8300 base: 0xfed00000
23:55:16: SMP: Allowing 4 CPUs, 0 hotplug CPUs
23:55:16: Allocating PCI resources starting at dfffe000 (gap: dfffe000:1ff02000)
23:55:16: setup_percpu: NR_CPUS:4 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1
23:55:16: PERCPU: Embedded 26 pages/cpu @ffff880028200000 s77632 r8192 d20672 u524288
23:55:16: pcpu-alloc: s77632 r8192 d20672 u524288 alloc=1*2097152
23:55:16: pcpu-alloc: [0] 0 1 2 3 
23:55:16: Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 2066302
23:55:16: Kernel command line: auto BOOT_IMAGE=2.6 ro root=907 libata.fua=1 tsc_khz=2500210 amd64_edac_mod.ecc_enable_override=1 acpi_enforce_resources=lax k10temp.force=1
23:55:16: PID hash table entries: 4096 (order: 3, 32768 bytes)
23:55:16: Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes)
23:55:16: Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes)
23:55:16: Checking aperture...
23:55:16: No AGP bridge found
23:55:16: Node 0: aperture @ 20000000 size 32 MB
23:55:16: Aperture pointing to e820 RAM. Ignoring.
23:55:16: Your BIOS doesn't leave a aperture memory hole
23:55:16: Please enable the IOMMU option in the BIOS setup
23:55:16: This costs you 64 MB of RAM
23:55:16: Mapping aperture over 65536 KB of RAM @ 20000000
23:55:16: Memory: 8118736k/8912896k available (4077k kernel code, 525112k absent, 269048k reserved, 2777k data, 492k init)
23:55:16: SLUB: Genslabs=13, HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
23:55:16: Hierarchical RCU implementation.
23:55:16: ^IRCU-based detection of stalled CPUs is disabled.
23:55:16: ^IVerbose stalled-CPUs detection is disabled.
23:55:16: NR_IRQS:384
23:55:16: Console: colour VGA+ 80x25
23:55:16: console [tty0] enabled
23:55:16: Fast TSC calibration failed
23:55:16: TSC: Unable to calibrate against PIT
23:55:16: TSC: using HPET reference calibration
23:55:16: Using user defined TSC freq: 2500.210 MHz
23:55:16: Detected 2500.213 MHz processor.
23:55:16: Calibrating delay loop (skipped), value calculated using timer frequency.. 5000.42 BogoMIPS (lpj=25002100)
23:55:16: pid_max: default: 32768 minimum: 301
23:55:16: Mount-cache hash table entries: 256
23:55:16: CPU: Physical Processor ID: 0
23:55:16: CPU: Processor Core ID: 0
23:55:16: mce: CPU supports 6 MCE banks
23:55:16: using C1E aware idle routine
23:55:16: Performance Events: AMD PMU driver.
23:55:16: ... version:                0
23:55:16: ... bit width:              48
23:55:16: ... generic registers:      4
23:55:16: ... value mask:             0000ffffffffffff
23:55:16: ... max period:             00007fffffffffff
23:55:16: ... fixed-purpose events:   0
23:55:16: ... event mask:             000000000000000f
23:55:16: Freeing SMP alternatives: 20k freed
23:55:16: ACPI: Core revision 20100702
23:55:16: Setting APIC routing to flat
23:55:16: ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
23:55:16: CPU0: AMD Phenom(tm) 9850 Quad-Core Processor stepping 03
23:55:16: NMI watchdog enabled, takes one hw-pmu counter.
23:55:16: Booting Node   0, Processors  #1
23:55:16: NMI watchdog enabled, takes one hw-pmu counter.
23:55:16: System has AMD C1E enabled
23:55:16: Switch to broadcast mode on CPU1
23:55:16:  #2
23:55:16: NMI watchdog enabled, takes one hw-pmu counter.
23:55:16: Switch to broadcast mode on CPU2
23:55:16:  #3 Ok.
23:55:16: NMI watchdog enabled, takes one hw-pmu counter.
23:55:16: Switch to broadcast mode on CPU3
23:55:16: Brought up 4 CPUs
23:55:16: Total of 4 processors activated (20001.68 BogoMIPS).
23:55:16: Switch to broadcast mode on CPU0
23:55:16: xor: automatically using best checksumming function: generic_sse
23:55:16:    generic_sse:  9959.200 MB/sec
23:55:16: xor: using function: generic_sse (9959.200 MB/sec)
23:55:16: NET: Registered protocol family 16
23:55:16: TOM: 00000000e0000000 aka 3584M
23:55:16: TOM2: 0000000220000000 aka 8704M
23:55:16: ACPI: bus type pci registered
23:55:16: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xe0000000-0xefffffff] (base 0xe0000000)
23:55:16: PCI: not using MMCONFIG
23:55:16: PCI: Using configuration type 1 for base access
23:55:16: PCI: Using configuration type 1 for extended access
23:55:16: bio: create slab <bio-0> at 0
23:55:16: raid6: int64x1   2439 MB/s
23:55:16: raid6: int64x2   2759 MB/s
23:55:16: raid6: int64x4   2031 MB/s
23:55:16: raid6: int64x8   1754 MB/s
23:55:16: raid6: sse2x1    3372 MB/s
23:55:16: raid6: sse2x2    5821 MB/s
23:55:16: raid6: sse2x4    6795 MB/s
23:55:16: raid6: using algorithm sse2x4 (6795 MB/s)
23:55:16: ACPI: Executed 3 blocks of module-level executable AML code
23:55:16: ACPI: Interpreter enabled
23:55:16: ACPI: (supports S0 S5)
23:55:16: ACPI: Using IOAPIC for interrupt routing
23:55:16: PCI: MMCONFIG for domain 0000 [bus 00-ff] at [mem 0xe0000000-0xefffffff] (base 0xe0000000)
23:55:16: PCI: MMCONFIG at [mem 0xe0000000-0xefffffff] reserved in ACPI motherboard resources
23:55:16: ACPI Warning: Incorrect checksum in table [OEMB] - 0xDD, should be 0xD4 (20100702/tbutils-314)
23:55:16: ACPI: No dock devices found.
23:55:16: PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
23:55:16: ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
23:55:16: pci_root PNP0A03:00: host bridge window [io  0x0000-0x0cf7]
23:55:16: pci_root PNP0A03:00: host bridge window [io  0x0d00-0xffff]
23:55:16: pci_root PNP0A03:00: host bridge window [mem 0x000a0000-0x000bffff]
23:55:16: pci_root PNP0A03:00: host bridge window [mem 0x000d0000-0x000dffff]
23:55:16: pci_root PNP0A03:00: host bridge window [mem 0xf0000000-0xfebfffff]
23:55:16: pci 0000:01:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
23:55:16: pci 0000:00:03.0: PCI bridge to [bus 01-01]
23:55:16: pci 0000:02:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
23:55:16: pci 0000:00:04.0: PCI bridge to [bus 02-02]
23:55:16: pci 0000:03:00.0: disabling ASPM on pre-1.1 PCIe device.  You can enable it with 'pcie_aspm=force'
23:55:16: pci 0000:00:05.0: PCI bridge to [bus 03-03]
23:55:46: r8169 0000:03:00.0: eth0: link up
23:56:29: md: data-check of RAID array md6
23:56:29: md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
23:56:29: md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
23:56:29: md: using 128k window, over a total of 1166912 blocks.
23:56:29: sd 0:0:0:0: [sda] sd_init_command: block=0, count=0
23:56:29: sd 0:0:0:0: [sda] block=0
23:56:29: sd 0:0:0:0: [sda] reading 0/0 512 byte blocks.
23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
23:56:29: ata1.00: WARNING: zero len r/w req
23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
23:56:29: Inserting command ffff88021984ed00 into mlqueue
23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
23:56:29: ata1.00: WARNING: zero len r/w req
23:56:29: leaving scsi_dispatch_cmnd()
23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
23:56:29: Inserting command ffff88021984ed00 into mlqueue
23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
23:56:29: ata1.00: WARNING: zero len r/w req
23:56:29: leaving scsi_dispatch_cmnd()
23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
23:56:29: Inserting command ffff88021984ed00 into mlqueue
23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
23:56:29: ata1.00: WARNING: zero len r/w req
23:56:29: leaving scsi_dispatch_cmnd()
23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
23:56:29: Inserting command ffff88021984ed00 into mlqueue
23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
23:56:29: ata1.00: WARNING: zero len r/w req
23:56:29: leaving scsi_dispatch_cmnd()
23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
23:56:29: Inserting command ffff88021984ed00 into mlqueue
23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
23:56:29: ata1.00: WARNING: zero len r/w req
23:56:29: leaving scsi_dispatch_cmnd()
23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 SUCCESS
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
23:56:29: sd 0:0:0:0: Notifying upper driver of completion (result 70000)
23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
23:56:29: 0 sectors total, 0 bytes done.
23:56:29: leaving scsi_dispatch_cmnd()
23:56:29: ------------[ cut here ]------------
23:56:29: kernel BUG at drivers/scsi/scsi_lib.c:1113!
23:56:29: invalid opcode: 0000 [#1] SMP 
23:56:29: last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
23:56:29: CPU 3 
23:56:29: Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core
23:56:29: 
23:56:29: Pid: 5446, comm: md6_resync Not tainted 2.6.36-rc6-00070-g44c064a #3 MS-7376/MS-7376
23:56:29: RIP: 0010:[<ffffffff812ac592>]  [<ffffffff812ac592>] scsi_setup_fs_cmnd+0x4e/0xbb
23:56:29: RSP: 0018:ffff88021af05ab0  EFLAGS: 00010046
23:56:29: RAX: 0000000000000000 RBX: ffff88021f39cb88 RCX: ffff88021f2ee960
23:56:29: RDX: 0000000000000000 RSI: ffff88021f39cb88 RDI: ffff88021f65bc00
23:56:29: RBP: ffff88021af05ac0 R08: 00000000000003e8 R09: ffff88021f677848
23:56:29: R10: 0000000000000000 R11: ffff88021f677848 R12: ffff88021f65bc00
23:56:29: R13: 0000000000000000 R14: ffff88021f65bc48 R15: ffff88021f2f7000
23:56:29: FS:  00007f096e6a27c0(0000) GS:ffff880028380000(0000) knlGS:0000000000000000
23:56:29: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
23:56:29: CR2: 0000003a10c1e8f0 CR3: 000000021c612000 CR4: 00000000000006e0
23:56:29: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
23:56:29: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
23:56:29: Process md6_resync (pid: 5446, threadinfo ffff88021af04000, task ffff88021988ac00)
23:56:29: Stack:
23:56:29:  0000000000000000 ffff88021f39cb88 ffff88021af05b40 ffffffff812b2af8
23:56:29: <0> ffff88021af05b40 ffffffff8116b8e5 0000000000000200 0000000000000000
23:56:29: <0> ffff88021f511868 ffff88021f2ee960 ffff88021f511958 ffff88021f65bc00
23:56:29: Call Trace:
23:56:29:  [<ffffffff812b2af8>] sd_prep_fn+0x252/0xb00
23:56:29:  [<ffffffff8116b8e5>] ? cfq_dispatch_requests+0x6c3/0x7ec
23:56:29:  [<ffffffff81160487>] blk_peek_request+0xb3/0x177
23:56:29:  [<ffffffff812abc42>] scsi_request_fn+0x8b/0x4cb
23:56:29:  [<ffffffff81160d9c>] __generic_unplug_device+0x32/0x37
23:56:29:  [<ffffffff81160dcc>] generic_unplug_device+0x2b/0x3a
23:56:29:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
23:56:29:  [<ffffffff81308275>] unplug_slaves+0x69/0x9f
23:56:29:  [<ffffffff813082c3>] raid1_unplug+0x18/0x28
23:56:29:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
23:56:29:  [<ffffffff8131c1b6>] md_unplug+0x1d/0x33
23:56:29:  [<ffffffff8131cb18>] md_do_sync+0x94c/0xba6
23:56:29:  [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
23:56:29:  [<ffffffff8131d17e>] md_thread+0xf6/0x114
23:56:29:  [<ffffffff8131d088>] ? md_thread+0x0/0x114
23:56:29:  [<ffffffff8131d088>] ? md_thread+0x0/0x114
23:56:29:  [<ffffffff81049e4f>] kthread+0x7d/0x85
23:56:29:  [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
Comment 14 Nicholas A. Bellinger 2010-10-05 01:14:59 UTC
On Mon, 2010-10-04 at 20:03 -0400, George Spelvin wrote:
> > Would you mind enabling CONFIG_SCSI_LOGGING=y in your kernel build and calling 
> > 
> > echo 0xffffffff > /proc/sys/dev/scsi/logging_level
> > 
> > so we can double check to see which CDBs are actually generating the issue..?
> > 
> > Thanks!
> 
> Here's a syslog starting at boot time for that (I also added verbose
> SCSI errors, FWIW.)  I did
> echo 0xffffffff > /proc/sys/dev/scsi/logging_level; echo check > /sys/block/md6/md/sync_action
> to minimize time delay and resultany unrelated log spam.
> 
> Note that md6 is mirrored across *every* drive on the machine.  (It's the
> emergency recovery /boot partition.)

<SNIP>

> 23:56:29: md: data-check of RAID array md6
> 23:56:29: md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
> 23:56:29: md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
> 23:56:29: md: using 128k window, over a total of 1166912 blocks.
> 23:56:29: sd 0:0:0:0: [sda] sd_init_command: block=0, count=0
> 23:56:29: sd 0:0:0:0: [sda] block=0
> 23:56:29: sd 0:0:0:0: [sda] reading 0/0 512 byte blocks.
> 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> 23:56:29: ata1.00: WARNING: zero len r/w req
> 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> 23:56:29: ata1.00: WARNING: zero len r/w req
> 23:56:29: leaving scsi_dispatch_cmnd()
> 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> 23:56:29: ata1.00: WARNING: zero len r/w req
> 23:56:29: leaving scsi_dispatch_cmnd()
> 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> 23:56:29: ata1.00: WARNING: zero len r/w req
> 23:56:29: leaving scsi_dispatch_cmnd()
> 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> 23:56:29: ata1.00: WARNING: zero len r/w req
> 23:56:29: leaving scsi_dispatch_cmnd()
> 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> 23:56:29: ata1.00: WARNING: zero len r/w req
> 23:56:29: leaving scsi_dispatch_cmnd()
> 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 SUCCESS
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> 23:56:29: sd 0:0:0:0: Notifying upper driver of completion (result 70000)
> 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> 23:56:29: 0 sectors total, 0 bytes done.
> 23:56:29: leaving scsi_dispatch_cmnd()

Ok, it looks like my initial guess about FUA / BARRIER breakage was
completely wrong here.  So the issue is in fact being caused by a
READ_10 with a transfer length of zero generated somewhere else UPL MD
code (perhaps something to do with MD metadata..?)

Would you be able to 'git bisect' on your system with Linus'es
linux-2.6.git tree from commit 9fe6206f400646a (v2.6.35) to HEAD at
v2.6.36-rc6 to help us pinpoint which commit the breakage was
introduced..?

Thanks!

--nab


> 23:56:29: ------------[ cut here ]------------
> 23:56:29: kernel BUG at drivers/scsi/scsi_lib.c:1113!
> 23:56:29: invalid opcode: 0000 [#1] SMP 
> 23:56:29: last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
> 23:56:29: CPU 3 
> 23:56:29: Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core
> 23:56:29: 
> 23:56:29: Pid: 5446, comm: md6_resync Not tainted 2.6.36-rc6-00070-g44c064a #3 MS-7376/MS-7376
> 23:56:29: RIP: 0010:[<ffffffff812ac592>]  [<ffffffff812ac592>] scsi_setup_fs_cmnd+0x4e/0xbb
> 23:56:29: RSP: 0018:ffff88021af05ab0  EFLAGS: 00010046
> 23:56:29: RAX: 0000000000000000 RBX: ffff88021f39cb88 RCX: ffff88021f2ee960
> 23:56:29: RDX: 0000000000000000 RSI: ffff88021f39cb88 RDI: ffff88021f65bc00
> 23:56:29: RBP: ffff88021af05ac0 R08: 00000000000003e8 R09: ffff88021f677848
> 23:56:29: R10: 0000000000000000 R11: ffff88021f677848 R12: ffff88021f65bc00
> 23:56:29: R13: 0000000000000000 R14: ffff88021f65bc48 R15: ffff88021f2f7000
> 23:56:29: FS:  00007f096e6a27c0(0000) GS:ffff880028380000(0000) knlGS:0000000000000000
> 23:56:29: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> 23:56:29: CR2: 0000003a10c1e8f0 CR3: 000000021c612000 CR4: 00000000000006e0
> 23:56:29: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> 23:56:29: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> 23:56:29: Process md6_resync (pid: 5446, threadinfo ffff88021af04000, task ffff88021988ac00)
> 23:56:29: Stack:
> 23:56:29:  0000000000000000 ffff88021f39cb88 ffff88021af05b40 ffffffff812b2af8
> 23:56:29: <0> ffff88021af05b40 ffffffff8116b8e5 0000000000000200 0000000000000000
> 23:56:29: <0> ffff88021f511868 ffff88021f2ee960 ffff88021f511958 ffff88021f65bc00
> 23:56:29: Call Trace:
> 23:56:29:  [<ffffffff812b2af8>] sd_prep_fn+0x252/0xb00
> 23:56:29:  [<ffffffff8116b8e5>] ? cfq_dispatch_requests+0x6c3/0x7ec
> 23:56:29:  [<ffffffff81160487>] blk_peek_request+0xb3/0x177
> 23:56:29:  [<ffffffff812abc42>] scsi_request_fn+0x8b/0x4cb
> 23:56:29:  [<ffffffff81160d9c>] __generic_unplug_device+0x32/0x37
> 23:56:29:  [<ffffffff81160dcc>] generic_unplug_device+0x2b/0x3a
> 23:56:29:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
> 23:56:29:  [<ffffffff81308275>] unplug_slaves+0x69/0x9f
> 23:56:29:  [<ffffffff813082c3>] raid1_unplug+0x18/0x28
> 23:56:29:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
> 23:56:29:  [<ffffffff8131c1b6>] md_unplug+0x1d/0x33
> 23:56:29:  [<ffffffff8131cb18>] md_do_sync+0x94c/0xba6
> 23:56:29:  [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
> 23:56:29:  [<ffffffff8131d17e>] md_thread+0xf6/0x114
> 23:56:29:  [<ffffffff8131d088>] ? md_thread+0x0/0x114
> 23:56:29:  [<ffffffff8131d088>] ? md_thread+0x0/0x114
> 23:56:29:  [<ffffffff81049e4f>] kthread+0x7d/0x85
> 23:56:29:  [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
Comment 15 Nicholas A. Bellinger 2010-10-05 01:23:25 UTC
Hi Neil,

Do you know if any of the recent changes into drivers/md/ code could
starting causing zero-length bio READ to be generated to MD RAID1
backstores along the lines of what George is currently seeing w/ 10x
RAID1 arrays during assembly..?

Thanks,

--nab


On Mon, 2010-10-04 at 17:10 -0700, Nicholas A. Bellinger wrote:
> On Mon, 2010-10-04 at 20:03 -0400, George Spelvin wrote:
> > > Would you mind enabling CONFIG_SCSI_LOGGING=y in your kernel build and calling 
> > > 
> > > echo 0xffffffff > /proc/sys/dev/scsi/logging_level
> > > 
> > > so we can double check to see which CDBs are actually generating the issue..?
> > > 
> > > Thanks!
> > 
> > Here's a syslog starting at boot time for that (I also added verbose
> > SCSI errors, FWIW.)  I did
> > echo 0xffffffff > /proc/sys/dev/scsi/logging_level; echo check > /sys/block/md6/md/sync_action
> > to minimize time delay and resultany unrelated log spam.
> > 
> > Note that md6 is mirrored across *every* drive on the machine.  (It's the
> > emergency recovery /boot partition.)
> 
> <SNIP>
> 
> > 23:56:29: md: data-check of RAID array md6
> > 23:56:29: md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
> > 23:56:29: md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
> > 23:56:29: md: using 128k window, over a total of 1166912 blocks.
> > 23:56:29: sd 0:0:0:0: [sda] sd_init_command: block=0, count=0
> > 23:56:29: sd 0:0:0:0: [sda] block=0
> > 23:56:29: sd 0:0:0:0: [sda] reading 0/0 512 byte blocks.
> > 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> > 23:56:29: ata1.00: WARNING: zero len r/w req
> > 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> > 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> > 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> > 23:56:29: ata1.00: WARNING: zero len r/w req
> > 23:56:29: leaving scsi_dispatch_cmnd()
> > 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> > 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> > 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> > 23:56:29: ata1.00: WARNING: zero len r/w req
> > 23:56:29: leaving scsi_dispatch_cmnd()
> > 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> > 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> > 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> > 23:56:29: ata1.00: WARNING: zero len r/w req
> > 23:56:29: leaving scsi_dispatch_cmnd()
> > 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> > 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> > 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> > 23:56:29: ata1.00: WARNING: zero len r/w req
> > 23:56:29: leaving scsi_dispatch_cmnd()
> > 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 RETRY
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> > 23:56:29: Inserting command ffff88021984ed00 into mlqueue
> > 23:56:29: sd 0:0:0:0: [sda] Send: 0xffff88021984ed00 
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: buffer = 0xffff88021984ee00, bufflen = 0, queuecommand 0xffffffff812be49d
> > 23:56:29: ata1.00: WARNING: zero len r/w req
> > 23:56:29: leaving scsi_dispatch_cmnd()
> > 23:56:29: sd 0:0:0:0: [sda] Done: 0xffff88021984ed00 SUCCESS
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: sd 0:0:0:0: [sda] CDB: Read(10): 28 00 00 00 00 00 00 00 00 00
> > 23:56:29: sd 0:0:0:0: [sda] scsi host busy 1 failed 0
> > 23:56:29: sd 0:0:0:0: Notifying upper driver of completion (result 70000)
> > 23:56:29: sd 0:0:0:0: [sda]  Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
> > 23:56:29: 0 sectors total, 0 bytes done.
> > 23:56:29: leaving scsi_dispatch_cmnd()
> 
> Ok, it looks like my initial guess about FUA / BARRIER breakage was
> completely wrong here.  So the issue is in fact being caused by a
> READ_10 with a transfer length of zero generated somewhere else UPL MD
> code (perhaps something to do with MD metadata..?)
> 
> Would you be able to 'git bisect' on your system with Linus'es
> linux-2.6.git tree from commit 9fe6206f400646a (v2.6.35) to HEAD at
> v2.6.36-rc6 to help us pinpoint which commit the breakage was
> introduced..?
> 
> Thanks!
> 
> --nab
> 
> 
> > 23:56:29: ------------[ cut here ]------------
> > 23:56:29: kernel BUG at drivers/scsi/scsi_lib.c:1113!
> > 23:56:29: invalid opcode: 0000 [#1] SMP 
> > 23:56:29: last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
> > 23:56:29: CPU 3 
> > 23:56:29: Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core
> > 23:56:29: 
> > 23:56:29: Pid: 5446, comm: md6_resync Not tainted 2.6.36-rc6-00070-g44c064a #3 MS-7376/MS-7376
> > 23:56:29: RIP: 0010:[<ffffffff812ac592>]  [<ffffffff812ac592>] scsi_setup_fs_cmnd+0x4e/0xbb
> > 23:56:29: RSP: 0018:ffff88021af05ab0  EFLAGS: 00010046
> > 23:56:29: RAX: 0000000000000000 RBX: ffff88021f39cb88 RCX: ffff88021f2ee960
> > 23:56:29: RDX: 0000000000000000 RSI: ffff88021f39cb88 RDI: ffff88021f65bc00
> > 23:56:29: RBP: ffff88021af05ac0 R08: 00000000000003e8 R09: ffff88021f677848
> > 23:56:29: R10: 0000000000000000 R11: ffff88021f677848 R12: ffff88021f65bc00
> > 23:56:29: R13: 0000000000000000 R14: ffff88021f65bc48 R15: ffff88021f2f7000
> > 23:56:29: FS:  00007f096e6a27c0(0000) GS:ffff880028380000(0000) knlGS:0000000000000000
> > 23:56:29: CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> > 23:56:29: CR2: 0000003a10c1e8f0 CR3: 000000021c612000 CR4: 00000000000006e0
> > 23:56:29: DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> > 23:56:29: DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> > 23:56:29: Process md6_resync (pid: 5446, threadinfo ffff88021af04000, task ffff88021988ac00)
> > 23:56:29: Stack:
> > 23:56:29:  0000000000000000 ffff88021f39cb88 ffff88021af05b40 ffffffff812b2af8
> > 23:56:29: <0> ffff88021af05b40 ffffffff8116b8e5 0000000000000200 0000000000000000
> > 23:56:29: <0> ffff88021f511868 ffff88021f2ee960 ffff88021f511958 ffff88021f65bc00
> > 23:56:29: Call Trace:
> > 23:56:29:  [<ffffffff812b2af8>] sd_prep_fn+0x252/0xb00
> > 23:56:29:  [<ffffffff8116b8e5>] ? cfq_dispatch_requests+0x6c3/0x7ec
> > 23:56:29:  [<ffffffff81160487>] blk_peek_request+0xb3/0x177
> > 23:56:29:  [<ffffffff812abc42>] scsi_request_fn+0x8b/0x4cb
> > 23:56:29:  [<ffffffff81160d9c>] __generic_unplug_device+0x32/0x37
> > 23:56:29:  [<ffffffff81160dcc>] generic_unplug_device+0x2b/0x3a
> > 23:56:29:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
> > 23:56:29:  [<ffffffff81308275>] unplug_slaves+0x69/0x9f
> > 23:56:29:  [<ffffffff813082c3>] raid1_unplug+0x18/0x28
> > 23:56:29:  [<ffffffff8115f0de>] blk_unplug+0x12/0x14
> > 23:56:29:  [<ffffffff8131c1b6>] md_unplug+0x1d/0x33
> > 23:56:29:  [<ffffffff8131cb18>] md_do_sync+0x94c/0xba6
> > 23:56:29:  [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
> > 23:56:29:  [<ffffffff8131d17e>] md_thread+0xf6/0x114
> > 23:56:29:  [<ffffffff8131d088>] ? md_thread+0x0/0x114
> > 23:56:29:  [<ffffffff8131d088>] ? md_thread+0x0/0x114
> > 23:56:29:  [<ffffffff81049e4f>] kthread+0x7d/0x85
> > 23:56:29:  [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-scsi" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
Comment 16 linux 2010-10-05 01:24:48 UTC
> Would you be able to 'git bisect' on your system with Linus'es
> linux-2.6.git tree from commit 9fe6206f400646a (v2.6.35) to HEAD at
> v2.6.36-rc6 to help us pinpoint which commit the breakage was
> introduced..?

It's tedious, but I can, HOWEVER...
any advice avoiding false positives from
https://bugzilla.kernel.org/show_bug.cgi?id=16275
introduced in 74450be123b6f3cb480c358a056be398cce6aa6e
and fixed in 2c7d46ec192e4f2b350f67a0e185b9bce646cd6b?

I suppose I could cherry-pick the latter when in the
vulnerable range...
Comment 17 Neil Brown 2010-10-05 01:53:36 UTC
I'm guessing the problem can be fixed by the following patch.

The likely problem is 'bi_flags' which could have a stray flag left over
from some earlier usage of the structure.

I'm far from certain though.

diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
index ad83a4d..117d403 100644
--- a/drivers/md/raid1.c
+++ b/drivers/md/raid1.c
@@ -1837,16 +1837,7 @@ static sector_t sync_request(mddev_t *mddev, sector_t sector_nr, int *skipped, i
 		mdk_rdev_t *rdev;
 		bio = r1_bio->bios[i];
 
-		/* take from bio_init */
-		bio->bi_next = NULL;
-		bio->bi_flags |= 1 << BIO_UPTODATE;
-		bio->bi_rw = READ;
-		bio->bi_vcnt = 0;
-		bio->bi_idx = 0;
-		bio->bi_phys_segments = 0;
-		bio->bi_size = 0;
-		bio->bi_end_io = NULL;
-		bio->bi_private = NULL;
+		bio_init(bio);
 
 		rdev = rcu_dereference(conf->mirrors[i].rdev);
 		if (rdev == NULL ||
Comment 18 linux 2010-10-05 12:31:23 UTC
> I'm guessing the problem can be fixed by the following patch.
> 
> The likely problem is 'bi_flags' which could have a stray flag left over
> from some earlier usage of the structure.
> 
> I'm far from certain though.

H'm... it didn't *fix* it, but it *changed* it into a NULL pointer bug.  The old backtrace was

Call Trace:
 [<ffffffff812b171d>] sd_prep_fn+0x241/0x868
 [<ffffffff81160487>] blk_peek_request+0xb3/0x177
 [<ffffffff812aae96>] scsi_request_fn+0x84/0x424
 [<ffffffff8103f279>] ? del_timer+0x7f/0x89
 [<ffffffff81160d9c>] __generic_unplug_device+0x32/0x37
 [<ffffffff81160dcc>] generic_unplug_device+0x2b/0x3a
 [<ffffffff8115f0de>] blk_unplug+0x12/0x14
 [<ffffffff81306b31>] unplug_slaves+0x69/0x9f
 [<ffffffff81306b7f>] raid1_unplug+0x18/0x28
 [<ffffffff8115f0de>] blk_unplug+0x12/0x14
 [<ffffffff8131aa72>] md_unplug+0x1d/0x33
 [<ffffffff8131b3d4>] md_do_sync+0x94c/0xba6
 [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
 [<ffffffff8131ba3a>] md_thread+0xf6/0x114
 [<ffffffff8131b944>] ? md_thread+0x0/0x114
 [<ffffffff8131b944>] ? md_thread+0x0/0x114
 [<ffffffff81049e4f>] kthread+0x7d/0x85
 [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
 [<ffffffff81049dd2>] ? kthread+0x0/0x85
 [<ffffffff81002c90>] ? kernel_thread_helper+0x0/0x10
or
Call Trace:
 [<ffffffff812b171d>] sd_prep_fn+0x241/0x868
 [<ffffffff8115eb7e>] ? elv_rb_del+0x30/0x49
 [<ffffffff81160487>] blk_peek_request+0xb3/0x177
 [<ffffffff812aae96>] scsi_request_fn+0x84/0x424
 [<ffffffff81160c18>] __blk_run_queue+0x3f/0x72
 [<ffffffff8115e831>] elv_insert+0x80/0x1a8
 [<ffffffff8115e9f1>] __elv_add_request+0x98/0x9f
 [<ffffffff8116174e>] __make_request+0x34a/0x3cd
 [<ffffffff8115feda>] generic_make_request+0x19a/0x204
 [<ffffffff8116000b>] submit_bio+0xc7/0xd0
 [<ffffffff810bb519>] ? bio_clone+0x39/0x44
 [<ffffffff8131be2b>] md_super_write+0xab/0xba
 [<ffffffff81322c77>] write_page+0x161/0x2c9
 [<ffffffff81092dca>] ? __slab_free+0x1f/0x25e
 [<ffffffff813232d2>] bitmap_daemon_work+0x417/0x498
 [<ffffffff81000c98>] ? __switch_to+0xea/0x212
 [<ffffffff8131da82>] md_check_recovery+0x19/0x43f
 [<ffffffff8130af28>] raid10d+0x34/0x804
 [<ffffffff8103f1ce>] ? try_to_del_timer_sync+0x83/0x8f

but with your patch, I got:

md: data-check of RAID array md6
md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
md: using 128k window, over a total of 1166912 blocks.
BUG: unable to handle kernel NULL pointer dereference at (null)
IP: [<ffffffff81309aa5>] sync_request+0x3da/0x519
PGD 21c607067 PUD 21928a067 PMD 0 
Oops: 0000 [#1] SMP 
last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
CPU 3 
Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core

Pid: 3950, comm: md6_resync Not tainted 2.6.36-rc6-00070-g44c064a-dirty #5 MS-7376/MS-7376
RIP: 0010:[<ffffffff81309aa5>]  [<ffffffff81309aa5>] sync_request+0x3da/0x519
RSP: 0018:ffff88021f265c20  EFLAGS: 00010256
RAX: 0000000000000000 RBX: ffff88021f5fe540 RCX: 0000000000000000
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88021d9ff180
RBP: ffff88021f265cc0 R08: 000000000000000a R09: 0000000000000000
R10: 0000000000000000 R11: dead000000200200 R12: ffff88021a37d9c0
R13: ffff88021f4eac00 R14: 0000000000000000 R15: ffff88021d9ff180
FS:  00007fb76ec35700(0000) GS:ffff880028380000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000000000000000 CR3: 000000021b034000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process md6_resync (pid: 3950, threadinfo ffff88021f264000, task ffff88021db72c00)
Stack:
 0000000000000000 0000000200000009 ffff880000000000 ffff88021a37da80
<0> ffff88021f5fe540 ffffffffffffffff ffffffff0000000a 000000000000000a
<0> ffff88021f4eada0 0000000000239c80 0000000000000018 0000000000000000
Call Trace:
 [<ffffffff8131c95c>] md_do_sync+0x778/0xba6
 [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
 [<ffffffff8131d196>] md_thread+0xf6/0x114
 [<ffffffff8131d0a0>] ? md_thread+0x0/0x114
 [<ffffffff8131d0a0>] ? md_thread+0x0/0x114
 [<ffffffff81049e4f>] kthread+0x7d/0x85
 [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
 [<ffffffff81049dd2>] ? kthread+0x0/0x85
 [<ffffffff81002c90>] ? kernel_thread_helper+0x0/0x10
Code: c9 e9 9a 00 00 00 49 63 c1 4d 8b 7c c4 50 49 83 7f 50 00 0f 84 84 00 00 00 41 0f b7 47 28 49 8b 57 48 31 c9 4c 89 ff 48 c1 e0 04 <4c> 8b 1c 10 44 89 d2 44 89 45 90 44 89 4d 88 44 89 55 80 4c 89 
RIP  [<ffffffff81309aa5>] sync_request+0x3da/0x519
 RSP <ffff88021f265c20>
CR2: 0000000000000000
---[ end trace 5567bf9375a1b1a7 ]---
Comment 19 Neil Brown 2010-10-05 20:40:12 UTC
Yes, of course it does .  Doh!

Sorry about that.

Try this instead.  It is nearly as ugly as the original, but it should be safer,
at least for now.

NeilBrown

diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
index ad83a4d..3b11fe9 100644
--- a/drivers/md/raid1.c
+++ b/drivers/md/raid1.c
@@ -1835,18 +1835,17 @@ static sector_t sync_request(mddev_t *mddev, sector_t sector_nr, int *skipped, i
 
 	for (i=0; i < conf->raid_disks; i++) {
 		mdk_rdev_t *rdev;
+		int f, m;
+		struct bio_vec *bv;
 		bio = r1_bio->bios[i];
 
-		/* take from bio_init */
-		bio->bi_next = NULL;
-		bio->bi_flags |= 1 << BIO_UPTODATE;
-		bio->bi_rw = READ;
-		bio->bi_vcnt = 0;
-		bio->bi_idx = 0;
-		bio->bi_phys_segments = 0;
-		bio->bi_size = 0;
-		bio->bi_end_io = NULL;
-		bio->bi_private = NULL;
+		f = bio->bi_flags & BIO_POOL_MASK;
+		m = bio->bi_max_vecs;
+		bv = bio->bi_io_vec;
+		bio_init(bio);
+		bio->bi_flags = f;
+		bio->bi_max_vecs = m;
+		bio->bi_io_vec = bv;
 
 		rdev = rcu_dereference(conf->mirrors[i].rdev);
 		if (rdev == NULL ||
Comment 20 linux 2010-10-05 23:01:41 UTC
> Try this instead.  It is nearly as ugly as the original, but it should be
> safer, at least for now.

Unfortunately, it results in no change in the BUG:

md: data-check of RAID array md6
md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for data-check.
md: using 128k window, over a total of 1166912 blocks.
ata1.00: WARNING: zero len r/w req
------------[ cut here ]------------
kernel BUG at drivers/scsi/scsi_lib.c:1113!
invalid opcode: 0000 [#1] SMP
last sysfs file: /sys/devices/virtual/block/md6/md/sync_action
CPU 3
Modules linked in: ctr twofish_generic twofish_x86_64 twofish_common serpent xcbc sha512_generic sha256_generic crypto_null ipg 8250_pci 8250_pnp 8250 serial_core

Pid: 7019, comm: md6_resync Not tainted 2.6.36-rc6-00070-g44c064a-dirty #8 MS-7376/MS-7376
RIP: 0010:[<ffffffff812ac592>]  [<ffffffff812ac592>] scsi_setup_fs_cmnd+0x4e/0xbb
RSP: 0018:ffff880219863ab0  EFLAGS: 00010046
RAX: 0000000000000000 RBX: ffff88021cd83d78 RCX: ffff88021e821190
RDX: 0000000000000000 RSI: ffff88021cd83d78 RDI: ffff88021f542000
RBP: ffff880219863ac0 R08: 00000000000003e8 R09: ffff880219863b40
R10: ffff88002838e450 R11: ffff880219863b40 R12: ffff88021f542000
R13: 0000000000000000 R14: ffff88021f542048 R15: ffff88021f3a8c00
FS:  00007f18492027c0(0000) GS:ffff880028380000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
CR2: 0000003a10c1e8f0 CR3: 000000021eba7000 CR4: 00000000000006e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process md6_resync (pid: 7019, threadinfo ffff880219862000, task ffff88021f3b2c00)
Stack:
 0000000000000000 ffff88021cd83d78 ffff880219863b40 ffffffff812b2af8
<0> ffff880219863b40 ffffffff8116b8e5 0000000000000000 0000000000000000
<0> ffff88021fc3f068 ffff88021e821190 ffff88021fc3f158 ffff88021f542000
Call Trace:
 [<ffffffff812b2af8>] sd_prep_fn+0x252/0xb00
 [<ffffffff8116b8e5>] ? cfq_dispatch_requests+0x6c3/0x7ec
 [<ffffffff81160487>] blk_peek_request+0xb3/0x177
 [<ffffffff812abc42>] scsi_request_fn+0x8b/0x4cb
 [<ffffffff81160d9c>] __generic_unplug_device+0x32/0x37
 [<ffffffff81160dcc>] generic_unplug_device+0x2b/0x3a
 [<ffffffff8115f0de>] blk_unplug+0x12/0x14
 [<ffffffff81308275>] unplug_slaves+0x69/0x9f
 [<ffffffff813082c3>] raid1_unplug+0x18/0x28
 [<ffffffff8115f0de>] blk_unplug+0x12/0x14
 [<ffffffff8131c202>] md_unplug+0x1d/0x33
 [<ffffffff8131cb64>] md_do_sync+0x94c/0xba6
 [<ffffffff8102f88f>] ? finish_task_switch+0x34/0x74
 [<ffffffff8131d1ca>] md_thread+0xf6/0x114
 [<ffffffff8131d0d4>] ? md_thread+0x0/0x114
 [<ffffffff8131d0d4>] ? md_thread+0x0/0x114
 [<ffffffff81049e4f>] kthread+0x7d/0x85
 [<ffffffff81002c94>] kernel_thread_helper+0x4/0x10
 [<ffffffff81049dd2>] ? kthread+0x0/0x85



Just FYI, bugzilla is corrupting all the patches you send me, converting
tabs to 4 spaces.  I can fix them, but if you generate a really large
one for some reason, a direct Cc: would be appreciated.

> diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
> index ad83a4d..3b11fe9 100644
> --- a/drivers/md/raid1.c
> +++ b/drivers/md/raid1.c
> @@ -1835,18 +1835,17 @@ static sector_t sync_request(mddev_t *mddev, sector_t
> sector_nr, int *skipped, i
> 
>      for (i=0; i < conf->raid_disks; i++) {
>          mdk_rdev_t *rdev;
> +        int f, m;
> +        struct bio_vec *bv;
>          bio = r1_bio->bios[i];
> 
> -        /* take from bio_init */
> -        bio->bi_next = NULL;
> -        bio->bi_flags |= 1 << BIO_UPTODATE;
> -        bio->bi_rw = READ;
> -        bio->bi_vcnt = 0;
> -        bio->bi_idx = 0;
> -        bio->bi_phys_segments = 0;
> -        bio->bi_size = 0;
> -        bio->bi_end_io = NULL;
> -        bio->bi_private = NULL;
> +        f = bio->bi_flags & BIO_POOL_MASK;
> +        m = bio->bi_max_vecs;
> +        bv = bio->bi_io_vec;
> +        bio_init(bio);
> +        bio->bi_flags = f;
> +        bio->bi_max_vecs = m;
> +        bio->bi_io_vec = bv;
> 
>          rdev = rcu_dereference(conf->mirrors[i].rdev);
>          if (rdev == NULL ||
Comment 21 Neil Brown 2010-10-06 01:47:16 UTC
Thanks for the testing.

Given that, I don't see how it could be an 'md' problem.
Very little has changed in md - especially md/raid1 - recently, and nothing
close to where the error is happening.

It looks like a 'git bisect' might be the only option.

BTW, my patch is fairly bogus and should not be used.  It does clear
bi_flags better so we can be sure that first read request is going down 
with the correct flags, but it has other problem which would quickly lead
to badness after that first request.
Comment 22 Neil Brown 2010-10-06 14:14:09 UTC
I noticed that you had a bitmap configured, and when I added that to my
testing I easily reproduced the problem.
And there have been some bitmap related changes, though I wouldn't have thought
that would affect this code...

Nevertheless, git bisect shows the culprit to be

commit ef4256733506f2459a0c436b62267d22a3f0cec6
Author: NeilBrown <neilb@suse.de>
Date:   Tue Jun 1 19:37:33 2010 +1000

    md/bitmap: optimise scanning of empty bitmaps.



I cannot see why just now.  Maybe in the morning....

NeilBrown
Comment 23 Neil Brown 2010-10-07 00:45:13 UTC
OK, I found out why.
That patch causes bitmap_start_sync to sometimes return much larger values
for sync_blocks, and when raid1.c::sync_request shifts that int <<9, it
overflows and becomes zero.

This is the simple fix that I will send to Linus.  I'll fix it to use
sector_t for the next merge window.

Thanks!!

diff --git a/drivers/md/raid1.c b/drivers/md/raid1.c
index ad83a4d..fba4d2f 100644
--- a/drivers/md/raid1.c
+++ b/drivers/md/raid1.c
@@ -1912,7 +1912,7 @@ static sector_t sync_request(mddev_t *mddev, sector_t sector_nr, int *skipped, i
 			    !test_bit(MD_RECOVERY_REQUESTED, &mddev->recovery))
 				break;
 			BUG_ON(sync_blocks < (PAGE_SIZE>>9));
-			if (len > (sync_blocks<<9))
+			if ((len >> 9) > sync_blocks)
 				len = sync_blocks<<9;
 		}
Comment 24 Rafael J. Wysocki 2010-10-07 19:50:56 UTC
Handled-By : Neil Brown <neilb@suse.de>
Patch : https://bugzilla.kernel.org/show_bug.cgi?id=19642#c23
Comment 25 linux 2010-10-07 20:08:46 UTC
Fix verified, thanks!
Comment 26 linux 2010-10-09 16:35:29 UTC
Looking at that fix:
-		if (len > (sync_blocks<<9))
+		if ((len >> 9) > sync_blocks)
 			len = sync_blocks<<9;

Is len guaranteed to be zero?  Otherwise, if len=513 and sync_blocks=1,
the two are not equivalent.  They would be if the condition were changed to
"if (len >> 9 >= sync_blocks)".

Oh... looking at the code, it appears that len is always a multiple
of 512.  In fact, the code would have significantly less shifting
if it were in units of blocks rather than bytes.

However, the other thing is that it appears that the test above can
never be true.  len starts out at PAGE_SIZE, and is possibly
decreased if that would exceed max_sector - sector_nr.

sync_blocks, on the other hand, has a BUG_ON if it's *less*
than PAGE_SIZE.  (And there's no test at all if the loop doesn't start
with sync_blocks == 0.)
Comment 27 Neil Brown 2010-10-09 20:00:53 UTC
On 9 Oct 2010 12:35:01 -0400
"George Spelvin" <linux@horizon.com> wrote:

> Looking at that fix:
> -		if (len > (sync_blocks<<9))
> +		if ((len >> 9) > sync_blocks)
>  			len = sync_blocks<<9;
> 
> Is len guaranteed to be zero?  Otherwise, if len=513 and sync_blocks=1,
> the two are not equivalent.  They would be if the condition were changed to
> "if (len >> 9 >= sync_blocks)".
> 
> Oh... looking at the code, it appears that len is always a multiple
> of 512.  In fact, the code would have significantly less shifting
> if it were in units of blocks rather than bytes.
> 
> However, the other thing is that it appears that the test above can
> never be true.  len starts out at PAGE_SIZE, and is possibly
> decreased if that would exceed max_sector - sector_nr.
> 
> sync_blocks, on the other hand, has a BUG_ON if it's *less*
> than PAGE_SIZE.  (And there's no test at all if the loop doesn't start
> with sync_blocks == 0.)

Correct.

I did consider just removing that test.
However the BUG_ON is a case of 'we don't support this yet' rather than 'this
is never possible'.
I might like to support bitmap chunks less than a page one day, and then this
could will be needed.  It was originally written when the intent was to
support small chunks.   Then I found it was really hard and possible not
necessary so I decided to exclude the possibility for now.


Thanks for the review.

NeilBrown
Comment 28 Rafael J. Wysocki 2010-10-10 17:27:32 UTC
Fixed by commit 7571ae887d3b96d8e7ce63d43828866c6a91cdc6 .

Note You need to log in before you can comment on or make changes to this bug.