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

[John Baldwin]

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.

-- 
John Baldwin