PROBLEM: I/O scheduler problem with an 8 SATA disks raid 5 under heavy load ?

From: Guillaume Laurès
Date: Mon Jan 07 2008 - 10:07:05 EST


Hello,

Dear kernel developers, my dmesg asked me to report this, so here I go ;)
Here is what I found in my dmesg: "anticipatory: forced dispatching is broken (nr_sorted=1), please report this".

- First, let's talk about the machine: it's quite pushed so maybe the cause is me doing something wrong rather than a bug in the kernel.

I got this alert on a dual core amd64 xen host. It has 8 SATA drives making a raid 5 array. This array makes a virtual block device for one of the virtual machines: an Openfiler appliance. Openfiler then manages logical volumes on this device including an XFS partition shared via NFS. 2 MythTV hosts continuously write MPEG2 tv shows on it (1 to 4Gb each).
Still following ? Here is a summary: MPEG2 files -> NFS -> XFS -> LVM -> Xen VBD -> RAID 5 -> 8x SATA disks.

- Next, the symptoms.

This setup is only 2 weeks old. Behavior was quite good, except for some unexplained failures from the sata_nv attached disks. Not always from the same disk. Never from any disks attached through the sata_sil HBA.
Eventually a second disk would go down before the end of the raid reconstruction (still a sata_nv attached one).
Since the disks showed nothing wrong with smartmontools I re-added them each time. So far the raid array was strong enough to be fully recovered, mdadm --force and xfs_check are my friends ;-)
It seems to happen more often now that the XFS partition is quite heavily fragmented, and I can't even run the defragmenter without a quick failure.
I didn't payed big attention to the logs and quickly decided to buy a SATA Sil PCI card to get rid of the Nvidia SATA HBA.

- Now the problem.

Yesterday, however, the MPEG2 streams hanged for a few tens of seconds just as usual. But there were no disk failure. The array was still in good shape, although dmesg showed the same "ata[56]: Resetting port", "SCSI errors" etc. fuss.
However this was new in dmesg: "anticipatory: forced dispatching is broken (nr_sorted=1), please report this". Got 4 identical in a row.
Maybe managing 8 block devices queues under load with the anticipatory scheduler is too much ? I immediately switched to deadline on the 8 disks, and I'll see if it it happens again by stressing the whole system more and more.
I have no clue if anticipatory is a good choice or definitely not in my case, anyone can point some documentation or good advices ?

- How to reproduce.

Here is what I would do:
Harness a small CPU with lots of sata/scsi drives.
Do raid 5 with big block size (1-4Mb) on it.
Make a 50G XFS file system with sunit/swidth options
Trigger bonnie++ with 1G<files<4G and fill the FS to 80-95%, trying to achieve 98%+ fragmentation.
Defrag !

- Finally the usual bug report stuff is attached.

Attachment: cpuinfo
Description: Binary data

t-Access ATA Maxtor 6L200S0 BACE PQ: 0 ANSI: 5
SCSI device sdb: 398297088 512-byte hdwr sectors (203928 MB)
sdb: Write Protect is off
sdb: Mode Sense: 00 3a 00 00
SCSI device sdb: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sdb: 398297088 512-byte hdwr sectors (203928 MB)
sdb: Write Protect is off
sdb: Mode Sense: 00 3a 00 00
SCSI device sdb: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdb: sdb1 sdb2 sdb3
sd 1:0:0:0: Attached scsi disk sdb
scsi 2:0:0:0: Direct-Access ATA Maxtor 6L200S0 BACE PQ: 0 ANSI: 5
SCSI device sdc: 398297088 512-byte hdwr sectors (203928 MB)
sdc: Write Protect is off
sdc: Mode Sense: 00 3a 00 00
SCSI device sdc: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sdc: 398297088 512-byte hdwr sectors (203928 MB)
sdc: Write Protect is off
sdc: Mode Sense: 00 3a 00 00
SCSI device sdc: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdc: sdc1 sdc2 sdc3
sd 2:0:0:0: Attached scsi disk sdc
scsi 3:0:0:0: Direct-Access ATA Maxtor 6L200S0 BACE PQ: 0 ANSI: 5
SCSI device sdd: 398297088 512-byte hdwr sectors (203928 MB)
sdd: Write Protect is off
sdd: Mode Sense: 00 3a 00 00
SCSI device sdd: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sdd: 398297088 512-byte hdwr sectors (203928 MB)
sdd: Write Protect is off
sdd: Mode Sense: 00 3a 00 00
SCSI device sdd: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdd: sdd1 sdd2 sdd3
sd 3:0:0:0: Attached scsi disk sdd
sata_nv 0000:00:07.0: version 3.2
ACPI: PCI Interrupt Link [APSI] enabled at IRQ 21
ACPI: PCI Interrupt 0000:00:07.0[A] -> Link [APSI] -> GSI 21 (level, low) -> IRQ 21
sata_nv 0000:00:07.0: Using ADMA mode
PCI: Setting latency timer of device 0000:00:07.0 to 64
ata5: SATA max UDMA/133 cmd 0xFFFFC20000006480 ctl 0xFFFFC200000064A0 bmdma 0xCC00 irq 21
ata6: SATA max UDMA/133 cmd 0xFFFFC20000006580 ctl 0xFFFFC200000065A0 bmdma 0xCC08 irq 21
scsi4 : sata_nv
ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata5.00: ATA-7, max UDMA/133, 398297088 sectors: LBA48 NCQ (depth 31/32)
ata5.00: ata5: dev 0 multi count 16
ata5.00: configured for UDMA/133
scsi5 : sata_nv
ata6: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata6.00: ATA-7, max UDMA/133, 390721968 sectors: LBA48 NCQ (depth 31/32)
ata6.00: ata6: dev 0 multi count 16
ata6.00: configured for UDMA/133
scsi 4:0:0:0: Direct-Access ATA Maxtor 6B200M0 BANC PQ: 0 ANSI: 5
ata5: bounce limit 0xFFFFFFFFFFFFFFFF, segment boundary 0xFFFFFFFF, hw segs 61
SCSI device sde: 398297088 512-byte hdwr sectors (203928 MB)
sde: Write Protect is off
sde: Mode Sense: 00 3a 00 00
SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sde: 398297088 512-byte hdwr sectors (203928 MB)
sde: Write Protect is off
sde: Mode Sense: 00 3a 00 00
SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sde: sde1 sde2 sde3
sd 4:0:0:0: Attached scsi disk sde
scsi 5:0:0:0: Direct-Access ATA ST3200827AS 3.AA PQ: 0 ANSI: 5
ata6: bounce limit 0xFFFFFFFFFFFFFFFF, segment boundary 0xFFFFFFFF, hw segs 61
SCSI device sdf: 390721968 512-byte hdwr sectors (200050 MB)
sdf: Write Protect is off
sdf: Mode Sense: 00 3a 00 00
SCSI device sdf: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sdf: 390721968 512-byte hdwr sectors (200050 MB)
sdf: Write Protect is off
sdf: Mode Sense: 00 3a 00 00
SCSI device sdf: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdf: sdf1
sd 5:0:0:0: Attached scsi disk sdf
ACPI: PCI Interrupt Link [APSJ] enabled at IRQ 20
ACPI: PCI Interrupt 0000:00:08.0[A] -> Link [APSJ] -> GSI 20 (level, low) -> IRQ 20
sata_nv 0000:00:08.0: Using ADMA mode
PCI: Setting latency timer of device 0000:00:08.0 to 64
ata7: SATA max UDMA/133 cmd 0xFFFFC20000028480 ctl 0xFFFFC200000284A0 bmdma 0xB800 irq 20
ata8: SATA max UDMA/133 cmd 0xFFFFC20000028580 ctl 0xFFFFC200000285A0 bmdma 0xB808 irq 20
scsi6 : sata_nv
ata7: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata7.00: ATA-7, max UDMA/133, 390721968 sectors: LBA48 NCQ (depth 31/32)
ata7.00: ata7: dev 0 multi count 16
ata7.00: configured for UDMA/133
scsi7 : sata_nv
ata8: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata8.00: ATA-6, max UDMA/133, 390721968 sectors: LBA48
ata8.00: ata8: dev 0 multi count 16
ata8.00: configured for UDMA/133
scsi 6:0:0:0: Direct-Access ATA ST3200827AS 3.AA PQ: 0 ANSI: 5
ata7: bounce limit 0xFFFFFFFFFFFFFFFF, segment boundary 0xFFFFFFFF, hw segs 61
SCSI device sdg: 390721968 512-byte hdwr sectors (200050 MB)
sdg: Write Protect is off
sdg: Mode Sense: 00 3a 00 00
SCSI device sdg: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sdg: 390721968 512-byte hdwr sectors (200050 MB)
sdg: Write Protect is off
sdg: Mode Sense: 00 3a 00 00
SCSI device sdg: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdg: sdg1
sd 6:0:0:0: Attached scsi disk sdg
scsi 7:0:0:0: Direct-Access ATA ST3200822AS 3.01 PQ: 0 ANSI: 5
ata8: bounce limit 0xFFFFFFFFFFFFFFFF, segment boundary 0xFFFFFFFF, hw segs 61
SCSI device sdh: 390721968 512-byte hdwr sectors (200050 MB)
sdh: Write Protect is off
sdh: Mode Sense: 00 3a 00 00
SCSI device sdh: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
SCSI device sdh: 390721968 512-byte hdwr sectors (200050 MB)
sdh: Write Protect is off
sdh: Mode Sense: 00 3a 00 00
SCSI device sdh: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
sdh: sdh1
sd 7:0:0:0: Attached scsi disk sdh
pata_amd 0000:00:06.0: version 0.2.7
ata: 0x170 IDE port busy
ata: conflict with ide1
PCI: Setting latency timer of device 0000:00:06.0 to 64
ata9: PATA max UDMA/133 cmd 0x1F0 ctl 0x3F6 bmdma 0xE000 irq 14
ata10: DUMMY
scsi8 : pata_amd
ATA: abnormal status 0x8 on port 0x1F7
scsi9 : pata_amd
usbmon: debugfs is not available
ohci_hcd: 2006 August 04 USB 1.1 'Open' Host Controller (OHCI) Driver (PCI)
ACPI: PCI Interrupt Link [APCF] enabled at IRQ 23
ACPI: PCI Interrupt 0000:00:02.0[A] -> Link [APCF] -> GSI 23 (level, low) -> IRQ 23
PCI: Setting latency timer of device 0000:00:02.0 to 64
ohci_hcd 0000:00:02.0: OHCI Host Controller
ohci_hcd 0000:00:02.0: new USB bus registered, assigned bus number 1
ohci_hcd 0000:00:02.0: irq 23, io mem 0xfe02f000
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 10 ports detected
usb 1-5: new low speed USB device using ohci_hcd and address 2
usb 1-5: configuration #1 chosen from 1 choice
usb 1-6: new full speed USB device using ohci_hcd and address 3
usb 1-6: configuration #1 chosen from 1 choice
usbcore: registered new interface driver hiddev
input: Logitech USB Receiver as /class/input/input0
input: USB HID v1.10 Keyboard [Logitech USB Receiver] on usb-0000:00:02.0-5
input: Logitech USB Receiver as /class/input/input1
input: USB HID v1.10 Mouse [Logitech USB Receiver] on usb-0000:00:02.0-5
usbcore: registered new interface driver usbhid
drivers/usb/input/hid-core.c: v2.6:USB HID core driver
serio: i8042 KBD port at 0x60,0x64 irq 1
serio: i8042 AUX port at 0x60,0x64 irq 12
mice: PS/2 mouse device common for all mice
md: raid10 personality registered for level 10
device-mapper: ioctl: 4.11.0-ioctl (2006-10-12) initialised: dm-devel@xxxxxxxxxx
TCP cubic registered
NET: Registered protocol family 1
NET: Registered protocol family 15
md: Skipping autodetection of RAID arrays. (raid=noautodetect)
md: Loading md_d1: /dev/sda3
md: bind<sda3>
md: bind<sdb3>
md: bind<sdc3>
md: bind<sdd3>
md: bind<sde3>
raid10: raid set md_d1 active with 5 out of 6 devices
md_d1: bitmap initialized from disk: read 11/11 pages, set 228531 bits, status: 0
created bitmap (167 pages) for device md_d1
md_d1: p1 p2 p3
md_d1: p1 p2 p3
ReiserFS: md_d1p2: found reiserfs format "3.6" with standard journal
ReiserFS: md_d1p2: using ordered data mode
ReiserFS: md_d1p2: journal params: device md_d1p2, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
ReiserFS: md_d1p2: checking transaction log (md_d1p2)
ReiserFS: md_d1p2: Using r5 hash to sort names
VFS: Mounted root (reiserfs filesystem).
Freeing unused kernel memory: 228k freed
sd 0:0:0:0: Attached scsi generic sg0 type 0
sd 1:0:0:0: Attached scsi generic sg1 type 0
sd 2:0:0:0: Attached scsi generic sg2 type 0
sd 3:0:0:0: Attached scsi generic sg3 type 0
sd 4:0:0:0: Attached scsi generic sg4 type 0
sd 5:0:0:0: Attached scsi generic sg5 type 0
sd 6:0:0:0: Attached scsi generic sg6 type 0
sd 7:0:0:0: Attached scsi generic sg7 type 0
forcedeth.c: Reverse Engineered nForce ethernet driver. Version 0.59.
ACPI: PCI Interrupt Link [APCH] enabled at IRQ 22
ACPI: PCI Interrupt 0000:00:0a.0[A] -> Link [APCH] -> GSI 22 (level, low) -> IRQ 22
PCI: Setting latency timer of device 0000:00:0a.0 to 64
forcedeth: using HIGHDMA
Initializing USB Mass Storage driver...
scsi10 : SCSI emulation for USB Mass Storage devices
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
usb-storage: device found at 3
usb-storage: waiting for device to settle before scanning
ieee1394: Initialized config rom entry `ip1394'
eth0: forcedeth.c: subsystem: 01462:7125 bound to 0000:00:0a.0
i2c_adapter i2c-0: nForce2 SMBus adapter at 0x4c00
i2c_adapter i2c-1: nForce2 SMBus adapter at 0x4c40
ACPI: PCI Interrupt 0000:01:0c.0[A] -> Link [APC4] -> GSI 19 (level, low) -> IRQ 19
udev: renamed network interface eth0 to eth1
ohci1394: fw-host0: OHCI-1394 1.0 (PCI): IRQ=[19] MMIO=[fdeff000-fdeff7ff] Max Packet=[2048] IR/IT contexts=[4/8]
ieee1394: Host added: ID:BUS[0-00:1023] GUID[0010dc0000cbb4fa]
input: Power Button (FF) as /class/input/input2
ACPI: Power Button (FF) [PWRF]
input: Power Button (CM) as /class/input/input3
ACPI: Power Button (CM) [PWRB]
ACPI: Fan [FAN] (on)
ACPI: Thermal Zone [THRM] (22 C)
Capability LSM initialized
Bridge firewalling registered
802.1Q VLAN Support v1.8 Ben Greear <greearb@xxxxxxxxxxxxxxx>
All bugs added by David S. Miller <davem@xxxxxxxxxx>
md: md0 stopped.
md: bind<sdb2>
md: bind<sdc2>
md: bind<sdd2>
md: bind<sde2>
md: bind<sda2>
md: raid1 personality registered for level 1
raid1: raid set md0 active with 5 out of 5 mirrors
md0: bitmap initialized from disk: read 2/2 pages, set 0 bits, status: 0
created bitmap (17 pages) for device md0
md: md2 stopped.
md: bind<sdf1>
md: bind<sdg1>
md: bind<sdh1>
md: bind<sdd1>
md: bind<sdc1>
md: bind<sde1>
md: bind<sda1>
md: bind<sdb1>
raid5: automatically using best checksumming function: generic_sse
generic_sse: 5276.000 MB/sec
raid5: using function: generic_sse (5276.000 MB/sec)
raid6: int64x1 2046 MB/s
raid6: int64x2 2750 MB/s
raid6: int64x4 2890 MB/s
raid6: int64x8 1953 MB/s
raid6: sse2x1 1637 MB/s
raid6: sse2x2 1851 MB/s
raid6: sse2x4 2289 MB/s
raid6: using algorithm sse2x4 (2289 MB/s)
md: raid6 personality registered for level 6
md: raid5 personality registered for level 5
md: raid4 personality registered for level 4
raid5: device sdb1 operational as raid disk 0
raid5: device sda1 operational as raid disk 7
raid5: device sde1 operational as raid disk 6
raid5: device sdc1 operational as raid disk 5
raid5: device sdd1 operational as raid disk 4
raid5: device sdh1 operational as raid disk 3
raid5: device sdg1 operational as raid disk 2
raid5: device sdf1 operational as raid disk 1
raid5: allocated 8462kB for md2
raid5: raid level 5 set md2 active with 8 out of 8 devices, algorithm 2
RAID5 conf printout:
--- rd:8 wd:8
disk 0, o:1, dev:sdb1
disk 1, o:1, dev:sdf1
disk 2, o:1, dev:sdg1
disk 3, o:1, dev:sdh1
disk 4, o:1, dev:sdd1
disk 5, o:1, dev:sdc1
disk 6, o:1, dev:sde1
disk 7, o:1, dev:sda1
md2: bitmap initialized from disk: read 12/12 pages, set 0 bits, status: 0
created bitmap (187 pages) for device md2
ReiserFS: md0: warning: read_super_block: found reiserfs format "3.6" with non-standard journal
ReiserFS: md0: using ordered data mode
ReiserFS: md0: journal params: device md0, size 512, journal first block 18, max trans len 256, max batch 225, max commit age 30, max trans age 30
ReiserFS: md0: checking transaction log (md0)
ReiserFS: md0: Using r5 hash to sort names
Adding 2097144k swap on /dev/md_d1p1. Priority:-1 extents:1 across:2097144k
scsi 10:0:0:0: Direct-Access Generic USB SD Reader 1.00 PQ: 0 ANSI: 0
sd 10:0:0:0: Attached scsi removable disk sdi
sd 10:0:0:0: Attached scsi generic sg8 type 0
scsi 10:0:0:1: Direct-Access Generic USB CF Reader 1.01 PQ: 0 ANSI: 0
sd 10:0:0:1: Attached scsi removable disk sdj
sd 10:0:0:1: Attached scsi generic sg9 type 0
scsi 10:0:0:2: Direct-Access Generic USB SM Reader 1.02 PQ: 0 ANSI: 0
sd 10:0:0:2: Attached scsi removable disk sdk
sd 10:0:0:2: Attached scsi generic sg10 type 0
scsi 10:0:0:3: Direct-Access Generic USB MS Reader 1.03 PQ: 0 ANSI: 0
sd 10:0:0:3: Attached scsi removable disk sdl
sd 10:0:0:3: Attached scsi generic sg11 type 0
usb-storage: device scan complete
eth1.1: dev_set_promiscuity(master, 1)
device eth1 entered promiscuous mode
device eth1.1 entered promiscuous mode
eth1.6: dev_set_promiscuity(master, 1)
device eth1.6 entered promiscuous mode
eth1.8: dev_set_promiscuity(master, 1)
device eth1.8 entered promiscuous mode
eth1.9: dev_set_promiscuity(master, 1)
device eth1.9 entered promiscuous mode
xenbr1: port 1(eth1.1) entering learning state
xenbr1: topology change detected, propagating
xenbr1: port 1(eth1.1) entering forwarding state
xenbr6: port 1(eth1.6) entering learning state
xenbr6: topology change detected, propagating
xenbr6: port 1(eth1.6) entering forwarding state
xenbr8: port 1(eth1.8) entering learning state
xenbr8: topology change detected, propagating
xenbr8: port 1(eth1.8) entering forwarding state
xenbr9: port 1(eth1.9) entering learning state
xenbr9: topology change detected, propagating
xenbr9: port 1(eth1.9) entering forwarding state
NET: Registered protocol family 17
device vif1.0 entered promiscuous mode
xenbr9: port 2(vif1.0) entering learning state
xenbr9: topology change detected, propagating
xenbr9: port 2(vif1.0) entering forwarding state
device vif2.0 entered promiscuous mode
xenbr9: port 3(vif2.0) entering learning state
xenbr9: topology change detected, propagating
xenbr9: port 3(vif2.0) entering forwarding state
blkback: ring-ref 8, event-channel 6, protocol 2 (x86_32-abi)
blkback: ring-ref 8, event-channel 6, protocol 2 (x86_32-abi)
blkback: ring-ref 9, event-channel 7, protocol 2 (x86_32-abi)
ata5: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x400
ata5: CPB 0: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 1: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 2: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 3: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 4: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 5: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 6: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 7: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 8: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 9: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 10: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 11: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 12: ctl_flags 0x1f, resp_flags 0x2
ata5: CPB 13: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 14: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 15: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 16: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 17: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 18: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 19: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 20: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 21: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 22: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 23: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 24: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 25: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 26: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 27: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 28: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 29: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 30: ctl_flags 0x1f, resp_flags 0x1
ata5: Resetting port
ata5.00: exception Emask 0x0 SAct 0x1f02 SErr 0x0 action 0x2 frozen
ata5.00: cmd 60/40:08:8f:eb:67/00:00:03:00:00/40 tag 1 cdb 0x0 data 32768 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/08:40:17:eb:67/00:00:03:00:00/40 tag 8 cdb 0x0 data 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/18:48:47:eb:67/00:00:03:00:00/40 tag 9 cdb 0x0 data 12288 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/08:50:77:eb:67/00:00:03:00:00/40 tag 10 cdb 0x0 data 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/08:58:87:eb:67/00:00:03:00:00/40 tag 11 cdb 0x0 data 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5.00: cmd 60/48:60:d7:eb:67/00:00:03:00:00/40 tag 12 cdb 0x0 data 36864 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5: soft resetting port
ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata5.00: configured for UDMA/133
ata5: EH complete
SCSI device sde: 398297088 512-byte hdwr sectors (203928 MB)
sde: Write Protect is off
sde: Mode Sense: 00 3a 00 00
SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
anticipatory: forced dispatching is broken (nr_sorted=1), please report this
anticipatory: forced dispatching is broken (nr_sorted=1), please report this
anticipatory: forced dispatching is broken (nr_sorted=1), please report this
anticipatory: forced dispatching is broken (nr_sorted=1), please report this
ata5: EH in ADMA mode, notifier 0x1 notifier_error 0x0 gen_ctl 0x1501000 status 0x1540
ata5: CPB 0: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 1: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 2: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 3: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 4: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 5: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 6: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 7: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 8: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 9: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 10: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 11: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 12: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 13: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 14: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 15: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 16: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 17: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 18: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 19: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 20: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 21: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 22: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 23: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 24: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 25: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 26: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 27: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 28: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 29: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 30: ctl_flags 0x1f, resp_flags 0x1
ata5: Resetting port
ata5.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2 frozen
ata5.00: cmd 61/08:00:12:52:bd/00:00:17:00:00/40 tag 0 cdb 0x0 data 4096 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5: soft resetting port
ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata6: EH in ADMA mode, notifier 0x0 notifier_error 0x0 gen_ctl 0x1501000 status 0x500
ata6: CPB 0: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 1: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 2: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 3: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 4: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 5: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 6: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 7: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 8: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 9: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 10: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 11: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 12: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 13: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 14: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 15: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 16: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 17: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 18: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 19: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 20: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 21: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 22: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 23: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 24: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 25: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 26: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 27: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 28: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 29: ctl_flags 0x1f, resp_flags 0x1
ata6: CPB 30: ctl_flags 0x1f, resp_flags 0x1
ata6: Resetting port
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336135
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336199
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336215
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164335991
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336295
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336375
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336407
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336423
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336439
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336455
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336519
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336567
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336575
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336495
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336431
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336415
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336503
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336527
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336551
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336591
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336599
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336615
sd 5:0:0:0: SCSI error: return code = 0x06000000
end_request: I/O error, dev sdf, sector 164336695
ata5.00: configured for UDMA/133
ata5: EH complete
SCSI device sde: 398297088 512-byte hdwr sectors (203928 MB)
sde: Write Protect is off
sde: Mode Sense: 00 3a 00 00
SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA
raid5:md2: read error corrected (8 sectors at 164335928 on sdf1)
raid5:md2: read error corrected (8 sectors at 164335936 on sdf1)
raid5:md2: read error corrected (8 sectors at 164335944 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336072 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336080 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336088 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336096 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336104 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336136 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336152 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336160 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336168 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336176 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336184 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336192 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336200 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336208 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336216 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336232 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336240 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336248 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336256 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336264 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336272 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336280 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336288 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336296 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336312 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336320 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336328 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336344 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336352 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336360 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336368 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336376 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336392 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336400 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336408 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336416 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336424 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336432 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336440 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336456 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336464 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336472 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336488 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336496 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336504 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336512 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336520 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336528 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336536 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336552 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336560 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336568 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336576 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336584 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336592 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336600 on sdf1)
raid5:md2: read error corrected (8 sectors at 164336632 on sdf1)
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop anticipato not found
elevator: type noop [anticipat not found
elevator: type [deadline] not found
elevator: type [deadline] not found
elevator: type [deadline] not found
elevator: type [deadline] not found
elevator: type [deadline] not found
elevator: type [deadline] not found
elevator: type [deadline] not found
elevator: type [deadline] not found
ata5: EH in ADMA mode, notifier 0x1 notifier_error 0x0 gen_ctl 0x1501000 status 0x1540
ata5: CPB 0: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 1: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 2: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 3: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 4: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 5: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 6: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 7: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 8: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 9: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 10: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 11: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 12: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 13: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 14: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 15: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 16: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 17: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 18: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 19: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 20: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 21: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 22: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 23: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 24: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 25: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 26: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 27: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 28: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 29: ctl_flags 0x1f, resp_flags 0x1
ata5: CPB 30: ctl_flags 0x1f, resp_flags 0x1
ata5: Resetting port
ata5.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x2 frozen
ata5.00: cmd 61/08:00:1a:52:bd/00:00:17:00:00/40 tag 0 cdb 0x0 data 4096 out
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata5: soft resetting port
ata5: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
ata5.00: configured for UDMA/133
ata5: EH complete
SCSI device sde: 398297088 512-byte hdwr sectors (203928 MB)
sde: Write Protect is off
sde: Mode Sense: 00 3a 00 00
SCSI device sde: write cache: enabled, read cache: enabled, doesn't support DPO or FUA

Attachment: lspci
Description: Binary data

Attachment: modules
Description: Binary data

Attachment: scsi
Description: Binary data

Attachment: ver_linux
Description: Binary data


Thanks for your help !

GoM