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

[Alexander Sack]

On Tue, Apr 27, 2010 at 9:45 AM, John Baldwin <jhb at freebsd.org> wrote:
> On Monday 26 April 2010 10:10:17 pm Alexander Sack wrote:
>> 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,
>
> Maxim has a patch for the atkbd driver that works in his testing.  I think it
> is on another thread however.

Alright, I will take a look and do the same on my end as another
datapoint.  I have been waiting all day to get my hands on this box!
:)

-aps