LIBATA AHCI engine timeout hang with ATAPI devices

LIBATA AHCI engine timeout hang with ATAPI devices

[Eric A. Cottrell]

Hello,

I made the mistake of getting the Plextor SATA DVD Recorder with my new system not realizing that SATA support is just coming 
online.  I want to turn this into an opportunity to make the Plextor work.  Thanks to the IDE information pages I got a good start.

I have success using the ata_piix and ahci drivers with SATA Hard Drives.  I noticed that the Plextor works with the ata_piix driver 
  but not with the AHCI driver.  The AHCI driver hangs after the INQUIRY is printed.

System is a P4 3.4 GHz with a Asus P5AD-2 Premium (925XE chipset) MB with 1M Memory.  Processor is running at 3.5 GHz with a 1GHz 
FSB. I am using the 2.6.12-rc2 kernel for testing.

It looks to me like the AHCI driver is not doing a request sense when the engine timeout function is called.  The queued command is 
not properly released after the engine timeout so no more commands are processed.  I also noticed that the TEST UNIT READY command 
is sent by the SCSI code when the AHCI driver is used instead of the REPORT LUN command.

I would like to work on fixing this problem unless it has already been fixed.

The ata_piix Good Log

scsi scan: INQUIRY successful with code 0x0
   Vendor: PLEXTOR   Model: DVDR   PX-716A    Rev: 1.04
Type:   CD-ROM                             ANSI SCSI revision: 05
scsi scan: Sending REPORT LUNS to host 0 channel 0 id 0 (try 0)
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: f759eb00, time: 6000, (f8baa860)
scsi <0:0:0:0> send 0xf759eb00                  scsi0 : destination target 0, lun 0
         command: Report luns: a0 00 00 00 00 00 00 00 10 00 00 00
buffer = 0xf639c000, bufflen = 4096, done = 0xf8bacae0, queuecommand 0xf8bd23d0
ata_scsi_dump_cdb: CDB (1:0,0,0) a0 00 00 00 00 00 00 00 10
ata_scsi_translate: ENTER
ata_sg_setup_one: mapped buffer of 4096 bytes for read
ata_fill_sg: PRD[0] = (0x3639C000, 0x1000)
ata_dev_select: ENTER, ata1: device 0, wait 1
ata_tf_load_pio: feat 0x1 nsect 0x0 lba 0x0 0x0 0x0
ata_tf_load_pio: device 0xA0
ata_exec_command_pio: ata1: cmd 0xA0
ata_scsi_translate: EXIT
leaving scsi_dispatch_cmnd()
atapi_packet_task: busy wait
atapi_packet_task: send cdb
ata_host_intr: ata1: host_stat 0x25
ata_host_intr: ata1: protocol 7 (dev_stat 0x51)
ata_sg_clean: unmapping 1 sg elements
atapi_qc_complete: request check condition
scsi_delete_timer: scmd: f759eb00, rtn: 1
scsi <0:0:0:0> done 0xf759eb00 FAILED         2 scsi0 : destination target 0, lun 0
         command: Report luns: a0 00 00 00 00 00 00 00 10 00 00 00
Unrecognized sense data (in hex):
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
scsi host busy 1 failed 0
Waking error handler thread
Error handler scsi_eh_0 waking up
ata_scsi_error: ENTER
ata_eng_timeout: ENTER
ata_qc_timeout: ENTER
atapi_request_sense: ATAPI request sense
ata_dev_select: ENTER, ata1: device 0, wait 1
ata_tf_load_pio: feat 0x0 nsect 0x0 lba 0x0 0x0 0x20
ata_tf_load_pio: device 0xA0
ata_exec_command_pio: ata1: cmd 0xA0
atapi_packet_task: busy wait
atapi_packet_task: send cdb
__atapi_pio_bytes: data read
ata_qc_complete: EXIT
atapi_request_sense: EXIT
Notifying upper driver of completion for device 0 8000002
ata_qc_timeout: EXIT
ata_eng_timeout: EXIT
ata_scsi_error: EXIT
scsi_restart_operations: waking up host to restart
Error handler scsi_eh_0 sleeping
scsi scan: REPORT LUNS failed (try 0) result 0x8000002
scsi scan: Sequential scan oftarget0:0:0

The AHCI bad log

scsi scan: INQUIRY successful with code 0x0
   Vendor: PLEXTOR   Model: DVDR   PX-716A    Rev: 1.04
   Type:   CD-ROM                             ANSI SCSI revision: 05
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: f29f6e00, time: 30000, (f8baa860)
scsi <2:0:0:0> send 0xf29f6e00                  scsi2 : destination target 0, lun 0
         command: Test Unit Ready: 00 00 00 00 00 00
buffer = 0xc04d4e00, bufflen = 0, done = 0xf8bacae0, queuecommand 0xf8bd23d0
ata_scsi_dump_cdb: CDB (1:0,0,0) 00 00 00 00 00 00 00 00 00
ata_scsi_translate: ENTER
ata_scsi_translate: EXIT
leaving scsi_dispatch_cmnd()
ahci_interrupt: ENTER
ahci_interrupt: port 0
ata1: error occurred, port reset
atapi_qc_complete: request check condition
scsi_delete_timer: scmd: f29f6e00, rtn: 1
ahci_interrupt: port 1
ahci_interrupt: port 2
ahci_interrupt: port 3
ahci_interrupt: EXIT
scsi <2:0:0:0> done 0xf29f6e00 FAILED         2 scsi2 : destination target 0, lun 0
         command: Test Unit Ready: 00 00 00 00 00 00
Unrecognized sense data (in hex):
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
         00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
scsi host busy 1 failed 0
Waking error handler thread
Error handler scsi_eh_2 waking up
ata_scsi_error: ENTER
ahci_eng_timeout: ENTER
ata1: error occurred, port reset
atapi_qc_complete: request check condition
Notifying upper driver of completion for device 0 2
ata_scsi_error: EXIT
scsi_restart_operations: waking up host to restart
Error handler scsi_eh_2 sleeping
Leaving scsi_init_cmd_from_req()
scsi_add_timer: scmd: f29f6e00, time: 30000, (f8baa860)
scsi <2:0:0:0> send 0xf29f6e00                  scsi2 : destination target 0, lun 0
         command: Test Unit Ready: 00 00 00 00 00 00
buffer = 0xc04d4e00, bufflen = 0, done = 0xf8bacae0, queuecommand 0xf8bd23d0
ata_scsi_dump_cdb: CDB (1:0,0,0) 00 00 00 00 00 00 00 00 00
ata_scsi_translate: ENTER
scsi_delete_timer: scmd: f29f6e00, rtn: 1
leaving scsi_dispatch_cmnd()
scsi <2:0:0:0> done 0xf29f6e00 MLQUEUE       28 scsi2 : destination target 0, lun 0
         command: Test Unit Ready: 00 00 00 00 00 00
scsi host busy 1 failed 0
Inserting command f29f6e00 into mlqueue
scsi_delete_timer: scmd: f29f6e00, rtn: 0
scsi2 (0:0) unblocking device at zero depth
scsi_add_timer: scmd: f29f6e00, time: 30000, (f8baa860)
scsi <2:0:0:0> send 0xf29f6e00                  scsi2 : destination target 0, lun 0
         command: Test Unit Ready: 00 00 00 00 00 00
buffer = 0xc04d4e00, bufflen = 0, done = 0xf8bacae0, queuecommand 0xf8bd23d0
ata_scsi_dump_cdb: CDB (1:0,0,0) 00 00 00 00 00 00 00 00 00
ata_scsi_translate: ENTER
scsi_delete_timer: scmd: f29f6e00, rtn: 1
leaving scsi_dispatch_cmnd()
scsi <2:0:0:0> done 0xf29f6e00 MLQUEUE       28 scsi2 : destination target 0, lun 0
         command: Test Unit Ready: 00 00 00 00 00 00
scsi host busy 1 failed 0
Inserting command f29f6e00 into mlqueue
scsi_delete_timer: scmd: f29f6e00, rtn: 0
scsi2 (0:0) unblocking device at zero depth
... The Test Unit Ready keeps repeating ...

73 Eric  eac@shore.net

[PATCH] Re: LIBATA AHCI engine timeout hang with ATAPI devices

[Jeff Garzik]

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

Eric A. Cottrell wrote:
> Hello,
> 
> I made the mistake of getting the Plextor SATA DVD Recorder with my new 
> system not realizing that SATA support is just coming online.  I want to 
> turn this into an opportunity to make the Plextor work.  Thanks to the 
> IDE information pages I got a good start.
> 
> I have success using the ata_piix and ahci drivers with SATA Hard 
> Drives.  I noticed that the Plextor works with the ata_piix driver  but 
> not with the AHCI driver.  The AHCI driver hangs after the INQUIRY is 
> printed.

You need something like the attached patch.

In general, ATAPI is still very much experimental at this point.  One 
known bug that affects libata is that ATAPI DMA is not aligned to a 
4-byte boundary.

	Jeff



[-- Attachment #2: patch --]
[-- Type: text/plain, Size: 1874 bytes --]

# This is a BitKeeper generated diff -Nru style patch.
#
# ChangeSet
#   2005/02/17 04:43:52-05:00 jgarzik@pobox.com 
#   [libata ahci] finish ATAPI support
# 
# drivers/scsi/ahci.c
#   2005/02/17 04:42:57-05:00 jgarzik@pobox.com +9 -13
#   [libata ahci] finish ATAPI support
# 
diff -Nru a/drivers/scsi/ahci.c b/drivers/scsi/ahci.c
--- a/drivers/scsi/ahci.c	2005-04-08 15:10:54 -04:00
+++ b/drivers/scsi/ahci.c	2005-04-08 15:10:54 -04:00
@@ -38,7 +38,7 @@
 #include <asm/io.h>
 
 #define DRV_NAME	"ahci"
-#define DRV_VERSION	"1.00"
+#define DRV_VERSION	"1.10"
 
 
 enum {
@@ -49,6 +49,7 @@
 	AHCI_CMD_SLOT_SZ	= 32 * 32,
 	AHCI_RX_FIS_SZ		= 256,
 	AHCI_CMD_TBL_HDR	= 0x80,
+	AHCI_CMD_TBL_CDB	= 0x40,
 	AHCI_CMD_TBL_SZ		= AHCI_CMD_TBL_HDR + (AHCI_MAX_SG * 16),
 	AHCI_PORT_PRIV_DMA_SZ	= AHCI_CMD_SLOT_SZ + AHCI_CMD_TBL_SZ +
 				  AHCI_RX_FIS_SZ,
@@ -477,7 +478,8 @@
 
 static void ahci_qc_prep(struct ata_queued_cmd *qc)
 {
-	struct ahci_port_priv *pp = qc->ap->private_data;
+	struct ata_port *ap = qc->ap;
+	struct ahci_port_priv *pp = ap->private_data;
 	u32 opts;
 	const u32 cmd_fis_len = 5; /* five dwords */
 
@@ -489,18 +491,8 @@
 	opts = (qc->n_elem << 16) | cmd_fis_len;
 	if (qc->tf.flags & ATA_TFLAG_WRITE)
 		opts |= AHCI_CMD_WRITE;
-
-	switch (qc->tf.protocol) {
-	case ATA_PROT_ATAPI:
-	case ATA_PROT_ATAPI_NODATA:
-	case ATA_PROT_ATAPI_DMA:
+	if (is_atapi_taskfile(&qc->tf))
 		opts |= AHCI_CMD_ATAPI;
-		break;
-
-	default:
-		/* do nothing */
-		break;
-	}
 
 	pp->cmd_slot[0].opts = cpu_to_le32(opts);
 	pp->cmd_slot[0].status = 0;
@@ -512,6 +504,10 @@
 	 * a SATA Register - Host to Device command FIS.
 	 */
 	ata_tf_to_fis(&qc->tf, pp->cmd_tbl, 0);
+	if (opts & AHCI_CMD_ATAPI) {
+		memset(pp->cmd_tbl + AHCI_CMD_TBL_CDB, 0, 32);
+		memcpy(pp->cmd_tbl + AHCI_CMD_TBL_CDB, qc->cdb, ap->cdb_len);
+	}
 
 	if (!(qc->flags & ATA_QCFLAG_DMAMAP))
 		return;

Re: LIBATA AHCI engine timeout hang with ATAPI devices

[Eric A. Cottrell]

Jeff Garzik wrote:
> You need something like the attached patch.
> 
> In general, ATAPI is still very much experimental at this point.  One 
> known bug that affects libata is that ATAPI DMA is not aligned to a 
> 4-byte boundary.
> 
Hello,

Thanks.

I already have that patch applied.  I will poke around the code over the weekend and see if I can figure out the problem.
I am alittle rusty as my last disk driver code was modifying Heathkit CPM BIOS to support a SMS SASI board for 8 inch floppies and 
Shugart SA1000 series hard drives!

I would like to help get ATAPI to work as I suspect more SATA ATAPI stuff will appear as motherboards use SATA.  It appears that the 
ahci/libata code is missing some needed steps that the ata_piix/libata code does.  Looking at the code and patches I can see that 
libata had to change to permit the hardware to perform tasks that libata did.

Thank you for your web page on IDE drives.  I downloaded alot of specs and even read a small bit of them.

73 Eric eac@shore.net

Re: LIBATA AHCI engine timeout hang with ATAPI devices

[Eric A. Cottrell]

Hello,

I made some progress fixing ATAPI problems even with my system being down a few days due to a video card failure.

One ATAPI problem area is the lack of filling the sense buffer when there is an error.  There are ata to scsi mapping functions for 
hard drives but nothing for ATAPI.  The SCSI system sends some commands that are not supported by ATAPI so an illegal request sense 
key should be sent up from the driver.

I recently noticed the docs for the PACKET command said that ATAPI devices return error information in the task file.  One of the 
bytes looks like information in the third byte of the sense information.  I added a function that translated the ATAPI error 
information into a basic SCSI sense block without any additional sense information.

Using the AHCI driver I do see valid sense information.  The request luns command returns a illegal request as it is not supported 
by the drive.  The ata_piix driver always returned a zero for the sense.  I need to do some more work to fix it and other problems.

73 Eric  eac@shore.net