Minute+ delay between kernel load and initialization (solved!)

[Alexander Sack]

On Tue, Apr 20, 2010 at 12:02 PM, John Baldwin <jhb at freebsd.org> wrote:
> On Tuesday 20 April 2010 11:56:34 am Charles Owens wrote:
>> On 4/20/2010 9:13 AM, John Baldwin wrote:
>> > On Monday 19 April 2010 6:05:06 pm Charles Owens wrote:
>> >
>> >> On 1/18/2010 10:05 AM, Charles Owens wrote:
>> >>
>> >>> Hello,
>> >>>
>> >>> We have a new system based on the Intel S5520 motherboard that seems to
>> >>> work fine except during _every_ boot it pauses for about one minute 15
>> >>> seconds just before any kernel initialization messages appear.   We see
>> >>> the loader appearing to complete its work (the kernel is loaded) and
>> >>> then... it sits.  Once it starts up again (with usual kernel-boot
>> >>> messages) it appears to boot normally (no error messages).
>> >>>
>> >>> This has been seen with both FreeBSD 8.0 and 7.1, using GENERIC kernels.
>> >>>  I'd appreciate any and all assistance in figuring this out.
>> >>>
>> >>> Boot output follows (happens to be from a PAE-enabled kernel)
>> >>>
>> >>> Thank you,
>> >>>
>> >>> Charles
>> >>>
>> >>>
>> >>>
>> >> [truncated]
>> >>
>> >> An answer to this was graciously provided by Titus Manea.   For details,
>> >> see
>> >>
>> >> http://www.freebsd.org/cgi/query-pr.cgi?pr=i386/144956
>> >>
>> > Interesting.  I do not see the long delay on Nehalem machines here.  Would
>> > either of you be able to debug this further?  You could maybe grab TSC
> values
>> > at various points during the early console probe and print out the
> relevant
>> > deltas after cninit() returns.  You could then move the TSC probe points
>> > around to pinpoint which operations are taking a long time.
>> >
>>
>> John,
>>
>> I'm not going to have the cycles to look at this any time soon,
>> unfortunately.   But, just in case, how does one display TSC values?  We
>> did try to enable the kernel debugger, but the delay happens _before_
>> the debugger prompt is available.
>>
>> We now think of this more as an issue seen with some particular
>> motherboard/BIOS combinations .... initially the only thing we really
>> had to go on was the fact that the behavior was seen on new
>> Nehalem-based systems.
>
> You would have to patch the source to add various calls to rdtsc() that were
> saved in some sort of global array.  Then, once the console was fully
> initialized you could print out the TSC deltas by walking the array and
> printing out the delta between each pair of entries.  You could then move the
> rdtsc() calls around on subsequent tests to narrow down where the pause is
> happening.

Sorry John, I completely missed this.  If you haven't done it already,
I can look into it for sure.  I have several Nehalem machines that do
this.  Its on my TODO list though I thought the kdb probe was the fix?
 Is that NOT the fix?

Just let me know, guys,

-aps