9010 – (SATA-Hotplug) SCSI device is not offlined properly and tries to cache data from previous device

Bug 9010 (SATA-Hotplug) - SCSI device is not offlined properly and tries to cache data from previous device

Summary: SCSI device is not offlined properly and tries to cache data from previous de...

Status:	CLOSED OBSOLETE

Alias:	SATA-Hotplug

Product:	IO/Storage
Classification:	Unclassified
Component:	Serial ATA (show other bugs)
Hardware:	All Linux

Importance:	P1 high
Assignee:	Jeff Garzik

URL:
Keywords:

Depends on:
Blocks:

Reported:	2007-09-11 23:30 UTC by Bjoern Olausson
Modified:	2012-05-17 14:43 UTC (History)
CC List:	6 users (show)

See Also:
Kernel Version:	2.6.23.1
Subsystem:
Regression:	No
Bisected commit-id:

Attachments
dmsg output (63.27 KB, text/plain) 2007-10-10 06:08 UTC, Bjoern Olausson	Details
Add an attachment (proposed patch, testcase, etc.)

Description Bjoern Olausson 2007-09-11 23:30:18 UTC

Most recent kernel where this bug did not occur:
-/-

Distribution:
Gentoo

Hardware Environment:
H/W path                   Device       Class       Description
===============================================================
                                        system      P5W DH Deluxe
/0                                      bus         P5W DH Deluxe
/0/0                                    memory      64KB BIOS
/0/4                                    processor   Intel(R) Core(TM)2 CPU          6600  @ 2.4
/0/4/5                                  memory      32KB L1 cache
/0/4/6                                  memory      4MB L2 cache
/0/4/7                                  memory      L3 cache
/0/3c                                   memory      2GB System Memory
/0/3c/0                                 memory      1GB DIMM SDRAM Synchronous
/0/3c/1                                 memory      DIMM [empty]
/0/3c/2                                 memory      1GB DIMM SDRAM Synchronous
/0/3c/3                                 memory      DIMM [empty]
/0/100                                  bridge      975X Express Memory Controller Hub
/0/100/1                                bridge      975X Express PCI Express Root Port
/0/100/1/0                              display     G70 [GeForce 7600 GT]
/0/100/1b                               multimedia  82801G (ICH7 Family) High Definition Audio
/0/100/1c                               bridge      82801G (ICH7 Family) PCI Express Port 1
/0/100/1c.3                             bridge      82801G (ICH7 Family) PCI Express Port 4
/0/100/1c.3/0              eth0         network     88E8053 PCI-E Gigabit Ethernet Controller
/0/100/1c.5                             bridge      82801GR/GH/GHM (ICH7 Family) PCI Express Po
/0/100/1c.5/0                           storage     JMicron 20360/20363 AHCI Controller
/0/100/1c.5/0.1                         storage     JMicron 20360/20363 AHCI Controller
/0/100/1d                               bus         82801G (ICH7 Family) USB UHCI #1
/0/100/1d/1                usb2         bus         UHCI Host Controller
/0/100/1d/1/2                           generic     USB RECEIVER
/0/100/1d.1                             bus         82801G (ICH7 Family) USB UHCI #2
/0/100/1d.1/1              usb3         bus         UHCI Host Controller
/0/100/1d.1/1/1                         generic     ASUS DH Remote
/0/100/1d.1/1/2                         bus         Logitech BT Mini-Receiver
/0/100/1d.1/1/2/2                       generic     Logitech BT Mini-Receiver
/0/100/1d.1/1/2/3                       generic     Logitech BT Mini-Receiver
/0/100/1d.2                             bus         82801G (ICH7 Family) USB UHCI #3
/0/100/1d.2/1              usb4         bus         UHCI Host Controller
/0/100/1d.2/1/1                         generic     Bluetooth Device
/0/100/1d.3                             bus         82801G (ICH7 Family) USB UHCI #4
/0/100/1d.3/1              usb5         bus         UHCI Host Controller
/0/100/1d.7                             bus         82801G (ICH7 Family) USB2 EHCI Controller
/0/100/1d.7/1              usb1         bus         EHCI Host Controller
/0/100/1d.7/1/1                         bus         USB2.0 Hub
/0/100/1d.7/1/1/1                       generic     USB Receiver
/0/100/1d.7/1/1/2                       generic     iP5200
/0/100/1d.7/1/1/3                       generic     Astra 2200/2200SU
/0/100/1d.7/1/7                         bus         USB2.0 Hub
/0/100/1d.7/1/7/1                       bus         USB2.0 Hub
/0/100/1d.7/1/7/2          scsi8        generic     USB Storage
/0/100/1d.7/1/7/2/0.0.0    /dev/sdd     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.0/0  /dev/sdd     disk
/0/100/1d.7/1/7/2/0.0.1    /dev/sde     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.1/0  /dev/sde     disk
/0/100/1d.7/1/7/2/0.0.2    /dev/sdf     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.2/0  /dev/sdf     disk
/0/100/1d.7/1/7/2/0.0.3    /dev/sdg     disk        STORAGE DEVICE
/0/100/1d.7/1/7/2/0.0.3/0  /dev/sdg     disk
/0/100/1d.7/1/7/3                       generic     RTL8187_Wireless
/0/100/1e                               bridge      82801 PCI Bridge
/0/100/1e/0                             multimedia  SB X-Fi
/0/100/1e/1                             multimedia  Bt878 Video Capture
/0/100/1e/1.1                           multimedia  Bt878 Audio Capture
/0/100/1e/2                             network     AR5212 802.11abg NIC
/0/100/1e/3                             bus         TSB43AB22/A IEEE-1394a-2000 Controller (PHY
/0/100/1f                               bridge      82801GB/GR (ICH7 Family) LPC Interface Brid
/0/100/1f.1                scsi6        storage     82801G (ICH7 Family) IDE Controller
/0/100/1f.1/0.0.0          /dev/cdrom1  disk        DVDR   PX-760A
/0/100/1f.1/0.1.0          /dev/cdrom   disk        DVD-ROM PX-130A
/0/100/1f.2                scsi0        storage     82801GR/GH (ICH7 Family) Serial ATA Storage
/0/100/1f.2/0              /dev/sda     disk        69GB WDC WD740ADFD-00
/0/100/1f.2/0/1            /dev/sda1    volume      47MB Linux filesystem partition
/0/100/1f.2/0/2            /dev/sda2    volume      956MB Linux swap / Solaris partition
/0/100/1f.2/0/3            /dev/sda3    volume      68GB Linux filesystem partition
/0/100/1f.2/1              /dev/sdb     disk        149GB WDC WD1600BEVS-0
/0/100/1f.2/1/1            /dev/sdb1    volume      149GB Linux filesystem partition
/0/100/1f.2/0.0.0          /dev/sdc     disk        69GB WDC WD740ADFD-00
/0/100/1f.2/0.0.0/1        /dev/sdc1    volume      69GB HPFS/NTFS partition
/0/100/1f.3                             bus         82801G (ICH7 Family) SMBus Controller
/1                         irlan0       network     Ethernet interface
/2                         wlan0        network     Wireless interface


Software Environment:
Portage 2.1.3.7 (default-linux/amd64/2007.0/desktop, gcc-4.1.2, glibc-2.5-r4, 2.6.23-rc6 x86_64)
=================================================================
System uname: 2.6.23-rc6 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz
Gentoo Base System release 1.12.9
Timestamp of tree: Tue, 11 Sep 2007 16:20:01 +0000
distcc 2.18.3 x86_64-pc-linux-gnu (protocols 1 and 2) (default port 3632) [disabled]
ccache version 2.4 [enabled]
app-shells/bash:     3.2_p17
dev-java/java-config: 1.3.7, 2.0.33-r1
dev-lang/python:     2.4.4-r4
dev-python/pycrypto: 2.0.1-r6
dev-util/ccache:     2.4-r7
sys-apps/baselayout: 1.12.9-r2
sys-apps/sandbox:    1.2.17
sys-devel/autoconf:  2.13, 2.61
sys-devel/automake:  1.4_p6, 1.5, 1.6.3, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2, 1.10
sys-devel/binutils:  2.17
sys-devel/gcc-config: 1.3.16
sys-devel/libtool:   1.5.24
virtual/os-headers:  2.6.21
ACCEPT_KEYWORDS="amd64"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-march=nocona -O2 -pipe -fomit-frame-pointer"
CHOST="x86_64-pc-linux-gnu"

Problem Description:

Comment #23 From Tejun Heo 2007-09-11 18:24:47 [reply]
http://bugzilla.kernel.org/show_bug.cgi?id=8923#c23
-------
[...]That seems like a dangerous bug.  SCSI device hasn't been offlined properly and it's trying to cache data from the previous device to the new one.
-------

For this log the Disk was attached while booting, than removed and attached
again:

ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
ata2: irq_stat 0x00400000, PHY RDY changed
ata2: soft resetting port
ata2: SATA link down (SStatus 21 SControl 300)
ata2: failed to recover some devices, retrying in 5 secs
ata2: hard resetting port
ata2: SATA link down (SStatus 0 SControl 300)
ata2: limiting SATA link speed to 1.5 Gbps
ata2.00: limiting speed to UDMA/133:PIO3
ata2: failed to recover some devices, retrying in 5 secs
ata2: hard resetting port
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: COMRESET failed (errno=-16)
ata2: hard resetting port
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata2.00: model number mismatch 'WDC WD1600BEVS-00RST0' != 'Config  Disk'
ata2.00: revalidation failed (errno=-19)
ata2.00: disabled
ata2: hard resetting port
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: COMRESET failed (errno=-16)
ata2: hard resetting port
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
ata2.00: 640 sectors, multi 1: LBA 
ata2.00: configured for UDMA/133
ata2: EH pending after completion, repeating EH (cnt=4)
ata2: exception Emask 0x10 SAct 0x0 SErr 0x4050002 action 0x3
ata2: irq_stat 0x00400040, connection status changed
ata2: soft resetting port
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: qc timeout (cmd 0xec)
ata2.00: failed to IDENTIFY (I/O error, err_mask=0x5)
ata2.00: revalidation failed (errno=-5)
ata2: failed to recover some devices, retrying in 5 secs
ata2: hard resetting port
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: COMRESET failed (errno=-16)
ata2: hard resetting port
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: configured for UDMA/133
ata2: EH pending after completion, repeating EH (cnt=3)
ata2: EH complete
ata2.00: detaching (SCSI 1:0:0:0)
sd 1:0:0:0: [sdb] Synchronizing SCSI cache
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
sd 1:0:0:0: [sdb] Stopping disk
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
ata2.00: irq_stat 0x40000001
ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0 
         res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
ata2.00: configured for UDMA/133
ata2: EH complete
sd 1:0:0:0: [sdb] START_STOP FAILED
sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
scsi 1:0:0:0: Direct-Access     ATA      Config  Disk     RGL1 PQ: 0 ANSI: 5
sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support
DPO or FUA
sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support
DPO or FUA
 sdb: unknown partition table
sd 1:0:0:0: [sdb] Attached SCSI disk
sd 1:0:0:0: Attached scsi generic sg1 type 0
sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support
DPO or FUA
ata2: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0x2 frozen
ata2: irq_stat 0x00400000, PHY RDY changed
ata2: soft resetting port
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: qc timeout (cmd 0xec)
ata2.00: failed to IDENTIFY (I/O error, err_mask=0x4)
ata2.00: revalidation failed (errno=-5)
ata2: failed to recover some devices, retrying in 5 secs
ata2: hard resetting port
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: COMRESET failed (errno=-16)
ata2: hard resetting port
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: model number mismatch 'Config  Disk' != 'WDC WD1600BEVS-00RST0'
ata2.00: revalidation failed (errno=-19)
ata2: limiting SATA link speed to 1.5 Gbps
ata2.00: limiting speed to UDMA/133:PIO3
ata2: failed to recover some devices, retrying in 5 secs
ata2: hard resetting port
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: COMRESET failed (errno=-16)
ata2: hard resetting port
ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata2.00: model number mismatch 'Config  Disk' != 'WDC WD1600BEVS-00RST0'
ata2.00: revalidation failed (errno=-19)
ata2.00: disabled
ata2: hard resetting port
ata2: port is slow to respond, please be patient (Status 0x80)
ata2: COMRESET failed (errno=-16)
ata2: hard resetting port
ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
ata2.00: ATA-7: WDC WD1600BEVS-00RST0, 04.01G04, max UDMA/133
ata2.00: 312581808 sectors, multi 0: LBA48 NCQ (depth 31/32)
ata2.00: configured for UDMA/133
ata2: EH pending after completion, repeating EH (cnt=4)
ata2: EH complete
ata2.00: detaching (SCSI 1:0:0:0)
sd 1:0:0:0: [sdb] Stopping disk
scsi 1:0:0:0: Direct-Access     ATA      WDC WD1600BEVS-0 04.0 PQ: 0 ANSI: 5
sd 1:0:0:0: [sdb] 312581808 512-byte hardware sectors (160042 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support
DPO or FUA
sd 1:0:0:0: [sdb] 312581808 512-byte hardware sectors (160042 MB)
sd 1:0:0:0: [sdb] Write Protect is off
sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support
DPO or FUA
 sdb: sdb1
sd 1:0:0:0: [sdb] Attached SCSI disk
sd 1:0:0:0: Attached scsi generic sg1 type 0


full log can be found on:
http://paste.olausson.de/00fefaea1b.html

Steps to reproduce:
Hot-Plug/-Unplug SATA device.

regards
Bjoern

Comment 1 Bjoern Olausson 2007-09-22 09:55:58 UTC

Any news here?

behavior did not change in 2.6.23-rc7

regards
Bjoern

Comment 2 Bjoern Olausson 2007-10-10 06:08:31 UTC

Created attachment 13098 [details]
dmsg output

Still problems here with the disc connected to the SIL chip....

This is how it looks when adding/removing the disk from the ICH7 port:
Oct 10 14:54:05 freax ata4: exception Emask 0x10 SAct 0x0 SErr 0x4000000 action 0x2 frozen
Oct 10 14:54:05 freax ata4: irq_stat 0x00000040, connection status changed
Oct 10 14:54:06 freax ata4: soft resetting port
Oct 10 14:54:06 freax ata4: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Oct 10 14:54:06 freax ata4.00: ATA-7: WDC WD1600BEVS-00RST0, 04.01G04, max UDMA/133
Oct 10 14:54:06 freax ata4.00: 312581808 sectors, multi 0: LBA48 NCQ (depth 31/32)
Oct 10 14:54:06 freax ata4.00: configured for UDMA/133
Oct 10 14:54:06 freax ata4: EH complete
Oct 10 14:54:06 freax scsi 3:0:0:0: Direct-Access     ATA      WDC WD1600BEVS-0 04.0 PQ: 0 ANSI: 5
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] 312581808 512-byte hardware sectors (160042 MB)
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Write Protect is off
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Mode Sense: 00 3a 00 00
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] 312581808 512-byte hardware sectors (160042 MB)
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Write Protect is off
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Mode Sense: 00 3a 00 00
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 14:54:06 freax sdh: sdh1
Oct 10 14:54:06 freax sd 3:0:0:0: [sdh] Attached SCSI disk
Oct 10 14:54:06 freax sd 3:0:0:0: Attached scsi generic sg9 type 0
Oct 10 14:54:17 freax kjournald starting.  Commit interval 5 seconds
Oct 10 14:54:17 freax EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
Oct 10 14:54:17 freax EXT3 FS on sdh1, internal journal
Oct 10 14:54:17 freax EXT3-fs: recovery complete.
Oct 10 14:54:17 freax EXT3-fs: mounted filesystem with ordered data mode.
Oct 10 14:54:17 freax hald: mounted /dev/sdh1 on behalf of uid 1001


Oct 10 15:01:46 freax ata4: exception Emask 0x50 SAct 0x0 SErr 0x90800 action 0x6 frozen
Oct 10 15:01:46 freax ata4: irq_stat 0x00400000, PHY RDY changed
Oct 10 15:01:46 freax ata4: hard resetting port
Oct 10 15:01:47 freax ata4: SATA link down (SStatus 0 SControl 300)
Oct 10 15:01:47 freax ata4: failed to recover some devices, retrying in 5 secs
Oct 10 15:01:52 freax ata4: hard resetting port
Oct 10 15:01:52 freax ata4: SATA link down (SStatus 0 SControl 300)
Oct 10 15:01:52 freax ata4: limiting SATA link speed to 1.5 Gbps
Oct 10 15:01:52 freax ata4.00: limiting speed to UDMA/133:PIO3
Oct 10 15:01:52 freax ata4: failed to recover some devices, retrying in 5 secs
Oct 10 15:01:57 freax ata4: hard resetting port
Oct 10 15:01:58 freax ata4: SATA link down (SStatus 0 SControl 310)
Oct 10 15:01:58 freax ata4.00: disabled
Oct 10 15:01:58 freax ata4: EH complete
Oct 10 15:01:58 freax ata4.00: detaching (SCSI 3:0:0:0)
Oct 10 15:01:58 freax sd 3:0:0:0: [sdh] Synchronizing SCSI cache
Oct 10 15:01:58 freax sd 3:0:0:0: [sdh] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK
Oct 10 15:01:58 freax sd 3:0:0:0: [sdh] Stopping disk
Oct 10 15:01:58 freax sd 3:0:0:0: [sdh] START_STOP FAILED
Oct 10 15:01:58 freax sd 3:0:0:0: [sdh] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK




And this is how it looks when attaching and removing the disk from the SIL port:

Oct 10 13:51:52 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
Oct 10 13:51:52 freax ata2: irq_stat 0x00400000, PHY RDY changed
Oct 10 13:51:54 freax ata2: soft resetting port
Oct 10 13:51:54 freax ata2: SATA link down (SStatus 21 SControl 300)
Oct 10 13:51:54 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:51:59 freax ata2: hard resetting port
Oct 10 13:52:00 freax ata2: SATA link down (SStatus 0 SControl 300)
Oct 10 13:52:00 freax ata2: limiting SATA link speed to 1.5 Gbps
Oct 10 13:52:00 freax ata2.00: limiting speed to UDMA/133:PIO3
Oct 10 13:52:00 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:52:05 freax ata2: hard resetting port
Oct 10 13:52:10 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:52:15 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:52:15 freax ata2: hard resetting port
Oct 10 13:52:16 freax ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 10 13:52:16 freax ata2.00: model number mismatch 'Config  Disk' != 'External Disk 0'
Oct 10 13:52:16 freax ata2.00: revalidation failed (errno=-19)
Oct 10 13:52:16 freax ata2.00: disabled
Oct 10 13:52:16 freax ata2: hard resetting port
Oct 10 13:52:22 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:52:26 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:52:26 freax ata2: hard resetting port
Oct 10 13:52:27 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:52:27 freax ata2.00: ATA-6: External Disk 0, RGL10364, max UDMA/133
Oct 10 13:52:27 freax ata2.00: 312581808 sectors, multi 1: LBA48
Oct 10 13:52:27 freax ata2.00: configured for UDMA/133
Oct 10 13:52:27 freax ata2: EH pending after completion, repeating EH (cnt=4)
Oct 10 13:52:27 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x4000000 action 0x3
Oct 10 13:52:27 freax ata2: irq_stat 0x00000040, connection status changed
Oct 10 13:52:28 freax ata2: soft resetting port
Oct 10 13:52:28 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:52:28 freax ata2.00: configured for UDMA/133
Oct 10 13:52:28 freax ata2: EH complete
Oct 10 13:52:28 freax ata2.00: detaching (SCSI 1:0:0:0)
Oct 10 13:52:28 freax sd 1:0:0:0: [sdb] Stopping disk
Oct 10 13:52:29 freax scsi 1:0:0:0: Direct-Access     ATA      External Disk 0  RGL1 PQ: 0 ANSI: 5
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] 312581808 512-byte hardware sectors (160042 MB)
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] Write Protect is off
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] 312581808 512-byte hardware sectors (160042 MB)
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] Write Protect is off
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 10 13:52:29 freax sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 13:52:30 freax sdb: sdb1
Oct 10 13:52:30 freax sd 1:0:0:0: [sdb] Attached SCSI disk
Oct 10 13:52:30 freax sd 1:0:0:0: Attached scsi generic sg1 type 0


Oct 10 13:53:27 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
Oct 10 13:53:27 freax ata2: irq_stat 0x00400000, PHY RDY changed
Oct 10 13:53:29 freax ata2: soft resetting port
Oct 10 13:53:29 freax ata2: SATA link down (SStatus 21 SControl 300)
Oct 10 13:53:29 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:53:34 freax ata2: hard resetting port
Oct 10 13:53:34 freax ata2: SATA link down (SStatus 0 SControl 300)
Oct 10 13:53:34 freax ata2: limiting SATA link speed to 1.5 Gbps
Oct 10 13:53:34 freax ata2.00: limiting speed to UDMA/133:PIO3
Oct 10 13:53:34 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:53:39 freax ata2: hard resetting port
Oct 10 13:53:45 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:53:49 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:53:49 freax ata2: hard resetting port
Oct 10 13:53:50 freax ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 10 13:53:50 freax ata2.00: model number mismatch 'External Disk 0' != 'Config  Disk'
Oct 10 13:53:50 freax ata2.00: revalidation failed (errno=-19)
Oct 10 13:53:50 freax ata2.00: disabled
Oct 10 13:53:50 freax ata2: hard resetting port
Oct 10 13:53:56 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:54:00 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:54:00 freax ata2: hard resetting port
Oct 10 13:54:01 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:54:01 freax ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
Oct 10 13:54:01 freax ata2.00: 640 sectors, multi 1: LBA
Oct 10 13:54:01 freax ata2.00: configured for UDMA/133
Oct 10 13:54:01 freax ata2: EH pending after completion, repeating EH (cnt=4)
Oct 10 13:54:01 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x4040000 action 0x3
Oct 10 13:54:01 freax ata2: irq_stat 0x00000040, connection status changed
Oct 10 13:54:02 freax ata2: soft resetting port
Oct 10 13:54:02 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:54:32 freax ata2.00: qc timeout (cmd 0xec)
Oct 10 13:54:32 freax ata2.00: failed to IDENTIFY (I/O error, err_mask=0x5)
Oct 10 13:54:32 freax ata2.00: revalidation failed (errno=-5)
Oct 10 13:54:32 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:54:37 freax ata2: hard resetting port
Oct 10 13:54:42 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:54:47 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:54:47 freax ata2: hard resetting port
Oct 10 13:54:48 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:54:48 freax ata2.00: configured for UDMA/133
Oct 10 13:54:48 freax ata2: EH pending after completion, repeating EH (cnt=3)
Oct 10 13:54:48 freax ata2: EH complete
Oct 10 13:54:48 freax ata2.00: detaching (SCSI 1:0:0:0)
Oct 10 13:54:48 freax sd 1:0:0:0: [sdb] Synchronizing SCSI cache
Oct 10 13:54:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:54:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:54:48 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:54:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:54:48 freax ata2.00: configured for UDMA/133
Oct 10 13:54:48 freax ata2: EH complete
Oct 10 13:54:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:54:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:54:48 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:54:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:54:48 freax ata2.00: configured for UDMA/133
Oct 10 13:54:48 freax ata2: EH complete
Oct 10 13:54:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:54:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:54:48 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:54:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:54:48 freax ata2.00: configured for UDMA/133
Oct 10 13:54:48 freax ata2: EH complete
Oct 10 13:54:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:54:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:54:48 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:54:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:54:48 freax hald[8702]: forcibly attempting to lazy unmount /dev/sdb1 as enclosing drive was disconnected
Oct 10 13:54:48 freax Buffer I/O error on device sdb1, logical block 1545
Oct 10 13:54:48 freax lost page write due to I/O error on sdb1
Oct 10 13:54:48 freax WARNING: at fs/buffer.c:1154 mark_buffer_dirty()
Oct 10 13:54:48 freax
Oct 10 13:54:48 freax Call Trace:
Oct 10 13:54:48 freax [<ffffffff802a4487>] mark_buffer_dirty+0x39/0x88
Oct 10 13:54:48 freax [<ffffffff802f15c0>] journal_update_superblock+0x76/0xce
Oct 10 13:54:48 freax [<ffffffff802f1d9e>] journal_destroy+0x1b4/0x204
Oct 10 13:54:48 freax [<ffffffff80248963>] autoremove_wake_function+0x0/0x2e
Oct 10 13:54:48 freax [<ffffffff802b7061>] mb_cache_shrink+0x72/0x97
Oct 10 13:54:48 freax [<ffffffff802d02ca>] ext3_put_super+0x29/0x1ca
Oct 10 13:54:48 freax [<ffffffff80287037>] generic_shutdown_super+0x60/0xf3
Oct 10 13:54:48 freax [<ffffffff8028717c>] deactivate_super+0x43/0x61
Oct 10 13:54:48 freax [<ffffffff802870d7>] kill_block_super+0xd/0x1e
Oct 10 13:54:48 freax [<ffffffff80287182>] deactivate_super+0x49/0x61
Oct 10 13:54:48 freax [<ffffffff8029a185>] sys_umount+0x1f9/0x22c
Oct 10 13:54:48 freax [<ffffffff80288576>] sys_newstat+0x19/0x31
Oct 10 13:54:48 freax [<ffffffff80595733>] trace_hardirqs_on_thunk+0x35/0x37
Oct 10 13:54:48 freax [<ffffffff8020b6de>] system_call+0x7e/0x83
Oct 10 13:54:48 freax
Oct 10 13:54:48 freax Buffer I/O error on device sdb1, logical block 1545
Oct 10 13:54:48 freax lost page write due to I/O error on sdb1
Oct 10 13:54:48 freax Buffer I/O error on device sdb1, logical block 0
Oct 10 13:54:48 freax lost page write due to I/O error on sdb1
Oct 10 13:54:48 freax hald: unmounted /dev/sdb1 from '/media/ICYBOX' on behalf of uid 0
Oct 10 13:54:48 freax ata2.00: failed to IDENTIFY (I/O error, err_mask=0x40)
Oct 10 13:54:48 freax ata2.00: revalidation failed (errno=-5)
Oct 10 13:54:48 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:54:55 freax ata2: soft resetting port
Oct 10 13:54:55 freax ata2: SATA link down (SStatus 21 SControl 300)
Oct 10 13:54:55 freax ata2: limiting SATA link speed to 1.5 Gbps
Oct 10 13:54:55 freax ata2.00: limiting speed to UDMA/133:PIO3
Oct 10 13:54:55 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:55:00 freax ata2: hard resetting port
Oct 10 13:55:01 freax ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 10 13:55:01 freax ata2.00: serial number mismatch '0A19EAF__________0_A' != '0000000__________0_A'
Oct 10 13:55:01 freax ata2.00: revalidation failed (errno=-19)
Oct 10 13:55:01 freax ata2.00: disabled
Oct 10 13:55:02 freax ata2: hard resetting port
Oct 10 13:55:07 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:55:12 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:55:12 freax ata2: hard resetting port
Oct 10 13:55:13 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:55:13 freax ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
Oct 10 13:55:13 freax ata2.00: 640 sectors, multi 1: LBA
Oct 10 13:55:13 freax ata2.00: configured for UDMA/133
Oct 10 13:55:13 freax ata2: EH pending after completion, repeating EH (cnt=4)
Oct 10 13:55:13 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0x3
Oct 10 13:55:13 freax ata2: irq_stat 0x00000040, connection status changed
Oct 10 13:55:13 freax agetty[23520]: /dev/ttyS0: not a character device
Oct 10 13:55:13 freax ata2: soft resetting port
Oct 10 13:55:14 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:55:23 freax agetty[23532]: /dev/ttyS0: not a character device
Oct 10 13:55:33 freax agetty[23544]: /dev/ttyS0: not a character device
Oct 10 13:55:43 freax agetty[23556]: /dev/ttyS0: not a character device
Oct 10 13:55:44 freax ata2.00: qc timeout (cmd 0xec)
Oct 10 13:55:44 freax ata2.00: failed to IDENTIFY (I/O error, err_mask=0x5)
Oct 10 13:55:44 freax ata2.00: revalidation failed (errno=-5)
Oct 10 13:55:44 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:55:49 freax ata2: hard resetting port
Oct 10 13:55:53 freax agetty[23568]: /dev/ttyS0: not a character device
Oct 10 13:55:54 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:55:59 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:55:59 freax ata2: hard resetting port
Oct 10 13:56:00 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH pending after completion, repeating EH (cnt=3)
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: configured for UDMA/133
Oct 10 13:56:00 freax ata2: EH complete
Oct 10 13:56:00 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:00 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:00 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:00 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:00 freax ata2.00: failed to IDENTIFY (I/O error, err_mask=0x40)
Oct 10 13:56:00 freax ata2.00: revalidation failed (errno=-5)
Oct 10 13:56:00 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:56:03 freax agetty[23585]: /dev/ttyS0: not a character device
Oct 10 13:56:07 freax ata2: soft resetting port
Oct 10 13:56:07 freax ata2: SATA link down (SStatus 21 SControl 300)
Oct 10 13:56:07 freax ata2: limiting SATA link speed to 1.5 Gbps
Oct 10 13:56:07 freax ata2.00: limiting speed to UDMA/133:PIO3
Oct 10 13:56:07 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:56:12 freax ata2: hard resetting port
Oct 10 13:56:13 freax agetty[23600]: /dev/ttyS0: not a character device
Oct 10 13:56:13 freax ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 10 13:56:13 freax ata2.00: configured for UDMA/133
Oct 10 13:56:13 freax ata2: EH pending after completion, repeating EH (cnt=4)
Oct 10 13:56:13 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0x3
Oct 10 13:56:13 freax ata2: irq_stat 0x00000040, connection status changed
Oct 10 13:56:13 freax ata2: hard resetting port
Oct 10 13:56:19 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:56:23 freax agetty[23616]: /dev/ttyS0: not a character device
Oct 10 13:56:23 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:56:23 freax ata2: hard resetting port
Oct 10 13:56:24 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:56:24 freax ata2.00: configured for UDMA/133
Oct 10 13:56:24 freax ata2: EH complete
Oct 10 13:56:24 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:24 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:24 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:24 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:24 freax ata2.00: configured for UDMA/133
Oct 10 13:56:24 freax ata2: EH complete
Oct 10 13:56:24 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:24 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:24 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:24 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:24 freax ata2.00: configured for UDMA/133
Oct 10 13:56:24 freax ata2: EH complete
Oct 10 13:56:24 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:24 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:24 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:24 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:24 freax ata2.00: configured for UDMA/133
Oct 10 13:56:24 freax ata2: EH complete
Oct 10 13:56:24 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:24 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:24 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:24 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:25 freax ata2.00: failed to IDENTIFY (I/O error, err_mask=0x40)
Oct 10 13:56:25 freax ata2.00: revalidation failed (errno=-5)
Oct 10 13:56:25 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:56:32 freax ata2: soft resetting port
Oct 10 13:56:32 freax ata2: SATA link down (SStatus 21 SControl 300)
Oct 10 13:56:32 freax ata2: limiting SATA link speed to 1.5 Gbps
Oct 10 13:56:32 freax ata2.00: limiting speed to UDMA/133:PIO2
Oct 10 13:56:32 freax ata2: failed to recover some devices, retrying in 5 secs
Oct 10 13:56:33 freax agetty[23628]: /dev/ttyS0: not a character device
Oct 10 13:56:37 freax ata2: hard resetting port
Oct 10 13:56:38 freax ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 10 13:56:38 freax ata2.00: configured for UDMA/133
Oct 10 13:56:38 freax ata2: EH pending after completion, repeating EH (cnt=4)
Oct 10 13:56:38 freax ata2: exception Emask 0x10 SAct 0x0 SErr 0x4010000 action 0x3
Oct 10 13:56:38 freax ata2: irq_stat 0x00000040, connection status changed
Oct 10 13:56:38 freax ata2: hard resetting port
Oct 10 13:56:43 freax agetty[23640]: /dev/ttyS0: not a character device
Oct 10 13:56:43 freax ata2: port is slow to respond, please be patient (Status 0x80)
Oct 10 13:56:48 freax ata2: COMRESET failed (errno=-16)
Oct 10 13:56:48 freax ata2: hard resetting port
Oct 10 13:56:48 freax ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Stopping disk
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 10 13:56:48 freax ata2.00: irq_stat 0x40000001
Oct 10 13:56:48 freax ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 10 13:56:48 freax res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 10 13:56:48 freax ata2.00: configured for UDMA/133
Oct 10 13:56:48 freax ata2: EH complete
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] START_STOP FAILED
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
Oct 10 13:56:48 freax scsi 1:0:0:0: Direct-Access     ATA      Config  Disk     RGL1 PQ: 0 ANSI: 5
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Write Protect is off
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Write Protect is off
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 13:56:48 freax sdb: unknown partition table
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Attached SCSI disk
Oct 10 13:56:48 freax sd 1:0:0:0: Attached scsi generic sg1 type 0
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Write Protect is off
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 10 13:56:48 freax sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Oct 10 13:56:53 freax init: Id "S0" respawning too fast: disabled for 5 minutes

Comment 3 Bjoern Olausson 2007-10-29 18:41:20 UTC

Hotpluging still does not work correct on the SIL thougth the boot delay on the Silicon Image 4723 (asus p5w-dh delux) is fixed.

If you plug, unplug and replug the device... things get even worse (see last dmsg output (3).

The disks is hard reseted (you can hear it)




1) Hotpluging a disk for the first time shows up the following in dmsg:

Oct 30 02:33:09 freax [  951.885385] ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
Oct 30 02:33:09 freax [  951.885390] ata2: irq_stat 0x00400000, PHY RDY changed
Oct 30 02:33:09 freax [  951.885396] ata2: hard resetting port
Oct 30 02:33:09 freax [  952.607499] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:33:09 freax [  952.607517] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:33:14 freax [  957.598288] ata2: hard resetting port
Oct 30 02:33:15 freax [  957.903345] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:33:15 freax [  957.903353] ata2: limiting SATA link speed to 1.5 Gbps
Oct 30 02:33:15 freax [  957.903357] ata2.00: limiting speed to UDMA/133:PIO3
Oct 30 02:33:15 freax [  957.903358] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:33:20 freax [  962.893411] ata2: hard resetting port
Oct 30 02:33:20 freax [  963.198770] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 30 02:33:21 freax [  963.731326] ata2.00: model number mismatch 'Config  Disk' != 'External Disk 0'
Oct 30 02:33:21 freax [  963.731421] ata2.00: revalidation failed (errno=-19)
Oct 30 02:33:21 freax [  963.731458] ata2.00: disabled
Oct 30 02:33:21 freax [  964.230585] ata2: hard resetting port
Oct 30 02:33:21 freax [  964.536883] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 30 02:33:22 freax [  965.068468] ata2.00: ATA-6: External Disk 0, RGL10364, max UDMA/133
Oct 30 02:33:22 freax [  965.068473] ata2.00: 145226112 sectors, multi 1: LBA48
Oct 30 02:33:22 freax [  965.068555] ata2.00: configured for UDMA/133
Oct 30 02:33:22 freax [  965.068559] ata2: EH pending after completion, repeating EH (cnt=4)
Oct 30 02:33:22 freax [  965.068567] ata2: exception Emask 0x10 SAct 0x0 SErr 0x4040000 action 0x3
Oct 30 02:33:22 freax [  965.068569] ata2: irq_stat 0x00000040, connection status changed
Oct 30 02:33:22 freax [  965.068574] ata2: hard resetting port
Oct 30 02:33:23 freax [  965.790385] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 30 02:33:23 freax [  965.906243] ata2.00: configured for UDMA/133
Oct 30 02:33:23 freax [  965.906251] ata2: EH complete
Oct 30 02:33:23 freax [  965.906264] ata2.00: detaching (SCSI 1:0:0:0)
Oct 30 02:33:23 freax [  965.906524] sd 1:0:0:0: [sdb] Stopping disk
Oct 30 02:33:23 freax [  966.062277] scsi 1:0:0:0: Direct-Access     ATA      External Disk 0  RGL1 PQ: 0 ANSI: 5
Oct 30 02:33:23 freax [  966.062415] sd 1:0:0:0: [sdb] 145226112 512-byte hardware sectors (74356 MB)
Oct 30 02:33:23 freax [  966.062467] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:33:23 freax [  966.062502] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:33:23 freax [  966.062557] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:33:23 freax [  966.062646] sd 1:0:0:0: [sdb] 145226112 512-byte hardware sectors (74356 MB)
Oct 30 02:33:23 freax [  966.062695] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:33:23 freax [  966.062729] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:33:23 freax [  966.062781] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:33:24 freax [  966.062956]  sdb: sdb1
Oct 30 02:33:24 freax [  966.984134] sd 1:0:0:0: [sdb] Attached SCSI disk
Oct 30 02:33:24 freax [  966.984218] sd 1:0:0:0: Attached scsi generic sg1 type 0







2) removing the disk shows the following:

Oct 30 02:34:47 freax [ 1050.239909] ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
Oct 30 02:34:47 freax [ 1050.239914] ata2: irq_stat 0x00400000, PHY RDY changed
Oct 30 02:34:47 freax [ 1050.239920] ata2: hard resetting port
Oct 30 02:34:48 freax [ 1050.961633] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:34:48 freax [ 1050.961642] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:34:53 freax [ 1055.952117] ata2: hard resetting port
Oct 30 02:34:53 freax [ 1056.256843] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:34:53 freax [ 1056.256852] ata2: limiting SATA link speed to 1.5 Gbps
Oct 30 02:34:53 freax [ 1056.256856] ata2.00: limiting speed to UDMA/133:PIO3
Oct 30 02:34:53 freax [ 1056.256858] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:34:58 freax [ 1061.247358] ata2: hard resetting port
Oct 30 02:34:59 freax [ 1061.552201] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 30 02:34:59 freax [ 1062.085279] ata2.00: model number mismatch 'External Disk 0' != 'Config  Disk'
Oct 30 02:34:59 freax [ 1062.085285] ata2.00: revalidation failed (errno=-19)
Oct 30 02:34:59 freax [ 1062.085288] ata2.00: disabled
Oct 30 02:35:00 freax [ 1062.585281] ata2: hard resetting port
Oct 30 02:35:00 freax [ 1062.889050] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 30 02:35:00 freax [ 1063.423224] ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
Oct 30 02:35:00 freax [ 1063.423230] ata2.00: 640 sectors, multi 1: LBA
Oct 30 02:35:01 freax [ 1063.938356] ata2.00: failed to IDENTIFY (I/O error, err_mask=0x100)
Oct 30 02:35:01 freax [ 1063.938361] ata2.00: revalidation failed (errno=-5)
Oct 30 02:35:01 freax [ 1063.938365] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:35:06 freax [ 1068.928314] ata2: hard resetting port
Oct 30 02:35:06 freax [ 1069.232999] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:35:06 freax [ 1069.233008] ata2: limiting SATA link speed to 1.5 Gbps
Oct 30 02:35:06 freax [ 1069.233013] ata2.00: limiting speed to UDMA/133:PIO3
Oct 30 02:35:06 freax [ 1069.233015] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:35:11 freax [ 1074.222933] ata2: hard resetting port
Oct 30 02:35:12 freax [ 1074.527285] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 30 02:35:12 freax [ 1075.060872] ata2.00: serial number mismatch '0A7F97F__________0_A' != '0000000__________0_A'
Oct 30 02:35:12 freax [ 1075.060877] ata2.00: revalidation failed (errno=-19)
Oct 30 02:35:12 freax [ 1075.060881] ata2.00: disabled
Oct 30 02:35:13 freax [ 1075.560814] ata2: EH pending after completion, repeating EH (cnt=4)
Oct 30 02:35:13 freax [ 1075.560825] ata2: exception Emask 0x10 SAct 0x0 SErr 0x4050000 action 0x3
Oct 30 02:35:13 freax [ 1075.560828] ata2: irq_stat 0x00000040, connection status changed
Oct 30 02:35:13 freax [ 1075.560834] ata2: hard resetting port
Oct 30 02:35:13 freax [ 1076.283146] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 30 02:35:13 freax [ 1076.398732] ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
Oct 30 02:35:13 freax [ 1076.398737] ata2.00: 640 sectors, multi 1: LBA
Oct 30 02:35:13 freax [ 1076.398873] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.398878] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.398888] ata2.00: detaching (SCSI 1:0:0:0)
Oct 30 02:35:13 freax [ 1076.399147] sd 1:0:0:0: [sdb] Synchronizing SCSI cache
Oct 30 02:35:13 freax [ 1076.399196] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.399236] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.399271] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.399272]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.399453] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.399494] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.399544] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.399582] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.399616] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.399617]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.399793] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.399833] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.399884] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.399922] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.399956] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.399957]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.400341] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.400388] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.400439] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.400477] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.400511] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.400512]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.400688] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.400728] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.400779] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.400822] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.400855] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.400856]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.401035] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.401074] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.401126] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.401164] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.401198] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.401199]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.401540] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.401588] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.401728] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.401768] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.401802] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.401803]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.402186] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.402238] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.402289] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.402327] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.402361] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.402362]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.402540] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.402580] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.402631] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.402669] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.402703] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.402704]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.402883] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.402922] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.403116] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.403158] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.403193] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.403194]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.403376] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.403415] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.403468] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.403506] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.403540] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.403541]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.403727] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.403766] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.403826] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.403863] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.403897] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.403898]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.404949] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.405011] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.405064] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.405388] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.405393] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.405394]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.405526] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.405533] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.405554] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.405555] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.405559] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.405560]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.405687] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.405692] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.405711] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.405713] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.405716] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.405717]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.405842] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.405847] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.405872] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.405873] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.405876] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.405877]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.406240] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.406246] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.406268] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.406270] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.406273] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.406274]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.406424] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.406429] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.406449] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.406451] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.406454] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.406455]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.406581] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.406588] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.406595] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Oct 30 02:35:13 freax [ 1076.406599] sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Oct 30 02:35:13 freax [ 1076.406622] sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
Oct 30 02:35:13 freax [ 1076.406649] sd 1:0:0:0: [sdb] Stopping disk
Oct 30 02:35:13 freax [ 1076.406683] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.406701] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.406716] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.406732]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.406875] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.406880] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.406900] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.406902] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.406905] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.406906]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.407032] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.407037] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.407056] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.407058] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.407061] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.407062]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.407190] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.407219] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.407249] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.407267] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.407282] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.407298]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.407442] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.407446] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.407465] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.407467] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.407470] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.407487]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.407632] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.407636] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.407654] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 30 02:35:13 freax [ 1076.407656] ata2.00: irq_stat 0x40000001
Oct 30 02:35:13 freax [ 1076.407659] ata2.00: cmd e0/00:00:00:00:00/00:00:00:00:00/a0 tag 0 cdb 0x0 data 0
Oct 30 02:35:13 freax [ 1076.407660]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Oct 30 02:35:13 freax [ 1076.407844] ata2.00: configured for UDMA/133
Oct 30 02:35:13 freax [ 1076.407850] ata2: EH complete
Oct 30 02:35:13 freax [ 1076.407855] sd 1:0:0:0: [sdb] START_STOP FAILED
Oct 30 02:35:13 freax [ 1076.407859] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Oct 30 02:35:13 freax [ 1076.407861] sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Oct 30 02:35:13 freax [ 1076.407865] sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
Oct 30 02:35:13 freax [ 1076.408330] scsi 1:0:0:0: Direct-Access     ATA      Config  Disk     RGL1 PQ: 0 ANSI: 5
Oct 30 02:35:13 freax [ 1076.408593] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Oct 30 02:35:13 freax [ 1076.408605] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:35:13 freax [ 1076.408607] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:35:13 freax [ 1076.408626] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:35:13 freax [ 1076.408677] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Oct 30 02:35:13 freax [ 1076.408688] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:35:13 freax [ 1076.408690] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:35:13 freax [ 1076.408707] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:35:13 freax [ 1076.408710]  sdb: unknown partition table
Oct 30 02:35:13 freax [ 1076.409022] sd 1:0:0:0: [sdb] Attached SCSI disk
Oct 30 02:35:13 freax [ 1076.409230] sd 1:0:0:0: Attached scsi generic sg1 type 0
Oct 30 02:35:13 freax [ 1076.409277] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Oct 30 02:35:13 freax [ 1076.409304] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:35:13 freax [ 1076.409317] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:35:13 freax [ 1076.409347] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA





3) Re-adding the disk:

Oct 30 02:36:43 freax [ 1165.343128] ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
Oct 30 02:36:43 freax [ 1165.343133] ata2: irq_stat 0x00400000, PHY RDY changed
Oct 30 02:36:43 freax [ 1165.343139] ata2: hard resetting port
Oct 30 02:36:43 freax [ 1166.070069] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:36:43 freax [ 1166.070186] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:36:48 freax [ 1171.060049] ata2: hard resetting port
Oct 30 02:36:49 freax [ 1171.365520] ata2: SATA link down (SStatus 0 SControl 300)
Oct 30 02:36:49 freax [ 1171.365526] ata2: limiting SATA link speed to 1.5 Gbps
Oct 30 02:36:49 freax [ 1171.365529] ata2.00: limiting speed to UDMA/133:PIO3
Oct 30 02:36:49 freax [ 1171.365533] ata2: failed to recover some devices, retrying in 5 secs
Oct 30 02:36:54 freax [ 1176.355483] ata2: hard resetting port
Oct 30 02:36:54 freax [ 1176.660428] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Oct 30 02:36:54 freax [ 1177.194270] ata2.00: model number mismatch 'Config  Disk' != 'External Disk 0'
Oct 30 02:36:54 freax [ 1177.194277] ata2.00: revalidation failed (errno=-19)
Oct 30 02:36:54 freax [ 1177.194280] ata2.00: disabled
Oct 30 02:36:55 freax [ 1177.693996] ata2: hard resetting port
Oct 30 02:36:55 freax [ 1177.997702] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 30 02:36:56 freax [ 1178.532822] ata2.00: ATA-6: External Disk 0, RGL10364, max UDMA/133
Oct 30 02:36:56 freax [ 1178.532827] ata2.00: 1 sectors, multi 1: LBA48
Oct 30 02:36:56 freax [ 1178.532910] ata2.00: configured for UDMA/133
Oct 30 02:36:56 freax [ 1178.532915] ata2: EH pending after completion, repeating EH (cnt=4)
Oct 30 02:36:56 freax [ 1178.532923] ata2: exception Emask 0x10 SAct 0x0 SErr 0x4040000 action 0x3
Oct 30 02:36:56 freax [ 1178.532925] ata2: irq_stat 0x00000040, connection status changed
Oct 30 02:36:56 freax [ 1178.532930] ata2: hard resetting port
Oct 30 02:36:56 freax [ 1179.255498] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Oct 30 02:36:57 freax [ 1179.370686] ata2.00: configured for UDMA/133
Oct 30 02:36:57 freax [ 1179.370695] ata2: EH complete
Oct 30 02:36:57 freax [ 1179.370709] ata2.00: detaching (SCSI 1:0:0:0)
Oct 30 02:36:57 freax [ 1179.371016] sd 1:0:0:0: [sdb] Stopping disk
Oct 30 02:36:57 freax [ 1179.530023] scsi 1:0:0:0: Direct-Access     ATA      External Disk 0  RGL1 PQ: 0 ANSI: 5
Oct 30 02:36:57 freax [ 1179.530092] sd 1:0:0:0: [sdb] 1 512-byte hardware sectors (0 MB)
Oct 30 02:36:57 freax [ 1179.530104] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:36:57 freax [ 1179.530126] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:36:57 freax [ 1179.530166] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:36:57 freax [ 1179.530245] sd 1:0:0:0: [sdb] 1 512-byte hardware sectors (0 MB)
Oct 30 02:36:57 freax [ 1179.530257] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:36:57 freax [ 1179.530276] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:36:57 freax [ 1179.530316] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:36:58 freax [ 1179.530352]  sdb: sdb1
Oct 30 02:36:58 freax [ 1180.451284]  sdb: p1 exceeds device capacity
Oct 30 02:36:58 freax [ 1180.451385] sd 1:0:0:0: [sdb] Attached SCSI disk
Oct 30 02:36:58 freax [ 1180.451452] sd 1:0:0:0: Attached scsi generic sg1 type 0
Oct 30 02:36:58 freax [ 1180.477574] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477579] sdb: rw=0, want=145211335, limit=1
Oct 30 02:36:58 freax [ 1180.477582] Buffer I/O error on device sdb1, logical block 18151408
Oct 30 02:36:58 freax [ 1180.477586] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477588] sdb: rw=0, want=145211335, limit=1
Oct 30 02:36:58 freax [ 1180.477590] Buffer I/O error on device sdb1, logical block 18151408
Oct 30 02:36:58 freax [ 1180.477599] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477603] sdb: rw=0, want=145211527, limit=1
Oct 30 02:36:58 freax [ 1180.477605] Buffer I/O error on device sdb1, logical block 18151432
Oct 30 02:36:58 freax [ 1180.477608] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477610] sdb: rw=0, want=145211527, limit=1
Oct 30 02:36:58 freax [ 1180.477611] Buffer I/O error on device sdb1, logical block 18151432
Oct 30 02:36:58 freax [ 1180.477626] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477638] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.477652] Buffer I/O error on device sdb1, logical block 0
Oct 30 02:36:58 freax [ 1180.477670] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477686] sdb: rw=0, want=79, limit=1
Oct 30 02:36:58 freax [ 1180.477699] Buffer I/O error on device sdb1, logical block 1
Oct 30 02:36:58 freax [ 1180.477718] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477733] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.477746] Buffer I/O error on device sdb1, logical block 0
Oct 30 02:36:58 freax [ 1180.477767] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477782] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.477798] Buffer I/O error on device sdb1, logical block 0
Oct 30 02:36:58 freax [ 1180.477818] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477831] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.477845] Buffer I/O error on device sdb1, logical block 18151433
Oct 30 02:36:58 freax [ 1180.477869] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477882] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.477896] Buffer I/O error on device sdb1, logical block 18151433
Oct 30 02:36:58 freax [ 1180.477915] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477929] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.477947] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477962] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.477979] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.477993] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.478013] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478027] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.478048] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478062] sdb: rw=0, want=145211479, limit=1
Oct 30 02:36:58 freax [ 1180.478078] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478096] sdb: rw=0, want=145211527, limit=1
Oct 30 02:36:58 freax [ 1180.478112] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478128] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.478149] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478162] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.478179] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478192] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478210] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478222] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478237] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478251] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478267] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478282] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478297] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478311] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478329] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478340] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478355] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478369] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478384] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478397] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478412] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478426] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478451] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478464] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478480] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478494] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478509] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478521] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478536] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478549] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478564] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478578] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478592] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478607] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478622] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478635] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478651] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478665] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478679] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478694] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478709] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478723] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478738] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478751] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478766] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478780] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478794] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478808] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478824] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478839] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478853] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478868] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.478885] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.478899] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.511509] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.511608] sdb: rw=0, want=145211335, limit=1
Oct 30 02:36:58 freax [ 1180.511646] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.511681] sdb: rw=0, want=145211335, limit=1
Oct 30 02:36:58 freax [ 1180.511722] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.511757] sdb: rw=0, want=145211527, limit=1
Oct 30 02:36:58 freax [ 1180.511792] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.511826] sdb: rw=0, want=145211527, limit=1
Oct 30 02:36:58 freax [ 1180.511874] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.511910] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.511945] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.511980] sdb: rw=0, want=79, limit=1
Oct 30 02:36:58 freax [ 1180.512015] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512050] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.512087] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512122] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.512161] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512196] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512236] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512271] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512320] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512355] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512393] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512428] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512465] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512504] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512543] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512578] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512617] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512652] sdb: rw=0, want=145211479, limit=1
Oct 30 02:36:58 freax [ 1180.512690] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512724] sdb: rw=0, want=145211527, limit=1
Oct 30 02:36:58 freax [ 1180.512762] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512797] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512835] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512869] sdb: rw=0, want=145211535, limit=1
Oct 30 02:36:58 freax [ 1180.512907] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.512958] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.512995] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513030] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513067] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513102] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513141] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513176] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513212] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513247] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513286] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513323] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513360] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513394] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513431] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513465] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513502] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513537] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513573] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513608] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513644] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513679] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513715] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513749] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513786] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513821] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513857] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513892] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513928] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.513963] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.513999] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514034] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514071] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514107] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514117] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514134] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514148] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514164] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514179] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514195] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514210] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514224] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514240] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514254] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514270] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514284] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514300] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514306] sdb: rw=0, want=71, limit=1
Oct 30 02:36:58 freax [ 1180.514323] attempt to access beyond end of device
Oct 30 02:36:58 freax [ 1180.514491] sdb: rw=0, want=71, limit=1

Comment 4 Bjoern Olausson 2007-10-29 18:47:15 UTC

Adding the disk th an ICH7 port works flawless and shows the following

1) Adding disk:

Oct 30 02:44:44 freax [ 1646.002822] ata3: exception Emask 0x10 SAct 0x0 SErr 0x4040000 action 0x2 frozen
Oct 30 02:44:44 freax [ 1646.002828] ata3: irq_stat 0x00000040, connection status changed
Oct 30 02:44:44 freax [ 1646.002835] ata3: hard resetting port
Oct 30 02:44:45 freax [ 1646.876457] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Oct 30 02:44:45 freax [ 1646.878594] ata3.00: ATA-7: WDC WD740ADFD-00NLR1, 20.07P20, max UDMA/133
Oct 30 02:44:45 freax [ 1646.878599] ata3.00: 145226112 sectors, multi 0: LBA48 NCQ (not used)
Oct 30 02:44:45 freax [ 1646.881374] ata3.00: configured for UDMA/133
Oct 30 02:44:45 freax [ 1646.881382] ata3: EH complete
Oct 30 02:44:45 freax [ 1646.881510] scsi 2:0:0:0: Direct-Access     ATA      WDC WD740ADFD-00 20.0 PQ: 0 ANSI: 5
Oct 30 02:44:45 freax [ 1646.881621] sd 2:0:0:0: [sdg] 145226112 512-byte hardware sectors (74356 MB)
Oct 30 02:44:45 freax [ 1646.881635] sd 2:0:0:0: [sdg] Write Protect is off
Oct 30 02:44:45 freax [ 1646.881651] sd 2:0:0:0: [sdg] Mode Sense: 00 3a 00 00
Oct 30 02:44:45 freax [ 1646.881686] sd 2:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:44:45 freax [ 1646.881753] sd 2:0:0:0: [sdg] 145226112 512-byte hardware sectors (74356 MB)
Oct 30 02:44:45 freax [ 1646.881764] sd 2:0:0:0: [sdg] Write Protect is off
Oct 30 02:44:45 freax [ 1646.881780] sd 2:0:0:0: [sdg] Mode Sense: 00 3a 00 00
Oct 30 02:44:45 freax [ 1646.881812] sd 2:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:44:45 freax [ 1646.881836]  sdg: sdg1
Oct 30 02:44:45 freax [ 1646.889961] sd 2:0:0:0: [sdg] Attached SCSI disk
Oct 30 02:44:45 freax [ 1646.890049] sd 2:0:0:0: Attached scsi generic sg7 type 0




2) Removing Disk

Oct 30 02:45:35 freax [ 1696.745375] ata3: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0x2 frozen
Oct 30 02:45:35 freax [ 1696.745380] ata3: irq_stat 0x00400000, PHY RDY changed
Oct 30 02:45:37 freax [ 1698.944933] ata3: soft resetting port
Oct 30 02:45:37 freax [ 1698.944942] ata3: SATA link down (SStatus 11 SControl 300)
Oct 30 02:45:37 freax [ 1698.944949] ata3: failed to recover some devices, retrying in 5 secs
Oct 30 02:45:42 freax [ 1703.935595] ata3: hard resetting port
Oct 30 02:45:43 freax [ 1704.240601] ata3: SATA link down (SStatus 0 SControl 300)
Oct 30 02:45:43 freax [ 1704.240610] ata3: limiting SATA link speed to 1.5 Gbps
Oct 30 02:45:43 freax [ 1704.240614] ata3.00: limiting speed to UDMA/133:PIO3
Oct 30 02:45:43 freax [ 1704.240617] ata3: failed to recover some devices, retrying in 5 secs
Oct 30 02:45:48 freax [ 1709.230815] ata3: hard resetting port
Oct 30 02:45:48 freax [ 1709.535480] ata3: SATA link down (SStatus 0 SControl 310)
Oct 30 02:45:48 freax [ 1709.535489] ata3.00: disabled
Oct 30 02:45:48 freax [ 1710.035682] ata3: EH complete
Oct 30 02:45:48 freax [ 1710.035699] ata3.00: detaching (SCSI 2:0:0:0)
Oct 30 02:45:48 freax [ 1710.036086] sd 2:0:0:0: [sdg] Synchronizing SCSI cache
Oct 30 02:45:48 freax [ 1710.036161] sd 2:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK
Oct 30 02:45:48 freax [ 1710.036212] sd 2:0:0:0: [sdg] Stopping disk
Oct 30 02:45:48 freax [ 1710.036275] sd 2:0:0:0: [sdg] START_STOP FAILED
Oct 30 02:45:48 freax [ 1710.036312] sd 2:0:0:0: [sdg] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK



3) Re-adding the disk:

Oct 30 02:46:28 freax [ 1750.004095] ata3: exception Emask 0x10 SAct 0x0 SErr 0x4040000 action 0x2 frozen
Oct 30 02:46:28 freax [ 1750.004101] ata3: irq_stat 0x00000040, connection status changed
Oct 30 02:46:28 freax [ 1750.004108] ata3: hard resetting port
Oct 30 02:46:29 freax [ 1750.876085] ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Oct 30 02:46:29 freax [ 1750.878223] ata3.00: ATA-7: WDC WD740ADFD-00NLR1, 20.07P20, max UDMA/133
Oct 30 02:46:29 freax [ 1750.878228] ata3.00: 145226112 sectors, multi 0: LBA48 NCQ (not used)
Oct 30 02:46:29 freax [ 1750.881016] ata3.00: configured for UDMA/133
Oct 30 02:46:29 freax [ 1750.881024] ata3: EH complete
Oct 30 02:46:29 freax [ 1750.881149] scsi 2:0:0:0: Direct-Access     ATA      WDC WD740ADFD-00 20.0 PQ: 0 ANSI: 5
Oct 30 02:46:29 freax [ 1750.881248] sd 2:0:0:0: [sdg] 145226112 512-byte hardware sectors (74356 MB)
Oct 30 02:46:29 freax [ 1750.881262] sd 2:0:0:0: [sdg] Write Protect is off
Oct 30 02:46:29 freax [ 1750.881276] sd 2:0:0:0: [sdg] Mode Sense: 00 3a 00 00
Oct 30 02:46:29 freax [ 1750.881311] sd 2:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:46:29 freax [ 1750.881384] sd 2:0:0:0: [sdg] 145226112 512-byte hardware sectors (74356 MB)
Oct 30 02:46:29 freax [ 1750.881396] sd 2:0:0:0: [sdg] Write Protect is off
Oct 30 02:46:29 freax [ 1750.881413] sd 2:0:0:0: [sdg] Mode Sense: 00 3a 00 00
Oct 30 02:46:29 freax [ 1750.881445] sd 2:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Oct 30 02:46:29 freax [ 1750.881468]  sdg: sdg1
Oct 30 02:46:29 freax [ 1750.894050] sd 2:0:0:0: [sdg] Attached SCSI disk
Oct 30 02:46:29 freax [ 1750.894156] sd 2:0:0:0: Attached scsi generic sg7 type 0

Comment 5 Bjoern Olausson 2007-10-29 18:59:42 UTC

When I hotplug the disk for the second/third/fourth.... time on the SIL, i wasn't able to acces the disk (mount it or use it in any way)... for example with cfdisk (of course -z works):

FATAL ERROR: Bad primary partition 0: Partition begins after end-of-disk

sfdisk -d shows:
# partition table of /dev/sdb
unit: sectors

/dev/sdb1 : start=       63, size=145211472, Id=83
/dev/sdb2 : start=        0, size=        0, Id= 0
/dev/sdb3 : start=        0, size=        0, Id= 0
/dev/sdb4 : start=        0, size=        0, Id= 0


Connecting the disk to the ICH7... no problem:

cfdisk shows:
Name   Flags      Part Type   FS Type     [Label]               Size (MB)
sdg1   Primary    Linux       ext3        [test]                74348.31

sfdisk -d /dev/sdg
# partition table of /dev/sdg
unit: sectors

/dev/sdg1 : start=       63, size=145211472, Id=83
/dev/sdg2 : start=        0, size=        0, Id= 0
/dev/sdg3 : start=        0, size=        0, Id= 0
/dev/sdg4 : start=        0, size=        0, Id= 0

Comment 6 Jeff Garzik 2007-11-02 09:07:35 UTC

Coming in a bit late on this bug...  which drivers are problematic here?

ahci?  sata_sil24?

Comment 7 Bjoern Olausson 2007-11-02 12:16:39 UTC

AHCI I guess, there is no special driver for the Silicon Image 4723.

Tejun has had his fun with the SIL4723 in this bug here:
http://bugzilla.kernel.org/show_bug.cgi?id=8923

Hotpluging on the normal ICH7 ports is working fine.

regards
Bjoern

Comment 8 Tejun Heo 2007-11-02 17:49:22 UTC

Jeff, the offlining issue is probably a problem in SCSI midlayer.  I can kind of reproduce it here.  I just haven't had the time to look through it yet.

Comment 9 Luke Bratch 2007-11-19 15:37:16 UTC

I seem to have killed a drive by hotplugging with the SIL4723 - I was expecting data loss but the drive seems to have been totally killed (even marked as bad by SMART).  Is this the expected behaviour, and is there any workaround or is the drive totally lost?

Thanks.

Comment 10 Tejun Heo 2007-11-19 17:23:10 UTC

Luke, can you please post the result of "smartctl -a /dev/sdX"?  How old is the drive?  4723 can't really kill the drive.

Comment 11 Bjoern Olausson 2007-11-19 17:33:14 UTC

On 11/20/07, bugme-daemon@bugzilla.kernel.org
<bugme-daemon@bugzilla.kernel.org> wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=9010
>
>
> l_bratch@yahoo.co.uk changed:
>
>            What    |Removed                     |Added
> ----------------------------------------------------------------------------
>                  CC|                            |l_bratch@yahoo.co.uk
>
>
>
>
> ------- Comment #9 from l_bratch@yahoo.co.uk  2007-11-19 15:37 -------
> I seem to have killed a drive by hotplugging with the SIL4723 - I was
> expecting
> data loss but the drive seems to have been totally killed (even marked as bad
> by SMART).  Is this the expected behaviour, and is there any workaround or is
> the drive totally lost?
>
> Thanks.

mmmh, I could recover my drives by re-partitioning/re-formating them,
none has been marked as bad... but I'll check the smart status on the
two drives I tested...

I'll pray that this is just a co-incidnce you observed...

regards
Bjoern

Comment 12 Tejun Heo 2007-11-19 17:52:07 UTC

What did you originally mean by dead drive?

Comment 13 Bjoern Olausson 2007-11-20 03:21:28 UTC

mmh, maybe dead was the wrong term... but the drive was rendered useless. As you can see in my previous posts, the partitiontable or somthing else got corrupted when attaching the disk. Even switching the controler didn't reveal the partitions/data on the disk. Even creating partitions on the drive when it is attached to the SIL, the same happens. But asap I am on my Desktop PC I'll try that again and check SMART... just in case... (for now I left it connected to the SIL and didn't bother the disk... since I posted the last error Comment #5 )

regards
Bjeorn

Comment 14 Bjoern Olausson 2007-11-20 04:12:25 UTC

(In reply to comment #10)
> Luke, can you please post the result of "smartctl -a /dev/sdX"?  How old is
> the
> drive?  4723 can't really kill the drive.
>
 
He posted the error in the gentoo forum...
http://forums.gentoo.org/viewtopic-p-4521437.html#4521437

It doesn't look like the drive is completely dead, but here is the result for you Tejun:

ReiserFS: sde1: found reiserfs format "3.6" with standard journal
ReiserFS: sde1: using ordered data mode
ReiserFS: sde1: journal params: device sde1, size 8192, journal first block 18, max trans len 1024, max batch 900, max commit age 30, max trans age 30
ReiserFS: sde1: checking transaction log (sde1)
ReiserFS: sde1: Using r5 hash to sort names
printk: 188 messages suppressed.
sky2 0000:03:00.0: error interrupt status=0xc0000000
ata6.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata6.00: irq_stat 0x48000000
ata6.00: cmd 60/08:00:ff:41:f9/00:00:05:00:00/40 tag 0 cdb 0x0 data 4096 in
         res 41/40:00:ff:41:f9/97:00:05:00:00/40 Emask 0x409 (media error) <F>
ata6.00: status: { DRDY ERR }
ata6.00: error: { UNC }
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 976773168 512-byte hardware sectors (500108 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
printk: 267 messages suppressed.
sky2 0000:03:00.0: error interrupt status=0xc0000000
ata6.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata6.00: irq_stat 0x48000000
ata6.00: cmd 60/08:00:ff:41:f9/00:00:05:00:00/40 tag 0 cdb 0x0 data 4096 in
         res 41/40:00:ff:41:f9/de:00:05:00:00/40 Emask 0x409 (media error) <F>
ata6.00: status: { DRDY ERR }
ata6.00: error: { UNC }
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 976773168 512-byte hardware sectors (500108 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
printk: 128 messages suppressed.
sky2 0000:03:00.0: error interrupt status=0xc0000000
ata6.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata6.00: irq_stat 0x48000000
ata6.00: cmd 60/08:00:ff:41:f9/00:00:05:00:00/40 tag 0 cdb 0x0 data 4096 in
         res 41/40:00:ff:41:f9/5b:00:05:00:00/40 Emask 0x409 (media error) <F>
ata6.00: status: { DRDY ERR }
ata6.00: error: { UNC }
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 976773168 512-byte hardware sectors (500108 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
printk: 129 messages suppressed.
sky2 0000:03:00.0: error interrupt status=0xc0000000
ata6.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata6.00: irq_stat 0x48000000
ata6.00: cmd 60/08:00:ff:41:f9/00:00:05:00:00/40 tag 0 cdb 0x0 data 4096 in
         res 41/40:00:ff:41:f9/de:00:05:00:00/40 Emask 0x409 (media error) <F>
ata6.00: status: { DRDY ERR }
ata6.00: error: { UNC }
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 976773168 512-byte hardware sectors (500108 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
ata6.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata6.00: irq_stat 0x48000000
ata6.00: cmd 60/08:00:ff:41:f9/00:00:05:00:00/40 tag 0 cdb 0x0 data 4096 in
         res 41/40:00:ff:41:f9/de:00:05:00:00/40 Emask 0x409 (media error) <F>
ata6.00: status: { DRDY ERR }
ata6.00: error: { UNC }
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 976773168 512-byte hardware sectors (500108 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
printk: 121 messages suppressed.
sky2 0000:03:00.0: error interrupt status=0xc0000000
ata6.00: exception Emask 0x0 SAct 0x1 SErr 0x0 action 0x0
ata6.00: irq_stat 0x48000000
ata6.00: cmd 60/08:00:ff:41:f9/00:00:05:00:00/40 tag 0 cdb 0x0 data 4096 in
         res 41/40:00:ff:41:f9/de:00:05:00:00/40 Emask 0x409 (media error) <F>
ata6.00: status: { DRDY ERR }
ata6.00: error: { UNC }
ata6.00: configured for UDMA/133
ata6: EH complete
sd 5:0:0:0: [sde] 976773168 512-byte hardware sectors (500108 MB)
sd 5:0:0:0: [sde] Write Protect is off
sd 5:0:0:0: [sde] Mode Sense: 00 3a 00 00
sd 5:0:0:0: [sde] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
ReiserFS: warning: is_tree_node: node level 5910 does not match to the expected one 1
ReiserFS: sde1: warning: vs-5150: search_by_key: invalid format found in block 12527672. Fsck?
ReiserFS: sde1: warning: vs-13070: reiserfs_read_locked_inode: i/o failure occurred trying to find stat data of [2 826253 0x0 SD]
ReiserFS: sde1: warning: xattrs/ACLs enabled and couldn't find/create .reiserfs_priv. Failing mount.


regards
Bjoern

Comment 15 Luke Bratch 2007-11-20 04:26:33 UTC

(In reply to comment #10)
> Luke, can you please post the result of "smartctl -a /dev/sdX"?  How old is
> the
> drive?  4723 can't really kill the drive.
> 

The drive is around 1.5 years old, and just above you can see where Bjoern Olausson posted my dmesg output.  Here is smartctl -a /dev/sde:

smartctl version 5.37 [x86_64-pc-linux-gnu] Copyright (C) 2002-6 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Model Family:     Western Digital Caviar SE16 family
Device Model:     WDC WD5000KS-00MNB0
Serial Number:    WD-WMANU1085294
Firmware Version: 06.02E06
User Capacity:    500,107,862,016 bytes
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   7
ATA Standard is:  Exact ATA specification draft version not indicated
Local Time is:    Tue Nov 20 12:21:14 2007 GMT
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: FAILED!
Drive failure expected in less than 24 hours. SAVE ALL DATA.
See vendor-specific Attribute list for failed Attributes.

General SMART Values:
Offline data collection status:  (0x84)	Offline data collection activity
					was suspended by an interrupting command from host.
					Auto Offline Data Collection: Enabled.
Self-test execution status:      (   0)	The previous self-test routine completed
					without error or no self-test has ever 
					been run.
Total time to complete Offline 
data collection: 		 (16800) seconds.
Offline data collection
capabilities: 			 (0x7b) SMART execute Offline immediate.
					Auto Offline data collection on/off support.
					Suspend Offline collection upon new
					command.
					Offline surface scan supported.
					Self-test supported.
					Conveyance Self-test supported.
					Selective Self-test supported.
SMART capabilities:            (0x0003)	Saves SMART data before entering
					power-saving mode.
					Supports SMART auto save timer.
Error logging capability:        (0x01)	Error logging supported.
					General Purpose Logging supported.
Short self-test routine 
recommended polling time: 	 (   2) minutes.
Extended self-test routine
recommended polling time: 	 ( 190) minutes.
Conveyance self-test routine
recommended polling time: 	 (   6) minutes.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x000f   200   200   051    Pre-fail  Always       -       0
  3 Spin_Up_Time            0x0003   227   221   021    Pre-fail  Always       -       5633
  4 Start_Stop_Count        0x0032   100   100   000    Old_age   Always       -       966
  5 Reallocated_Sector_Ct   0x0033   136   136   140    Pre-fail  Always   FAILING_NOW 511
  7 Seek_Error_Rate         0x000f   083   083   051    Pre-fail  Always       -       2840
  9 Power_On_Hours          0x0032   087   087   000    Old_age   Always       -       10096
 10 Spin_Retry_Count        0x0013   100   100   051    Pre-fail  Always       -       0
 11 Calibration_Retry_Count 0x0012   100   100   051    Old_age   Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       957
190 Temperature_Celsius     0x0022   065   039   045    Old_age   Always   In_the_past 35
194 Temperature_Celsius     0x0022   253   253   000    Old_age   Always       -       35
196 Reallocated_Event_Count 0x0032   195   195   000    Old_age   Always       -       5
197 Current_Pending_Sector  0x0012   200   200   000    Old_age   Always       -       21
198 Offline_Uncorrectable   0x0010   200   200   000    Old_age   Offline      -       0
199 UDMA_CRC_Error_Count    0x003e   200   200   000    Old_age   Always       -       0
200 Multi_Zone_Error_Rate   0x0009   200   200   051    Pre-fail  Offline      -       0

SMART Error Log Version: 1
ATA Error Count: 59 (device log contains only the most recent five errors)
	CR = Command Register [HEX]
	FR = Features Register [HEX]
	SC = Sector Count Register [HEX]
	SN = Sector Number Register [HEX]
	CL = Cylinder Low Register [HEX]
	CH = Cylinder High Register [HEX]
	DH = Device/Head Register [HEX]
	DC = Device Command Register [HEX]
	ER = Error register [HEX]
	ST = Status register [HEX]
Powered_Up_Time is measured from power on, and printed as
DDd+hh:mm:SS.sss where DD=days, hh=hours, mm=minutes,
SS=sec, and sss=millisec. It "wraps" after 49.710 days.

Error 59 occurred at disk power-on lifetime: 10096 hours (420 days + 16 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 51 00 ff 41 f9 40

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 08 00 ff 41 f9 05 08      00:04:45.094  READ FPDMA QUEUED
  27 00 00 00 00 00 00 00      00:04:45.093  READ NATIVE MAX ADDRESS EXT
  ec 00 00 00 00 00 00 00      00:04:45.093  IDENTIFY DEVICE
  ef 03 46 00 00 00 00 00      00:04:45.093  SET FEATURES [Set transfer mode]
  27 00 00 00 00 00 00 00      00:04:45.067  READ NATIVE MAX ADDRESS EXT

Error 58 occurred at disk power-on lifetime: 10096 hours (420 days + 16 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 51 00 ff 41 f9 40

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 08 00 ff 41 f9 05 08      00:04:40.750  READ FPDMA QUEUED
  27 00 00 00 00 00 00 00      00:04:40.750  READ NATIVE MAX ADDRESS EXT
  ec 00 00 00 00 00 00 00      00:04:40.750  IDENTIFY DEVICE
  ef 03 46 00 00 00 00 00      00:04:40.749  SET FEATURES [Set transfer mode]
  27 00 00 00 00 00 00 00      00:04:40.724  READ NATIVE MAX ADDRESS EXT

Error 57 occurred at disk power-on lifetime: 10096 hours (420 days + 16 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 51 00 ff 41 f9 40

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 08 00 ff 41 f9 05 08      00:04:36.216  READ FPDMA QUEUED
  27 00 00 00 00 00 00 00      00:04:36.216  READ NATIVE MAX ADDRESS EXT
  ec 00 00 00 00 00 00 00      00:04:36.215  IDENTIFY DEVICE
  ef 03 46 00 00 00 00 00      00:04:36.215  SET FEATURES [Set transfer mode]
  27 00 00 00 00 00 00 00      00:04:36.189  READ NATIVE MAX ADDRESS EXT

Error 56 occurred at disk power-on lifetime: 10096 hours (420 days + 16 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 51 00 ff 41 f9 40

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 08 00 ff 41 f9 05 08      00:04:31.490  READ FPDMA QUEUED
  27 00 00 00 00 00 00 00      00:04:31.490  READ NATIVE MAX ADDRESS EXT
  ec 00 00 00 00 00 00 00      00:04:31.489  IDENTIFY DEVICE
  ef 03 46 00 00 00 00 00      00:04:31.489  SET FEATURES [Set transfer mode]
  27 00 00 00 00 00 00 00      00:04:31.463  READ NATIVE MAX ADDRESS EXT

Error 55 occurred at disk power-on lifetime: 10096 hours (420 days + 16 hours)
  When the command that caused the error occurred, the device was active or idle.

  After command completion occurred, registers were:
  ER ST SC SN CL CH DH
  -- -- -- -- -- -- --
  40 51 00 ff 41 f9 40

  Commands leading to the command that caused the error were:
  CR FR SC SN CL CH DH DC   Powered_Up_Time  Command/Feature_Name
  -- -- -- -- -- -- -- --  ----------------  --------------------
  60 08 00 ff 41 f9 05 08      00:04:27.147  READ FPDMA QUEUED
  27 00 00 00 00 00 00 00      00:04:27.146  READ NATIVE MAX ADDRESS EXT
  ec 00 00 00 00 00 00 00      00:04:27.146  IDENTIFY DEVICE
  ef 03 46 00 00 00 00 00      00:04:27.146  SET FEATURES [Set transfer mode]
  27 00 00 00 00 00 00 00      00:04:27.120  READ NATIVE MAX ADDRESS EXT

SMART Self-test log structure revision number 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]


SMART Selective self-test log data structure revision number 1
 SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1        0        0  Not_testing
    2        0        0  Not_testing
    3        0        0  Not_testing
    4        0        0  Not_testing
    5        0        0  Not_testing
Selective self-test flags (0x0):
  After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.

Comment 16 Bjoern Olausson 2007-11-20 05:03:16 UTC

thanks, but you shouldn't reveal your serial to everyone (i did the same mistake on my first post) :-)

just paste it like this:
Device Model:     WDC WD5000KS-00MNB0
Serial Number:    WD-*****

Comment 17 Bjoern Olausson 2007-11-20 05:50:20 UTC

Okay, heres some mor information from my drive.
(it is attached to SIL while booting, NO hotplug)

cfdisk does no longer detect the drive capacity:
Disk Drive: /dev/sdb
Size: 512 bytes, 0 MB

(and no, I didn't modify the Serial....)

root@freax $ smartctl -a /dev/sdb
smartctl version 5.37 [x86_64-pc-linux-gnu] Copyright (C) 2002-6 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Device Model:     External Disk 0
Serial Number:    0000000__________0_A
Firmware Version: RGL10364
User Capacity:    512 bytes
Device is:        Not in smartctl database [for details use: -P showall]
ATA Version is:   6
ATA Standard is:  ATA/ATAPI-6 T13 1410D revision 2
Local Time is:    Tue Nov 20 14:41:36 2007 CET
SMART support is: Available - device has SMART capability.
SMART support is: Disabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED
See vendor-specific Attribute list for marginal Attributes.

General SMART Values:
Offline data collection status:  (0x00) Offline data collection activity
                                        was never started.
                                        Auto Offline Data Collection: Disabled.
Total time to complete Offline
data collection:                 (   0) seconds.
Offline data collection
capabilities:                    (0x00)         Offline data collection not supported.
SMART capabilities:            (0x0000) Automatic saving of SMART data                                  is not implemented.
Error logging capability:        (0x00) Error logging NOT supported.
                                        No General Purpose Logging support.

SMART Attributes Data Structure revision number: 64
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
255 Unknown_Attribute       0x373f   200   016   063    Pre-fail  Always   In_the_past 69269232549888
 95 Unknown_Attribute       0x5f30   095   095   048    Old_age   Offline      -       53186180112223
 65 Unknown_Attribute       0x035f   000   000   095    Pre-fail  Always   FAILING_NOW 54229448262718
 51 Unknown_Attribute       0x3430   054   120   048    Old_age   Offline      -       119238735193413
 68 Unknown_Attribute       0x7320   105   032   032    Old_age   Offline  In_the_past 35322351067243
 32 Unknown_Attribute       0x2020   032   032   032    Old_age   Offline  FAILING_NOW 35322350018592
 32 Unknown_Attribute       0x2020   032   032   032    Old_age   Offline  FAILING_NOW 549774696480
 16 Unknown_Attribute       0x3f00   000   016   000    Old_age   Offline  FAILING_NOW 1103823436796
120 Unknown_Attribute       0x7800   000   000   000    Old_age   Offline  FAILING_NOW 0
 40 Unknown_Attribute       0x6000   052   064   000    Old_age   Offline      -       4226880
 64 Unknown_Attribute       0x0020   000   000   032    Old_age   Offline  FAILING_NOW 0

Warning: device does not support Error Logging
SMART Error Log Version: 64
No Errors Logged

Warning: device does not support Self Test Logging
SMART Self-test log structure revision number 64
Warning: ATA Specification requires self-test log structure revision number = 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]


Device does not support Selective Self Tests/Logging


Now I'll try to recover the drive on the ICH7... lets see what happens

Comment 18 Bjoern Olausson 2007-11-20 06:35:17 UTC

Okay, if I attache the drive to the ICH7 port it works fine an I can create new partitions...

root@freax $ smartctl -a /dev/sdc
smartctl version 5.37 [x86_64-pc-linux-gnu] Copyright (C) 2002-6 Bruce Allen
Home page is http://smartmontools.sourceforge.net/

=== START OF INFORMATION SECTION ===
Model Family:     Western Digital Raptor family
Device Model:     WDC WD740ADFD-00NLR1
Serial Number:    WD-****
Firmware Version: 20.07P20
User Capacity:    74,355,769,344 bytes
Device is:        In smartctl database [for details use: -P show]
ATA Version is:   7
ATA Standard is:  ATA/ATAPI-7 published, ANSI INCITS 397-2005
Local Time is:    Tue Nov 20 15:34:06 2007 CET
SMART support is: Available - device has SMART capability.
SMART support is: Enabled

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED

General SMART Values:
Offline data collection status:  (0x82) Offline data collection activity
                                        was completed without error.
                                        Auto Offline Data Collection: Enabled.
Self-test execution status:      (   0) The previous self-test routine completed
                                        without error or no self-test has ever
                                        been run.
Total time to complete Offline
data collection:                 (2391) seconds.
Offline data collection
capabilities:                    (0x7b) SMART execute Offline immediate.
                                        Auto Offline data collection on/off support.
                                        Suspend Offline collection upon new
                                        command.
                                        Offline surface scan supported.
                                        Self-test supported.
                                        Conveyance Self-test supported.
                                        Selective Self-test supported.
SMART capabilities:            (0x0003) Saves SMART data before entering
                                        power-saving mode.
                                        Supports SMART auto save timer.
Error logging capability:        (0x01) Error logging supported.
                                        General Purpose Logging supported.
Short self-test routine
recommended polling time:        (   2) minutes.
Extended self-test routine
recommended polling time:        (  39) minutes.
Conveyance self-test routine
recommended polling time:        (   5) minutes.

SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
  1 Raw_Read_Error_Rate     0x000b   200   200   051    Pre-fail  Always       -       0
  3 Spin_Up_Time            0x0007   170   168   021    Pre-fail  Always       -       2533
  4 Start_Stop_Count        0x0032   100   100   040    Old_age   Always       -       855
  5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always       -       0
  7 Seek_Error_Rate         0x000a   200   200   051    Old_age   Always       -       0
  9 Power_On_Hours          0x0032   098   098   000    Old_age   Always       -       1929
 10 Spin_Retry_Count        0x0012   100   100   051    Old_age   Always       -       0
 11 Calibration_Retry_Count 0x0012   100   100   051    Old_age   Always       -       0
 12 Power_Cycle_Count       0x0032   100   100   000    Old_age   Always       -       577
194 Temperature_Celsius     0x0022   112   091   000    Old_age   Always       -       31
196 Reallocated_Event_Count 0x0032   200   200   000    Old_age   Always       -       0
197 Current_Pending_Sector  0x0012   200   200   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0012   200   200   000    Old_age   Always       -       0
199 UDMA_CRC_Error_Count    0x000a   200   253   000    Old_age   Always       -       1
200 Multi_Zone_Error_Rate   0x0008   200   200   051    Old_age   Offline      -       0

SMART Error Log Version: 1
No Errors Logged

SMART Self-test log structure revision number 1
No self-tests have been logged.  [To run self-tests, use: smartctl -t]


SMART Selective self-test log data structure revision number 1
 SPAN  MIN_LBA  MAX_LBA  CURRENT_TEST_STATUS
    1        0        0  Not_testing
    2        0        0  Not_testing
    3        0        0  Not_testing
    4        0        0  Not_testing
    5        0        0  Not_testing
Selective self-test flags (0x0):
  After scanning selected spans, do NOT read-scan remainder of disk.
If Selective self-test is pending on power-up, resume after 0 minute delay.

Comment 19 Natalie Protasevich 2008-02-11 02:45:56 UTC

What is the status of this problem, any updates please.
Thanks.

Comment 20 Bjoern Olausson 2008-02-11 13:54:42 UTC

mmh, good question, IMHO it was in the todo queue of Tejun. I'll check with 2.6.24.2 and give a short summary. But don't expect the results untill Monday. I am away the next 5 days.

regards
Bjoern

Comment 21 Bjoern Olausson 2008-02-17 07:43:09 UTC

Okay, looks odd.

Here I removed the drive from ata6 to test it on the jmicron port:
----------------------------------------------------------------------
Feb 17 16:28:24 freax [ 4173.497590] ata6: exception Emask 0x10 SAct 0x0 SErr 0x990000 action 0xa frozen
Feb 17 16:28:24 freax [ 4173.497594] ata6: irq_stat 0x00400000, PHY RDY changed
Feb 17 16:28:24 freax [ 4173.497596] ata6: SError: { PHYRdyChg 10B8B Dispar LinkSeq }
Feb 17 16:28:24 freax [ 4173.497604] ata6: hard resetting link
Feb 17 16:28:25 freax [ 4174.234671] ata6: SATA link down (SStatus 0 SControl 300)
Feb 17 16:28:25 freax [ 4174.234685] ata6: failed to recover some devices, retrying in 5 secs
Feb 17 16:28:30 freax [ 4179.325915] ata6: hard resetting link
Feb 17 16:28:31 freax [ 4179.636403] ata6: SATA link down (SStatus 0 SControl 300)
Feb 17 16:28:31 freax [ 4179.636417] ata6: failed to recover some devices, retrying in 5 secs
Feb 17 16:28:36 freax [ 4184.728354] ata6: hard resetting link
Feb 17 16:28:36 freax [ 4185.038801] ata6: SATA link down (SStatus 0 SControl 300)
Feb 17 16:28:36 freax [ 4185.038814] ata6.00: disabled
Feb 17 16:28:37 freax [ 4185.548667] ata6: EH complete
Feb 17 16:28:37 freax [ 4185.548677] ata6.00: detaching (SCSI 5:0:0:0)
Feb 17 16:28:37 freax [ 4185.549029] sd 5:0:0:0: [sdd] Synchronizing SCSI cache
Feb 17 16:28:37 freax [ 4185.549066] sd 5:0:0:0: [sdd] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK
Feb 17 16:28:37 freax [ 4185.549069] sd 5:0:0:0: [sdd] Stopping disk
Feb 17 16:28:37 freax [ 4185.549078] sd 5:0:0:0: [sdd] START_STOP FAILED
Feb 17 16:28:37 freax [ 4185.549079] sd 5:0:0:0: [sdd] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK
-------------------------------------------------

Here I added the disk to the first jmicron port:
---------------------------------------------------
Feb 17 16:29:06 freax [ 4214.642400] ata2: exception Emask 0x10 SAct 0x0 SErr 0x90000 action 0xa frozen
Feb 17 16:29:06 freax [ 4214.642406] ata2: irq_stat 0x00400000, PHY RDY changed
Feb 17 16:29:06 freax [ 4214.642409] ata2: SError: { PHYRdyChg 10B8B }
Feb 17 16:29:06 freax [ 4214.642418] ata2: hard resetting link
Feb 17 16:29:06 freax [ 4215.378801] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:29:06 freax [ 4215.378812] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:29:12 freax [ 4220.469916] ata2: hard resetting link
Feb 17 16:29:12 freax [ 4220.779519] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:29:12 freax [ 4220.779529] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:29:17 freax [ 4225.870294] ata2: hard resetting link
Feb 17 16:29:17 freax [ 4226.180809] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:29:17 freax [ 4226.180819] ata2.00: disabled
Feb 17 16:29:18 freax [ 4226.690742] ata2: hard resetting link
Feb 17 16:29:18 freax [ 4227.002459] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:29:18 freax [ 4227.002476] ata2: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x9 t4
Feb 17 16:29:18 freax [ 4227.002479] ata2: irq_stat 0x00000040, connection status changed
Feb 17 16:29:18 freax [ 4227.002489] ata2: hard resetting link
Feb 17 16:29:19 freax [ 4227.738502] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:29:19 freax [ 4227.738517] ata2: EH complete
Feb 17 16:29:19 freax [ 4227.738533] ata2.00: detaching (SCSI 1:0:0:0)
Feb 17 16:29:19 freax [ 4227.738760] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:29:19 freax [ 4227.738790] sd 1:0:0:0: [sdb] START_STOP FAILED
Feb 17 16:29:19 freax [ 4227.738792] sd 1:0:0:0: [sdb] Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK,SUGGEST_OK
Feb 17 16:29:24 freax [ 4233.251078] ata2: exception Emask 0x10 SAct 0x0 SErr 0x4050002 action 0xa frozen
Feb 17 16:29:24 freax [ 4233.251083] ata2: irq_stat 0x00000040, connection status changed
Feb 17 16:29:24 freax [ 4233.251087] ata2: SError: { RecovComm PHYRdyChg CommWake DevExch }
Feb 17 16:29:24 freax [ 4233.251097] ata2: hard resetting link
Feb 17 16:29:27 freax [ 4236.219278] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Feb 17 16:29:27 freax [ 4236.219366] ata2.00: ATA-6: External Disk 0, RGL10364, max UDMA/133
Feb 17 16:29:27 freax [ 4236.219369] ata2.00: 312581808 sectors, multi 1: LBA48
Feb 17 16:29:27 freax [ 4236.219469] ata2.00: configured for UDMA/133
Feb 17 16:29:27 freax [ 4236.219475] ata2: EH complete
Feb 17 16:29:27 freax [ 4236.219576] scsi 1:0:0:0: Direct-Access     ATA      External Disk 0  RGL1 PQ: 0 ANSI: 5
Feb 17 16:29:27 freax [ 4236.219681] sd 1:0:0:0: [sdb] 312581808 512-byte hardware sectors (160042 MB)
Feb 17 16:29:27 freax [ 4236.219694] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:29:27 freax [ 4236.219696] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:29:27 freax [ 4236.219714] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:29:27 freax [ 4236.219776] sd 1:0:0:0: [sdb] 312581808 512-byte hardware sectors (160042 MB)
Feb 17 16:29:27 freax [ 4236.219787] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:29:27 freax [ 4236.219789] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:29:27 freax [ 4236.219807] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:29:27 freax [ 4236.219811]  sdb: sdb1
Feb 17 16:29:27 freax [ 4236.220033] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:29:27 freax [ 4236.220077] sd 1:0:0:0: Attached scsi generic sg1 type 0
Feb 17 16:29:35 freax [ 4244.268373] kjournald starting.  Commit interval 5 seconds
Feb 17 16:29:35 freax [ 4244.268383] EXT3-fs warning: maximal mount count reached, running e2fsck is recommended
Feb 17 16:29:35 freax [ 4244.287644] EXT3 FS on sdb1, internal journal
Feb 17 16:29:35 freax [ 4244.287651] EXT3-fs: mounted filesystem with ordered data mode.
Feb 17 16:29:35 freax hald: mounted /dev/sdb1 on behalf of uid 1001
Feb 17 16:30:09 freax hald: unmounted /dev/sdb1 from '/media/ICYBOX' on behalf of uid 1001
------------------------------------------------------------

Mounted the device to see if it is working, and it did.


Now I removed the drive:
----------------------------------------------------------
Feb 17 16:30:27 freax [ 4296.020845] ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xa frozen
Feb 17 16:30:27 freax [ 4296.020851] ata2: irq_stat 0x00400000, PHY RDY changed
Feb 17 16:30:27 freax [ 4296.020854] ata2: SError: { PHYRdyChg }
Feb 17 16:30:27 freax [ 4296.020862] ata2: hard resetting link
Feb 17 16:30:28 freax [ 4296.757052] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:30:28 freax [ 4296.757062] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:30:33 freax [ 4301.848910] ata2: hard resetting link
Feb 17 16:30:33 freax [ 4302.159609] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:30:33 freax [ 4302.159619] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:30:38 freax [ 4307.250541] ata2: hard resetting link
Feb 17 16:30:41 freax [ 4309.791156] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Feb 17 16:30:41 freax [ 4309.791238] ata2.00: model number mismatch 'External Disk 0' != 'Config  Disk'
Feb 17 16:30:41 freax [ 4309.791240] ata2.00: revalidation failed (errno=-19)
Feb 17 16:30:41 freax [ 4309.791242] ata2.00: disabled
Feb 17 16:30:42 freax [ 4310.301245] ata2: hard resetting link
Feb 17 16:30:44 freax [ 4312.841138] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Feb 17 16:30:44 freax [ 4312.841212] ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
Feb 17 16:30:44 freax [ 4312.841214] ata2.00: 640 sectors, multi 1: LBA
Feb 17 16:30:44 freax [ 4312.841221] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.841297] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.841313] ata2: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x9 t4
Feb 17 16:30:44 freax [ 4312.841325] ata2: irq_stat 0x00000040, connection status changed
Feb 17 16:30:44 freax [ 4312.841400] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.841476] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.841484] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.841492] ata2.00: detaching (SCSI 1:0:0:0)
Feb 17 16:30:44 freax [ 4312.841774] sd 1:0:0:0: [sdb] Synchronizing SCSI cache
Feb 17 16:30:44 freax [ 4312.841804] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.841806] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.841810] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.841811]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.841813] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.841815] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.841881] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.841953] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.841959] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.841979] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.841981] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.841984] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.841985]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.841987] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.841989] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.842055] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.842128] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.842135] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.842155] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.842157] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.842160] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.842161]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.842163] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.842165] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.842231] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.842305] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.842309] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.842341] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.842343] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.842347] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.842347]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.842350] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.842351] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.842417] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.842490] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.842495] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.842513] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.842515] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.842518] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.842519]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.842521] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.842523] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.842589] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.842662] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.842666] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.842685] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.842687] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.842690] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.842691]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.842693] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.842694] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.843004] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.843335] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.843343] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.843370] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.843372] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.843375] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.843376]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.843378] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.843380] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.843447] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.843522] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.843531] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.843550] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.843552] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.843555] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.843556]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.843558] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.843559] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.843625] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.843698] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.843703] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.843723] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.843725] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.843728] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.843729]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.843731] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.843733] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.843798] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.843869] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.843873] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.843891] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.843892] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.843895] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.843896]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.843907] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.843914] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.843983] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:44 freax [ 4312.844056] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.844060] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.844081] ata2: limiting SATA link speed to 1.5 Gbps
Feb 17 16:30:44 freax [ 4312.844083] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x4
Feb 17 16:30:44 freax [ 4312.844085] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.844088] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:44 freax [ 4312.844089]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.844091] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.844092] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.844096] ata2: hard resetting link
Feb 17 16:30:47 freax [ 4315.382749] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Feb 17 16:30:47 freax [ 4315.382841] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.382933] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.382947] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.382980] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.382986] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.382995] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.382997]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.383016] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.383025] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.383099] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.383179] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.383187] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.383219] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.383221] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.383224] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.383225]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.383227] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.383229] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.383299] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.383378] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.383382] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.383405] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.383407] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.383410] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.383418]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.383428] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.383435] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.383510] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.383597] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.383608] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.383634] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.383645] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.383655] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.383662]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.383676] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.383684] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.383758] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.383838] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.383842] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.383863] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.383865] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.383868] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.383869]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.383871] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.383872] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.383941] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.384020] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.384024] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.384044] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.384053] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.384061] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.384070]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.384081] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.384089] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.384164] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.384244] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.384247] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.384269] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Feb 17 16:30:47 freax [ 4315.384270] ata2.00: irq_stat 0x40000001
Feb 17 16:30:47 freax [ 4315.384274] ata2.00: cmd e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
Feb 17 16:30:47 freax [ 4315.384274]          res 51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:47 freax [ 4315.384276] ata2.00: status: { DRDY ERR }
Feb 17 16:30:47 freax [ 4315.384278] ata2.00: error: { ABRT }
Feb 17 16:30:47 freax [ 4315.384346] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:30:47 freax [ 4315.384425] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.384430] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.384437] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Feb 17 16:30:47 freax [ 4315.384440] sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Feb 17 16:30:47 freax [ 4315.384456] sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
Feb 17 16:30:47 freax [ 4315.384469] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:30:47 freax [ 4315.384614] scsi 1:0:0:0: Direct-Access     ATA      Config  Disk     RGL1 PQ: 0 ANSI: 5
Feb 17 16:30:47 freax [ 4315.384699] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Feb 17 16:30:47 freax [ 4315.384710] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:30:47 freax [ 4315.384712] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:30:47 freax [ 4315.384731] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:30:47 freax [ 4315.384796] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Feb 17 16:30:47 freax [ 4315.384816] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:30:47 freax [ 4315.384827] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:30:47 freax [ 4315.384853] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:30:47 freax [ 4315.384872]  sdb: unknown partition table
Feb 17 16:30:47 freax [ 4315.385908] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:30:47 freax [ 4315.385954] sd 1:0:0:0: Attached scsi generic sg1 type 0
Feb 17 16:30:47 freax [ 4315.385988] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Feb 17 16:30:47 freax [ 4315.385999] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:30:47 freax [ 4315.386001] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:30:47 freax [ 4315.386020] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:30:47 freax [ 4315.921044] ata2.00: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xa frozen
Feb 17 16:30:47 freax [ 4315.921050] ata2.00: irq_stat 0x00400000, PHY RDY changed
Feb 17 16:30:47 freax [ 4315.921054] ata2: SError: { PHYRdyChg }
Feb 17 16:30:47 freax [ 4315.921061] ata2.00: cmd c4/00:08:20:00:00/00:00:00:00:00/e0 tag 0 pio 4096 in
Feb 17 16:30:47 freax [ 4315.921063]          res 50/00:00:01:01:80/00:00:00:00:00/a0 Emask 0x10 (ATA bus error)
Feb 17 16:30:47 freax [ 4315.921066] ata2.00: status: { DRDY }
Feb 17 16:30:47 freax [ 4315.921073] ata2: hard resetting link
Feb 17 16:30:48 freax [ 4316.657840] ata2: SATA link down (SStatus 0 SControl 310)
Feb 17 16:30:48 freax [ 4316.657850] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:30:53 freax [ 4321.749575] ata2: hard resetting link
Feb 17 16:30:53 freax [ 4322.060034] ata2: SATA link down (SStatus 0 SControl 310)
Feb 17 16:30:53 freax [ 4322.060044] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:30:58 freax [ 4327.150576] ata2: hard resetting link
Feb 17 16:31:01 freax [ 4329.692366] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
Feb 17 16:31:01 freax [ 4329.692477] ata2.00: serial number mismatch '0A19EAF__________0_A' != '0000000__________0_A'
Feb 17 16:31:01 freax [ 4329.692479] ata2.00: revalidation failed (errno=-19)
Feb 17 16:31:01 freax [ 4329.692481] ata2.00: disabled
Feb 17 16:31:01 freax [ 4330.202154] ata2: hard resetting link
Feb 17 16:31:04 freax [ 4332.744537] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Feb 17 16:31:04 freax [ 4332.744620] ata2.00: ATA-6: Config  Disk, RGL10364, max UDMA/133
Feb 17 16:31:04 freax [ 4332.744623] ata2.00: 640 sectors, multi 1: LBA
Feb 17 16:31:04 freax [ 4332.744632] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:31:04 freax [ 4332.744716] ata2.00: configured for PIO4
Feb 17 16:31:04 freax [ 4332.744727] ata2: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x9 t4
Feb 17 16:31:04 freax [ 4332.744734] ata2: irq_stat 0x00000040, connection status changed
Feb 17 16:31:04 freax [ 4332.744812] ata2.00: device is on DMA blacklist, disabling DMA
Feb 17 16:31:04 freax [ 4332.744887] ata2.00: configured for PIO4
Feb 17 16:31:04 freax [ 4332.744893] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK
Feb 17 16:31:04 freax [ 4332.744896] sd 1:0:0:0: [sdb] Sense Key : Aborted Command [current] [descriptor]
Feb 17 16:31:04 freax [ 4332.744900] Descriptor sense data with sense descriptors (in hex):
Feb 17 16:31:04 freax [ 4332.744902]         72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 00
Feb 17 16:31:04 freax [ 4332.744923]         00 80 01 01
Feb 17 16:31:04 freax [ 4332.744934] sd 1:0:0:0: [sdb] Add. Sense: No additional sense information
Feb 17 16:31:04 freax [ 4332.744946] end_request: I/O error, dev sdb, sector 32
Feb 17 16:31:04 freax [ 4332.744956] Buffer I/O error on device sdb, logical block 4
Feb 17 16:31:04 freax [ 4332.744967] sd 1:0:0:0: rejecting I/O to offline device
Feb 17 16:31:04 freax [ 4332.744977] sd 1:0:0:0: rejecting I/O to offline device
Feb 17 16:31:04 freax [ 4332.744984] Buffer I/O error on device sdb, logical block 79
Feb 17 16:31:04 freax [ 4332.744991] ata2: EH complete
Feb 17 16:31:04 freax [ 4332.745001] sd 1:0:0:0: [sdb] Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK,SUGGEST_OK
Feb 17 16:31:04 freax [ 4332.745008] end_request: I/O error, dev sdb, sector 40
Feb 17 16:31:04 freax [ 4332.745016] Buffer I/O error on device sdb, logical block 5
Feb 17 16:31:04 freax [ 4332.745024] Buffer I/O error on device sdb, logical block 6
Feb 17 16:31:04 freax [ 4332.745034] Buffer I/O error on device sdb, logical block 7
Feb 17 16:31:04 freax [ 4332.745042] Buffer I/O error on device sdb, logical block 8
Feb 17 16:31:04 freax [ 4332.745045] Buffer I/O error on device sdb, logical block 9
Feb 17 16:31:04 freax [ 4332.745047] Buffer I/O error on device sdb, logical block 10
Feb 17 16:31:04 freax [ 4332.745050] Buffer I/O error on device sdb, logical block 11
Feb 17 16:31:04 freax [ 4332.745065] sd 1:0:0:0: rejecting I/O to offline device
Feb 17 16:31:04 freax [ 4332.745067] Buffer I/O error on device sdb, logical block 79
Feb 17 16:31:04 freax [ 4332.745074] ata2.00: detaching (SCSI 1:0:0:0)
Feb 17 16:31:04 freax [ 4332.745342] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:31:04 freax [ 4332.745690] scsi 1:0:0:0: Direct-Access     ATA      Config  Disk     RGL1 PQ: 0 ANSI: 5
Feb 17 16:31:04 freax [ 4332.745768] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Feb 17 16:31:04 freax [ 4332.745779] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:31:04 freax [ 4332.745781] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:31:04 freax [ 4332.745800] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:31:04 freax [ 4332.745845] sd 1:0:0:0: [sdb] 640 512-byte hardware sectors (0 MB)
Feb 17 16:31:04 freax [ 4332.745855] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:31:04 freax [ 4332.745857] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:31:04 freax [ 4332.745875] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:31:04 freax [ 4332.745878]  sdb: unknown partition table
Feb 17 16:31:04 freax [ 4332.745959] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:31:04 freax [ 4332.745998] sd 1:0:0:0: Attached scsi generic sg1 type 0
-----------------------------------------------------------

now re plug the device:
-----------------------------------------------------------
Feb 17 16:41:50 freax [ 4977.840074] ata2: exception Emask 0x10 SAct 0x0 SErr 0x10000 action 0xa frozen
Feb 17 16:41:50 freax [ 4977.840080] ata2: irq_stat 0x00400000, PHY RDY changed
Feb 17 16:41:50 freax [ 4977.840083] ata2: SError: { PHYRdyChg }
Feb 17 16:41:50 freax [ 4977.840091] ata2: hard resetting link
Feb 17 16:41:51 freax [ 4978.576507] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:41:51 freax [ 4978.576516] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:41:56 freax [ 4983.678479] ata2: hard resetting link
Feb 17 16:41:57 freax [ 4983.989543] ata2: SATA link down (SStatus 0 SControl 300)
Feb 17 16:41:57 freax [ 4983.989553] ata2: failed to recover some devices, retrying in 5 secs
Feb 17 16:42:02 freax [ 4989.090894] ata2: hard resetting link
Feb 17 16:42:04 freax [ 4991.638546] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Feb 17 16:42:04 freax [ 4991.638619] ata2.00: model number mismatch 'Config  Disk' != 'External Disk 0'
Feb 17 16:42:04 freax [ 4991.638622] ata2.00: revalidation failed (errno=-19)
Feb 17 16:42:04 freax [ 4991.638624] ata2.00: disabled
Feb 17 16:42:05 freax [ 4992.149526] ata2: hard resetting link
Feb 17 16:42:07 freax [ 4994.695718] ata2: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
Feb 17 16:42:07 freax [ 4994.695802] ata2.00: ATA-6: External Disk 0, RGL10364, max UDMA/133
Feb 17 16:42:07 freax [ 4994.695805] ata2.00: 1 sectors, multi 1: LBA48
Feb 17 16:42:07 freax [ 4994.695914] ata2.00: configured for UDMA/133
Feb 17 16:42:07 freax [ 4994.695922] ata2: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x9 t4
Feb 17 16:42:07 freax [ 4994.695924] ata2: irq_stat 0x00000040, connection status changed
Feb 17 16:42:07 freax [ 4994.696084] ata2.00: configured for UDMA/133
Feb 17 16:42:07 freax [ 4994.696087] ata2: EH complete
Feb 17 16:42:07 freax [ 4994.696095] ata2.00: detaching (SCSI 1:0:0:0)
Feb 17 16:42:07 freax [ 4994.696345] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:42:08 freax [ 4995.139171] scsi 1:0:0:0: Direct-Access     ATA      External Disk 0  RGL1 PQ: 0 ANSI: 5
Feb 17 16:42:08 freax [ 4995.139390] sd 1:0:0:0: [sdb] 1 512-byte hardware sectors (0 MB)
Feb 17 16:42:08 freax [ 4995.139402] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:42:08 freax [ 4995.139405] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:42:08 freax [ 4995.139423] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:42:08 freax [ 4995.139472] sd 1:0:0:0: [sdb] 1 512-byte hardware sectors (0 MB)
Feb 17 16:42:08 freax [ 4995.139483] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:42:08 freax [ 4995.139485] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:42:08 freax [ 4995.139503] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Feb 17 16:42:09 freax [ 4995.139506]  sdb: sdb1
Feb 17 16:42:09 freax [ 4996.266625]  sdb: p1 exceeds device capacity
Feb 17 16:42:09 freax [ 4996.266734] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:42:09 freax [ 4996.266791] sd 1:0:0:0: Attached scsi generic sg1 type 0
Feb 17 16:42:09 freax [ 4996.281486] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281491] sdb: rw=0, want=65, limit=1
Feb 17 16:42:09 freax [ 4996.281494] Buffer I/O error on device sdb1, logical block 0
Feb 17 16:42:09 freax [ 4996.281496] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281498] sdb: rw=0, want=67, limit=1
Feb 17 16:42:09 freax [ 4996.281500] Buffer I/O error on device sdb1, logical block 1
Feb 17 16:42:09 freax [ 4996.281502] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281504] sdb: rw=0, want=69, limit=1
Feb 17 16:42:09 freax [ 4996.281506] Buffer I/O error on device sdb1, logical block 2
Feb 17 16:42:09 freax [ 4996.281508] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281509] sdb: rw=0, want=71, limit=1
Feb 17 16:42:09 freax [ 4996.281511] Buffer I/O error on device sdb1, logical block 3
Feb 17 16:42:09 freax [ 4996.281515] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281517] sdb: rw=0, want=73, limit=1
Feb 17 16:42:09 freax [ 4996.281519] Buffer I/O error on device sdb1, logical block 4
Feb 17 16:42:09 freax [ 4996.281521] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281522] sdb: rw=0, want=75, limit=1
Feb 17 16:42:09 freax [ 4996.281524] Buffer I/O error on device sdb1, logical block 5
Feb 17 16:42:09 freax [ 4996.281526] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281528] sdb: rw=0, want=77, limit=1
Feb 17 16:42:09 freax [ 4996.281530] Buffer I/O error on device sdb1, logical block 6
Feb 17 16:42:09 freax [ 4996.281532] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281533] sdb: rw=0, want=79, limit=1
Feb 17 16:42:09 freax [ 4996.281535] Buffer I/O error on device sdb1, logical block 7
Feb 17 16:42:09 freax [ 4996.281539] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281541] sdb: rw=0, want=81, limit=1
Feb 17 16:42:09 freax [ 4996.281542] Buffer I/O error on device sdb1, logical block 8
Feb 17 16:42:09 freax [ 4996.281544] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281546] sdb: rw=0, want=83, limit=1
Feb 17 16:42:09 freax [ 4996.281548] Buffer I/O error on device sdb1, logical block 9
Feb 17 16:42:09 freax [ 4996.281550] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281551] sdb: rw=0, want=85, limit=1
Feb 17 16:42:09 freax [ 4996.281554] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281555] sdb: rw=0, want=87, limit=1
Feb 17 16:42:09 freax [ 4996.281560] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281562] sdb: rw=0, want=89, limit=1
Feb 17 16:42:09 freax [ 4996.281564] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281566] sdb: rw=0, want=91, limit=1
Feb 17 16:42:09 freax [ 4996.281568] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281569] sdb: rw=0, want=93, limit=1
Feb 17 16:42:09 freax [ 4996.281572] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281573] sdb: rw=0, want=95, limit=1
Feb 17 16:42:09 freax [ 4996.281576] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281578] sdb: rw=0, want=65, limit=1
Feb 17 16:42:09 freax [ 4996.281580] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281581] sdb: rw=0, want=67, limit=1
Feb 17 16:42:09 freax [ 4996.281596] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281598] sdb: rw=0, want=69, limit=1
Feb 17 16:42:09 freax [ 4996.281600] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281602] sdb: rw=0, want=71, limit=1
Feb 17 16:42:09 freax [ 4996.287674] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287740] sdb: rw=0, want=65, limit=1
Feb 17 16:42:09 freax [ 4996.287744] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287745] sdb: rw=0, want=67, limit=1
Feb 17 16:42:09 freax [ 4996.287747] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287749] sdb: rw=0, want=69, limit=1
Feb 17 16:42:09 freax [ 4996.287751] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287753] sdb: rw=0, want=71, limit=1
Feb 17 16:42:09 freax [ 4996.287757] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287759] sdb: rw=0, want=73, limit=1
Feb 17 16:42:09 freax [ 4996.287761] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287762] sdb: rw=0, want=75, limit=1
Feb 17 16:42:09 freax [ 4996.287764] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287766] sdb: rw=0, want=77, limit=1
Feb 17 16:42:09 freax [ 4996.287768] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287769] sdb: rw=0, want=79, limit=1
Feb 17 16:42:09 freax [ 4996.287773] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287775] sdb: rw=0, want=81, limit=1
Feb 17 16:42:09 freax [ 4996.287777] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287778] sdb: rw=0, want=83, limit=1
Feb 17 16:42:09 freax [ 4996.287780] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287782] sdb: rw=0, want=85, limit=1
Feb 17 16:42:09 freax [ 4996.287784] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287785] sdb: rw=0, want=87, limit=1
Feb 17 16:42:09 freax [ 4996.287790] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287792] sdb: rw=0, want=89, limit=1
Feb 17 16:42:09 freax [ 4996.287793] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287795] sdb: rw=0, want=91, limit=1
Feb 17 16:42:09 freax [ 4996.287797] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287798] sdb: rw=0, want=93, limit=1
Feb 17 16:42:09 freax [ 4996.287800] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287802] sdb: rw=0, want=95, limit=1
Feb 17 16:42:09 freax [ 4996.287804] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287806] sdb: rw=0, want=65, limit=1
Feb 17 16:42:09 freax [ 4996.287808] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287809] sdb: rw=0, want=67, limit=1
Feb 17 16:42:09 freax [ 4996.287811] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287813] sdb: rw=0, want=69, limit=1
Feb 17 16:42:09 freax [ 4996.287815] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287816] sdb: rw=0, want=71, limit=1
-----------------------------------------------------------

So the bug is still present.

regards
Bjoern

Comment 22 Bjoern Olausson 2008-02-17 07:43:54 UTC

tested with

root@freax $ uname -a
Linux freax 2.6.24.2-unpatched #1 SMP PREEMPT Sat Feb 16 19:25:29 CET 2008 x86_64 Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz GenuineIntel GNU/Linux

Comment 23 Bjoern Olausson 2008-03-19 01:00:59 UTC

anything new regarding this bug?

Comment 24 Natalie Protasevich 2008-03-19 01:43:43 UTC

Since bug analysis shows this is scsi layer problem - copying to SCSI devel

Comment 25 Anonymous Emailer 2008-03-19 13:24:41 UTC

Reply-To: James.Bottomley@HansenPartnership.com

On Wed, 2008-03-19 at 01:43 -0700, bugme-daemon@bugzilla.kernel.org
wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=9010
> 
> 
> protasnb@gmail.com changed:
> 
>            What    |Removed                     |Added
> ----------------------------------------------------------------------------
>                  CC|                            |linux-scsi@vger.kernel.org
> 
> 
> 
> 
> ------- Comment #24 from protasnb@gmail.com  2008-03-19 01:43 -------
> Since bug analysis shows this is scsi layer problem - copying to SCSI devel

That's rather a long bug report; what I can't seem to find is a
description of what the problem actually is.  If I had to guess I'd say
that unplugging and replugging a different SATA drive in the same slot
doesn't properly get the parameters of the new device; is that it?

James

Comment 26 Bjoern Olausson 2008-03-21 06:35:06 UTC

To make it short:

Attach drive for the first time: --> sdb1
The disk works, I can access it.

When I remove it is removed... somehow... but It looks like there is a ghost disk added (still with the kernelname sdb1) but not accessible (of couse.. I hold the disk in my hand...).

replugging the same device doesn't fix the problem and does not work.

here's a short version of the above dmsg:

#######################################################################
#######################################################################
###########1) Hotpluging a disk for the first time#####################
#######################################################################
#######################################################################

Oct 30 02:33:09 freax [  951.885385] ata2: exception Emask 0x10 SAct 0x0 SErr
0x10000 action 0x2 frozen
Oct 30 02:33:09 freax [  951.885390] ata2: irq_stat 0x00400000, PHY RDY changed
Oct 30 02:33:09 freax [  951.885396] ata2: hard resetting port
Oct 30 02:33:09 freax [  952.607499] ata2: SATA link down (SStatus 0 SControl
.
.
.
Oct 30 02:33:23 freax [  965.906251] ata2: EH complete
Oct 30 02:33:23 freax [  965.906264] ata2.00: detaching (SCSI 1:0:0:0)
Oct 30 02:33:23 freax [  965.906524] sd 1:0:0:0: [sdb] Stopping disk
Oct 30 02:33:23 freax [  966.062277] scsi 1:0:0:0: Direct-Access     ATA     
External Disk 0  RGL1 PQ: 0 ANSI: 5
Oct 30 02:33:23 freax [  966.062415] sd 1:0:0:0: [sdb] 145226112 512-byte
hardware sectors (74356 MB)
Oct 30 02:33:23 freax [  966.062467] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:33:23 freax [  966.062502] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:33:23 freax [  966.062557] sd 1:0:0:0: [sdb] Write cache: enabled,
read cache: enabled, doesn't support DPO or FUA
Oct 30 02:33:23 freax [  966.062646] sd 1:0:0:0: [sdb] 145226112 512-byte
hardware sectors (74356 MB)
Oct 30 02:33:23 freax [  966.062695] sd 1:0:0:0: [sdb] Write Protect is off
Oct 30 02:33:23 freax [  966.062729] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Oct 30 02:33:23 freax [  966.062781] sd 1:0:0:0: [sdb] Write cache: enabled,
read cache: enabled, doesn't support DPO or FUA
Oct 30 02:33:24 freax [  966.062956]  sdb: sdb1
Oct 30 02:33:24 freax [  966.984134] sd 1:0:0:0: [sdb] Attached SCSI disk
Oct 30 02:33:24 freax [  966.984218] sd 1:0:0:0: Attached scsi generic sg1 type
0

#######################################################################
#######################################################################
###########2) removing the disk shows the following:###################
#######################################################################
#######################################################################

Oct 30 02:34:47 freax [ 1050.239909] ata2: exception Emask 0x10 SAct 0x0 SErr
0x10000 action 0x2 frozen
Oct 30 02:34:47 freax [ 1050.239914] ata2: irq_stat 0x00400000, PHY RDY changed
Oct 30 02:34:47 freax [ 1050.239920] ata2: hard resetting port
Oct 30 02:34:48 freax [ 1050.961633] ata2: SATA link down (SStatus 0 SControl
300)
Oct 30 02:34:48 freax [ 1050.961642] ata2: failed to recover some devices,
retrying in 5 secs
Oct 30 02:34:53 freax [ 1055.952117] ata2: hard resetting port
Oct 30 02:34:53 freax [ 1056.256843] ata2: SATA link down (SStatus 0 SControl
.
.
.
Feb 17 16:30:44 freax [ 4312.842519]          res
51/04:00:01:01:80/00:00:00:00:00/a0 Emask 0x1 (device error)
Feb 17 16:30:44 freax [ 4312.842521] ata2.00: status: { DRDY ERR }
Feb 17 16:30:44 freax [ 4312.842523] ata2.00: error: { ABRT }
Feb 17 16:30:44 freax [ 4312.842589] ata2.00: device is on DMA blacklist,
disabling DMA
Feb 17 16:30:44 freax [ 4312.842662] ata2.00: configured for PIO4
Feb 17 16:30:44 freax [ 4312.842666] ata2: EH complete
Feb 17 16:30:44 freax [ 4312.842685] ata2.00: exception Emask 0x0 SAct 0x0 SErr
0x0 action 0x0
Feb 17 16:30:44 freax [ 4312.842687] ata2.00: irq_stat 0x40000001
Feb 17 16:30:44 freax [ 4312.842690] ata2.00: cmd
e7/00:00:00:00:00/00:00:00:00:00/a0 tag 0
.
.
.
Feb 17 16:30:47 freax [ 4315.384346] ata2.00: device is on DMA blacklist,
disabling DMA
Feb 17 16:30:47 freax [ 4315.384425] ata2.00: configured for PIO4
Feb 17 16:30:47 freax [ 4315.384430] ata2: EH complete
Feb 17 16:30:47 freax [ 4315.384437] sd 1:0:0:0: [sdb] Result: hostbyte=DID_OK
driverbyte=DRIVER_SENSE,SUGGEST_OK
Feb 17 16:30:47 freax [ 4315.384440] sd 1:0:0:0: [sdb] Sense Key : Aborted
Command [current] [descriptor]
Feb 17 16:30:47 freax [ 4315.384456] sd 1:0:0:0: [sdb] Add. Sense: No
additional sense information
Feb 17 16:30:47 freax [ 4315.384469] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:30:47 freax [ 4315.384614] scsi 1:0:0:0: Direct-Access     ATA     
Config  Disk     RGL1 PQ: 0 ANSI: 5
Feb 17 16:30:47 freax [ 4315.384699] sd 1:0:0:0: [sdb] 640 512-byte hardware
sectors (0 MB)
Feb 17 16:30:47 freax [ 4315.384710] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:30:47 freax [ 4315.384712] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:30:47 freax [ 4315.384731] sd 1:0:0:0: [sdb] Write cache: disabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:30:47 freax [ 4315.384796] sd 1:0:0:0: [sdb] 640 512-byte hardware
sectors (0 MB)
Feb 17 16:30:47 freax [ 4315.384816] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:30:47 freax [ 4315.384827] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:30:47 freax [ 4315.384853] sd 1:0:0:0: [sdb] Write cache: disabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:30:47 freax [ 4315.384872]  sdb: unknown partition table
Feb 17 16:30:47 freax [ 4315.385908] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:30:47 freax [ 4315.385954] sd 1:0:0:0: Attached scsi generic sg1 type
0
Feb 17 16:30:47 freax [ 4315.385988] sd 1:0:0:0: [sdb] 640 512-byte hardware
sectors (0 MB)
Feb 17 16:30:47 freax [ 4315.385999] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:30:47 freax [ 4315.386001] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:30:47 freax [ 4315.386020] sd 1:0:0:0: [sdb] Write cache: disabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:30:47 freax [ 4315.921044] ata2.00: exception Emask 0x10 SAct 0x0
SErr 0x10000 action 0xa frozen
.
.
.
Feb 17 16:31:04 freax [ 4332.745067] Buffer I/O error on device sdb, logical
block 79
Feb 17 16:31:04 freax [ 4332.745074] ata2.00: detaching (SCSI 1:0:0:0)
Feb 17 16:31:04 freax [ 4332.745342] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:31:04 freax [ 4332.745690] scsi 1:0:0:0: Direct-Access     ATA     
Config  Disk     RGL1 PQ: 0 ANSI: 5
Feb 17 16:31:04 freax [ 4332.745768] sd 1:0:0:0: [sdb] 640 512-byte hardware
sectors (0 MB)
Feb 17 16:31:04 freax [ 4332.745779] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:31:04 freax [ 4332.745781] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:31:04 freax [ 4332.745800] sd 1:0:0:0: [sdb] Write cache: disabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:31:04 freax [ 4332.745845] sd 1:0:0:0: [sdb] 640 512-byte hardware
sectors (0 MB)
Feb 17 16:31:04 freax [ 4332.745855] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:31:04 freax [ 4332.745857] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:31:04 freax [ 4332.745875] sd 1:0:0:0: [sdb] Write cache: disabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:31:04 freax [ 4332.745878]  sdb: unknown partition table
Feb 17 16:31:04 freax [ 4332.745959] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:31:04 freax [ 4332.745998] sd 1:0:0:0: Attached scsi generic sg1 type




#######################################################################
#######################################################################
###########3) replugging the SAME disk:################################
#######################################################################
#######################################################################

Feb 17 16:41:50 freax [ 4977.840074] ata2: exception Emask 0x10 SAct 0x0 SErr
0x10000 action 0xa frozen
Feb 17 16:41:50 freax [ 4977.840080] ata2: irq_stat 0x00400000, PHY RDY changed
Feb 17 16:41:50 freax [ 4977.840083] ata2: SError: { PHYRdyChg }
Feb 17 16:41:50 freax [ 4977.840091] ata2: hard resetting link
Feb 17 16:41:51 freax [ 4978.576507] ata2: SATA link down (SStatus 0 SControl
300)
Feb 17 16:41:51 freax [ 4978.576516] ata2: failed to recover some devices,
retrying in 5 secs
Feb 17 16:41:56 freax [ 4983.678479] ata2: hard resetting link
Feb 17 16:41:57 freax [ 4983.989543] ata2: SATA link down (SStatus 0 SControl
300)
Feb 17 16:41:57 freax [ 4983.989553] ata2: failed to recover some devices,
retrying in 5 secs
Feb 17 16:42:02 freax [ 4989.090894] ata2: hard resetting link
Feb 17 16:42:04 freax [ 4991.638546] ata2: SATA link up 3.0 Gbps (SStatus 123
SControl 300)
Feb 17 16:42:04 freax [ 4991.638619] ata2.00: model number mismatch 'Config 
Disk' != 'External Disk 0'
Feb 17 16:42:04 freax [ 4991.638622] ata2.00: revalidation failed (errno=-19)
Feb 17 16:42:04 freax [ 4991.638624] ata2.00: disabled
Feb 17 16:42:05 freax [ 4992.149526] ata2: hard resetting link
Feb 17 16:42:07 freax [ 4994.695718] ata2: SATA link up 3.0 Gbps (SStatus 123
SControl 300)
Feb 17 16:42:07 freax [ 4994.695802] ata2.00: ATA-6: External Disk 0, RGL10364,
max UDMA/133
Feb 17 16:42:07 freax [ 4994.695805] ata2.00: 1 sectors, multi 1: LBA48
Feb 17 16:42:07 freax [ 4994.695914] ata2.00: configured for UDMA/133
Feb 17 16:42:07 freax [ 4994.695922] ata2: exception Emask 0x10 SAct 0x0 SErr
0x0 action 0x9 t4
Feb 17 16:42:07 freax [ 4994.695924] ata2: irq_stat 0x00000040, connection
status changed
Feb 17 16:42:07 freax [ 4994.696084] ata2.00: configured for UDMA/133
Feb 17 16:42:07 freax [ 4994.696087] ata2: EH complete
Feb 17 16:42:07 freax [ 4994.696095] ata2.00: detaching (SCSI 1:0:0:0)
Feb 17 16:42:07 freax [ 4994.696345] sd 1:0:0:0: [sdb] Stopping disk
Feb 17 16:42:08 freax [ 4995.139171] scsi 1:0:0:0: Direct-Access     ATA     
External Disk 0  RGL1 PQ: 0 ANSI: 5
Feb 17 16:42:08 freax [ 4995.139390] sd 1:0:0:0: [sdb] 1 512-byte hardware
sectors (0 MB)
Feb 17 16:42:08 freax [ 4995.139402] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:42:08 freax [ 4995.139405] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:42:08 freax [ 4995.139423] sd 1:0:0:0: [sdb] Write cache: enabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:42:08 freax [ 4995.139472] sd 1:0:0:0: [sdb] 1 512-byte hardware
sectors (0 MB)
Feb 17 16:42:08 freax [ 4995.139483] sd 1:0:0:0: [sdb] Write Protect is off
Feb 17 16:42:08 freax [ 4995.139485] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
Feb 17 16:42:08 freax [ 4995.139503] sd 1:0:0:0: [sdb] Write cache: enabled,
read cache: enabled, doesn't support DPO or FUA
Feb 17 16:42:09 freax [ 4995.139506]  sdb: sdb1
Feb 17 16:42:09 freax [ 4996.266625]  sdb: p1 exceeds device capacity
Feb 17 16:42:09 freax [ 4996.266734] sd 1:0:0:0: [sdb] Attached SCSI disk
Feb 17 16:42:09 freax [ 4996.266791] sd 1:0:0:0: Attached scsi generic sg1 type
0
Feb 17 16:42:09 freax [ 4996.281486] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.281491] sdb: rw=0, want=65, limit=1
Feb 17 16:42:09 freax [ 4996.281494] Buffer I/O error on device sdb1, logical
block 0
.
.
.
Feb 17 16:42:09 freax [ 4996.287815] attempt to access beyond end of device
Feb 17 16:42:09 freax [ 4996.287816] sdb: rw=0, want=71, limit=1


##################################################################
##################################################################

Thats it.


Regards
Bjoern

Comment 27 Anonymous Emailer 2008-03-21 07:30:34 UTC

Reply-To: James.Bottomley@HansenPartnership.com

On Fri, 2008-03-21 at 06:35 -0700, bugme-daemon@bugzilla.kernel.org
wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=9010
> 
> 
> 
> 
> 
> ------- Comment #26 from lkmlist@gmail.com  2008-03-21 06:35 -------
> To make it short:
> 
> Attach drive for the first time: --> sdb1
> The disk works, I can access it.
> 
> When I remove it is removed... somehow... but It looks like there is a ghost
> disk added (still with the kernelname sdb1) but not accessible (of couse.. I
> hold the disk in my hand...).
> 
> replugging the same device doesn't fix the problem and does not work.
> 
> here's a short version of the above dmsg:
[...]

All of this seems to show a hotplug failure in libata.  The SCSI
mid-layer handles this reasonably well (there are problems with
unplugging and replugging a device very rapidly).  All of our hotplug
busses (SAS, FC, iSCSI) work just fine.  For the non-hotplug busses like
SPI, you have to tell the kernel you've removed the disk manually, but
otherwise even that works.

This seems to be the place where the trouble is:


> Feb 17 16:30:47 freax [ 4315.384346] ata2.00: device is on DMA blacklist,
> disabling DMA
> Feb 17 16:30:47 freax [ 4315.384425] ata2.00: configured for PIO4
> Feb 17 16:30:47 freax [ 4315.384430] ata2: EH complete
> Feb 17 16:30:47 freax [ 4315.384437] sd 1:0:0:0: [sdb] Result:
> hostbyte=DID_OK
> driverbyte=DRIVER_SENSE,SUGGEST_OK
> Feb 17 16:30:47 freax [ 4315.384440] sd 1:0:0:0: [sdb] Sense Key : Aborted
> Command [current] [descriptor]
> Feb 17 16:30:47 freax [ 4315.384456] sd 1:0:0:0: [sdb] Add. Sense: No
> additional sense information
> Feb 17 16:30:47 freax [ 4315.384469] sd 1:0:0:0: [sdb] Stopping disk

This last message is from sd just before it tries to do the final put of
the device.  This is the tricky one, it's a special path only used by
libata (which sets the manage_start_stop flag).  After finishing this,
the device should be dead and gone.

> Feb 17 16:30:47 freax [ 4315.384614] scsi 1:0:0:0: Direct-Access     ATA     
> Config  Disk     RGL1 PQ: 0 ANSI: 5
> Feb 17 16:30:47 freax [ 4315.384699] sd 1:0:0:0: [sdb] 640 512-byte hardware
> sectors (0 MB)
> Feb 17 16:30:47 freax [ 4315.384710] sd 1:0:0:0: [sdb] Write Protect is off
> Feb 17 16:30:47 freax [ 4315.384712] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00
> 00
> Feb 17 16:30:47 freax [ 4315.384731] sd 1:0:0:0: [sdb] Write cache: disabled,
> read cache: enabled, doesn't support DPO or FUA
> Feb 17 16:30:47 freax [ 4315.384796] sd 1:0:0:0: [sdb] 640 512-byte hardware
> sectors (0 MB)
> Feb 17 16:30:47 freax [ 4315.384816] sd 1:0:0:0: [sdb] Write Protect is off
> Feb 17 16:30:47 freax [ 4315.384827] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00
> 00
> Feb 17 16:30:47 freax [ 4315.384853] sd 1:0:0:0: [sdb] Write cache: disabled,
> read cache: enabled, doesn't support DPO or FUA
> Feb 17 16:30:47 freax [ 4315.384872]  sdb: unknown partition table
> Feb 17 16:30:47 freax [ 4315.385908] sd 1:0:0:0: [sdb] Attached SCSI disk
> Feb 17 16:30:47 freax [ 4315.385954] sd 1:0:0:0: Attached scsi generic sg1
> type
> 0
> Feb 17 16:30:47 freax [ 4315.385988] sd 1:0:0:0: [sdb] 640 512-byte hardware
> sectors (0 MB)
> Feb 17 16:30:47 freax [ 4315.385999] sd 1:0:0:0: [sdb] Write Protect is off
> Feb 17 16:30:47 freax [ 4315.386001] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00
> 00
> Feb 17 16:30:47 freax [ 4315.386020] sd 1:0:0:0: [sdb] Write cache: disabled,
> read cache: enabled, doesn't support DPO or FUA
> Feb 17 16:30:47 freax [ 4315.921044] ata2.00: exception Emask 0x10 SAct 0x0
> SErr 0x10000 action 0xa frozen

This is pretty bad ... SCSI has been told to readd the disk somehow, so
it has to do a rescan.  This must have come from some piece of
libata ... it's definitely using the cached data in libata to
manufacture the INQUIRY that makes SCSI think something is there.

Then your log actually repeats this sequence

> Feb 17 16:31:04 freax [ 4332.745067] Buffer I/O error on device sdb, logical
> block 79
> Feb 17 16:31:04 freax [ 4332.745074] ata2.00: detaching (SCSI 1:0:0:0)
> Feb 17 16:31:04 freax [ 4332.745342] sd 1:0:0:0: [sdb] Stopping disk
> Feb 17 16:31:04 freax [ 4332.745690] scsi 1:0:0:0: Direct-Access     ATA     
> Config  Disk     RGL1 PQ: 0 ANSI: 5
> Feb 17 16:31:04 freax [ 4332.745768] sd 1:0:0:0: [sdb] 640 512-byte hardware
> sectors (0 MB)
> Feb 17 16:31:04 freax [ 4332.745779] sd 1:0:0:0: [sdb] Write Protect is off
> Feb 17 16:31:04 freax [ 4332.745781] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00
> 00
> Feb 17 16:31:04 freax [ 4332.745800] sd 1:0:0:0: [sdb] Write cache: disabled,
> read cache: enabled, doesn't support DPO or FUA
> Feb 17 16:31:04 freax [ 4332.745845] sd 1:0:0:0: [sdb] 640 512-byte hardware
> sectors (0 MB)
> Feb 17 16:31:04 freax [ 4332.745855] sd 1:0:0:0: [sdb] Write Protect is off
> Feb 17 16:31:04 freax [ 4332.745857] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00
> 00
> Feb 17 16:31:04 freax [ 4332.745875] sd 1:0:0:0: [sdb] Write cache: disabled,
> read cache: enabled, doesn't support DPO or FUA
> Feb 17 16:31:04 freax [ 4332.745878]  sdb: unknown partition table
> Feb 17 16:31:04 freax [ 4332.745959] sd 1:0:0:0: [sdb] Attached SCSI disk
> Feb 17 16:31:04 freax [ 4332.745998] sd 1:0:0:0: Attached scsi generic sg1
> type

So, the bottom line is that hotplug does work in SCSI (I can even
demonstrate it with SATA as long as I use a SAS controller), so this
does look to be a libata issue.  The complicating factor is that libata
does have special shutdown paths in SCSI ... they don't look like they
could be causing this, but it's not impossible.

James

Comment 28 Bjoern Olausson 2008-03-22 04:52:25 UTC

Hotplug works fine on my ICH7 ports, it's just that damn jmicron controller. So it must be an effect trigered by a hardware or firmware "feature".

So finally someone from libata has to fix this problem?

thanks for the explanation

regards
Bjoern

Comment 29 Anonymous Emailer 2008-03-22 15:26:16 UTC

Reply-To: James.Bottomley@HansenPartnership.com

On Sat, 2008-03-22 at 04:52 -0700, bugme-daemon@bugzilla.kernel.org
wrote:
> Hotplug works fine on my ICH7 ports, it's just that damn jmicron controller.
> So
> it must be an effect trigered by a hardware or firmware "feature".
> 
> So finally someone from libata has to fix this problem?

I think so ... I don't rule out it's being caused by one of the libata
specific pieces in SCSI, but the analysis of the problem definitely has
to begin in libata.

> thanks for the explanation

You're welcome.

James

Comment 30 Marc Bejarano 2008-10-21 11:25:45 UTC

jeff?

Comment 31 Bjoern Olausson 2008-10-22 07:07:13 UTC

Did anyone take care of this?

If you want't I can try to reproduce it with 2.6.27.*

Kind regards
Bjoern

Comment 32 Alan 2012-05-17 14:42:54 UTC

Should be obsolete now, if not please reopen versus recent kernel

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