This service will be undergoing maintenance at 00:00 UTC, 2016-09-28. It is expected to last about 1 hours
Bug 142636 - Bootup pauses after Audit(...): initialized message
Bootup pauses after Audit(...): initialized message
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: kernel (Show other bugs)
3
i686 Linux
medium Severity medium
: ---
: ---
Assigned To: Dave Jones
Brian Brock
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2004-12-10 23:43 EST by Eli
Modified: 2015-01-04 17:13 EST (History)
3 users (show)

See Also:
Fixed In Version: 2.6.11-1.27_FC3
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2005-05-27 09:26:41 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)

  None (edit)
Description Eli 2004-12-10 23:43:40 EST
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 05:44:22 EST
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 10:48:21 EST
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 13:13:17 EST
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-01 21:41:08 EST
This is fixed in 2.6.10-1.741_FC3.

Thanks!
Comment 5 Eli 2005-04-26 08:52:34 EDT
And broken again in kernel-2.6.11-1.14_FC3.
Comment 6 Alan Cox 2005-04-26 09:18:32 EDT
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-26 21:28:31 EDT
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-26 21:45:41 EDT
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-26 22:11:26 EDT
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-26 22:15:16 EDT
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-26 22:48:11 EDT
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.