dapper 180s boot-stall ... probable hdparm on IDE CD drives

Raised severity to major, since several minute hangs in the boot process are major problems.

A copy of the /var/log/messages file associated with a problem boot. I don't know how to read this, but maybe someone here does.

I belive this is the same text that's put on the screen while booting, so it may be informative. The system "hangs" for three or four minutes at the section where the wifi0 ... failed errors occur, unless I control-C to force it to continue before the time out.

Hi

I get the same symptoms, ie hanging at 'loading hardware drivers' for a while, and 'Configuring the network'.
I have a Prism II card (BENQ AWL100) which has always been recoqnised and worked fine with the orinoco driver.

But in addition, I always get an error on eth1 (yes, I dont know why it shows it as eth1, when earlier in the boot its wlan0), its
eth1 ; invalid skb-> cb magic (0x00000000, expected 0x08a36a2).

I've no idea what this means.

This has been going on for longer ie, probably last 6-8 weeks, always broken.

I can post log if that will help. after all, prism II cards must still be quite popular ...

I can add a little more information -- I opened up the case to check the chipset: my Toshiba card is from Agere systems. That's a common manufacturer, and the card is supported automatically on the install CD. That's how I've been doing updates: Boot in rescue mode, do apt-get -d dist-upgrade, then reboot and install.

I can also add that when I run lshw -C network my wireless card shows up twice: once on eth1, and once on "wlan0_ifrename." The second listing is more complete (includes driver and version information). Otherwise, they differ in that the eth01 listing is physical device 0 and the wlan0 listing is physial device 2.

I can confirm the same issue here. System installed with Kubuntu Flight5 and dist-upraded today. Wireless card is a SMC2532W-B (Prism II).

Adding hostap and hostap_cs to /etc/modprobe.d/blacklist allows the system to boot up without stalling.

The interface is still not automatically setup. Also the second interface (wlan0_ifrename) then disappears.

When trying to enable the interface in 'System Settings' > 'Network Settings' the interface appears to enable and then disable immediately.

Configuring the interface with dhclient from the command line works as expected.

Hope this helps a little.

several confirmations for this bug, changing status

I did a reinstall of Dapper on April 9th, followed by appropriate upgrading. The bug as reported here seems to be resolved. There are no hangs during boot, and wireless networking works. I haven't been able to get network-manager to function, but that is probably a seperate issue.

I did what Kaglan suggested and Hey presto its fixed! I had exactly the same result ie as of 18th April after reinstalling flight 5 and then doing a full dist-upgrade.

Also the network manager too didnt want to perform but networking wirelessly the old way works fine.

So thsi si only a bug in certain circumstances ..

Sorry, Julian, can you explain a little better what you did? Does dapper beta works for you? Thanks!

I have the same issue with an wired nic.
(is not available when during booting "loading Hardware drivers" hangs)

this happend to with:
linux-2.6.15-20-k7
i am now on linux-2.6.15-20-386 to test if it appears with this kernel also.

>Adding hostap and hostap_cs to /etc/modprobe.d/blacklist allows the system to boot up without stalling.

This does not work for me.
System still hangs while "loading Hardware Drivers".

$ uname --all
Linux ubuntu2 2.6.15-20-386

# cat /proc/cpuinfo
processor : 0
vendor_id : AuthenticAMD
cpu family : 6
model : 6
model name : AMD Athlon(tm) XP 2000+

Motherboard is a ASROCK K7VT 4A Pro (Via VT8237 chipset).
Nic is a onboard:
product: VT6102 [Rhine-II]
vendor: VIA Technologies, Inc.

Output from lsmod

dmesg

 # /etc/init.d/networking restart
 * Reconfiguring network interfaces... WARNING: /etc/modprobe.d/blacklist line 28: ignoring bad line starting with 'hostap'
WARNING: /etc/modprobe.d/blacklist line 29: ignoring bad line starting with 'hostap_cs'
WARNING: /etc/modprobe.d/blacklist line 28: ignoring bad line starting with 'hostap'
WARNING: /etc/modprobe.d/blacklist line 29: ignoring bad line starting with 'hostap_cs'
WARNING: /etc/modprobe.d/blacklist line 28: ignoring bad line starting with 'hostap'
WARNING: /etc/modprobe.d/blacklist line 29: ignoring bad line starting with 'hostap_cs'

<snip>

seems like on wired connections something different is causing trobble.

I have just installed the kernel update.
Problem still present.

$ uname --all
Linux ubuntu2 2.6.15-21-386

I have the same here. But on this is on a server.

HP/Compaq DL-360, running Breezy with lattest updates.

Did a 'apt-get dist-upgrade' for dapper. No boot afterwards.

Went on to the console, there had been no new kernel installed... was trying to boot off 2.6.12 from breezy - naughty boy :-(.

Did a manual install of linux-image-386 from the beta dapper CD, and it starts booting, but hangs on 'Loading Harware Drivers'. Haven's gotten around to waiting to see if it moves on.

I'll update when I have more info.

I'm having the same problem with a Toshiba Satellite A60 and a Cisco Aironet 340 PCMCIA wireless card.

I dist-upgraded to dapper a couple of days ago and have been experiencing the reported hangs and problems with network connectivity.

Thilo Six: I think you should add the lines 'blacklist hostap' and 'blacklist hostap_cs' instead of just 'hostap' and 'hostap_cs'. However, doing so did not help for me.

I had the same Problem caused by hostap and hostap_cs. I solved the
Problem on my machine by blacklisting the hostap modules.

see also bug
<a href="https://launchpad.net/distros/ubuntu/+source/pcmciautils/+bug/37260/+index">
https://launchpad.net/distros/ubuntu/+source/pcmciautils/+bug/37260/+index
</a>

Did a followup on my previous situation.

I was getting *A LOT* of "Fake start-stop-daemon called. Doing nothing." during the boot process.
Since start-stop-daemon belongs to dpkg pkg, I forced a re-install of dpkg from the 'current' snapshot.

*SHARAM* All problems solved. Machine booted in a few seconds.

I believe the dist-upgrade process got thumbled up somewhere, on the dpkg upgrade procedure...
Since no daemons started on account of the dummy start-stop-daemon, all other stuff - includind udev - was hung up.

Hope this help all you guys (or at least some).

I did add:
blacklist hostap
blacklist hostap_cs

to /etc/modprobe.d/blacklist (thanks joenix)

Also did:
# aptitude -f reinstall dpkg

Problem persists.

Thilo, please wait while it's "hanging" and see whether it carries on after three minutes.

If it does, attach /var/log/udev from that boot.

I think it never took that long. I would have gone mad otherwise.
But last boot it took quite long but i haven´t meassured with a clock though.

Anyway here is the log.

/var/log/udev after boot

Reinstalling dpkg didn't help for me. I didn't see any "Fake start-stop-daemon called", so I think that is a different problem.

Scott James Remnant: the boot did carry on after three minutes. I'll attach /var/log/udev as well.

This is a copy of /var/log/udev, made right after booting.

joenix, could you please open a new bug at https://launchpad.net/distros/ubuntu/+source/udev/+filebug and attach that file to it once reported -- you have a slightly different problem to Thilo and it will only be confusing if I attempt to address you both at the same time.

Thilo, a couple of interesting things from your boot ...

UEVENT[1146485653.660855] add@/class/sound/sequencer
UEVENT[1146485653.661309] add@/class/sound/sequencer2
UEVENT[1146483565.704583] add@/module/snd_seq_dummy
UEVENT[1146485829.758535] add@/module/lp
UEVENT[1146485829.760120] add@/class/printer/lp0

There's almost 180 seconds between the event for the sound card being sent, and the event for the printer. This is a magic number, because it's the longest that we wait for hardware to respond to configuration.

So this implies one of the devices before 1146483565.704583 failed to complete configuration, and that we hung around for it. Everything after 1146485829.758535 is a record of what "else" happened during the boot process -- this is deliberately logged on failed boots.

The log of what was processed is more interesting ...

UDEV [1146485653.750400] add@/devices/pci0000:00/0000:00:11.5/card0-0
UDEV [1146485653.771296] add@/class/sound/controlC0
UDEV [1146485653.776458] add@/class/sound/mixer
UDEV [1146485709.010692] add@/block/hdc
UDEV [1146485829.759557] add@/module/lp
UDEV [1146485829.762179] add@/class/printer/lp0

The sound card events are processed in under a tenth of a second, as we'd expect. Likewise after the magic barrier, the printer events are processed within a thousandth of a second or two, again as we'd expect.

The interesting one is that "/block/hdc" stuck in the middle, which shouldn't be there ... if we look for the original send of this event and compare the two times:

UEVENT[1146485650.591980] add@/block/hdc
UDEV [1146485709.010692] add@/block/hdc

This event took almost 60s to be processed.

Likewise there's a UEVENT for /block/hdd but not UDEV, implying that this was not processed.

So let's look at those events together:

UEVENT[1146485650.591980] add@/block/hdc
ACTION=add
DEVPATH=/block/hdc
SUBSYSTEM=block
SEQNUM=1569
MINOR=0
MAJOR=22
PHYSDEVPATH=/devices/pci0000:00/0000:00:0f.1/ide1/1.0
PHYSDEVBUS=ide
PHYSDEVDRIVER=ide-cdrom

UEVENT[1146485650.594503] add@/block/hdd
ACTION=add
DEVPATH=/block/hdd
SUBSYSTEM=block
SEQNUM=1570
MINOR=64
MAJOR=22
PHYSDEVPATH=/devices/pci0000:00/0000:00:0f.1/ide1/1.1
PHYSDEVBUS=ide
PHYSDEVDRIVER=ide-cdrom

UDEV [1146485709.010692] add@/block/hdc
UDEV_LOG=3
ACTION=add
DEVPATH=/block/hdc
SUBSYSTEM=block
SEQNUM=1569
MINOR=0
MAJOR=22
PHYSDEVPATH=/devices/pci0000:00/0000:00:0f.1/ide1/1.0
PHYSDEVBUS=ide
PHYSDEVDRIVER=ide-cdrom
UDEVD_EVENT=1
ID_CDROM=1
ID_CDROM_CD_R=1
ID_CDROM_CD_RW=1
ID_CDROM_MRW=1
ID_CDROM_MRW_W=1
ID_CDROM_RAM=1
ID_TYPE=cd
ID_MODEL=SONY_CD-RW_CRX140E
ID_SERIAL=
ID_REVISION=1.0c
ID_BUS=ata
ID_PATH=pci-0000:00:0f.1-ide-1:0
DEVNAME=/dev/hdc
DEVLINKS=/dev/cdrom /dev/cdrw /dev/disk/by-path/pci-0000:00:0f.1-ide-1:0

This is where my suspicion lies, your CD-RW drive (/dev/hdc) took 60s to configure, and the seco...

> A common cause of this is hdparm, where we have a problem
> with certain "one-in-a-million" combinations of hardware.

I knew i am a special person ..... OK,ok my Computer is. SCNR ;)

Erm..

Well you do not even know how much i await eagerly your input Scott James Remnant.

In the meantime i installed Ubuntu complete new.
Since I have /home and /var/cache/apt/archives/ on seperate partitions this was just some time to spend and nothing to lose.

Damn is Dapper fast. ;)

After your mail I put the hdparm konfiguration back in place and was able (after some reboots) to repeat "the error".
Before that Dapper boots really fast, i was suprised.
The time from power on to gdm took only maybe 20sec i think.

Now after i turned on dma it´s like up the pole.

Here my data:
----------------------------------------------------------------------------------
# hdparm /dev/hda

/dev/hda:
 multcount = 0 (off)
 IO_support = 1 (32-bit)
 unmaskirq = 1 (on)
 using_dma = 1 (on)
 keepsettings = 0 (off)
 readonly = 0 (off)
 readahead = 256 (on)
 geometry = 39761/16/63, sectors = 40079088, start = 0

# hdparm /dev/hdc

/dev/hdc:
 IO_support = 1 (32-bit)
 unmaskirq = 1 (on)
 using_dma = 1 (on)
 keepsettings = 0 (off)
 readonly = 0 (off)
 readahead = 256 (on)
 HDIO_GETGEO failed: Invalid argument

# hdparm /dev/hdd

/dev/hdd:
 IO_support = 1 (32-bit)
 unmaskirq = 1 (on)
 using_dma = 1 (on)
 keepsettings = 0 (off)
 readonly = 0 (off)
 readahead = 256 (on)
 HDIO_GETGEO failed: Invalid argument

----------------------------------------------------------------------------------

# dmesg | grep hd
[4294667.296000] Kernel command line: root=/dev/hda2 ro quiet splash vga=0x317 hdc=ide_cd rootflags=commit=21
[4294667.296000] ide_setup: hdc=ide_cd -- BAD OPTION
[4294671.157000] ide0: BM-DMA at 0xfc00-0xfc07, BIOS settings: hda:DMA, hdb:pio
[4294671.157000] ide1: BM-DMA at 0xfc08-0xfc0f, BIOS settings: hdc:DMA, hdd:DMA
[4294671.543000] hda: WDC WD205AA, ATA DISK drive
[4294672.966000] hdc: SONY CD-RW CRX140E, ATAPI CD/DVD-ROM drive
[4294673.680000] hdd: HITACHI DVD-ROM GD-5000, ATAPI CD/DVD-ROM drive
[4294673.754000] hda: max request size: 128KiB
[4294673.879000] hda: 40079088 sectors (20520 MB) w/2048KiB Cache, CHS=39761/16/63, UDMA(66)
[4294673.879000] hda: cache flushes not supported
[4294673.880000] hda: hda1 hda2 hda3 hda4 < hda5 hda6 hda7 hda8 >
[4294674.005000] hdc: ATAPI 32X CD-ROM CD-R/RW drive, 4096kB Cache, UDMA(33)
[4294674.036000] hdd: ATAPI 40X DVD-ROM drive, 512kB Cache, DMA
[4294691.439000] hdc: set_drive_speed_status: status=0x51 { DriveReady SeekComplete Error }
[4294691.439000] hdc: set_drive_speed_status: error=0x24 { AbortedCommand LastFailedSense=0x02 }
[4294751.438000] hdd: lost interrupt
[4294752.399000] Adding 1124416k swap on /dev/hda3. Priority:-1 extents:1 across:1124416k
[4294752.491000] EXT3 FS on hda2, internal journal
[4294753.288000] EXT3 FS on hda1, internal journal
[4294753.334000] EXT3 FS on hda5, internal journal
[4294753.335000] EXT3 FS on hda6, internal journal

----------------...

/var/log/udev from a "broken" boot - with hdparm

/etc/hdparm.conf

/var/log/udev without hdparm

Maybe some can explain me this:

# hdparm /dev/hda

/dev/hda:
 multcount = 0 (off)
 IO_support = 1 (32-bit)
 unmaskirq = 1 (on)
 using_dma = 1 (on)
 keepsettings = 0 (off)
 readonly = 0 (off)
 readahead = 256 (on)
 geometry = 39761/16/63, sectors = 40079088, start = 0

# hdparm /dev/hdc

/dev/hdc:
 IO_support = 1 (32-bit)
 unmaskirq = 1 (on)
 using_dma = 1 (on)
 keepsettings = 0 (off)
 readonly = 0 (off)
 readahead = 256 (on)
 HDIO_GETGEO failed: Invalid argument

# hdparm /dev/hdd

/dev/hdd:
 IO_support = 1 (32-bit)
 unmaskirq = 1 (on)
 using_dma = 1 (on)
 keepsettings = 0 (off)
 readonly = 0 (off)
 readahead = 256 (on)
 HDIO_GETGEO failed: Invalid argument

dma is on even without setting it in /etc/hdparm.conf

/etc/hdparm.conf -> dma is on even with config comented out

What i forgot to mention:

When boot "hangs" hlad has a problem, too.
This even prevent X to start sometimes.

and...

once i saw the message:

unmount of lokal filesystems.........................failed

on shutdown.

s/hlad/hald/g

Ok, so just to confirm this ... if you remove the following lines from your /etc/hdparm.conf:

/dev/hdc {
        dma = on
}

/dev/hdd {
        dma = on
}

Then the boot works absolutely fine, with no delay?

(That would appear to be confirmed by your copy of /var/log/udev without the hdparm settings ... the longest event takes 4.1s to be processed, and no events are missed.)

> Ok, so just to confirm this ... if you remove the following lines from your /etc/hdparm.conf:
>
> /dev/hdc {
> dma = on
> }
>
> /dev/hdd {
> dma = on
> }
>
> Then the boot works absolutely fine, with no delay?
>

Yes. Without these lines Dapper boots as i would expect it.

In meantime i had some further testing and it seems my network problems
are comeing somehow from the package resolvconf.
I purged it and removed it´s config from /etc (it was still there even
with purge).
Now my network is reliable also.

Thilo Six wrote the following on 03.05.2006 20:16:
>> Ok, so just to confirm this ... if you remove the following lines from your /etc/hdparm.conf:
>>
>> /dev/hdc {
>> dma = on
>> }
>>
>> /dev/hdd {
>> dma = on
>> }
>>
>> Then the boot works absolutely fine, with no delay?
>>
>
> Yes. Without these lines Dapper boots as i would expect it.

And also to make it clear, dma is on also witout these lines.
This is other then in breezy so it might be a new feature, to prevent
newbees asking why their dvd not run.

Ok, marking this as Rejected as you added those hdparm lines yourself.

If the documentation that told you to do that was from an Ubuntu source, please ask the author to remove it; on Ubuntu dma is enabled automatically if it's possible -- forcing it to be enabled can cause problems.

The reason you were having problems is due to hdparm being unable to enable dma itself, which isn't needed because it was already enabled anyway.

Scott James Remnant wrote the following on 03.05.2006 20:45:
> Ok, marking this as Rejected as you added those hdparm lines yourself.
>
> If the documentation that told you to do that was from an Ubuntu source, please ask the author to remove it; on Ubuntu dma is enabled automatically if it's possible -- forcing it to be enabled can cause problems.
>
> The reason you were having problems is due to hdparm being unable to enable dma itself, which isn't needed because it was already enabled anyway.
>
> ** Changed in: udev (Ubuntu)
> Status: Confirmed => Rejected
>

OK Scott James Remnant thank you a lot for your help.

I suggest to put some lines about this in upcomming release Notes.
Otherwise a lot of breezy users will fell into it.

Because in Breezy it was needed to enable dma in hdparm.conf.
(That´s why i had it enabled, too.)

So I guess a lot of current breezy users will have this config.

For most people it's harmless

It's just the odd one in a million that hdparm fails for, and we don't know the combination of hardware that causes it.

OK lets see

500*10E6 / 10*10E6 = 500

By the ever growing community of Ubuntu this means 500 Users will have a problem. When not even more..... ;)

If only we had 500 million users ;o)

So far it's definitely affected about 5 users.

Like I said, we don't know what causes it -- and in every case, it's been a change the user makes that breaks thing -- the defaults we ship are fine.