Read i/o errs and disk replacement

Read i/o errs and disk replacement

[Wolfgang Mader]

Hi all,

well, I hit the first incidence where I really have to work with my btrfs 
setup. To get things straight I want to double-check here to not screw things 
up right from the start. We are talking about a home server. There is no time 
or user pressure involved, and there are backups, too.


Software
-------------
Linux 3.13.3
Btrfs v3.12


Hardware
---------------
5 1T hard drives configured to be a raid 10 for both data and metadata
    Data, RAID10: total=282.00GiB, used=273.33GiB
    System, RAID10: total=64.00MiB, used=36.00KiB
    Metadata, RAID10: total=1.00GiB, used=660.48MiB


Error
--------
This is not btrfs' fault but due to an hd error. I saw in the system logs
    btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, corrupt 0, gen 0
and a subsequent check on btrfs showed
    [/dev/sdb].write_io_errs   0
    [/dev/sdb].read_io_errs    2
    [/dev/sdb].flush_io_errs   0
    [/dev/sdb].corruption_errs 0
    [/dev/sdb].generation_errs 0

So, I have a read error on sdb.


Questions
---------------
1)
Do I have to take action immediately (shutdown the system, umount the file 
system)? Can I even ignore the error? Unfortunately, I can not access SMART 
information through the sata interface of the enclosure which hosts the hds.

2)
I only can replace the disk, not add a new one and than swap over. There is no 
space left in the disk enclosure I am using. I also can not guarantee that if 
I remove sdb and start the system up again that all the other disks are named 
the same as they are now, and that the newly added disk will be names sdb 
again. Is this an issue?

3)
I know that btrfs can handle disks of different sizes. Is there a downside if I 
go for a 3T disk and add it to the 1T disks? Is there e.g. more stuff saved on 
the 3T disk, and if this ones fails I lose redundancy? Is a soft transition to 
3T where I replace every dying 1T disk with a 3T disk advisable?


Proposed solution for the current issue
--------------------------------------------------------------
1)
Delete the faulted drive using
    btrfs device delete /dev/sdb /path/to/pool
2)
Format the new disk with btrfs
    mkfs.btrfs
3)
Add the new disk to the filesystem using
    btrfs device add /dev/newdiskname /path/to/pool
4)
Balance the file system
    btrfs fs balance /path/to/pool

Is this the proper way to deal with the situation?


Thank you for your advice.
Best,
Wolfgang

Re: Read i/o errs and disk replacement

[Chris Murphy]

On Feb 18, 2014, at 6:19 AM, Wolfgang Mader <Wolfgang_Mader@brain-frog.de> wrote:

> Hi all,
> 
> well, I hit the first incidence where I really have to work with my btrfs 
> setup. To get things straight I want to double-check here to not screw things 
> up right from the start. We are talking about a home server. There is no time 
> or user pressure involved, and there are backups, too.
> 
> 
> Software
> -------------
> Linux 3.13.3
> Btrfs v3.12
> 
> 
> Hardware
> ---------------
> 5 1T hard drives configured to be a raid 10 for both data and metadata
>    Data, RAID10: total=282.00GiB, used=273.33GiB
>    System, RAID10: total=64.00MiB, used=36.00KiB
>    Metadata, RAID10: total=1.00GiB, used=660.48MiB
> 
> 
> Error
> --------
> This is not btrfs' fault but due to an hd error. I saw in the system logs
>    btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, corrupt 0, gen 0
> and a subsequent check on btrfs showed
>    [/dev/sdb].write_io_errs   0
>    [/dev/sdb].read_io_errs    2
>    [/dev/sdb].flush_io_errs   0
>    [/dev/sdb].corruption_errs 0
>    [/dev/sdb].generation_errs 0
> 
> So, I have a read error on sdb.
> 
> 
> Questions
> ---------------
> 1)
> Do I have to take action immediately (shutdown the system, umount the file 
> system)? Can I even ignore the error? Unfortunately, I can not access SMART 
> information through the sata interface of the enclosure which hosts the hds.

A full dmesg should be sufficient to determine if this is due to the drive reporting a read error, in which case Btrfs is expected to get a copy of the missing data from a mirror, send it up to the application layer without error, and then write it to the LBAs of the device(s) that reported the original read error. It is kinda important to make sure that there wasn't a device reset, but an explicit read error. If the drive merely hangs while in recovery, upon reset any way of knowing what sectors were slow or bad is lost.



> 
> 2)
> I only can replace the disk, not add a new one and than swap over. There is no 
> space left in the disk enclosure I am using. I also can not guarantee that if 
> I remove sdb and start the system up again that all the other disks are named 
> the same as they are now, and that the newly added disk will be names sdb 
> again. Is this an issue?
> 
> 3)
> I know that btrfs can handle disks of different sizes. Is there a downside if I 
> go for a 3T disk and add it to the 1T disks? Is there e.g. more stuff saved on 
> the 3T disk, and if this ones fails I lose redundancy? Is a soft transition to 
> 3T where I replace every dying 1T disk with a 3T disk advisable?
> 
> 
> Proposed solution for the current issue
> --------------------------------------------------------------
> 1)
> Delete the faulted drive using
>    btrfs device delete /dev/sdb /path/to/pool
> 2)
> Format the new disk with btrfs
>    mkfs.btrfs
> 3)
> Add the new disk to the filesystem using
>    btrfs device add /dev/newdiskname /path/to/pool
> 4)
> Balance the file system
>    btrfs fs balance /path/to/pool
> 
> Is this the proper way to deal with the situation?

I wouldn't do anything until you really understand what the problem is.


Chris Murphy

Re: Read i/o errs and disk replacement

[Wolfgang Mader]

On Tuesday 18 February 2014 11:48:49 Chris Murphy wrote:
> On Feb 18, 2014, at 6:19 AM, Wolfgang Mader <Wolfgang_Mader@brain-frog.de> 
wrote:
> > Hi all,
> > 
> > well, I hit the first incidence where I really have to work with my btrfs
> > setup. To get things straight I want to double-check here to not screw
> > things up right from the start. We are talking about a home server. There
> > is no time or user pressure involved, and there are backups, too.
> > 
> > 
> > Software
> > -------------
> > Linux 3.13.3
> > Btrfs v3.12
> > 
> > 
> > Hardware
> > ---------------
> > 5 1T hard drives configured to be a raid 10 for both data and metadata
> > 
> >    Data, RAID10: total=282.00GiB, used=273.33GiB
> >    System, RAID10: total=64.00MiB, used=36.00KiB
> >    Metadata, RAID10: total=1.00GiB, used=660.48MiB
> > 
> > Error
> > --------
> > This is not btrfs' fault but due to an hd error. I saw in the system logs
> > 
> >    btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, corrupt 0, gen 0
> > 
> > and a subsequent check on btrfs showed
> > 
> >    [/dev/sdb].write_io_errs   0
> >    [/dev/sdb].read_io_errs    2
> >    [/dev/sdb].flush_io_errs   0
> >    [/dev/sdb].corruption_errs 0
> >    [/dev/sdb].generation_errs 0
> > 
> > So, I have a read error on sdb.
> > 
> > 
> > Questions
> > ---------------
> > 1)
> > Do I have to take action immediately (shutdown the system, umount the file
> > system)? Can I even ignore the error? Unfortunately, I can not access
> > SMART
> > information through the sata interface of the enclosure which hosts the
> > hds.
> A full dmesg should be sufficient to determine if this is due to the drive
> reporting a read error, in which case Btrfs is expected to get a copy of
> the missing data from a mirror, send it up to the application layer without
> error, and then write it to the LBAs of the device(s) that reported the
> original read error. It is kinda important to make sure that there wasn't a
> device reset, but an explicit read error. If the drive merely hangs while
> in recovery, upon reset any way of knowing what sectors were slow or bad is
> lost.

Thank you for your quick response.

The first read error is occurring during system start up when the raid is 
activated for the first time

[Tue Feb 18 13:02:08 2014] btrfs: use lzo compression
[Tue Feb 18 13:02:08 2014] btrfs: disk space caching is enabled
[Tue Feb 18 13:02:09 2014] btrfs: bdev /dev/sdb errs: wr 0, rd 1, flush 0, 
corrupt 0, gen 0

and then dmsg is silent for the next 10 minutes.


The second read error happens while the device is in use and is preceded by

-------start----------
Feb 18 13:14:09 deck kernel: ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 
action 0x6
Feb 18 13:14:09 deck kernel: ata2.15: edma_err_cause=00000084 
pp_flags=00000001, dev error, EDMA self-disable
Feb 18 13:14:09 deck kernel: ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 
action 0x0
Feb 18 13:14:09 deck kernel: ata2.00: failed command: READ DMA
Feb 18 13:14:09 deck kernel: ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 
tag 0 dma 4096 in
                                      res 51/04:08:60:f2:30/00:00:00:00:00/e0 
Emask 0x1 (device error)
Feb 18 13:14:09 deck kernel: ata2.00: status: { DRDY ERR }
Feb 18 13:14:09 deck kernel: ata2.00: error: { ABRT }
Feb 18 13:14:09 deck kernel: ata2.15: hard resetting link
Feb 18 13:14:14 deck kernel: ata2.15: link is slow to respond, please be 
patient (ready=0)
Feb 18 13:14:19 deck kernel: ata2.15: SRST failed (errno=-16)
Feb 18 13:14:19 deck kernel: ata2.15: hard resetting link
Feb 18 13:14:24 deck kernel: ata2.15: link is slow to respond, please be 
patient (ready=0)
Feb 18 13:14:29 deck kernel: ata2.15: SATA link up 3.0 Gbps (SStatus 123 
SControl F300)
Feb 18 13:14:29 deck kernel: 
Feb 18 13:14:30 deck kernel: ata2.01: hard resetting link
Feb 18 13:14:31 deck kernel: ata2.02: hard resetting link
Feb 18 13:14:31 deck kernel: ata2.03: hard resetting link
Feb 18 13:14:32 deck kernel: ata2.04: hard resetting link
Feb 18 13:14:32 deck kernel: ata2.05: hard resetting link
Feb 18 13:14:33 deck kernel: ata2.06: hard resetting link
Feb 18 13:14:34 deck kernel: ata2.07: hard resetting link
Feb 18 13:14:34 deck kernel: ata2.00: configured for UDMA/133
Feb 18 13:14:34 deck kernel: ata2.01: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2.02: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2.03: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2.04: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2.05: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2.06: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2.07: configured for UDMA/133
Feb 18 13:14:35 deck kernel: ata2: EH complete
-------end-------

This output it repeated several times and than end in this read error

[Tue Feb 18 13:15:48 2014] btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, 
corrupt 0, gen 0
[Tue Feb 18 13:15:48 2014] ata2: EH complete
[Tue Feb 18 13:15:48 2014] btrfs read error corrected: ino 1 off 29184540672 
(dev /dev/sdb sector 3207776)

This might have to do with the fact, that my hds power down after 15 min of 
idle time. I will investigate this.


Best,
Wolfgang




> > 2)
> > I only can replace the disk, not add a new one and than swap over. There
> > is no space left in the disk enclosure I am using. I also can not
> > guarantee that if I remove sdb and start the system up again that all the
> > other disks are named the same as they are now, and that the newly added
> > disk will be names sdb again. Is this an issue?
> > 
> > 3)
> > I know that btrfs can handle disks of different sizes. Is there a downside
> > if I go for a 3T disk and add it to the 1T disks? Is there e.g. more
> > stuff saved on the 3T disk, and if this ones fails I lose redundancy? Is
> > a soft transition to 3T where I replace every dying 1T disk with a 3T
> > disk advisable?
> > 
> > 
> > Proposed solution for the current issue
> > --------------------------------------------------------------
> > 1)
> > Delete the faulted drive using
> > 
> >    btrfs device delete /dev/sdb /path/to/pool
> > 
> > 2)
> > Format the new disk with btrfs
> > 
> >    mkfs.btrfs
> > 
> > 3)
> > Add the new disk to the filesystem using
> > 
> >    btrfs device add /dev/newdiskname /path/to/pool
> > 
> > 4)
> > Balance the file system
> > 
> >    btrfs fs balance /path/to/pool
> > 
> > Is this the proper way to deal with the situation?
> 
> I wouldn't do anything until you really understand what the problem is.
> 
> 
> Chris Murphy

Re: Read i/o errs and disk replacement

[Chris Murphy]

On Feb 18, 2014, at 2:33 PM, Wolfgang Mader <Wolfgang_Mader@brain-frog.de> wrote:
> 
> 
> Feb 18 13:14:09 deck kernel: ata2.00: failed command: READ DMA
> Feb 18 13:14:09 deck kernel: ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 
> tag 0 dma 4096 in
>                                      res 51/04:08:60:f2:30/00:00:00:00:00/e0 
> Emask 0x1 (device error)
> Feb 18 13:14:09 deck kernel: ata2.00: status: { DRDY ERR }
> Feb 18 13:14:09 deck kernel: ata2.00: error: { ABRT }
> Feb 18 13:14:09 deck kernel: ata2.15: hard resetting link
> Feb 18 13:14:14 deck kernel: ata2.15: link is slow to respond, please be 
> patient (ready=0)
> Feb 18 13:14:19 deck kernel: ata2.15: SRST failed (errno=-16)
> Feb 18 13:14:19 deck kernel: ata2.15: hard resetting link
> Feb 18 13:14:24 deck kernel: ata2.15: link is slow to respond, please be 
> patient (ready=0)
> Feb 18 13:14:29 deck kernel: ata2.15: SATA link up 3.0 Gbps (SStatus 123 
> SControl F300)
> Feb 18 13:14:29 deck kernel: 
> Feb 18 13:14:30 deck kernel: ata2.01: hard resetting link
> Feb 18 13:14:31 deck kernel: ata2.02: hard resetting link
> Feb 18 13:14:31 deck kernel: ata2.03: hard resetting link
> Feb 18 13:14:32 deck kernel: ata2.04: hard resetting link
> Feb 18 13:14:32 deck kernel: ata2.05: hard resetting link
> Feb 18 13:14:33 deck kernel: ata2.06: hard resetting link
> Feb 18 13:14:34 deck kernel: ata2.07: hard resetting link
> Feb 18 13:14:34 deck kernel: ata2.00: configured for UDMA/133
> Feb 18 13:14:34 deck kernel: ata2.01: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2.02: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2.03: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2.04: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2.05: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2.06: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2.07: configured for UDMA/133
> Feb 18 13:14:35 deck kernel: ata2: EH complete

Two things. The full dmesg includes useful information separate from the error messages, including the model drive to ata device mapping, and why there's a failed read to ATA2.00 yet there's a reset in sequence for ata2.01, 2.02, 2.03 and so on. So the entire dmesg would be useful.

In any case the actual problem might not be discoverable due to the hard resetting. I'm not finding any useful translation, in 5 minute search, for SRST. But it makes me suspicious of a configuration problem, like maybe an unnecessary jumper setting on a drive or with the enclosure itself. So I'd check for that. Also, what model drives are being used? If they are consumer drives, they almost certainly have long error recoveries over 30 minutes. And if the drive is trying to honor the read request for more than 30 seconds, the default SCSI block layer will time out and produce messages like what we see here. So you probably need to change the SCSI block layer timeout. To set the command timer to something else use:

echo <value> /sys/block/<device>/device/timeout

Where value is e.g. 121 since many consumer drives time out at 120 seconds this means the kernel will wait 121 seconds before starting its error handling (which includes resetting the drive and then the bus).



> -------end-------
> 
> This output it repeated several times and than end in this read error
> 
> [Tue Feb 18 13:15:48 2014] btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, 
> corrupt 0, gen 0
> [Tue Feb 18 13:15:48 2014] ata2: EH complete
> [Tue Feb 18 13:15:48 2014] btrfs read error corrected: ino 1 off 29184540672 
> (dev /dev/sdb sector 3207776)

Well that reads like Btrfs knows what sector had a read problem, without corruption being the cause, and corrected it. So the question then is whether /dev/sdb is the same as ata2.00. If ata2.00 isn't a drive but is the drive enclosure then you've got a different (or additional) problem.



Chris Murphy

Re: Read i/o errs and disk replacement

[Duncan]

Chris Murphy posted on Tue, 18 Feb 2014 15:02:51 -0700 as excerpted:

>  Also, what model drives are being used? If they are
> consumer drives, they almost certainly have long error recoveries over
> 30 minutes.

FWIW, that should be 30 seconds, not 30 minutes (OUCH!).  The below 
context sort of makes that clear for those good enough at reading between 
the lines, thus the suggestion to change the kernel timeout to 121 
seconds, but just in case...

> And if the drive is trying to honor the read request for
> more than 30 seconds, the default SCSI block layer will time out and
> produce messages like what we see here. So you probably need to change
> the SCSI block layer timeout. To set the command timer to something else
> use:
> 
> echo <value> /sys/block/<device>/device/timeout
> 
> Where value is e.g. 121 since many consumer drives time out at 120
> seconds this means the kernel will wait 121 seconds before starting its
> error handling (which includes resetting the drive and then the bus).

-- 
Duncan - List replies preferred.   No HTML msgs.
"Every nonfree program has a lord, a master --
and if you use the program, he is your master."  Richard Stallman

Re: Read i/o errs and disk replacement

[Duncan]

Chris Murphy posted on Tue, 18 Feb 2014 11:48:49 -0700 as excerpted:

>> This is not btrfs' fault but due to an hd error. I saw in the system
>> logs
>>    btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, corrupt 0, gen 0
>> and a subsequent check on btrfs showed
>>    [/dev/sdb].write_io_errs   0 [/dev/sdb].read_io_errs    2
>>    [/dev/sdb].flush_io_errs   0 [/dev/sdb].corruption_errs 0
>>    [/dev/sdb].generation_errs 0
>> 
>> So, I have a read error on sdb.
>>

It's worth noting that those errors don't reset automatically at boot or 
whatever.  The idea is to give a sysadmin some idea how many errors have 
happened in the filesystem's lifetime or since the last manual reset.  So 
as long as the number of errors isn't increasing at each boot, it's 
probably a historical and long since corrected error.


btrfs device stats -z

can be used to reset to zero if desired.  See the btrfs (8) manpage.

-- 
Duncan - List replies preferred.   No HTML msgs.
"Every nonfree program has a lord, a master --
and if you use the program, he is your master."  Richard Stallman

Re: Read i/o errs and disk replacement

[Chris Murphy]

On Feb 18, 2014, at 3:45 PM, Duncan <1i5t5.duncan@cox.net> wrote:

> Chris Murphy posted on Tue, 18 Feb 2014 15:02:51 -0700 as excerpted:
> 
>> Also, what model drives are being used? If they are
>> consumer drives, they almost certainly have long error recoveries over
>> 30 minutes.
> 
> FWIW, that should be 30 seconds, not 30 minutes (OUCH!).

Ha! That's funny to imagine. Even 7 seconds is an eternity.


Chris Murphy

Re: Read i/o errs and disk replacement

[Wolfgang Mader]

[-- Attachment #1: Type: text/plain, Size: 5500 bytes --]

On Tuesday 18 February 2014 15:02:51 Chris Murphy wrote:
> On Feb 18, 2014, at 2:33 PM, Wolfgang Mader <Wolfgang_Mader@brain-frog.de> 
wrote:
> > Feb 18 13:14:09 deck kernel: ata2.00: failed command: READ DMA
> > Feb 18 13:14:09 deck kernel: ata2.00: cmd
> > c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
> > 
> >                                      res
> >                                      51/04:08:60:f2:30/00:00:00:00:00/e0
> > 
> > Emask 0x1 (device error)
> > Feb 18 13:14:09 deck kernel: ata2.00: status: { DRDY ERR }
> > Feb 18 13:14:09 deck kernel: ata2.00: error: { ABRT }
> > Feb 18 13:14:09 deck kernel: ata2.15: hard resetting link
> > Feb 18 13:14:14 deck kernel: ata2.15: link is slow to respond, please be
> > patient (ready=0)
> > Feb 18 13:14:19 deck kernel: ata2.15: SRST failed (errno=-16)
> > Feb 18 13:14:19 deck kernel: ata2.15: hard resetting link
> > Feb 18 13:14:24 deck kernel: ata2.15: link is slow to respond, please be
> > patient (ready=0)
> > Feb 18 13:14:29 deck kernel: ata2.15: SATA link up 3.0 Gbps (SStatus 123
> > SControl F300)
> > Feb 18 13:14:29 deck kernel:
> > Feb 18 13:14:30 deck kernel: ata2.01: hard resetting link
> > Feb 18 13:14:31 deck kernel: ata2.02: hard resetting link
> > Feb 18 13:14:31 deck kernel: ata2.03: hard resetting link
> > Feb 18 13:14:32 deck kernel: ata2.04: hard resetting link
> > Feb 18 13:14:32 deck kernel: ata2.05: hard resetting link
> > Feb 18 13:14:33 deck kernel: ata2.06: hard resetting link
> > Feb 18 13:14:34 deck kernel: ata2.07: hard resetting link
> > Feb 18 13:14:34 deck kernel: ata2.00: configured for UDMA/133
> > Feb 18 13:14:34 deck kernel: ata2.01: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2.02: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2.03: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2.04: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2.05: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2.06: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2.07: configured for UDMA/133
> > Feb 18 13:14:35 deck kernel: ata2: EH complete
> 
> Two things. The full dmesg includes useful information separate from the
> error messages, including the model drive to ata device mapping, and why
> there's a failed read to ATA2.00 yet there's a reset in sequence for
> ata2.01, 2.02, 2.03 and so on. So the entire dmesg would be useful.

You want it, you get it. I attache the full output to this mail, and hope that 
the list allows for attachements. Here is a short summary.

The hd enclosure is a Sharkoon 8-Bay which is connected via e-sata. The hds 
are mostly Segate Barracude ES.2 (ST31000NSSUN1.0T) and one from Hitachi 
(HUA7210SASUN1.0T). All of them are server grade hds and have a device time 
out of 30. The hds are sata 1.0 such that they do not feature native command 
queuing. I have generally a low read/write performance, around 10MB/sec. I 
test the enclosure with a sata 2 disk and got a way better performance, around 
70MB/sec. This is why I sticked with the Skarkoon. If the bad performance is 
due to bad configuration, I would be happy to fix it. :-)

Now to the dmesg output.
The SRST error you spotted in the logs points to wrong jumper setting 
concerning master, slave, cable select. My hds do not have a jumper for this 
setting.

The order of the hds is ata2.00->sda ata2.01->sdc etc. The port multiplier 
through which all those devices are accessed is ata2.15.

I rebooted the system two times to see if the read error count goes up. Didn't 
happen, it sits still at 2.




> 
> In any case the actual problem might not be discoverable due to the hard
> resetting. I'm not finding any useful translation, in 5 minute search, for
> SRST. But it makes me suspicious of a configuration problem, like maybe an
> unnecessary jumper setting on a drive or with the enclosure itself. So I'd
> check for that. Also, what model drives are being used? If they are
> consumer drives, they almost certainly have long error recoveries over 30
> minutes. And if the drive is trying to honor the read request for more than
> 30 seconds, the default SCSI block layer will time out and produce messages
> like what we see here. So you probably need to change the SCSI block layer
> timeout. To set the command timer to something else use:
> 
> echo <value> /sys/block/<device>/device/timeout
> 
> Where value is e.g. 121 since many consumer drives time out at 120 seconds
> this means the kernel will wait 121 seconds before starting its error
> handling (which includes resetting the drive and then the bus).
> > -------end-------
> > 
> > This output it repeated several times and than end in this read error
> > 
> > [Tue Feb 18 13:15:48 2014] btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0,
> > corrupt 0, gen 0
> > [Tue Feb 18 13:15:48 2014] ata2: EH complete
> > [Tue Feb 18 13:15:48 2014] btrfs read error corrected: ino 1 off
> > 29184540672 (dev /dev/sdb sector 3207776)
> 
> Well that reads like Btrfs knows what sector had a read problem, without
> corruption being the cause, and corrected it. So the question then is
> whether /dev/sdb is the same as ata2.00. If ata2.00 isn't a drive but is
> the drive enclosure then you've got a different (or additional) problem.
> 
> 
> 
> Chris Murphy--
> To unsubscribe from this list: send the line "unsubscribe linux-btrfs" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html

[-- Attachment #2: dmsgForSdb --]
[-- Type: text/plain, Size: 42912 bytes --]

[Tue Feb 18 12:48:13 2014] Booting Linux on physical CPU 0x0
[Tue Feb 18 12:48:13 2014] Initializing cgroup subsys cpuset
[Tue Feb 18 12:48:13 2014] Initializing cgroup subsys cpu
[Tue Feb 18 12:48:13 2014] Initializing cgroup subsys cpuacct
[Tue Feb 18 12:48:13 2014] Linux version 3.13.3-1-ARCH (nobody@root-armv5-copy) (gcc version 4.8.2 20131219 (prerelease) (GCC) ) #1 PREEMPT Fri Feb 14 07:05:06 MST 2014
[Tue Feb 18 12:48:13 2014] CPU: Feroceon 88FR131 [56251311] revision 1 (ARMv5TE), cr=00053977
[Tue Feb 18 12:48:13 2014] CPU: VIVT data cache, VIVT instruction cache
[Tue Feb 18 12:48:13 2014] Machine: BUBBA3 Kirkwood based miniserver
[Tue Feb 18 12:48:13 2014] Memory policy: Data cache writeback
[Tue Feb 18 12:48:13 2014] On node 0 totalpages: 131072
[Tue Feb 18 12:48:13 2014] free_area_init_node: node 0, pgdat c0790088, node_mem_map c0867000
[Tue Feb 18 12:48:13 2014]   Normal zone: 1024 pages used for memmap
[Tue Feb 18 12:48:13 2014]   Normal zone: 0 pages reserved
[Tue Feb 18 12:48:13 2014]   Normal zone: 131072 pages, LIFO batch:31
[Tue Feb 18 12:48:13 2014] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[Tue Feb 18 12:48:13 2014] pcpu-alloc: [0] 0 
[Tue Feb 18 12:48:13 2014] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 130048
[Tue Feb 18 12:48:13 2014] Kernel command line: root=/dev/sda1 console=ttyS0,115200 serial=4773 key=MY9lUnZnipL/8TwjF/qU/X3Gzoc= button=0
[Tue Feb 18 12:48:13 2014] PID hash table entries: 2048 (order: 1, 8192 bytes)
[Tue Feb 18 12:48:13 2014] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[Tue Feb 18 12:48:13 2014] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[Tue Feb 18 12:48:13 2014] Memory: 511144K/524288K available (5487K kernel code, 333K rwdata, 1660K rodata, 259K init, 828K bss, 13144K reserved)
[Tue Feb 18 12:48:13 2014] Virtual kernel memory layout:
    vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    fixmap  : 0xfff00000 - 0xfffe0000   ( 896 kB)
    vmalloc : 0xe0800000 - 0xff000000   ( 488 MB)
    lowmem  : 0xc0000000 - 0xe0000000   ( 512 MB)
    modules : 0xbf000000 - 0xc0000000   (  16 MB)
      .text : 0xc0008000 - 0xc0702e14   (7148 kB)
      .init : 0xc0703000 - 0xc0743c64   ( 260 kB)
      .data : 0xc0744000 - 0xc079760c   ( 334 kB)
       .bss : 0xc079760c - 0xc0866834   ( 829 kB)
[Tue Feb 18 12:48:13 2014] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[Tue Feb 18 12:48:13 2014] Preemptible hierarchical RCU implementation.
[Tue Feb 18 12:48:13 2014] NR_IRQS:114
[Tue Feb 18 12:48:13 2014] sched_clock: 32 bits at 166MHz, resolution 6ns, wraps every 25769803770ns
[Tue Feb 18 12:48:13 2014] Console: colour dummy device 80x30
[Tue Feb 18 12:48:33 2014] Calibrating delay loop... 1196.85 BogoMIPS (lpj=5984256)
[Tue Feb 18 12:48:33 2014] pid_max: default: 32768 minimum: 301
[Tue Feb 18 12:48:33 2014] Security Framework initialized
[Tue Feb 18 12:48:33 2014] AppArmor: AppArmor disabled by boot time parameter
[Tue Feb 18 12:48:33 2014] Mount-cache hash table entries: 512
[Tue Feb 18 12:48:33 2014] Initializing cgroup subsys devices
[Tue Feb 18 12:48:33 2014] Initializing cgroup subsys freezer
[Tue Feb 18 12:48:33 2014] Initializing cgroup subsys net_cls
[Tue Feb 18 12:48:33 2014] Initializing cgroup subsys blkio
[Tue Feb 18 12:48:33 2014] Initializing cgroup subsys bfqio
[Tue Feb 18 12:48:33 2014] Initializing cgroup subsys perf_event
[Tue Feb 18 12:48:33 2014] CPU: Testing write buffer coherency: ok
[Tue Feb 18 12:48:33 2014] Setting up static identity map for 0x538dd8 - 0x538e30
[Tue Feb 18 12:48:33 2014] devtmpfs: initialized
[Tue Feb 18 12:48:33 2014] pinctrl core: initialized pinctrl subsystem
[Tue Feb 18 12:48:33 2014] NET: Registered protocol family 16
[Tue Feb 18 12:48:33 2014] DMA: preallocated 256 KiB pool for atomic coherent allocations
[Tue Feb 18 12:48:33 2014] cpuidle: using governor ladder
[Tue Feb 18 12:48:33 2014] cpuidle: using governor menu
[Tue Feb 18 12:48:33 2014] Kirkwood: MV88F6281-A1, TCLK=166666667.
[Tue Feb 18 12:48:33 2014] Feroceon L2: Enabling L2
[Tue Feb 18 12:48:33 2014] Feroceon L2: Cache support initialised.
[Tue Feb 18 12:48:33 2014] initial MPP regs: 01112222 43303311 33330044 33003333 00000033 00000000 00000000
[Tue Feb 18 12:48:33 2014]   final MPP regs: 11112222 43303311 33330044 33003333 00000033 00000000 00000000
[Tue Feb 18 12:48:33 2014] Kirkwood PCIe port 0: link up
[Tue Feb 18 12:48:33 2014] Kirkwood PCIe port 1: link up
[Tue Feb 18 12:48:33 2014] PCI: bus0 uses PCIe port 0
[Tue Feb 18 12:48:33 2014] PCI host bridge to bus 0000:00
[Tue Feb 18 12:48:33 2014] pci_bus 0000:00: root bus resource [mem 0xe0000000-0xe7ffffff]
[Tue Feb 18 12:48:33 2014] pci_bus 0000:00: root bus resource [io  0x1000-0xffff]
[Tue Feb 18 12:48:33 2014] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[Tue Feb 18 12:48:33 2014] pci 0000:00:00.0: [11ab:6281] type 00 class 0x058000
[Tue Feb 18 12:48:33 2014] pci 0000:00:00.0: reg 0x10: [mem 0xd0000000-0xd00fffff 64bit pref]
[Tue Feb 18 12:48:33 2014] pci 0000:00:00.0: reg 0x18: [mem 0x00000000-0x1fffffff]
[Tue Feb 18 12:48:33 2014] pci 0000:00:00.0: supports D1 D2
[Tue Feb 18 12:48:33 2014] pci 0000:00:01.0: [168c:002a] type 00 class 0x028000
[Tue Feb 18 12:48:33 2014] pci 0000:00:01.0: reg 0x10: [mem 0x00000000-0x0000ffff 64bit]
[Tue Feb 18 12:48:33 2014] pci 0000:00:01.0: supports D1
[Tue Feb 18 12:48:33 2014] pci 0000:00:01.0: PME# supported from D0 D1 D3hot
[Tue Feb 18 12:48:33 2014] PCI: bus0: Fast back to back transfers disabled
[Tue Feb 18 12:48:33 2014] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 00
[Tue Feb 18 12:48:33 2014] PCI: bus1 uses PCIe port 1
[Tue Feb 18 12:48:33 2014] PCI host bridge to bus 0000:01
[Tue Feb 18 12:48:33 2014] pci_bus 0000:01: root bus resource [mem 0xe8000000-0xefffffff]
[Tue Feb 18 12:48:33 2014] pci_bus 0000:01: root bus resource [io  0x10000-0x1ffff]
[Tue Feb 18 12:48:33 2014] pci_bus 0000:01: No busn resource found for root bus, will use [bus 01-ff]
[Tue Feb 18 12:48:33 2014] PCI: bus1: Fast back to back transfers enabled
[Tue Feb 18 12:48:33 2014] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[Tue Feb 18 12:48:33 2014] pci 0000:00:01.0: BAR 0: assigned [mem 0xe0000000-0xe000ffff 64bit]
[Tue Feb 18 12:48:33 2014] bio: create slab <bio-0> at 0
[Tue Feb 18 12:48:33 2014] vgaarb: loaded
[Tue Feb 18 12:48:33 2014] SCSI subsystem initialized
[Tue Feb 18 12:48:33 2014] libata version 3.00 loaded.
[Tue Feb 18 12:48:33 2014] usbcore: registered new interface driver usbfs
[Tue Feb 18 12:48:33 2014] usbcore: registered new interface driver hub
[Tue Feb 18 12:48:33 2014] usbcore: registered new device driver usb
[Tue Feb 18 12:48:33 2014] pps_core: LinuxPPS API ver. 1 registered
[Tue Feb 18 12:48:33 2014] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[Tue Feb 18 12:48:33 2014] PTP clock support registered
[Tue Feb 18 12:48:33 2014] Switched to clocksource orion_clocksource
[Tue Feb 18 12:48:33 2014] FS-Cache: Loaded
[Tue Feb 18 12:48:33 2014] NET: Registered protocol family 2
[Tue Feb 18 12:48:33 2014] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[Tue Feb 18 12:48:33 2014] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[Tue Feb 18 12:48:33 2014] TCP: Hash tables configured (established 4096 bind 4096)
[Tue Feb 18 12:48:33 2014] TCP: reno registered
[Tue Feb 18 12:48:33 2014] UDP hash table entries: 256 (order: 0, 4096 bytes)
[Tue Feb 18 12:48:33 2014] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[Tue Feb 18 12:48:33 2014] NET: Registered protocol family 1
[Tue Feb 18 12:48:33 2014] PCI: CLS 32 bytes, default 32
[Tue Feb 18 12:48:33 2014] BUBBA3: driver ver 0.1 (build Feb 14 2014 06:49:19) loaded
[Tue Feb 18 12:48:33 2014] audit: initializing netlink socket (disabled)
[Tue Feb 18 12:48:33 2014] type=2000 audit(0.120:1): initialized
[Tue Feb 18 12:48:34 2014] VFS: Disk quotas dquot_6.5.2
[Tue Feb 18 12:48:34 2014] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[Tue Feb 18 12:48:34 2014] jffs2: version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
[Tue Feb 18 12:48:34 2014] aufs 3.13-20140127
[Tue Feb 18 12:48:34 2014] msgmni has been set to 998
[Tue Feb 18 12:48:34 2014] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[Tue Feb 18 12:48:34 2014] io scheduler noop registered
[Tue Feb 18 12:48:34 2014] io scheduler deadline registered
[Tue Feb 18 12:48:34 2014] io scheduler cfq registered
[Tue Feb 18 12:48:34 2014] io scheduler bfq registered (default)
[Tue Feb 18 12:48:34 2014] BFQ I/O-scheduler version: v7r1
[Tue Feb 18 12:48:34 2014] mv_xor mv_xor.0: Marvell shared XOR driver
[Tue Feb 18 12:48:34 2014] mv_xor mv_xor.0: Marvell XOR: ( xor cpy )
[Tue Feb 18 12:48:34 2014] mv_xor mv_xor.0: Marvell XOR: ( xor cpy )
[Tue Feb 18 12:48:34 2014] mv_xor mv_xor.1: Marvell shared XOR driver
[Tue Feb 18 12:48:34 2014] mv_xor mv_xor.1: Marvell XOR: ( xor cpy )
[Tue Feb 18 12:48:34 2014] mv_xor mv_xor.1: Marvell XOR: ( xor cpy )
[Tue Feb 18 12:48:34 2014] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[Tue Feb 18 12:48:34 2014] serial8250.0: ttyS0 at MMIO 0xf1012000 (irq = 33, base_baud = 10416666) is a 16550A
[Tue Feb 18 12:48:34 2014] console [ttyS0] enabled
[Tue Feb 18 12:48:34 2014] brd: module loaded
[Tue Feb 18 12:48:34 2014] loop: module loaded
[Tue Feb 18 12:48:34 2014] sata_mv sata_mv.0: version 1.28
[Tue Feb 18 12:48:34 2014] sata_mv sata_mv.0: cannot get optional clkdev
[Tue Feb 18 12:48:34 2014] sata_mv sata_mv.0: slots 32 ports 2
[Tue Feb 18 12:48:34 2014] scsi0 : sata_mv
[Tue Feb 18 12:48:34 2014] scsi1 : sata_mv
[Tue Feb 18 12:48:34 2014] ata1: SATA max UDMA/133 irq 21
[Tue Feb 18 12:48:34 2014] ata2: SATA max UDMA/133 irq 21
[Tue Feb 18 12:48:34 2014] m25p80 spi0.0: m25p16 (2048 Kbytes)
[Tue Feb 18 12:48:34 2014] Creating 3 MTD partitions on "spi_flash":
[Tue Feb 18 12:48:34 2014] 0x000000000000-0x0000000c0000 : "u-boot"
[Tue Feb 18 12:48:34 2014] 0x0000000c0000-0x0000000e0000 : "env"
[Tue Feb 18 12:48:34 2014] 0x0000000e0000-0x000000200000 : "data"
[Tue Feb 18 12:48:34 2014] libphy: orion_mdio_bus: probed
[Tue Feb 18 12:48:34 2014] mv643xx_eth: MV-643xx 10/100/1000 ethernet driver version 1.4
[Tue Feb 18 12:48:35 2014] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 12:48:35 2014] ata1.00: ATA-8: SEAGATE ST31000NSSUN1.0T 093454YYGN,     SU0D, max UDMA/133
[Tue Feb 18 12:48:35 2014] ata1.00: 1953525168 sectors, multi 0: LBA48 NCQ (depth 31/32)
[Tue Feb 18 12:48:35 2014] ata1.00: configured for UDMA/133
[Tue Feb 18 12:48:35 2014] scsi 0:0:0:0: Direct-Access     ATA      SEAGATE ST31000N n/a  PQ: 0 ANSI: 5
[Tue Feb 18 12:48:35 2014] sd 0:0:0:0: [sda] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:35 2014] sd 0:0:0:0: [sda] Write Protect is off
[Tue Feb 18 12:48:35 2014] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:35 2014] sd 0:0:0:0: Attached scsi generic sg0 type 0
[Tue Feb 18 12:48:35 2014] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:35 2014]  sda: sda1 sda2 sda3
[Tue Feb 18 12:48:35 2014] sd 0:0:0:0: [sda] Attached SCSI disk
[Tue Feb 18 12:48:35 2014] mv643xx_eth_port mv643xx_eth_port.0 eth0: port 0 with MAC address 00:00:00:00:00:00
[Tue Feb 18 12:48:36 2014] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 12:48:36 2014] ata2.15: Port Multiplier 1.2, 0x197b:0x321f r0, 8 ports, feat 0x5/0xf
[Tue Feb 18 12:48:36 2014] ata2.00: hard resetting link
[Tue Feb 18 12:48:37 2014] mv643xx_eth_port mv643xx_eth_port.1 eth1: port 0 with MAC address 00:00:00:00:00:00
[Tue Feb 18 12:48:37 2014] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[Tue Feb 18 12:48:37 2014] ehci-pci: EHCI PCI platform driver
[Tue Feb 18 12:48:37 2014] ehci-orion: EHCI orion driver
[Tue Feb 18 12:48:37 2014] orion-ehci orion-ehci.0: EHCI Host Controller
[Tue Feb 18 12:48:37 2014] orion-ehci orion-ehci.0: new USB bus registered, assigned bus number 1
[Tue Feb 18 12:48:37 2014] orion-ehci orion-ehci.0: irq 19, io mem 0xf1050000
[Tue Feb 18 12:48:37 2014] orion-ehci orion-ehci.0: USB 2.0 started, EHCI 1.00
[Tue Feb 18 12:48:37 2014] hub 1-0:1.0: USB hub found
[Tue Feb 18 12:48:37 2014] hub 1-0:1.0: 1 port detected
[Tue Feb 18 12:48:37 2014] usbcore: registered new interface driver usb-storage
[Tue Feb 18 12:48:37 2014] mousedev: PS/2 mouse device common for all mice
[Tue Feb 18 12:48:37 2014] rtc-mv rtc-mv: rtc core: registered rtc-mv as rtc0
[Tue Feb 18 12:48:37 2014] i2c /dev entries driver
[Tue Feb 18 12:48:37 2014] orion_wdt: Initial timeout 25 sec
[Tue Feb 18 12:48:37 2014] sdhci: Secure Digital Host Controller Interface driver
[Tue Feb 18 12:48:37 2014] sdhci: Copyright(c) Pierre Ossman
[Tue Feb 18 12:48:37 2014] sdhci-pltfm: SDHCI platform and OF driver helper
[Tue Feb 18 12:48:37 2014] ledtrig-cpu: registered to indicate activity on CPUs
[Tue Feb 18 12:48:37 2014] usbcore: registered new interface driver r8712u
[Tue Feb 18 12:48:37 2014] gre: GRE over IPv4 demultiplexor driver
[Tue Feb 18 12:48:37 2014] TCP: cubic registered
[Tue Feb 18 12:48:37 2014] NET: Registered protocol family 17
[Tue Feb 18 12:48:37 2014] Key type dns_resolver registered
[Tue Feb 18 12:48:37 2014] registered taskstats version 1
[Tue Feb 18 12:48:37 2014] usb 1-1: new high-speed USB device number 2 using orion-ehci
[Tue Feb 18 12:48:37 2014] ata2.01: hard resetting link
[Tue Feb 18 12:48:37 2014] hub 1-1:1.0: USB hub found
[Tue Feb 18 12:48:37 2014] hub 1-1:1.0: 4 ports detected
[Tue Feb 18 12:48:38 2014] ata2.02: hard resetting link
[Tue Feb 18 12:48:38 2014] ata2.03: hard resetting link
[Tue Feb 18 12:48:39 2014] ata2.04: hard resetting link
[Tue Feb 18 12:48:40 2014] ata2.05: hard resetting link
[Tue Feb 18 12:48:40 2014] UKSM: relative memcmp_cost = 2467 hash=234621611 cmp_ret=0.
[Tue Feb 18 12:48:40 2014] console [netcon0] enabled
[Tue Feb 18 12:48:40 2014] netconsole: network logging started
[Tue Feb 18 12:48:40 2014] input: gpio-keys as /devices/platform/gpio-keys/input/input0
[Tue Feb 18 12:48:40 2014] rtc-mv rtc-mv: setting system clock to 2014-02-18 11:48:27 UTC (1392724107)
[Tue Feb 18 12:48:40 2014] ata2.06: hard resetting link
[Tue Feb 18 12:48:41 2014] ata2.07: hard resetting link
[Tue Feb 18 12:48:42 2014] ata2.00: ATA-7: SEAGATE ST31000NSSUN1.0T 093454YY4D, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.00: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.01: ATA-7: SEAGATE ST31000NSSUN1.0T 093454YY7W, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.01: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.02: ATA-7: SEAGATE ST31000NSSUN1.0T 093454YZPT, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.02: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.03: ATA-7: HITACHI HUA7210SASUN1.0T 0902GB0XRE, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.03: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.04: ATA-7: SEAGATE ST31000NSSUN1.0T 093454Z0BT, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.04: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.05: ATA-7: SEAGATE ST31000NSSUN1.0T 091653MEY4, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.05: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.06: ATA-7: SEAGATE ST31000NSSUN1.0T 093354SA5R, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.06: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.07: ATA-7: SEAGATE ST31000NSSUN1.0T 0909536218, 0958, max UDMA/133
[Tue Feb 18 12:48:42 2014] ata2.07: 1953525168 sectors, multi 1: LBA48 
[Tue Feb 18 12:48:42 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 12:48:42 2014] ata2: EH complete
[Tue Feb 18 12:48:42 2014] scsi 1:0:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:42 2014] sd 1:0:0:0: [sdb] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:42 2014] sd 1:0:0:0: Attached scsi generic sg1 type 0
[Tue Feb 18 12:48:42 2014] sd 1:0:0:0: [sdb] Write Protect is off
[Tue Feb 18 12:48:42 2014] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:42 2014] scsi 1:1:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:42 2014] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:42 2014] sd 1:1:0:0: [sdc] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:42 2014] sd 1:1:0:0: Attached scsi generic sg2 type 0
[Tue Feb 18 12:48:42 2014] sd 1:1:0:0: [sdc] Write Protect is off
[Tue Feb 18 12:48:42 2014] scsi 1:2:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:42 2014]  sdb: unknown partition table
[Tue Feb 18 12:48:42 2014] sd 1:1:0:0: [sdc] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:42 2014] sd 1:1:0:0: [sdc] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:42 2014] sd 1:0:0:0: [sdb] Attached SCSI disk
[Tue Feb 18 12:48:42 2014] sd 1:2:0:0: [sdd] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:42 2014] sd 1:2:0:0: Attached scsi generic sg3 type 0
[Tue Feb 18 12:48:42 2014] sd 1:2:0:0: [sdd] Write Protect is off
[Tue Feb 18 12:48:42 2014] scsi 1:3:0:0: Direct-Access     ATA      HITACHI HUA7210S 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:42 2014] sd 1:2:0:0: [sdd] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:42 2014] sd 1:2:0:0: [sdd] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:42 2014] sd 1:3:0:0: [sde] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:42 2014]  sdc: unknown partition table
[Tue Feb 18 12:48:42 2014] sd 1:3:0:0: Attached scsi generic sg4 type 0
[Tue Feb 18 12:48:42 2014] sd 1:1:0:0: [sdc] Attached SCSI disk
[Tue Feb 18 12:48:42 2014] sd 1:3:0:0: [sde] Write Protect is off
[Tue Feb 18 12:48:42 2014] sd 1:3:0:0: [sde] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:42 2014] scsi 1:4:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:42 2014]  sdd: unknown partition table
[Tue Feb 18 12:48:42 2014] sd 1:3:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:42 2014] sd 1:2:0:0: [sdd] Attached SCSI disk
[Tue Feb 18 12:48:42 2014] sd 1:4:0:0: [sdf] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:42 2014] sd 1:4:0:0: Attached scsi generic sg5 type 0
[Tue Feb 18 12:48:42 2014] sd 1:4:0:0: [sdf] Write Protect is off
[Tue Feb 18 12:48:42 2014] sd 1:4:0:0: [sdf] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:42 2014] scsi 1:5:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:42 2014] sd 1:4:0:0: [sdf] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:42 2014] sd 1:5:0:0: [sdg] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:42 2014] sd 1:5:0:0: Attached scsi generic sg6 type 0
[Tue Feb 18 12:48:42 2014] sd 1:5:0:0: [sdg] Write Protect is off
[Tue Feb 18 12:48:42 2014] sd 1:5:0:0: [sdg] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:43 2014]  sdf: unknown partition table
[Tue Feb 18 12:48:43 2014] scsi 1:6:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:43 2014] sd 1:5:0:0: [sdg] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:43 2014]  sde: sde1
[Tue Feb 18 12:48:43 2014] sd 1:4:0:0: [sdf] Attached SCSI disk
[Tue Feb 18 12:48:43 2014] sd 1:3:0:0: [sde] Attached SCSI disk
[Tue Feb 18 12:48:43 2014] sd 1:6:0:0: [sdh] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:43 2014] sd 1:6:0:0: Attached scsi generic sg7 type 0
[Tue Feb 18 12:48:43 2014] sd 1:6:0:0: [sdh] Write Protect is off
[Tue Feb 18 12:48:43 2014] sd 1:6:0:0: [sdh] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:43 2014] scsi 1:7:0:0: Direct-Access     ATA      SEAGATE ST31000N 0958 PQ: 0 ANSI: 5
[Tue Feb 18 12:48:43 2014] sd 1:6:0:0: [sdh] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:43 2014] sd 1:7:0:0: [sdi] 1953525168 512-byte logical blocks: (1.00 TB/931 GiB)
[Tue Feb 18 12:48:43 2014] sd 1:7:0:0: Attached scsi generic sg8 type 0
[Tue Feb 18 12:48:43 2014] sd 1:7:0:0: [sdi] Write Protect is off
[Tue Feb 18 12:48:43 2014] sd 1:7:0:0: [sdi] Mode Sense: 00 3a 00 00
[Tue Feb 18 12:48:43 2014]  sdg: unknown partition table
[Tue Feb 18 12:48:43 2014] sd 1:7:0:0: [sdi] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[Tue Feb 18 12:48:43 2014] sd 1:5:0:0: [sdg] Attached SCSI disk
[Tue Feb 18 12:48:43 2014]  sdh: sdh1
[Tue Feb 18 12:48:43 2014] sd 1:6:0:0: [sdh] Attached SCSI disk
[Tue Feb 18 12:48:43 2014]  sdi: sdi1
[Tue Feb 18 12:48:43 2014] sd 1:7:0:0: [sdi] Attached SCSI disk
[Tue Feb 18 12:48:43 2014] kjournald starting.  Commit interval 5 seconds
[Tue Feb 18 12:48:43 2014] EXT3-fs (sda1): using internal journal
[Tue Feb 18 12:48:43 2014] EXT3-fs (sda1): mounted filesystem with writeback data mode
[Tue Feb 18 12:48:43 2014] VFS: Mounted root (ext3 filesystem) on device 8:1.
[Tue Feb 18 12:48:43 2014] devtmpfs: mounted
[Tue Feb 18 12:48:43 2014] Freeing unused kernel memory: 256K (c0703000 - c0743000)
[Tue Feb 18 12:48:43 2014] systemd[1]: systemd 208 running in system mode. (+PAM -LIBWRAP -AUDIT -SELINUX -IMA -SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ)
[Tue Feb 18 12:48:44 2014] systemd[1]: Inserted module 'autofs4'
[Tue Feb 18 12:48:44 2014] NET: Registered protocol family 10
[Tue Feb 18 12:48:44 2014] systemd[1]: Inserted module 'ipv6'
[Tue Feb 18 12:48:44 2014] systemd[1]: Set hostname to <deck>.
[Tue Feb 18 12:48:44 2014] random: systemd urandom read with 121 bits of entropy available
[Tue Feb 18 12:48:44 2014] random: nonblocking pool is initialized
[Tue Feb 18 12:48:44 2014] systemd[1]: Cannot add dependency job for unit cups.socket, ignoring: Unit cups.socket failed to load: No such file or directory.
[Tue Feb 18 12:48:44 2014] systemd[1]: Cannot add dependency job for unit cups.path, ignoring: Unit cups.path failed to load: No such file or directory.
[Tue Feb 18 12:48:44 2014] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory.
[Tue Feb 18 12:48:44 2014] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
[Tue Feb 18 12:48:44 2014] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[Tue Feb 18 12:48:44 2014] systemd[1]: Expecting device dev-ttyS0.device...
[Tue Feb 18 12:48:44 2014] systemd[1]: Expecting device sys-subsystem-net-devices-eth0.device...
[Tue Feb 18 12:48:44 2014] systemd[1]: Starting Remote File Systems.
[Tue Feb 18 12:48:44 2014] systemd[1]: Reached target Remote File Systems.
[Tue Feb 18 12:48:44 2014] systemd[1]: Starting Delayed Shutdown Socket.
[Tue Feb 18 12:48:44 2014] systemd[1]: Listening on Delayed Shutdown Socket.
[Tue Feb 18 12:48:44 2014] systemd[1]: Starting Device-mapper event daemon FIFOs.
[Tue Feb 18 12:48:44 2014] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[Tue Feb 18 12:48:44 2014] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[Tue Feb 18 12:48:44 2014] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Encrypted Volumes.
[Tue Feb 18 12:48:45 2014] systemd[1]: Reached target Encrypted Volumes.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
[Tue Feb 18 12:48:45 2014] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting udev Kernel Socket.
[Tue Feb 18 12:48:45 2014] systemd[1]: Listening on udev Kernel Socket.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting udev Control Socket.
[Tue Feb 18 12:48:45 2014] systemd[1]: Listening on udev Control Socket.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
[Tue Feb 18 12:48:45 2014] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Paths.
[Tue Feb 18 12:48:45 2014] systemd[1]: Reached target Paths.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Journal Socket.
[Tue Feb 18 12:48:45 2014] systemd[1]: Listening on Journal Socket.
[Tue Feb 18 12:48:45 2014] systemd[1]: Mounted Huge Pages File System.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Load Kernel Modules...
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting udev Coldplug all Devices...
[Tue Feb 18 12:48:45 2014] systemd[1]: Mounting POSIX Message Queue File System...
[Tue Feb 18 12:48:45 2014] RPC: Registered named UNIX socket transport module.
[Tue Feb 18 12:48:45 2014] RPC: Registered udp transport module.
[Tue Feb 18 12:48:45 2014] RPC: Registered tcp transport module.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Apply Kernel Variables...
[Tue Feb 18 12:48:45 2014] RPC: Registered tcp NFSv4.1 backchannel transport module.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[Tue Feb 18 12:48:45 2014] systemd[1]: Mounting Debug File System...
[Tue Feb 18 12:48:45 2014] systemd[1]: Started Set Up Additional Binary Formats.
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Setup Virtual Console...
[Tue Feb 18 12:48:45 2014] systemd[1]: Starting Journal Service...
[Tue Feb 18 12:48:45 2014] systemd[1]: Started Journal Service.
[Tue Feb 18 12:48:45 2014] FS-Cache: Netfs 'nfs' registered for caching
[Tue Feb 18 12:48:45 2014] systemd-journald[70]: Vacuuming done, freed 0 bytes
[Tue Feb 18 12:48:46 2014] systemd-udevd[94]: starting version 208
[Tue Feb 18 12:48:47 2014] cfg80211: Calling CRDA to update world regulatory domain
[Tue Feb 18 12:48:47 2014] PCI: enabling device 0000:00:01.0 (0140 -> 0142)
[Tue Feb 18 12:48:48 2014] raid6: int32x1     87 MB/s
[Tue Feb 18 12:48:48 2014] raid6: int32x2    133 MB/s
[Tue Feb 18 12:48:48 2014] raid6: int32x4    161 MB/s
[Tue Feb 18 12:48:49 2014] raid6: int32x8    169 MB/s
[Tue Feb 18 12:48:49 2014] raid6: using algorithm int32x8 (169 MB/s)
[Tue Feb 18 12:48:49 2014] raid6: using intx1 recovery algorithm
[Tue Feb 18 12:48:49 2014] xor: measuring software checksum speed
[Tue Feb 18 12:48:49 2014] systemd-journald[70]: Received request to flush runtime journal from PID 1
[Tue Feb 18 12:48:49 2014]    arm4regs  :  1090.400 MB/sec
[Tue Feb 18 12:48:49 2014]    8regs     :   774.800 MB/sec
[Tue Feb 18 12:48:49 2014]    32regs    :   825.600 MB/sec
[Tue Feb 18 12:48:49 2014] xor: using function: arm4regs (1090.400 MB/sec)
[Tue Feb 18 12:48:49 2014] ath: EEPROM regdomain: 0x60
[Tue Feb 18 12:48:49 2014] ath: EEPROM indicates we should expect a direct regpair map
[Tue Feb 18 12:48:49 2014] ath: Country alpha2 being used: 00
[Tue Feb 18 12:48:49 2014] ath: Regpair used: 0x60
[Tue Feb 18 12:48:49 2014] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[Tue Feb 18 12:48:49 2014] ieee80211 phy0: Atheros AR9280 Rev:2 mem=0xe0da0000, irq=9
[Tue Feb 18 12:48:55 2014] bio: create slab <bio-1> at 1
[Tue Feb 18 12:48:56 2014] Btrfs loaded
[Tue Feb 18 12:48:56 2014] btrfs: device label storage devid 1 transid 2053 /dev/sda3
[Tue Feb 18 12:48:56 2014] btrfs: device label dataPool devid 2 transid 9099 /dev/sdc
[Tue Feb 18 12:48:56 2014] btrfs: device label dataPool devid 5 transid 9099 /dev/sdg
[Tue Feb 18 12:48:56 2014] btrfs: device label dataPool devid 4 transid 9099 /dev/sdf
[Tue Feb 18 12:48:56 2014] btrfs: device label dataPool devid 1 transid 9099 /dev/sdb
[Tue Feb 18 12:48:56 2014] btrfs: device label home devid 1 transid 888 /dev/sda2
[Tue Feb 18 12:48:56 2014] btrfs: device label dataPool devid 3 transid 9099 /dev/sdd
[Tue Feb 18 12:48:56 2014] md: bind<sde1>
[Tue Feb 18 12:48:56 2014] md: bind<sdh1>
[Tue Feb 18 12:48:56 2014] md: bind<sdi1>
[Tue Feb 18 12:48:57 2014] async_tx: api initialized (async)
[Tue Feb 18 12:48:57 2014] md: raid6 personality registered for level 6
[Tue Feb 18 12:48:57 2014] md: raid5 personality registered for level 5
[Tue Feb 18 12:48:57 2014] md: raid4 personality registered for level 4
[Tue Feb 18 12:48:57 2014] md/raid:md0: device sdi1 operational as raid disk 2
[Tue Feb 18 12:48:57 2014] md/raid:md0: device sdh1 operational as raid disk 1
[Tue Feb 18 12:48:57 2014] md/raid:md0: device sde1 operational as raid disk 0
[Tue Feb 18 12:48:57 2014] md/raid:md0: allocated 0kB
[Tue Feb 18 12:48:57 2014] md/raid:md0: raid level 5 active with 3 out of 3 devices, algorithm 2
[Tue Feb 18 12:48:57 2014] RAID conf printout:
[Tue Feb 18 12:48:57 2014]  --- level:5 rd:3 wd:3
[Tue Feb 18 12:48:57 2014]  disk 0, o:1, dev:sde1
[Tue Feb 18 12:48:57 2014]  disk 1, o:1, dev:sdh1
[Tue Feb 18 12:48:57 2014]  disk 2, o:1, dev:sdi1
[Tue Feb 18 12:48:57 2014] created bitmap (8 pages) for device md0
[Tue Feb 18 12:48:57 2014] md0: bitmap initialized from disk: read 1 pages, set 0 of 14901 bits
[Tue Feb 18 12:48:57 2014] md0: detected capacity change from 0 to 1999929081856
[Tue Feb 18 12:48:57 2014]  md0: unknown partition table
[Tue Feb 18 12:48:57 2014] systemd-udevd[103]: renamed network interface wlan0 to wlp0s1
[Tue Feb 18 12:49:43 2014] mv643xx_eth_port mv643xx_eth_port.0 eth0: link down
[Tue Feb 18 12:49:43 2014] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[Tue Feb 18 12:49:45 2014] mv643xx_eth_port mv643xx_eth_port.0 eth0: link up, 100 Mb/s, full duplex, flow control disabled
[Tue Feb 18 12:49:45 2014] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[Tue Feb 18 13:01:31 2014] btrfs: device label dataPool devid 3 transid 9099 /dev/sdd
[Tue Feb 18 13:02:08 2014] btrfs: use lzo compression
[Tue Feb 18 13:02:08 2014] btrfs: disk space caching is enabled
[Tue Feb 18 13:02:09 2014] btrfs: bdev /dev/sdb errs: wr 0, rd 1, flush 0, corrupt 0, gen 0
[Tue Feb 18 13:13:37 2014] btrfs: device label dataPool devid 3 transid 9103 /dev/sdd
[Tue Feb 18 13:14:29 2014] ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 action 0x6
[Tue Feb 18 13:14:29 2014] ata2.15: edma_err_cause=00000084 pp_flags=00000001, dev error, EDMA self-disable
[Tue Feb 18 13:14:29 2014] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
[Tue Feb 18 13:14:29 2014] ata2.00: failed command: READ DMA
[Tue Feb 18 13:14:29 2014] ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
         res 51/04:08:60:f2:30/00:00:00:00:00/e0 Emask 0x1 (device error)
[Tue Feb 18 13:14:29 2014] ata2.00: status: { DRDY ERR }
[Tue Feb 18 13:14:29 2014] ata2.00: error: { ABRT }
[Tue Feb 18 13:14:29 2014] ata2.15: hard resetting link
[Tue Feb 18 13:14:34 2014] ata2.15: link is slow to respond, please be patient (ready=0)
[Tue Feb 18 13:14:39 2014] ata2.15: SRST failed (errno=-16)
[Tue Feb 18 13:14:39 2014] ata2.15: hard resetting link
[Tue Feb 18 13:14:44 2014] ata2.15: link is slow to respond, please be patient (ready=0)
[Tue Feb 18 13:14:49 2014] ata2.15: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 13:14:49 2014] ata2.00: hard resetting link
[Tue Feb 18 13:14:50 2014] ata2.01: hard resetting link
[Tue Feb 18 13:14:50 2014] ata2.02: hard resetting link
[Tue Feb 18 13:14:51 2014] ata2.03: hard resetting link
[Tue Feb 18 13:14:52 2014] ata2.04: hard resetting link
[Tue Feb 18 13:14:52 2014] ata2.05: hard resetting link
[Tue Feb 18 13:14:53 2014] ata2.06: hard resetting link
[Tue Feb 18 13:14:54 2014] ata2.07: hard resetting link
[Tue Feb 18 13:14:54 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 13:14:54 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 13:14:54 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 13:14:54 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 13:14:54 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 13:14:55 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 13:14:55 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 13:14:55 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 13:14:55 2014] ata2: EH complete
[Tue Feb 18 13:14:58 2014] ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 action 0x6
[Tue Feb 18 13:14:58 2014] ata2.15: edma_err_cause=00000084 pp_flags=00000001, dev error, EDMA self-disable
[Tue Feb 18 13:14:58 2014] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
[Tue Feb 18 13:14:58 2014] ata2.00: failed command: READ DMA
[Tue Feb 18 13:14:58 2014] ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
         res 51/04:08:60:f2:30/00:00:00:00:00/e0 Emask 0x1 (device error)
[Tue Feb 18 13:14:58 2014] ata2.00: status: { DRDY ERR }
[Tue Feb 18 13:14:58 2014] ata2.00: error: { ABRT }
[Tue Feb 18 13:14:58 2014] ata2.15: hard resetting link
[Tue Feb 18 13:14:59 2014] ata2.15: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 13:14:59 2014] ata2.00: hard resetting link
[Tue Feb 18 13:15:00 2014] ata2.01: hard resetting link
[Tue Feb 18 13:15:01 2014] ata2.02: hard resetting link
[Tue Feb 18 13:15:01 2014] ata2.03: hard resetting link
[Tue Feb 18 13:15:02 2014] ata2.04: hard resetting link
[Tue Feb 18 13:15:02 2014] ata2.05: hard resetting link
[Tue Feb 18 13:15:03 2014] ata2.06: hard resetting link
[Tue Feb 18 13:15:04 2014] ata2.07: hard resetting link
[Tue Feb 18 13:15:05 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 13:15:05 2014] ata2: EH complete
[Tue Feb 18 13:15:09 2014] ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 action 0x6
[Tue Feb 18 13:15:09 2014] ata2.15: edma_err_cause=00000084 pp_flags=00000001, dev error, EDMA self-disable
[Tue Feb 18 13:15:09 2014] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
[Tue Feb 18 13:15:09 2014] ata2.00: failed command: READ DMA
[Tue Feb 18 13:15:09 2014] ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
         res 51/04:08:60:f2:30/00:00:00:00:00/e0 Emask 0x1 (device error)
[Tue Feb 18 13:15:09 2014] ata2.00: status: { DRDY ERR }
[Tue Feb 18 13:15:09 2014] ata2.00: error: { ABRT }
[Tue Feb 18 13:15:09 2014] ata2.15: hard resetting link
[Tue Feb 18 13:15:10 2014] ata2.15: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 13:15:10 2014] ata2.00: hard resetting link
[Tue Feb 18 13:15:11 2014] ata2.01: hard resetting link
[Tue Feb 18 13:15:11 2014] ata2.02: hard resetting link
[Tue Feb 18 13:15:12 2014] ata2.03: hard resetting link
[Tue Feb 18 13:15:12 2014] ata2.04: hard resetting link
[Tue Feb 18 13:15:13 2014] ata2.05: hard resetting link
[Tue Feb 18 13:15:14 2014] ata2.06: hard resetting link
[Tue Feb 18 13:15:15 2014] ata2.07: hard resetting link
[Tue Feb 18 13:15:16 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 13:15:16 2014] ata2: EH complete
[Tue Feb 18 13:15:19 2014] ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 action 0x6
[Tue Feb 18 13:15:19 2014] ata2.15: edma_err_cause=00000084 pp_flags=00000001, dev error, EDMA self-disable
[Tue Feb 18 13:15:19 2014] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
[Tue Feb 18 13:15:19 2014] ata2.00: failed command: READ DMA
[Tue Feb 18 13:15:19 2014] ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
         res 51/04:08:60:f2:30/00:00:00:00:00/e0 Emask 0x1 (device error)
[Tue Feb 18 13:15:19 2014] ata2.00: status: { DRDY ERR }
[Tue Feb 18 13:15:19 2014] ata2.00: error: { ABRT }
[Tue Feb 18 13:15:19 2014] ata2.15: hard resetting link
[Tue Feb 18 13:15:20 2014] ata2.15: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 13:15:20 2014] ata2.00: hard resetting link
[Tue Feb 18 13:15:21 2014] ata2.01: hard resetting link
[Tue Feb 18 13:15:22 2014] ata2.02: hard resetting link
[Tue Feb 18 13:15:23 2014] ata2.03: hard resetting link
[Tue Feb 18 13:15:23 2014] ata2.04: hard resetting link
[Tue Feb 18 13:15:24 2014] ata2.05: hard resetting link
[Tue Feb 18 13:15:25 2014] ata2.06: hard resetting link
[Tue Feb 18 13:15:25 2014] ata2.07: hard resetting link
[Tue Feb 18 13:15:26 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 13:15:26 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 13:15:26 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 13:15:26 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 13:15:27 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 13:15:27 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 13:15:27 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 13:15:27 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 13:15:27 2014] ata2: EH complete
[Tue Feb 18 13:15:30 2014] ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 action 0x6
[Tue Feb 18 13:15:30 2014] ata2.15: edma_err_cause=00000084 pp_flags=00000001, dev error, EDMA self-disable
[Tue Feb 18 13:15:30 2014] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
[Tue Feb 18 13:15:30 2014] ata2.00: failed command: READ DMA
[Tue Feb 18 13:15:30 2014] ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
         res 51/04:08:60:f2:30/00:00:00:00:00/e0 Emask 0x1 (device error)
[Tue Feb 18 13:15:30 2014] ata2.00: status: { DRDY ERR }
[Tue Feb 18 13:15:30 2014] ata2.00: error: { ABRT }
[Tue Feb 18 13:15:30 2014] ata2.15: hard resetting link
[Tue Feb 18 13:15:31 2014] ata2.15: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 13:15:31 2014] ata2.00: hard resetting link
[Tue Feb 18 13:15:32 2014] ata2.01: hard resetting link
[Tue Feb 18 13:15:33 2014] ata2.02: hard resetting link
[Tue Feb 18 13:15:33 2014] ata2.03: hard resetting link
[Tue Feb 18 13:15:34 2014] ata2.04: hard resetting link
[Tue Feb 18 13:15:34 2014] ata2.05: hard resetting link
[Tue Feb 18 13:15:35 2014] ata2.06: hard resetting link
[Tue Feb 18 13:15:36 2014] ata2.07: hard resetting link
[Tue Feb 18 13:15:37 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 13:15:37 2014] ata2: EH complete
[Tue Feb 18 13:15:40 2014] ata2.15: exception Emask 0x1 SAct 0x0 SErr 0x0 action 0x6
[Tue Feb 18 13:15:40 2014] ata2.15: edma_err_cause=00000084 pp_flags=00000001, dev error, EDMA self-disable
[Tue Feb 18 13:15:40 2014] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
[Tue Feb 18 13:15:40 2014] ata2.00: failed command: READ DMA
[Tue Feb 18 13:15:40 2014] ata2.00: cmd c8/00:08:60:f2:30/00:00:00:00:00/e0 tag 0 dma 4096 in
         res 51/04:08:60:f2:30/00:00:00:00:00/e0 Emask 0x1 (device error)
[Tue Feb 18 13:15:41 2014] ata2.00: status: { DRDY ERR }
[Tue Feb 18 13:15:41 2014] ata2.00: error: { ABRT }
[Tue Feb 18 13:15:41 2014] ata2.15: hard resetting link
[Tue Feb 18 13:15:42 2014] ata2.15: SATA link up 3.0 Gbps (SStatus 123 SControl F300)
[Tue Feb 18 13:15:42 2014] ata2.00: hard resetting link
[Tue Feb 18 13:15:42 2014] ata2.01: hard resetting link
[Tue Feb 18 13:15:43 2014] ata2.02: hard resetting link
[Tue Feb 18 13:15:44 2014] ata2.03: hard resetting link
[Tue Feb 18 13:15:44 2014] ata2.04: hard resetting link
[Tue Feb 18 13:15:45 2014] ata2.05: hard resetting link
[Tue Feb 18 13:15:46 2014] ata2.06: hard resetting link
[Tue Feb 18 13:15:47 2014] ata2.07: hard resetting link
[Tue Feb 18 13:15:48 2014] ata2.00: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.01: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.02: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.03: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.04: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.05: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.06: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] ata2.07: configured for UDMA/133
[Tue Feb 18 13:15:48 2014] sd 1:0:0:0: [sdb]  
[Tue Feb 18 13:15:48 2014] Result: hostbyte=0x00 driverbyte=0x08
[Tue Feb 18 13:15:48 2014] sd 1:0:0:0: [sdb]  
[Tue Feb 18 13:15:48 2014] Sense Key : 0xb [current] [descriptor]
[Tue Feb 18 13:15:48 2014] Descriptor sense data with sense descriptors (in hex):
[Tue Feb 18 13:15:48 2014]         72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00 
[Tue Feb 18 13:15:48 2014]         00 30 f2 60 
[Tue Feb 18 13:15:48 2014] sd 1:0:0:0: [sdb]  
[Tue Feb 18 13:15:48 2014] ASC=0x0 ASCQ=0x0
[Tue Feb 18 13:15:48 2014] sd 1:0:0:0: [sdb] CDB: 
[Tue Feb 18 13:15:48 2014] cdb[0]=0x28: 28 00 00 30 f2 60 00 00 08 00
[Tue Feb 18 13:15:48 2014] end_request: I/O error, dev sdb, sector 3207776
[Tue Feb 18 13:15:48 2014] btrfs: bdev /dev/sdb errs: wr 0, rd 2, flush 0, corrupt 0, gen 0
[Tue Feb 18 13:15:48 2014] ata2: EH complete
[Tue Feb 18 13:15:48 2014] btrfs read error corrected: ino 1 off 29184540672 (dev /dev/sdb sector 3207776)
[Tue Feb 18 13:29:31 2014] btrfs: device label dataPool devid 3 transid 9104 /dev/sdd
[Tue Feb 18 13:36:16 2014] btrfs: device label dataPool devid 3 transid 9112 /dev/sdd