Bug 142636 - Bootup pauses after Audit(...): initialized message
Summary: Bootup pauses after Audit(...): initialized message
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 3
Hardware: i686
OS: Linux
medium
medium
Target Milestone: ---
Assignee: Dave Jones
QA Contact: Brian Brock
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2004-12-11 04:43 UTC by Eli
Modified: 2015-01-04 22:13 UTC (History)
3 users (show)

Fixed In Version: 2.6.11-1.27_FC3
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2005-05-27 13:26:41 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)

Description Eli 2004-12-11 04:43:40 UTC
From Bugzilla Helper:
User-Agent: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.7.5)
Gecko/20041111 Firefox/1.0

Description of problem:
I don't know if this is necessarily a kernel issue, but that's my
first guess.  If this is an issue with another package, point me in
the right direction please.

During bootup, the system pauses for a long time after the
"audit(...): initialized" line.  (Excerpt from dmesg below.)  This was
"pause" was long enough that I rebooted the computer the first couple
of times after installing Fedora Core 3.  I don't know what the system
is doing, but this can't be right.

ACPI: PCI interrupt 0000:01:0b.0[A] -> GSI 11 (level, low) -> IRQ 11
Simple Boot Flag at 0x7c set to 0x1
apm: BIOS not found.
audit: initializing netlink socket (disabled)
audit(1102716559.211:0): initialized
Total HugeTLB memory allocated, 0
VFS: Disk quotas dquot_6.5.1
Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
SELinux:  Registering netfilter hooks


Version-Release number of selected component (if applicable):
kernel-2.6.9-1.681_FC3

How reproducible:
Always

Steps to Reproduce:
1.  Turn on computer
2.  Watch the kernel messages for a moment.
3.  Wait.
4.  Wait.
5.  Wait.
6.  Wait.
7.  Go get a drink.
8.  Oh, hey, the computer isn't locked up afterall!
9.  Watch the kernel messages scroll.
    

Actual Results:  No output from the system for a long time during bootup.

Expected Results:  A steady stream of feedback that the system is
working, with <10 second pauses, max.

Additional info:

This is a Toshiba Satellite A45-S120

Comment 1 Sitsofe Wheeler 2004-12-11 10:44:22 UTC
You don't say what sort of feedback you want. If you mean the kernel probing
messages then you can try editing grub and removing " quiet" to see whether
there is any difference.

Comment 2 Eli 2004-12-11 15:48:21 UTC
Ok, I went back through the boot process taking notes this time.

" quiet" is the default, and with that enabled, you see "audit(...):
initialized" and then nothing happens for 37 seconds.  The next output
is "RedHat nash version 4.1.18 starting"

I removed " quiet" from /etc/grub.conf as suggested.

0:00 I see the grub screen with its 5-second countdown.
Lots of kernel messages...
0:13 "ide1 at ... on irq 15"
NO OUTPUT for 34 seconds.
0:47 continued kernel messages
...
1:23 rhgb starts
2:09 rhgb closes
2:14 Login screen

Why the 34 second pause?!

A 30-second pause is too long.
I rebooted this system thinking it had hung during that time.

At a _minimum_, the system needs to say "I'm doing xyz, and it may
take 40 seconds to complete..."


Comment 3 Alan Cox 2004-12-11 18:13:17 UTC
The mandatory worst case IDE probe time is 30 seconds. This occurs in
situations where we appear to have an IDE controller but do not.  I
have some idea how to deal with this and I think the essential change
is to make ide_default_io_base for x86-32 only scan legacy 0x1f0/0x170
if PCI bus is present.



Comment 4 Eli 2005-02-02 02:41:08 UTC
This is fixed in 2.6.10-1.741_FC3.

Thanks!

Comment 5 Eli 2005-04-26 12:52:34 UTC
And broken again in kernel-2.6.11-1.14_FC3.


Comment 6 Alan Cox 2005-04-26 13:18:32 UTC
Curious. The -ac tree includes a patch which only probes the ide legacy extra
IDE ports if no PCI device is present. If it was fixed in .10 I'm suprised it
became unfixed in .11

I take it this box does have PCI ?


Comment 7 Eli 2005-04-27 01:28:31 UTC
Thanks for replying, Alan.

Yes, this notebook does have PCI.  I'll include what I believe is the relevant
portion of 'lspci -v' near the end of this post.  I'm currently running
2.6.10-1.770_FC3.  (The <ignored> ports look peculiar...)

I'm willing to test kernel patches to track this down.

For context (i.e. these may not be relevant but I think they're worth
mentioning), 2.6.11-1.14_FC3 had a number of regressions on my Toshiba Satellite
notebook.
I can't suspend anymore (BUG:155980), and during the boot process if I hit Alt-D
to show details, it will hide details 3 or 4 times during the boot process. 
Each time it does, I hit Alt-D.  And there is this 30-second wait again.
(I also got a kernel panic with this kernel BUG:156050)
I don't have those problems with 2.6.10-1.770_FC3, but running that kernel I do
see time speed up while suspended (BUG:156051)

00:1f.0 ISA bridge: Intel Corp. 82801DBM (ICH4-M) LPC Interface Bridge (rev 03)
        Flags: bus master, medium devsel, latency 0

00:1f.1 IDE interface: Intel Corp. 82801DBM (ICH4-M) IDE Controller (rev 03)
(prog-if 8a [Master SecP PriP])
        Subsystem: Toshiba America Info Systems: Unknown device 0001
        Flags: bus master, medium devsel, latency 0, IRQ 11
        I/O ports at <ignored>
        I/O ports at <ignored>
        I/O ports at <ignored>
        I/O ports at <ignored>
        I/O ports at bfa0 [size=16]
        Memory at 2f080400 (32-bit, non-prefetchable) [size=1K]

00:1f.5 Multimedia audio controller: Intel Corp. 82801DB/DBL/DBM
(ICH4/ICH4-L/ICH4-M) AC'97 Audio Controller (rev 03)
        Subsystem: Toshiba America Info Systems: Unknown device 0241
        Flags: bus master, medium devsel, latency 0, IRQ 11
        I/O ports at 1000 [size=256]
        I/O ports at 1400 [size=64]
        Memory at 2f080800 (32-bit, non-prefetchable) [size=512]
        Memory at 2f080a00 (32-bit, non-prefetchable) [size=256]
        Capabilities: [50] Power Management version 2

00:1f.6 Modem: Intel Corp. 82801DB/DBL/DBM (ICH4/ICH4-L/ICH4-M) AC'97 Modem
Controller (rev 03) (prog-if 00 [Generic])
        Subsystem: Toshiba America Info Systems: Unknown device 0001
        Flags: bus master, medium devsel, latency 0, IRQ 11
        I/O ports at 1800 [size=256]
        I/O ports at 1480 [size=128]
        Capabilities: [50] Power Management version 2


Comment 8 Eli 2005-04-27 01:45:41 UTC
Rebooted into 2.6.11-1.14_FC3...
lspci -v is the same under both kernels.

# dmesg | grep hdc -3
ICH4: chipset revision 3
ICH4: not 100% native mode: will probe irqs later
    ide0: BM-DMA at 0xbfa0-0xbfa7, BIOS settings: hda:DMA, hdb:pio
    ide1: BM-DMA at 0xbfa8-0xbfaf, BIOS settings: hdc:DMA, hdd:pio
Probing IDE interface ide0...
hda: TOSHIBA MK4025GAS, ATA DISK drive
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Probing IDE interface ide1...
hdc: HL-DT-STCD-RW/DVD DRIVE GCC-4241N, ATAPI CD/DVD-ROM drive
ide1 at 0x170-0x177,0x376 on irq 15
Probing IDE interface ide2...
Probing IDE interface ide3...
--
hda: 78140160 sectors (40007 MB), CHS=65535/16/63, UDMA(100)
hda: cache flushes supported
 hda: hda1 hda2 hda3 hda4 < hda5 >
hdc: ATAPI 24X DVD-ROM CD-R/RW drive, 2048kB Cache, UDMA(33)
Uniform CD-ROM driver Revision: 3.20
ide-floppy driver 0.99.newide
usbcore: registered new driver hiddev

The pause occurs after the "ide1 at ..." line.  I did not notice the "Probing
IDE interface" messages on the console during boot.


Comment 9 Eli 2005-04-27 02:11:26 UTC
Rebooted to 2.6.10-1.770_FC3
# dmesg | grep hdc -3
ICH4: chipset revision 3
ICH4: not 100% native mode: will probe irqs later
    ide0: BM-DMA at 0xbfa0-0xbfa7, BIOS settings: hda:DMA, hdb:pio
    ide1: BM-DMA at 0xbfa8-0xbfaf, BIOS settings: hdc:DMA, hdd:pio
Probing IDE interface ide0...
hda: TOSHIBA MK4025GAS, ATA DISK drive
elevator: using anticipatory as default io scheduler
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Probing IDE interface ide1...
hdc: HL-DT-STCD-RW/DVD DRIVE GCC-4241N, ATAPI CD/DVD-ROM drive
ide1 at 0x170-0x177,0x376 on irq 15
hda: max request size: 128KiB
hda: 78140160 sectors (40007 MB), CHS=65535/16/63, UDMA(100)
hda: cache flushes supported
 hda: hda1 hda2 hda3 hda4 < hda5 >
hdc: ATAPI 24X DVD-ROM CD-R/RW drive, 2048kB Cache, UDMA(33)
Uniform CD-ROM driver Revision: 3.20
ide-floppy driver 0.99.newide
usbcore: registered new driver hiddev


Comment 10 Eli 2005-04-27 02:15:16 UTC
I looked back at the dmesg I saved from 2.6.11-1.14_FC3 and noticed something I
missed in the grep:

Probing IDE interface ide0...
hda: TOSHIBA MK4025GAS, ATA DISK drive
ide0 at 0x1f0-0x1f7,0x3f6 on irq 14
Probing IDE interface ide1...
hdc: HL-DT-STCD-RW/DVD DRIVE GCC-4241N, ATAPI CD/DVD-ROM drive
ide1 at 0x170-0x177,0x376 on irq 15
Probing IDE interface ide2...
Probing IDE interface ide3...
Probing IDE interface ide4...
ide4: Wait for ready failed before probe !
Probing IDE interface ide5...
hda: max request size: 128KiB

It's actually looking for 6 IDE controllers?!  And of course, there's the ide4
message...


Comment 11 Eli 2005-05-27 02:48:11 UTC
Looks like it's OK with 2.6.11-1.27_FC3.  Thanks!



Note You need to log in before you can comment on or make changes to this bug.