How to make SATA hotplug path tight?

How to make SATA hotplug path tight?

[Fajun Chen]

Hi,

I'm trying to speed up the SATA hotplug sequence so I can measure the
disk spinup time more accurately.  I noticed two delays which may be
unnecessary in SATA hotplug:
1. About 4-5 seconds delay during power cycle (power down then power
up) as shown below (detail log at the end):
[65642.680000] ata_eh_prep_resume: ENTER
[65642.680000] ata_eh_prep_resume: EXIT
[65642.680000] __ata_port_freeze: ata2 port frozen
[65646.970000] ata2: soft resetting port
[65646.970000] sil24_softreset: ENTER
Question: where is the delay introduced and can we eliminate this delay?

2. Soft reset fails sometimes then followed by a successful hard reset.
Question: may I do hard reset to start with and where is the best
place to change this? I know sata spec recommend attempting less
intrusive recovery procedure first, but I need to eliminate as much
unnecessary delay as possible.

Is there any other place in new eh where SATA hotplug can be optimized?

Thanks,
Fajun

Details log:

[65642.680000] ata2.00: ata_dev_read_id: ENTER, host 2, dev 0
[65642.680000] ata2: ata_dev_select: ENTER, ata2: device 0, wait 1
[65642.680000] ata_sg_setup_one: mapped buffer of 512 bytes for read
[65642.680000] ata_sg_clean: unmapping 1 sg elements
[65642.680000] ata_port_flush_task: ENTER
[65642.680000] ata_port_flush_task: flush #1
[65642.680000] ata2: ata_port_flush_task: flush #2
[65642.680000] ata2: ata_port_flush_task: EXIT
[65642.680000] ata2.00: ata_dev_configure: ENTER, host 2, dev 0
[65642.680000] ata2.00: ata_dev_configure: cfg 49:2f00 82:346b 83:7d09
84:6003 85:3469 86:3c09 87:6003 88:007f
[65642.680000] ata_dump_id: 49==0x2f00  53==0x0007  63==0x0407
64==0x0003  75==0x001f
[65642.680000] ata_dump_id: 80==0x00fe  81==0x0000  82==0x346b
83==0x7d09  84==0x6003
[65642.680000] ata_dump_id: 88==0x007f  93==0x0000
[65642.680000] ata2.00: ata_dev_configure: EXIT, drv_stat = 0x50
[65642.680000] ata_eh_revalidate_and_attach: EXIT
[65642.680000] ata_eh_resume: ENTER
[65642.680000] ata_eh_resume: EXIT
[65642.680000] ata_dev_set_xfermode: set features - xfer mode
[65642.680000] ata_port_flush_task: ENTER
[65642.680000] ata_port_flush_task: flush #1
[65642.680000] ata2: ata_port_flush_task: flush #2
[65642.680000] ata2: ata_port_flush_task: EXIT
[65642.680000] ata_dev_set_xfermode: EXIT, err_mask=0
[65642.680000] ata2.00: ata_dev_read_id: ENTER, host 2, dev 0
[65642.680000] ata2: ata_dev_select: ENTER, ata2: device 0, wait 1
[65642.680000] ata_sg_setup_one: mapped buffer of 512 bytes for read
[65642.680000] ata_sg_clean: unmapping 1 sg elements
[65642.680000] ata_port_flush_task: ENTER
[65642.680000] ata_port_flush_task: flush #1
[65642.680000] ata2: ata_port_flush_task: flush #2
[65642.680000] ata2: ata_port_flush_task: EXIT
[65642.680000] ata2.00: ata_dev_configure: ENTER, host 2, dev 0
[65642.680000] ata2.00: ata_dev_configure: cfg 49:2f00 82:346b 83:7d09
84:6003 85:3469 86:3c09 87:6003 88:207f
[65642.680000] ata_dump_id: 49==0x2f00  53==0x0007  63==0x0007
64==0x0003  75==0x001f
[65642.680000] ata_dump_id: 80==0x00fe  81==0x0000  82==0x346b
83==0x7d09  84==0x6003
[65642.680000] ata_dump_id: 88==0x207f  93==0x0000
[65642.680000] ata2.00: ata_dev_configure: EXIT, drv_stat = 0x50
[65642.680000] ata_dev_set_mode: xfer_shift=8, xfer_mode=0x45
[65642.680000] ata2.00: configured for UDMA/100
[65642.680000] ata_eh_suspend: ENTER
[65642.680000] ata_eh_suspend: EXIT
[65642.680000] ata_eh_recover: EXIT, rc=0
[65642.680000] ata2: EH pending after completion, repeating EH (cnt=4)
[65642.680000] ata_eh_autopsy: ENTER
[65642.680000] ata_eh_autopsy: EXIT
[65642.680000] ata2: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x1
[65642.680000] ata2: (irq_stat 0x00a00080, device exchanged)
[65642.680000] ata_eh_recover: ENTER
[65642.680000] ata_eh_prep_resume: ENTER
[65642.680000] ata_eh_prep_resume: EXIT
[65642.680000] __ata_port_freeze: ata2 port frozen
[65646.970000] ata2: soft resetting port
[65646.970000] sil24_softreset: ENTER
[65647.080000] ata_dev_classify: found ATA device by sig
[65647.080000] sil24_softreset: EXIT, class=1
[65647.080000] ata_std_postreset: ENTER
[65647.080000] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[65647.080000] ata_std_postreset: EXIT
[65647.080000] ata_eh_thaw_port: ata2 port thawed
[65647.080000] ata_eh_revalidate_and_attach: ENTER
[65647.080000] ata2.00: ata_dev_read_id: ENTER, host 2, dev 0
[65647.080000] ata2: ata_dev_select: ENTER, ata2: device 0, wait 1
[65647.080000] ata_sg_setup_one: mapped buffer of 512 bytes for read
[65647.080000] ata_sg_clean: unmapping 1 sg elements
[65647.080000] ata_port_flush_task: ENTER
[65647.080000] ata_port_flush_task: flush #1
[65647.080000] ata2: ata_port_flush_task: flush #2
[65647.080000] ata2: ata_port_flush_task: EXIT
[65647.080000] ata2.00: ata_dev_configure: ENTER, host 2, dev 0
[65647.080000] ata2.00: ata_dev_configure: cfg 49:2f00 82:346b 83:7d09
84:6003 85:3469 86:3c09 87:6003 88:207f
[65647.080000] ata_dump_id: 49==0x2f00  53==0x0007  63==0x0007
64==0x0003  75==0x001f
[65647.080000] ata_dump_id: 80==0x00fe  81==0x0000  82==0x346b
83==0x7d09  84==0x6003
[65647.080000] ata_dump_id: 88==0x207f  93==0x0000
[65647.080000] ata2.00: ata_dev_configure: EXIT, drv_stat = 0x50
[65647.080000] ata_eh_revalidate_and_attach: EXIT
[65647.080000] ata_eh_resume: ENTER
[65647.080000] ata_eh_resume: EXIT
[65647.080000] ata_dev_set_xfermode: set features - xfer mode
[65647.080000] ata_port_flush_task: ENTER
[65647.080000] ata_port_flush_task: flush #1
[65647.080000] ata2: ata_port_flush_task: flush #2
[65647.080000] ata2: ata_port_flush_task: EXIT
[65647.080000] ata_dev_set_xfermode: EXIT, err_mask=0
[65647.080000] ata2.00: ata_dev_read_id: ENTER, host 2, dev 0
[65647.080000] ata2: ata_dev_select: ENTER, ata2: device 0, wait 1
[65647.080000] ata_sg_setup_one: mapped buffer of 512 bytes for read
[65647.080000] ata_sg_clean: unmapping 1 sg elements
[65647.080000] ata_port_flush_task: ENTER
[65647.080000] ata_port_flush_task: flush #1
[65647.080000] ata2: ata_port_flush_task: flush #2
[65647.080000] ata2: ata_port_flush_task: EXIT
[65647.080000] ata2.00: ata_dev_configure: ENTER, host 2, dev 0
[65647.080000] ata2.00: ata_dev_configure: cfg 49:2f00 82:346b 83:7d09
84:6003 85:3469 86:3c09 87:6003 88:207f
[65647.080000] ata_dump_id: 49==0x2f00  53==0x0007  63==0x0007
64==0x0003  75==0x001f
[65647.080000] ata_dump_id: 80==0x00fe  81==0x0000  82==0x346b
83==0x7d09  84==0x6003
[65647.080000] ata_dump_id: 88==0x207f  93==0x0000
[65647.080000] ata2.00: ata_dev_configure: EXIT, drv_stat = 0x50
[65647.080000] ata_dev_set_mode: xfer_shift=8, xfer_mode=0x45
[65647.080000] ata2.00: configured for UDMA/100
[65647.080000] ata_eh_suspend: ENTER
[65647.080000] ata_eh_suspend: EXIT
[65647.080000] ata_eh_recover: EXIT, rc=0
[65647.080000] ata2: EH complete
[65647.080000] ata_scsi_error: EXIT
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 00 00 00 00 00 00 00 00 24
[65647.080000] ata_scsiop_noop: ENTER
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) a1 08 08 00 00 00 00 00 00
[65647.080000] ata_scsi_translate: ENTER
[65647.080000] ata_sg_setup: ENTER, ata2
[65647.080000] ata_sg_setup: 1 sg elements mapped
[65647.080000] ata_scsi_translate: EXIT
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 25 00 00 00 00 00 00 00 00
[65647.080000] ata_scsiop_read_cap: ENTER
[65647.080000] SCSI device sda: 234441648 512-byte hdwr sectors (120034 MB)
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 5a 00 3f 00 00 00 00 00 08
[65647.080000] ata_scsiop_mode_sense: ENTER
[65647.080000] sda: Write Protect is off
[65647.080000] sda: Mode Sense: 00 3a 00 00
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 5a 00 08 00 00 00 00 00 08
[65647.080000] ata_scsiop_mode_sense: ENTER
[65647.080000] ata_sg_clean: unmapping 1 sg elements
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 5a 00 08 00 00 00 00 00 24
[65647.080000] ata_scsiop_mode_sense: ENTER
[65647.080000] SCSI device sda: drive cache: write back
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 00 00 00 00 00 00 00 00 24
[65647.080000] ata_scsiop_noop: ENTER
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 25 00 00 00 00 00 00 00 00
[65647.080000] ata_scsiop_read_cap: ENTER
[65647.080000] SCSI device sda: 234441648 512-byte hdwr sectors (120034 MB)
[65647.080000] ata_scsi_dump_cdb: CDB (2:0,0,0) 5a 00 3f 00 00 00 00 00 08
[65647.080000] ata_scsiop_mode_sense: ENTER
[65647.090000] sda: Write Protect is off
[65647.090000] sda: Mode Sense: 00 3a 00 00
[65647.090000] ata_scsi_dump_cdb: CDB (2:0,0,0) 5a 00 08 00 00 00 00 00 08
[65647.090000] ata_scsiop_mode_sense: ENTER
[65647.090000] ata_scsi_dump_cdb: CDB (2:0,0,0) 5a 00 08 00 00 00 00 00 24
[65647.090000] ata_scsiop_mode_sense: ENTER
[65647.090000] SCSI device sda: drive cache: write back

Re: How to make SATA hotplug path tight?

[Leon Woestenberg]

Fajun,

On 9/15/06, Fajun Chen <fajunchen@gmail.com> wrote:
> Hi,
>
> I'm trying to speed up the SATA hotplug sequence so I can measure the
> disk spinup time more accurately.  I noticed two delays which may be
>
Did you check whether the SMART attribute that indicates disk spin-up
time did suit your needs?

Regards,

Leon.

Re: How to make SATA hotplug path tight?

[Tejun Heo]

On Fri, Sep 15, 2006 at 09:12:33AM -0600, Fajun Chen wrote:
> Hi,
> 
> I'm trying to speed up the SATA hotplug sequence so I can measure the
> disk spinup time more accurately.  I noticed two delays which may be
> unnecessary in SATA hotplug:
> 1. About 4-5 seconds delay during power cycle (power down then power
> up) as shown below (detail log at the end):
> [65642.680000] ata_eh_prep_resume: ENTER
> [65642.680000] ata_eh_prep_resume: EXIT
> [65642.680000] __ata_port_freeze: ata2 port frozen
> [65646.970000] ata2: soft resetting port
> [65646.970000] sil24_softreset: ENTER
> Question: where is the delay introduced and can we eliminate this delay?

It's probably waiting for ATA_BUSY to clear in prereset.

> 2. Soft reset fails sometimes then followed by a successful hard reset.
> Question: may I do hard reset to start with and where is the best
> place to change this? I know sata spec recommend attempting less
> intrusive recovery procedure first, but I need to eliminate as much
> unnecessary delay as possible.

ATA_FLAG_HRST_TO_RESUME.  You probably also want to tweak
ATA_SPINUP_WAIT.

> Is there any other place in new eh where SATA hotplug can be optimized?

Too many to point out.  :-)

-- 
tejun

Re: How to make SATA hotplug path tight?

[Fajun Chen]

On 9/15/06, Leon Woestenberg <leon.woestenberg@gmail.com> wrote:
> Fajun,
>
> On 9/15/06, Fajun Chen <fajunchen@gmail.com> wrote:
> > Hi,
> >
> > I'm trying to speed up the SATA hotplug sequence so I can measure the
> > disk spinup time more accurately.  I noticed two delays which may be
> >
> Did you check whether the SMART attribute that indicates disk spin-up
> time did suit your needs?
>
Leon, I need to measure this in software to make sure interface is
ready while SMART attributes spinup time may have some uncertainty.

Re: How to make SATA hotplug path tight?

[Fajun Chen]

On 9/15/06, Tejun Heo <htejun@gmail.com> wrote:
> On Fri, Sep 15, 2006 at 09:12:33AM -0600, Fajun Chen wrote:
> > Hi,
> >
> > I'm trying to speed up the SATA hotplug sequence so I can measure the
> > disk spinup time more accurately.  I noticed two delays which may be
> > unnecessary in SATA hotplug:
> > 1. About 4-5 seconds delay during power cycle (power down then power
> > up) as shown below (detail log at the end):
> > [65642.680000] ata_eh_prep_resume: ENTER
> > [65642.680000] ata_eh_prep_resume: EXIT
> > [65642.680000] __ata_port_freeze: ata2 port frozen
> > [65646.970000] ata2: soft resetting port
> > [65646.970000] sil24_softreset: ENTER
> > Question: where is the delay introduced and can we eliminate this delay?
>
> It's probably waiting for ATA_BUSY to clear in prereset.
>
> > 2. Soft reset fails sometimes then followed by a successful hard reset.
> > Question: may I do hard reset to start with and where is the best
> > place to change this? I know sata spec recommend attempting less
> > intrusive recovery procedure first, but I need to eliminate as much
> > unnecessary delay as possible.
>
> ATA_FLAG_HRST_TO_RESUME.  You probably also want to tweak
> ATA_SPINUP_WAIT.
>

    Tejun, I use SATA Sil24.  Where should ATA_FLAG_HRST_TO_RESUME be
flagged?  I made one attempt by making the following change in
libata.h and it seems not working sometimes (see log at the end)? I'm
a little puzzled by different flags such as ap->flags, ehc->flags...
Is there any document about new eh?

static inline void __ata_ehi_hotplugged(struct ata_eh_info *ehi)
{
	if (ehi->flags & ATA_EHI_HOTPLUGGED)
		return;

	ehi->flags |= ATA_EHI_HOTPLUGGED | ATA_EHI_RESUME_LINK;
	ehi->hotplug_timestamp = jiffies;

	ehi->action |= ATA_EH_HARDRESET;    // My Change for Hard Reset
	ehi->probe_mask |= (1 << ATA_MAX_DEVICES) - 1;
}
...
[ 5985.450000] ata1: EH pending after completion, repeating EH (cnt=4)
[ 5985.450000] ata_eh_autopsy: ENTER
[ 5985.450000] ata_eh_autopsy: EXIT
[ 5985.450000] ata1: exception Emask 0x10 SAct 0x0 SErr 0x0 action 0x1
[ 5985.450000] ata1: (irq_stat 0x00b40090, PHY RDY changed)
[ 5985.450000] ata_eh_recover: ENTER
[ 5985.450000] ata_eh_prep_resume: ENTER
[ 5985.450000] ata_eh_prep_resume: EXIT
[ 5985.450000] __ata_port_freeze: ata1 port frozen
[ 5985.450000] ata_wait_spinup: ENTER
[ 5985.450000] sata_phy_debounce: ENTER
[ 5985.970000] sata_phy_debounce: EXIT
[ 5988.990000] ata_wait_spinup: EXIT
[ 5988.990000] sata_phy_resume: ENTER
[ 5989.200000] sata_phy_debounce: ENTER
[ 5989.720000] sata_phy_debounce: EXIT
[ 5989.720000] sata_phy_resume: EXIT
[ 5989.720000] ata1: soft resetting port
[ 5989.720000] sil24_softreset: ENTER
[ 5989.830000] ata_dev_classify: found ATA device by sig
[ 5989.830000] sil24_softreset: EXIT, class=1
[ 5989.830000] ata_std_postreset: ENTER
[ 5989.830000] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
...

Re: How to make SATA hotplug path tight?

[Tejun Heo]

Fajun Chen wrote:
>    Tejun, I use SATA Sil24.  Where should ATA_FLAG_HRST_TO_RESUME be
> flagged?  I made one attempt by making the following change in
> libata.h and it seems not working sometimes (see log at the end)? I'm
> a little puzzled by different flags such as ap->flags, ehc->flags...
> Is there any document about new eh?

Add the flag to SIL24_COMMON_FLAGS.  No, there is no doc yet.  On my 
to-do list though.

-- 
tejun

Re: How to make SATA hotplug path tight?

[Tejun Heo]

[adding linux-ide back, please don't drop it]

Fajun Chen wrote:
> Hi Tejun,
> 
> I try to understand your eh code and still have several questions:
> 
> 1. Why software is needed after hard reset under certain condition?

Because some controllers including sil24 cannot acquire device signature 
after hardreset.

>     rc = ata_do_reset(ap, reset, classes);
>     did_followup_srst = 0;
>     if (reset == hardreset &&
>         ata_eh_followup_srst_needed(rc, classify, classes)) {
>         /* okay, let's do follow-up softreset */
>         did_followup_srst = 1;
>         reset = softreset;
>       ...
>       Sometimes this part of the code costed as many as 7 secs:
> [  366.400000] ata2: hard resetting port
> [  366.400000] sata_phy_debounce: ENTER
> [  368.490000] sata_phy_debounce: EXIT
> [  368.490000] sil24_softreset: ENTER
> [  375.750000] ata_dev_classify: found ATA device by sig
> [  375.750000] sil24_softreset: EXIT, class=1
>       Is there any way to get drive going without going through this?

Well, on hotplug case, you need to detect which class of device is 
attached, so you need a softreset there.

> 2.  What's the concept of port suspend and resume?

Port being suspended and resumed, I think. :-) You need ask more 
specifically.

-- 
tejun