Boot slowed by HDD speed testing

English Install/Boot/Login
#1

Each time I boot my opensuse 11.2 system one of the very first things that happens is that the system seems to test how fast it can handle my HDD, an older EIDE drive with the wide ribbon cable. This takes about a minute, one test each 15 secs or so until it gets down to about 33 speed and then the boot proceeds as normal.

I guess this is just the normal testing by the more advanced sata procedures in the kernel (2.6.34). If I were only booting this machine once every 6 months it would not be an issue, but I do so at least once a day.

Is there any way to indicate to the system the speed of the connection so that it does not have to do the test, or close the gap a bit so that it finds the answer more quickly? And even if this is possible, is it advisable?

#2

Hello,

I think you are describing udev mapping the devices.

Back in the good/bad old days, your disk would be a fixed node, created by the installation scripts or manually, … /dev/sdaX … always and forever … NICE!

But that made adding and removing disks something of a chore. Now, each time you boot, udev scans your controllers and creates the needed nodes … add a disk … everything just works like magic … NICE … and slow!

I read an article or a forum exchange recently about trying to bypass udev. My takeaway was that it would probably be alot more trouble than it is worth.

Have fun!

#3

On 2010-08-02 19:06, colbec wrote:
>
> Each time I boot my opensuse 11.2 system one of the very first things
> that happens is that the system seems to test how fast it can handle my
> HDD, an older EIDE drive with the wide ribbon cable. This takes about a
> minute, one test each 15 secs or so until it gets down to about 33 speed
> and then the boot proceeds as normal.

I have never seen this.

> Is there any way to indicate to the system the speed of the connection
> so that it does not have to do the test, or close the gap a bit so that
> it finds the answer more quickly? And even if this is possible, is it
> advisable?

Check the parameter file in the kernel documentation directory.

–
Cheers / Saludos,

Carlos E. R.
(from 11.2 x86_64 “Emerald” GM (Elessar))

#4

On 2010-08-03 01:36, oxala wrote:
>
> Hello,
>
> I think you are describing udev mapping the devices.
>
> Back in the good/bad old days, your disk would be a fixed node, created
> by the installation scripts or manually, … /dev/sdaX … always and
> forever … NICE!
>
> But that made adding and removing disks something of a chore. Now,
> each time you boot, udev scans your controllers and creates the needed
> nodes … add a disk … everything just works like magic … NICE …
> and slow!

Slow? It is very fast here.

If you have a machine where it is slow, I think you have to report it in Bugzilla so that it is solved.

–
Cheers / Saludos,

Carlos E. R.
(from 11.2 x86_64 “Emerald” GM (Elessar))

#5

In the case of a slow drive the kernel must prob tht device to set up the correct communications link. Which goes

query device wait for response
no response
Change spec
query device wait for response
no response
Change spec
query device wait for response
no response
Change spec

until there is a handshake established or all possible specs are exhausted

O good amount of time must be allowed in case the device needs to startup or initialize

With very old and slow devices this can take some time.

#6

On 2010-08-03 06:06, gogalthorp wrote:
>
> In the case of a slow drive the kernel must prob tht device to set up
> the correct communications link. Which goes
>
> query device wait for response
> no response
> Change spec
> query device wait for response
> no response
> Change spec
> query device wait for response
> no response
> Change spec
>
> until there is a handshake established or all possible specs are
> exhausted
>
> O good amount of time must be allowed in case the device needs to
> startup or initialize
>
> With very old and slow devices this can take some time.

Yes, this is possible: bus speed and such - but this is not the scenario that “oxala” proposed, that
of “udev mapping the devices”, which just means reading the partitions to find the uuid, label, id,
path, etc. The disk is already readable at this point.

Slowly matching bus speed, yes, it is very possible what you describe, although I have not seen it.

I remember time ago seeing a message during boot about using ide such bus speed and how to change
it, but I don’t remember what it said. But it is surely documented in the kernel source
documentation directory, file parameters.txt or similar. The OP should search there.

–
Cheers / Saludos,

Carlos E. R.
(from 11.2 x86_64 “Emerald” GM (Elessar))

#7

gogalthorp has provided an accurate description of what I see. I note that it is not in fact 15 sec but 30 sec per change spec iteration, and there are at least 4 of them which makes 2 minutes each boot. I can see why lots of time needs to be allowed, but in this case there is no restart reinitialize involved that I can see, just empty cycles elapsing.

Thx guys, this has given me something concrete for a search in the docs - there is no immediate parameters.txt file but maybe “bus speed” will turn something up.

#8

In theory you could hard code it but where is the question.

Only sure solution replace that ancient drive with a modern one with higher comm speed.

#9

Hello,

I used the word “slow” with a touch of tongue in cheek … slow compared to a static mapping of devices …

At boot time, udev does scan for devices and then tests how best to communicate with the devices it finds … on a single disk system … I’m sure it adds between 0.1 and 0.2 seconds to boot time! … SLOW!

My system has six disks across 2 controllers organized into 5 arrays, one of which has lvm hanging out on top of it. It takes several seconds for udev to create the nodes. This is slow compared to a static mapping … and it is MUCH EASIER when it comes time to change something … replace a disk … reboot … all works automagic no-brain goodness …

:slight_smile:

#10

Funny, when I bought the HDD it I thought it was fairly modern. Motherboard only has wide ribbon connector for HDD so I am stuck with that format. Drive is a 500GB Seagate Device: ST3500630A which is specd at ATA 100. So I think in this case unless the ribbon cable (replaced once) is a dud then it must be my mainboard speed (IBM NetVista 6792-22U, much older than the drive) which is the limiting factor.

I think I will put up with it. System is quite fast enough for my purposes, so it takes a couple of minutes to boot, no problemo.

#11

THAT’S THE SPIRIT!

Hee hee hee … having been around for more than a few days, I can’t help but be amused by some of the things that concern and/or annoy me from time to time … such as udev requiring a few seconds to figure out my maniacally redundant overly complex PERSONAL computer … designed such that it might actually do something more important than provide geeky me with an entertainment platform …

My first computer didn’t have a hard drive … and I wanted one soooooo badly … 10megs … ooooooo … the luxury of it all … to save my school paper without a floppy … lol

Don’t forget to have fun …

#12

On 2010-08-03 12:36, colbec wrote:
>
> gogalthorp has provided an accurate description of what I see. I note
> that it is not in fact 15 sec but 30 sec per change spec iteration, and
> there are at least 4 of them which makes 2 minutes each boot. I can see
> why lots of time needs to be allowed, but in this case there is no
> restart reinitialize involved that I can see, just empty cycles
> elapsing.
>
> Thx guys, this has given me something concrete for a search in the docs
> - there is no immediate parameters.txt file but maybe “bus speed” will
> turn something up.

/usr/src/linux/Documentation/kernel-parameters.txt

And there should be a hint in the boot log file around the place where this happens. Let me see…


<7>hda: host max PIO4 wanted PIO255(auto-tune) selected PIO4
<6>hda: UDMA/100 mode selected
<7>Probing IDE interface ide1...
<4>hdc: HL-DT-STDVD-RAM GSA-H20L, ATAPI CD/DVD-ROM drive
<4>hdd: ST3160021A, ATA DISK drive
<7>hdc: host max PIO4 wanted PIO255(auto-tune) selected PIO4
<6>hdc: UDMA/33 mode selected

No, I don’t see the hint, must have been years ago.

Look for settings related to PIO or UDMA - I’m guessing that is the probing part.

–
Cheers / Saludos,

Carlos E. R.
(from 11.2 x86_64 “Emerald” GM (Elessar))

#13

Can you check using hdparm -i or -I and see what udma mode, etc. your drive is using? You can also get the mode using the same utility. Also, although this link is pretty old, I believe the kernel arguments it references are still supported and may be something in the right direction. https://leuksman.com/pages/Ultra-DMA_HOWTO/Activating_and_Deactivating_UDMA

Lews Therin

#14

hdparm -i /dev/sda

/dev/sda:

Model=ST3500630A, FwRev=3.AAF, SerialNo=9QG9N49J
Config={ HardSect NotMFM HdSw>15uSec Fixed DTR>10Mbs RotSpdTol>.5% }
RawCHS=16383/16/63, TrkSize=0, SectSize=0, ECCbytes=4
BuffType=unknown, BuffSize=16384kB, MaxMultSect=16, MultSect=16
CurCHS=16383/16/63, CurSects=16514064, LBA=yes, LBAsects=976773168
IORDY=on/off, tPIO={min:240,w/IORDY:120}, tDMA={min:120,rec:120}
PIO modes: pio0 pio1 pio2 pio3 pio4
DMA modes: mdma0 mdma1 mdma2
UDMA modes: udma0 udma1 udma2 udma3 udma4 *udma5
AdvancedPM=no WriteCache=enabled
Drive conforms to: Unspecified: ATA/ATAPI-1,2,3,4,5,6,7

  • signifies the current active mode

From dmesg:

0.892290] scsi0 : ata_piix                                                                                                     
0.892534] scsi1 : ata_piix                                                                                                     
0.894874] ata1: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0x1800 irq 14                                                      
0.894883] ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0x1808 irq 15

…

21.728039] ata2: lost interrupt (Status 0x58)
21.728073] ata2: drained 2 bytes to clear DRQ.
21.728093] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
21.728498] scsi 1:0:0:0: CDB: Inquiry: 12 00 00 00 60 00
21.728521] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 dma 96 in
21.728523] res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
21.729327] ata2.00: status: { DRDY }
26.778021] ata2: link is slow to respond, please be patient (ready=0)
31.113028] ata2: soft resetting link
31.273344] ata2.00: configured for UDMA/66
31.274501] ata2: EH complete
52.768028] ata2: lost interrupt (Status 0x58)
52.768060] ata2: drained 2 bytes to clear DRQ.
52.768077] ata2.00: limiting speed to UDMA/44:PIO4
52.768084] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
52.768481] scsi 1:0:0:0: CDB: Inquiry: 12 00 00 00 60 00
52.768504] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 dma 96 in
52.768506] res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
52.769306] ata2.00: status: { DRDY }
57.818022] ata2: link is slow to respond, please be patient (ready=0)
61.235030] ata2: soft resetting link
61.395309] ata2.00: configured for UDMA/44
61.396515] ata2: EH complete
82.784031] ata2: lost interrupt (Status 0x58)
82.784063] ata2: drained 2 bytes to clear DRQ.
82.784078] ata2.00: limiting speed to UDMA/33:PIO4
82.784086] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
82.784484] scsi 1:0:0:0: CDB: Inquiry: 12 00 00 00 60 00
82.784506] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 dma 96 in
82.784509] res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
82.785309] ata2.00: status: { DRDY }
87.834025] ata2: link is slow to respond, please be patient (ready=0)
91.353027] ata2: soft resetting link
91.513311] ata2.00: configured for UDMA/33
91.514479] ata2: EH complete
112.736028] ata2: lost interrupt (Status 0x58)
112.736060] ata2: drained 2 bytes to clear DRQ.
112.736074] ata2.00: limiting speed to PIO4
112.736082] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
112.736480] scsi 1:0:0:0: CDB: Inquiry: 12 00 00 00 60 00
112.736501] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 dma 96 in
112.736504] res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
112.737306] ata2.00: status: { DRDY }
117.786021] ata2: link is slow to respond, please be patient (ready=0)
121.458028] ata2: soft resetting link
121.618309] ata2.00: configured for PIO4
121.619541] scsi scan: 96 byte inquiry failed. Consider BLIST_INQUIRY_36 for this device
121.619594] ata2: EH complete

The reference to BLIST_INQUIRY_36 is leading to some interesting reading that I am checking out.

#15

BLIST_INQUIRY_36 led me to a file in the kernel drivers/scsi/scsi_devinfo.c which contains a list of devices that are known to give some problems responding to standard parameter enquiry techniques. My drive is not specifically mentioned, and the file warns that arbitrary entries should not be added. Besides which I don’t have all of the details required for adding an entry. Here is an example entry for a Seagate drive:

{“SEAGATE”, “ST34555N”, “0930”, BLIST_NOTQ}

I can change the drive model name, but the third param is a mystery.

#16

On 08/04/2010 05:06 AM, colbec wrote:
>
> BLIST_INQUIRY_36 led me to a file in the kernel
> drivers/scsi/scsi_devinfo.c which contains a list of devices that are
> known to give some problems responding to standard parameter enquiry
> techniques. My drive is not specifically mentioned, and the file warns
> that arbitrary entries should not be added. Besides which I don’t have
> all of the details required for adding an entry. Here is an example
> entry for a Seagate drive:
>
> {“SEAGATE”, “ST34555N”, “0930”, BLIST_NOTQ}
>
> I can change the drive model name, but the third param is a mystery.

Those flags are defined in include/scsi/scsi_devinfo.h.

Specifically, that one is defined as

#define BLIST_NOTQ 0x020 /* Buggy Tagged Command Queuing */

There is also an entry

#define BLIST_INQUIRY_36 0x400 /* override additional length field */

That is the one recommended in the log message.

#17

Thx, but it was param #3, “0930” in my example, which is the mystery.

#18

On 08/04/2010 12:06 PM, colbec wrote:
>
> Thx, but it was param #3, “0930” in my example, which is the mystery.

Sorry. I guess I need to relearn how to count. Perhaps my 3-year old grandson
can teach me. He is pretty good at counting to 12.

The definition of the macro used by that table is just above it. The comment for
the 3rd argument is “revision known to be bad - unused”. I think “*” would be as
good a value as any.

#19

Hello,

I have apparently the same problem… I have not let the computer go for the whole 3 or 4 minutes, but I do get a reading similar at this

82.784086] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
82.784484] scsi 1:0:0:0: CDB: Inquiry: 12 00 00 00 60 00
82.784506] ata2.00: cmd a0/01:00:00:60:00/00:00:00:00:00/a0 tag 0 dma 96 in
82.784509] res 40/00:02:00:24:00/00:00:00:00:00/a0 Emask 0x4 (timeout)
82.785309] ata2.00: status: { DRDY }

every 30 secs or so… This is a brand new installation of OpenSUSE, I used to have win dual booting with ubuntu, and I had no problems… Tried to install Ubuntu as single OS, got the same problem (install never finished), tried OpenSUSE, installed, but now I have this problem…

I will try to let it wait 3 mins, but that si not acceptable, one of the reasons I chose Linux was fast boot :wink:

Can anyone help on getting a fix, instead of “live with it”? :slight_smile:

Thanks in advance.

#20

On 2010-08-10 13:36, reebomber wrote:

> Can anyone help on getting a fix, instead of “live with it”? :slight_smile:

Downgrade. Report in Bugzilla. Wait for a solution, perhaps os 11.4

–
Cheers / Saludos,

Carlos E. R.
(from 11.2 x86_64 “Emerald” GM (Elessar))