slow boot in opensuse 11.2 due to a hdd issue ( >4min )

English Install/Boot/Login
#1

hello guys, first some background:

i was very cautious in installing 11.2; i had previously evaluated sled10sp3, it was great but for some reason it never connected to a dhcp server to get the internet. my fear from installing 11.2 was that i blindly trusted lilo for years as my boot loader (dual booting with xp)

so i took the chance and installed 11.2 with lilo. didn’t work; so i went back and installed graphical grub; didn’t work either; then installed the system again but with the option “use trusted grub” (which is a text-only boot loader) which worked like a charm on my system.

the thing is, that my system overall boots quickly, except in the part when it starts detecting the hard-disk; which takes 4 minutes detecting the disk and partitions. when it “fails” detecting or doing something with the disk, it continues to boot rapidly then.

My system specs:

  • opensuse 11.2 & xp
  • default kernel 2.6.31.5-.0.1 using gnome desktop 2.28
  • amd athlon 64 x2 dual core processor
  • 2.5Gb Ram
  • integrated 256mb nvidia geforce 6100 nforce 430 graphic card (nvidia linux driver version 190.42)
  • MB model: nvidia MCP61 motherboard
  • 40gb maxtor IDE-HDD (/dev/sda, kernel driver= pata_amd)

partitions:
sda6 swap (227mb)
sda7 /boot ext3 (298mb)
sda8 /home xfs (10gb)
sda9 / xfs (8gb)

i am adding the start-up log file (/var/log/boot.msg)

please check the number beginning with “<4>[22.701043] ata1: lost interrupt (Status 0x58)” as the slow down starts there until it gets to “<4>[244.918796] sda1 sda2 <sda5 sda6 sda7 sda8 sda9>” when it resumes quickly from there to complete the boot process.

all i can say, is that 11.2 is a fantastic, wonderful & very stable distribution.

Thanks for taking the time to look into my problem in order to get a normal boot time.

<OF>

#2

[size=2]( var/log/boot.msg )

klogd 1.4.1, log source = ksyslog started.
<5> 0.000000] Linux version 2.6.31.5-0.1-desktop (geeko@buildhost) (gcc version 4.4.1 [gcc-4_4-branch revision 150839] (SUSE Linux) ) #1 SMP PREEMPT 2009-10-26 15:49:03 +0100
<6> 0.000000] KERNEL supported cpus:
<6> 0.000000] Intel GenuineIntel
<6> 0.000000] AMD AuthenticAMD
<6> 0.000000] NSC Geode by NSC
<6> 0.000000] Cyrix CyrixInstead
<6> 0.000000] Centaur CentaurHauls
<6> 0.000000] Transmeta GenuineTMx86
<6> 0.000000] Transmeta TransmetaCPU
<6> 0.000000] UMC UMC UMC UMC
<6> 0.000000] BIOS-provided physical RAM map:

…

<6> 1.243674] Freeing unused kernel memory: 464k freed
<6> 1.244037] Write protecting the kernel text: 4720k
<6> 1.244174] Write protecting the kernel read-only data: 2704k
<7> 1.287991] pata_amd 0000:00:06.0: version 0.4.1
<7> 1.288057] pata_amd 0000:00:06.0: setting latency timer to 64
<6> 1.288163] scsi0 : pata_amd
<6> 1.288310] scsi1 : pata_amd
<6> 1.289961] ata1: PATA max UDMA/133 cmd 0x1f0 ctl 0x3f6 bmdma 0xfff0 irq 14
<6> 1.289965] ata2: PATA max UDMA/133 cmd 0x170 ctl 0x376 bmdma 0xfff8 irq 15
<6> 1.447498] ata1.00: ATA-7: Maxtor 6E040L0, NAR61GA0, max UDMA/133
<6> 1.447503] ata1.00: 80293248 sectors, multi 16: LBA
<6> 1.447533] ata1.01: ATAPI: HL-DT-STDVD-RAM GSA-H22N, 1.00, max UDMA/66
<7> 1.447559] ata1: nv_mode_filter: 0x7f39f&0x7f39f->0x7f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 1.447565] ata1: nv_mode_filter: 0x1f39f&0x1f39f->0x1f39f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 1.453434] ata1.00: configured for UDMA/133
<6> 1.459358] ata1.01: configured for UDMA/66
<5> 1.460780] scsi 0:0:0:0: Direct-Access ATA Maxtor 6E040L0 NAR6 PQ: 0 ANSI: 5
<5> 1.460978] sd 0:0:0:0: [sda] 80293248 512-byte logical blocks: (41.1 GB/38.2 GiB)
<4> 22.701043] ata1: lost interrupt (Status 0x58)
<7> 22.701056] ata1: drained 1 bytes to clear DRQ.
<3> 22.701063] ata1.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 22.701082] ata1.01: cmd a0/01:00:00:60:00/00:00:00:00:00/b0 tag 0 dma 96 in
<3> 22.701084] cdb 12 00 00 00 60 00 00 00 00 00 00 00 00 00 00 00
<3> 22.701085] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 22.701100] ata1.01: status: { DRDY }
<4> 27.750025] ata1: link is slow to respond, please be patient (ready=0)
<6> 31.269028] ata1: soft resetting link
<7> 31.426620] ata1: nv_mode_filter: 0x7f39f&0x7f39f->0x7f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 31.426626] ata1: nv_mode_filter: 0x1f39f&0x1f39f->0x1f39f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 31.432444] ata1.00: configured for UDMA/133
<6> 31.438373] ata1.01: configured for UDMA/66
<6> 31.439676] ata1: EH complete
<4> 52.701035] ata1: lost interrupt (Status 0x58)
<7> 52.701050] ata1: drained 1 bytes to clear DRQ.
<4> 52.701058] ata1.01: limiting speed to UDMA/44:PIO4
<3> 52.701063] ata1.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 52.701085] ata1.01: cmd a0/01:00:00:60:00/00:00:00:00:00/b0 tag 0 dma 96 in
<3> 52.701087] cdb 12 00 00 00 60 00 00 00 00 00 00 00 00 00 00 00
<3> 52.701088] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 52.701103] ata1.01: status: { DRDY }
<4> 57.750018] ata1: link is slow to respond, please be patient (ready=0)
<6> 61.218021] ata1: soft resetting link
<7> 61.375518] ata1: nv_mode_filter: 0x7f39f&0x7f39f->0x7f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 61.375524] ata1: nv_mode_filter: 0xf39f&0x1f39f->0xf39f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 61.381432] ata1.00: configured for UDMA/133
<6> 61.387355] ata1.01: configured for UDMA/44
<6> 61.388692] ata1: EH complete
<5> 61.388720] sd 0:0:0:0: [sda] Write Protect is off
<7> 61.388724] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
<4> 82.701033] ata1: lost interrupt (Status 0x58)
<7> 82.701046] ata1: drained 1 bytes to clear DRQ.
<4> 82.701051] ata1.01: limiting speed to UDMA/33:PIO4
<3> 82.701054] ata1.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 82.701069] ata1.01: cmd a0/01:00:00:60:00/00:00:00:00:00/b0 tag 0 dma 96 in
<3> 82.701071] cdb 12 00 00 00 60 00 00 00 00 00 00 00 00 00 00 00
<3> 82.701073] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 82.701087] ata1.01: status: { DRDY }
<4> 87.750018] ata1: link is slow to respond, please be patient (ready=0)
<6> 91.167021] ata1: soft resetting link
<7> 91.324490] ata1: nv_mode_filter: 0x7f39f&0x7f39f->0x7f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 91.324496] ata1: nv_mode_filter: 0x739f&0x1f39f->0x739f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 91.330440] ata1.00: configured for UDMA/133
<6> 91.336355] ata1.01: configured for UDMA/33
<6> 91.337648] ata1: EH complete
<4> 112.701033] ata1: lost interrupt (Status 0x58)
<7> 112.701046] ata1: drained 1 bytes to clear DRQ.
<4> 112.701051] ata1.01: limiting speed to PIO4
<3> 112.701054] ata1.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 112.701069] ata1.01: cmd a0/01:00:00:60:00/00:00:00:00:00/b0 tag 0 dma 96 in
<3> 112.701071] cdb 12 00 00 00 60 00 00 00 00 00 00 00 00 00 00 00
<3> 112.701072] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 112.701086] ata1.01: status: { DRDY }
<4> 117.750018] ata1: link is slow to respond, please be patient (ready=0)
<6> 121.116020] ata1: soft resetting link
<7> 121.273507] ata1: nv_mode_filter: 0x7f39f&0x7f39f->0x7f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 121.273513] ata1: nv_mode_filter: 0x1f&0x1f39f->0x1f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 121.279419] ata1.00: configured for UDMA/133
<6> 121.285355] ata1.01: configured for PIO4
<6> 121.286695] ata1: EH complete
<6> 121.286716] scsi scan: 96 byte inquiry failed. Consider BLIST_INQUIRY_36 for this device
<5> 121.286722] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
<5> 121.287356] scsi 0:0:1:0: CD-ROM HL-DT-ST DVD-RAM GSA-H22N 1.00 PQ: 0 ANSI: 5
<6> 121.287447] sda:
<7> 121.287564] ata2: port disabled. ignoring.
<4> 151.704042] ata1: lost interrupt (Status 0x58)
<7> 151.705012] ata1: drained 32768 bytes to clear DRQ.
<3> 151.746780] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 151.746793] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
<3> 151.746795] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 151.746807] ata1.00: status: { DRDY }
<6> 151.746826] ata1: soft resetting link
<7> 151.903493] ata1: nv_mode_filter: 0x7f39f&0x7f39f->0x7f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 151.903500] ata1: nv_mode_filter: 0x1f&0x1f39f->0x1f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 151.909443] ata1.00: configured for UDMA/133
<6> 151.915357] ata1.01: configured for PIO4
<4> 151.916655] ata1.00: device reported invalid CHS sector 0
<6> 151.916662] ata1: EH complete
<4> 182.701033] ata1: lost interrupt (Status 0x58)
<7> 182.702016] ata1: drained 32768 bytes to clear DRQ.
<4> 182.743777] ata1.00: limiting speed to UDMA/100:PIO4
<3> 182.743781] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 182.743794] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
<3> 182.743796] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 182.743807] ata1.00: status: { DRDY }
<6> 182.743826] ata1: soft resetting link
<7> 182.900525] ata1: nv_mode_filter: 0x3f39f&0x7f39f->0x3f39f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 182.900530] ata1: nv_mode_filter: 0x1f&0x1f39f->0x1f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 182.906450] ata1.00: configured for UDMA/100
<6> 182.912357] ata1.01: configured for PIO4
<4> 182.913670] ata1.00: device reported invalid CHS sector 0
<6> 182.913675] ata1: EH complete
<4> 213.701048] ata1: lost interrupt (Status 0x58)
<7> 213.702017] ata1: drained 32768 bytes to clear DRQ.
<4> 213.744183] ata1.00: limiting speed to UDMA/33:PIO4
<3> 213.744187] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 213.744199] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
<3> 213.744201] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 213.744211] ata1.00: status: { DRDY }
<6> 213.744230] ata1: soft resetting link
<7> 213.901515] ata1: nv_mode_filter: 0x739f&0x7f39f->0x739f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 213.901520] ata1: nv_mode_filter: 0x1f&0x1f39f->0x1f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 213.907435] ata1.00: configured for UDMA/33
<6> 213.913399] ata1.01: configured for PIO4
<4> 213.914653] ata1.00: device reported invalid CHS sector 0
<6> 213.914659] ata1: EH complete
<4> 244.701040] ata1: lost interrupt (Status 0x58)
<7> 244.702017] ata1: drained 32768 bytes to clear DRQ.
<4> 244.743787] ata1.00: limiting speed to PIO4
<3> 244.743792] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
<3> 244.743921] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
<3> 244.743923] res 40/00:02:00:24:00/00:00:00:00:00/b0 Emask 0x4 (timeout)
<3> 244.744183] ata1.00: status: { DRDY }
<6> 244.744267] ata1: soft resetting link
<7> 244.901507] ata1: nv_mode_filter: 0x1f&0x7f39f->0x1f, BIOS=0x7f000 (0xc7c50000) ACPI=0x7f01f (15:30:0x15)
<7> 244.901513] ata1: nv_mode_filter: 0x1f&0x1f39f->0x1f, BIOS=0x1f000 (0xc7c50000) ACPI=0x1f01f (15:30:0x15)
<6> 244.907427] ata1.00: configured for PIO4
<6> 244.913399] ata1.01: configured for PIO4
<4> 244.914784] ata1.00: device reported invalid CHS sector 0
<6> 244.914795] ata1: EH complete
<4> 244.918796] sda1 sda2 < sda5 sda6 sda7 sda8 sda9 >
<6> 245.010592] sda: detected capacity change from 0 to 41110142976
<5> 245.010526] sd 0:0:0:0: [sda] Attached SCSI disk
<6> 245.029259] Uniform Multi-Platform E-IDE driver
<6> 245.039436] processor LNXCPU:00: registered as cooling_device0
<6> 245.039480] processor LNXCPU:01: registered as cooling_device1
<6> 245.048923] udev: starting version 146
<7> 246.508810] PM: Marking nosave pages: 000000000009f000 - 0000000000100000
<7> 246.508818] PM: Basic memory bitmaps created
<7> 246.654689] PM: Basic memory bitmaps freed
<6> 246.718580] PM: Starting manual resume from disk
<7> 246.718586] PM: Resume from partition 8:6
<7> 246.718588] PM: Checking hibernation image.
<7> 246.719501] PM: Resume from disk failed.
<6> 246.778530] SGI XFS with ACLs, security attributes, realtime, large block/inode numbers, no debug enabled
<6> 246.779178] SGI XFS Quota Management subsystem
<5> 246.837400] XFS mounting filesystem sda9
<7> 247.713158] Ending clean XFS mount for filesystem: sda9
<7> 251.173022] preloadtrace: systemtap: 0.9.9/0.142, base: f7e35000, memory: 34052+77432+22160+13600 data+text+ctx+net, probes: 34
<6> 255.813199] udev: starting version 146
<6> 255.849950] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input3
<6> 255.850008] ACPI: Power Button [PWRF]
<6> 255.850091] input: Power Button as /devices/LNXSYSTM:00/device:00/PNP0C0C:00/input/input4
<6> 255.850146] ACPI: Power Button [PWRB]
<6> 255.881684] i2c-adapter i2c-0: nForce2 SMBus adapter at 0x4d00
<6> 255.881705] i2c-adapter i2c-1: nForce2 SMBus adapter at 0x4e00
<6> 255.891975] forcedeth: Reverse Engineered nForce ethernet driver. Version 0.64.
<4> 255.892496] ACPI: PCI Interrupt Link [LMAC] enabled at IRQ 21
<7> 255.892503] alloc irq_desc for 21 on node 0
<7> 255.892505] alloc kstat_irqs on node 0
<6> 255.892518] forcedeth 0000:00:07.0: PCI INT A -> Link[LMAC] -> GSI 21 (level, low) -> IRQ 21
<7> 255.892523] forcedeth 0000:00:07.0: setting latency timer to 64
<6> 255.893873] Floppy drive(s): fd0 is 1.44M
<6> 255.908315] FDC 0 is a post-1991 82077
<6> 255.929254] input: PC Speaker as /devices/platform/pcspkr/input/input5
<6> 255.974990] gameport: EMU10K1 is pci0000:01:09.1/gameport0, io 0xef00, speed 59659kHz
<4> 256.052421] nvidia: module license ‘NVIDIA’ taints kernel.
<4> 256.052427] Disabling lock debugging due to kernel taint
<5> 256.064285] sd 0:0:0:0: Attached scsi generic sg0 type 0
<5> 256.064321] scsi 0:0:1:0: Attached scsi generic sg1 type 5
<4> 256.106721] ACPI: PCI Interrupt Link [LNKB] enabled at IRQ 19
<7> 256.106729] alloc irq_desc for 19 on node 0
<7> 256.106732] alloc kstat_irqs on node 0
<6> 256.106744] EMU10K1_Audigy 0000:01:09.0: PCI INT A -> Link[LNKB] -> GSI 19 (level, low) -> IRQ 19
<4> 256.110921] sr0: scsi3-mmc drive: 48x/48x writer dvd-ram cd/rw xa/form2 cdda tray
<6> 256.123290] Uniform CD-ROM driver Revision: 3.20
<7> 256.123435] sr 0:0:1:0: Attached scsi CD-ROM sr0
<6> 256.406168] forcedeth 0000:00:07.0: ifname eth0, PHY OUI 0x732 @ 1, addr 00:21:85:1a:df:34
<6> 256.406174] forcedeth 0000:00:07.0: highdma pwrctl mgmt lnktim msi desc-v3
<4> 256.406635] k8temp 0000:00:18.3: Temperature readouts might be wrong - check erratum #141
<4> 256.421301] ACPI: PCI Interrupt Link [LMC9] enabled at IRQ 20
<7> 256.421310] alloc irq_desc for 20 on node 0
<7> 256.421313] alloc kstat_irqs on node 0
<6> 256.421326] nvidia 0000:00:0d.0: PCI INT A -> Link[LMC9] -> GSI 20 (level, low) -> IRQ 20
<7> 256.421334] nvidia 0000:00:0d.0: setting latency timer to 64
<4> 256.421767] NVRM: loading NVIDIA UNIX x86 Kernel Module 190.42 Tue Oct 20 20:18:32 PDT 2009
<6> 257.568809] Adding 232900k swap on /dev/sda6. Priority:-1 extents:1 across:232900k
<6> 258.125242] device-mapper: uevent: version 1.0.3
<6> 258.125426] device-mapper: ioctl: 4.15.0-ioctl (2009-04-01) initialised: dm-devel@redhat.com
<6> 259.325485] loop: module loaded
<6> 259.357853] kjournald starting. Commit interval 15 seconds
<6> 259.358303] EXT3 FS on sda7, internal journal
<6> 259.358311] EXT3-fs: mounted filesystem with ordered data mode.
<5> 259.505851] XFS mounting filesystem sda8
<7> 260.455787] Ending clean XFS mount for filesystem: sda8
<6> 261.320444] fuse init (API version 7.12)
Kernel logging (ksyslog) stopped.
Kernel log daemon terminating.[/size]

#3

I think this is related to my post - did you find a solution?

#4

hi guys:
yesterday, i decided to start failsafe in order to improve this booting sequence. I added ‘noatime’ in fstab, unfortunately it didn’t help.

after looking very closely to the boot.msg log file, i found something that might be a key to what is going on, yet i don’t have the experience to go further…

this is what i discovered after the system iterates the hard disk/dvd transfer speed (my motherboard is a hybrid 2-sata-ports/1-ide-port system) and i’m using only the ide port with the gray-data-cable which goes to the hdd and the dvd (master & slave) . I don’t use or have any components attached to the sata port im my pc:

Take a close look at this and the time it takes iterating while downgrading the transfer speed:

<4> 26.937913] ata1: link is slow to respond, please be patient (ready=0)
<6> 30.931697] ata1.00: configured for UDMA/133
<6> 30.941625] ata1.01: configured for UDMA/66
<4> 51.899965] ata1.01: limiting speed to UDMA/44:PIO4
<4> 56.970353] ata1: link is slow to respond, please be patient (ready=0)
<6> 60.913168] ata1.00: configured for UDMA/133
<6> 60.923072] ata1.01: configured for UDMA/44
<4> 81.933346] ata1.01: limiting speed to UDMA/33:PIO4
<4> 87.003790] ata1: link is slow to respond, please be patient (ready=0)
<6> 90.895614] ata1.00: configured for UDMA/133
<6> 90.905516] ata1.01: configured for UDMA/33
<6> 121.186984] ata1.00: configured for UDMA/133
<6> 121.195912] ata1.01: configured for UDMA/33
<4> 152.067827] ata1.00: limiting speed to UDMA/100:PIO4
<6> 152.250284] ata1.00: configured for UDMA/100
<6> 152.259191] ata1.01: configured for UDMA/33
<4> 183.128989] ata1.00: limiting speed to UDMA/33:PIO4
<6> 183.310541] ata1.00: configured for UDMA/33
<6> 183.319515] ata1.01: configured for UDMA/33
<4> 214.188154] ata1.00: limiting speed to PIO4
<6> 214.368822] ata1.00: configured for PIO4
<6> 214.377751] ata1.01: configured for UDMA/33
<4> 235.207880] ata1.01: limiting speed to PIO4
<4> 240.272494] ata1: link is slow to respond, please be patient (ready=0)
<3> 240.808414] INFO: task ata_aux:16 blocked for more than 120 seconds.
<3> 240.811462] “echo 0 > /proc/sys/kernel/hung_task_timeout_secs” disables this message.
<6> 244.321281] ata1.00: configured for PIO4
<6> 244.330197] ata1.01: configured for PIO4
<4> 244.361692] sda5
<5> 244.362403] scsi 0:0:1:0: CD-ROM HL-DT-ST DVD-RAM GSA-H22N 1.00 PQ: 0 ANSI: 5
<7> 244.369123] ata2: port disabled. ignoring.
<4> 244.379736] sda6 sda7 sda8 sda9 >
<5> 244.421472] sd 0:0:0:0: [sda] Attached SCSI disk
<6> 244.428478] sda: detected capacity change from 0 to 41110142976

As you can see, the system is iterating and downgrading the transfer speed, and while it does this, it stops booting for 4 minutes until it reaches pio4.

I have 3 questions:

  • ¿can you give me a hint on how do i set pio4 to avoid this waiting (hdparm anyone?) so the system can continue booting quickly? -or-
  • ¿what is causing this system to adopt the slowest transfer speed? -or-
  • ¿perhaps two linux drivers are competing to control the ata port?

thanks in advance for your timely response and waiting eagerly for your replies.
<OF>

#5

What do you have connected to the ATI? Is there a CD/DVD . It may be missed configured. ie it is jumperd as slave and there is no master?? Or two masters on the same cable.Or it is master and it is connected to the slave connector. Often ATI device cables will have 2 connectors.

#6

You definitely do not want the drive communication to be using PIO - that’s the old I/O protocol and very slow. You need DMA. It appears the kernel is having a problem with the chipset; it could also be related to bios disk controller setting in conjunction with the kernel module.

Of course first eliminate physical problems: Disconnect the optical, check the jumper, check the cable connection, try a different cable, etc.

Do you get a different result booting “failsafe”? Try booting normally but add “ide=nodma” (w/o quotes) to the kernel line (hit Escape to drop into the grub menu stanzas, edit it there). If no change, try adding this to the kernel line: “insmod=sata_nv insmod=ahci”.

If still no change, reply back with (from a terminal as root):

lspci

hwinfo --ide

hwinfo --storage-ctrl

hwinfo --bios | grep Manufacturer -m 1

hwinfo --bios | grep Product: -m 1

cat /etc/sysconfig/kernel | grep INITRD

You may need to install the “hwinfo” package to do the above.

#7

Addition to my above post . . . also post back the bios settings possible for the disk controller, and which of those the bios is currently set at.

#8

I’m having the same trouble. The PC is an old ASUS TUSI-M mainboard with a Celeron on it, two PATA IDE disks (although the error is the same with just one) and openSUSE 11.1 installed. The board has worked fine for years and years so I’m fairly sure this is a software issue.

There’s some talk on Ubuntu forums of a kernel bug - does anyone know of this and how to apply any fix to openSUSE kernels?

Here’s the interesting boot section:

> dmesg
8< ------------------- snip
ata1: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0xd800 irq 14
ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0xd808 irq 15
ata1.00: HPA unlocked: 66055248 → 488397168, native 488397168
ata1.00: ATA-7: SAMSUNG SP2514N, VF100-41, max UDMA/100
ata1.00: 488397168 sectors, multi 16: LBA48
ata1.01: ATA-7: ST380215A, 3.AAD, max UDMA/100
ata1.01: 156301488 sectors, multi 16: LBA48
ata1.00: limited to UDMA/33 due to 40-wire cable
ata1.01: limited to UDMA/33 due to 40-wire cable
ata1.00: configured for UDMA/33
ata1.01: configured for UDMA/33
scsi 0:0:0:0: Direct-Access ATA SAMSUNG SP2514N VF10 PQ: 0 ANSI: 5
scsi 0:0:1:0: Direct-Access ATA ST380215A 3.AA PQ: 0 ANSI: 5
Uniform Multi-Platform E-IDE driver
BIOS EDD facility v0.16 2004-Jun-25, 2 devices found
udevd version 128 started
sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors: (250 GB/232 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors: (250 GB/232 GiB)
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sda:<6>usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
ohci_hcd: 2006 August 04 USB 1.1 ‘Open’ Host Controller (OHCI) Driver
ACPI: PCI Interrupt Link [LNKD] enabled at IRQ 12
PCI: setting IRQ 12 as level-triggered
ohci_hcd 0000:00:01.2: PCI INT D → Link[LNKD] → GSI 12 (level, low) → IRQ 12
ohci_hcd 0000:00:01.2: OHCI Host Controller
ohci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
ohci_hcd 0000:00:01.2: irq 12, io mem 0xed000000
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 3 ports detected
usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb1: Product: OHCI Host Controller
usb usb1: Manufacturer: Linux 2.6.27.42-0.1-pae ohci_hcd
usb usb1: SerialNumber: 0000:00:01.2
ohci_hcd 0000:00:01.3: PCI INT D → Link[LNKD] → GSI 12 (level, low) → IRQ 12
ohci_hcd 0000:00:01.3: OHCI Host Controller
ohci_hcd 0000:00:01.3: new USB bus registered, assigned bus number 2
ohci_hcd 0000:00:01.3: irq 12, io mem 0xec800000
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 2 ports detected
usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
usb usb2: Product: OHCI Host Controller
usb usb2: Manufacturer: Linux 2.6.27.42-0.1-pae ohci_hcd
usb usb2: SerialNumber: 0000:00:01.3
**ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for UDMA/33
ata1.01: configured for UDMA/33
ata1.00: device reported invalid CHS sector 0
ata1: EH complete
ata1.00: limiting speed to UDMA/25: PIO4
**ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for UDMA/25
ata1.01: configured for UDMA/33
ata1.00: device reported invalid CHS sector 0
ata1: EH complete
ata1.00: limiting speed to PIO4
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for PIO4
ata1.01: configured for UDMA/33
ata1.00: device reported invalid CHS sector 0
ata1: EH complete
sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors: (250 GB/232 GiB)
sda1 sda2 sda3
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Attached SCSI disk
sd 0:0:1:0: [sdb] 156301488 512-byte hardware sectors: (80.0 GB/74.5 GiB)
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sda: detected capacity change from 0 to 250059350016
sd 0:0:1:0: [sdb] Write Protect is off
sd 0:0:1:0: [sdb] Mode Sense: 00 3a 00 00
sd 0:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sd 0:0:1:0: [sdb] 156301488 512-byte hardware sectors: (80.0 GB/74.5 GiB)
sd 0:0:1:0: [sdb] Write Protect is off
sd 0:0:1:0: [sdb] Mode Sense: 00 3a 00 00
sd 0:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sdb: sdb1 sdb2 sdb3
sd 0:0:0:0: [sda] 488397168 512-byte hardware sectors: (250 GB/232 GiB)
sd 0:0:1:0: [sdb] Attached SCSI disk
sd 0:0:0:0: [sda] Write Protect is off
sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sda: detected capacity change from 0 to 250059350016
sd 0:0:1:0: [sdb] 156301488 512-byte hardware sectors: (80.0 GB/74.5 GiB)
sd 0:0:1:0: [sdb] Write Protect is off
sd 0:0:1:0: [sdb] Mode Sense: 00 3a 00 00
sd 0:0:1:0: [sdb] Write cache: enabled, read cache: enabled, doesn’t support DPO or FUA
sdb: detected capacity change from 0 to 80026361856
PM: Starting manual resume from disk
kjournald starting. Commit interval 5 seconds
EXT3 FS on sdb1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
udevd version 128 started
8< ------------------- snip

#9

Here’s some more requested output:

host:/ # lspci
00:00.0 Host bridge: Silicon Integrated Systems [SiS] 630 Host (rev 30)
00:00.1 IDE interface: Silicon Integrated Systems [SiS] 5513 [IDE] (rev d0)
00:01.0 ISA bridge: Silicon Integrated Systems [SiS] SiS85C503/5513 (LPC Bridge)
00:01.1 Ethernet controller: Silicon Integrated Systems [SiS] SiS900 PCI Fast Ethernet (rev 84)
00:01.2 USB Controller: Silicon Integrated Systems [SiS] USB 1.1 Controller (rev 07)
00:01.3 USB Controller: Silicon Integrated Systems [SiS] USB 1.1 Controller (rev 07)
00:02.0 PCI bridge: Silicon Integrated Systems [SiS] Virtual PCI-to-PCI bridge (AGP)
01:00.0 VGA compatible controller: Silicon Integrated Systems [SiS] 630/730 PCI/AGP VGA Display Adapter (rev 21)

host:/ # hwinfo --storage-ctrl
11: PCI 00.1: 0101 IDE interface
[Created at pci.318]
UDI: /org/freedesktop/Hal/devices/pci_1039_5513
Unique ID: hgAj.ZipAttGUTu6
SysFS ID: /devices/pci0000:00/0000:00:00.1
SysFS BusID: 0000:00:00.1
Hardware Class: storage
Model: “Silicon Integrated 5513 [IDE]”
Vendor: pci 0x1039 “Silicon Integrated Systems Corp.”
Device: pci 0x5513 “5513 [IDE]”
SubVendor: pci 0x1043 “ASUSTeK Computer Inc.”
SubDevice: pci 0x80e1
Revision: 0xd0
Driver: “pata_sis”
Driver Modules: “pata_sis”
I/O Ports: 0x1f0-0x1f7 (rw)
I/O Port: 0x3f6 (rw)
I/O Ports: 0x170-0x177 (rw)
I/O Port: 0x376 (rw)
I/O Ports: 0xd800-0xd80f (rw)
Module Alias: “pci:v00001039d00005513sv00001043sd000080E1bc01sc01i80”
Driver Info #0:
Driver Status: pata_sis is active
Driver Activation Cmd: “modprobe pata_sis”
Driver Info #1:
Driver Status: sis5513 is active
Driver Activation Cmd: “modprobe sis5513”
Driver Info #2:
Driver Status: pata_acpi is not active
Driver Activation Cmd: “modprobe pata_acpi”
Driver Info #3:
Driver Status: ata_generic is active
Driver Activation Cmd: “modprobe ata_generic”
Driver Info #4:
Driver Status: ide_pci_generic is active
Driver Activation Cmd: “modprobe ide_pci_generic”
Config Status: cfg=no, avail=yes, need=no, active=unknown

host:/ # hwinfo --bios | grep Manufacturer -m 1
Manufacturer: “System Manufacturer”
host:/ #
host:/ # hwinfo --bios | grep Product: -m 1
Product: “System Name”
host:/ # cat /etc/sysconfig/kernel | grep INITRD
INITRD_MODULES=“processor thermal pata_sis ata_generic sis5513 ide_pci_generic fan jbd ext3 edd”
DOMU_INITRD_MODULES=“xennet xenblk”

#10

Have you tried swapping in a different IDE cable? The log is showing a 40-wire being detected, dropping the speed to UDMA33/PIO4. While you actually have an 80-wire cable, given that the machine is old it is possible that the cable is not working properly now.

#11

Thanks for the suggestion, no I haven’t tried that and I’ll give it a go and post back.

#12

OK I switched the cable and added a known good hard disk. It seems that both the cable and the original disks may have been broken. Thanks for the tip!

dmesg|less

…
ata1: PATA max UDMA/100 cmd 0x1f0 ctl 0x3f6 bmdma 0xd800 irq 14
ata2: PATA max UDMA/100 cmd 0x170 ctl 0x376 bmdma 0xd808 irq 15
ata1.00: HPA unlocked: 66055248 → 488397168, native 488397168
ata1.00: ATA-7: SAMSUNG SP2514N, VF100-41, max UDMA/100
ata1.00: 488397168 sectors, multi 16: LBA48
ata1.01: ATA-7: ST380215A, 3.AAD, max UDMA/100
ata1.01: 156301488 sectors, multi 16: LBA48
ata1.00: configured for UDMA/100
ata1.01: configured for UDMA/100
scsi 0:0:0:0: Direct-Access ATA SAMSUNG SP2514N VF10 PQ: 0 ANSI: 5
scsi 0:0:1:0: Direct-Access ATA ST380215A 3.AA PQ: 0 ANSI: 5
…
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for UDMA/100
ata1.01: configured for UDMA/100
ata1.00: device reported invalid CHS sector 0
ata1: EH complete
ata1.00: limiting speed to UDMA/66: PIO4
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for UDMA/66
ata1.01: configured for UDMA/100
ata1.00: device reported invalid CHS sector 0
ata1: EH complete
ata1.00: limiting speed to UDMA/33: PIO4
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for UDMA/33
ata1.01: configured for UDMA/100
ata1.00: device reported invalid CHS sector 0
ata1: EH complete
ata1.00: limiting speed to PIO4
ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
ata1.00: status: { DRDY }
ata1: soft resetting link
ata1.00: configured for PIO4
ata1.01: configured for UDMA/100
ata1.00: device reported invalid CHS sector 0
ata1: EH complete

So ata1.00 the SAMSUNG SP2514N disk is the original, suspected damaged disk that won’t accept UDMA any more. The new disk ata1.01 is a Seagate Barracuda ST380215A and that seems to work fine. It’s enough for me if one disk is going with UDMA100 as long as the other, which will be less frequently used, doesn’t slow the whole thing down to its level?