Re: EARLY_AP_STARTUP hangs during boot

On Wed, 27 Jul 2016 14:43:36 -0700
John Baldwin <jhb_at_freebsd.org> wrote:

> On Tuesday, June 07, 2016 12:06:54 PM Gary Jennejohn wrote:
> > On Tue, 31 May 2016 13:10:06 -0700
> > John Baldwin <jhb_at_freebsd.org> wrote:
> >   
> > > On Saturday, May 28, 2016 02:11:41 PM Gary Jennejohn wrote:  
> > > > On Fri, 27 May 2016 09:50:05 +0200
> > > > Gary Jennejohn <gljennjohn_at_gmail.com> wrote:
> > > >     
> > > > > On Thu, 26 May 2016 16:54:35 -0700
> > > > > John Baldwin <jhb_at_freebsd.org> wrote:
> > > > >     
> > > > > > On Tuesday, May 17, 2016 06:47:41 PM Gary Jennejohn wrote:      
> > > > > > > On Mon, 16 May 2016 10:54:19 -0700
> > > > > > > John Baldwin <jhb_at_freebsd.org> wrote:
> > > > > > >         
> > > > > > > > On Monday, May 16, 2016 12:22:42 PM Gary Jennejohn wrote:        
> > > > > > > > > I tried out EARLY_AP_STARTUP, but the kernel hangs and I can't
> > > > > > > > > break into DDB.
> > > > > > > > > 
> > > > > > > > > I did a verbose boot and the last lines I see are related to routing
> > > > > > > > > MSI-X to various local APIC vectors.  I copied the last few lines and
> > > > > > > > > they look like this:
> > > > > > > > > 
> > > > > > > > > msi: routing MSI-X IRQ 256 to local APIC 2 vector 48
> > > > > > > > > msi: routing MSI-X IRQ 257 to local APIC 3 vector 48
> > > > > > > > > msi: routing MSI-X IRQ 258 to local APIC 4 vector 48
> > > > > > > > > msi: routing MSI-X IRQ 256 to local APIC 0 vector 49        
> > > > > > >          ^^^^^^^ Assigning        
> > > > > > > > > 
> > > > > > > > > I tried disabling msi and msix in /boot/loader.conf, but the settings
> > > > > > > > > were ignored (probabaly too early).          
> > > > > > > > 
> > > > > > > > No, those settings are not too early.  However, the routing to different
> > > > > > > > CPUs now happens earlier than it used to.  What is the line before the
> > > > > > > > MSI lines?  You can take a picture with your phone/camera if that's simplest.
> > > > > > > >         
> > > > > > > 
> > > > > > > Here a few lines before the MSI routing happens:
> > > > > > > 
> > > > > > > hpet0: <High Precision Event Timer> iomem 0xfed00000-0xfed003ff irq 0,8 on acpi0
> > > > > > > hpet0: vendor 0x4353, rev 0x1, 14318180 Hz, 3 timers, legacy route
> > > > > > > hpet0: t0 : irqs 0x00c0ff (0), MSI, periodic
> > > > > > > hpet0: t1 : irqs 0x00c0ff (0), MSI, periodic
> > > > > > > hpet0: t2 : irqs 0x00c0ff (0), MSI, periodic
> > > > > > > Timecounter "HPET" frequency 14318180 Hz quality 950        
> > > > > > 
> > > > > > The assigning message means it is in the loop using
> > > > > > bus_bind_intr() to setup per-CPU timers.  Can you please try
> > > > > > setting 'hint.hpet.0.per_cpu=0' at the loader prompt to see if
> > > > > > disabling the use of per-CPU timers allows you to boot?
> > > > > >       
> > > > > 
> > > > > Something has changed since the last time I generated a kernel with
> > > > > this option.
> > > > > 
> > > > > Now I get a NULL-pointer dereference in the kernel, doesn't matter
> > > > > whether I set the hint or not.
> > > > >     
> > > > 
> > > > OK, now that the startup has been fixed, I tried setting the hint at
> > > > the loader prompt, but the kenel hangs in exactly the same place as
> > > > before.  I actually booted twice to make certain I hadn't made a
> > > > typo when setting the hint.    
> > > 
> > > Humm, it shouldn't be calling bus_bind_intr() if the hint is set.  Actually,
> > > I guess it just binds them all to first CPU if per-CPU timers aren't set.
> > > Can you add debug printfs to hpet_attach() in sys/dev/acpica/acpi_hpet.c to
> > > narrow down which line in that function it hangs after?
> > > 
> > > Another option to try is to add the following to your kernel config:
> > > 
> > > options  	KTR
> > > options  	KTR_COMPILE=KTR_PROC
> > > options 		KTR_MASK=KTR_PROC
> > > options  	KTR_VERBOSE=1
> > > 
> > > this will spew a lot of crap to the screen, but if it stops spewing when it
> > > hangs then it might be tell us where the system is hung.  If you have any way
> > > to configure a serial console then this would also be useful even if it spews
> > > constantly when it is hung (assuming you could log the output of the serial
> > > console).
> > >   
> > 
> > I used the KTR options.
> > 
> > After the Timecounter "HPET" frequency 14318180 Hz quality 950 I see
> > 
> > cpu0 mi_switch: old thread 10000 (swapper)
> > cpu0 mi_switch: new thread 10022 (if_config_tqg_0)
> > cpu0 sleep_broadcast(0x80002f9a600, 0)
> > cpu0 msleep_spin: old thread 100022
> > cpu0 mi_switch: old thread 10022
> > cpu0 mi_switch: new thread 10016 (if_io_tqg_0)
> > cpu0 sleep_broadcast(0x80002f9a780, 0)
> > cpu0 msleep_spin: old thread 10016
> > cpu0 mi_switch: old thread 10016
> > cpu0 fork_exit: new thread 0x80004239510 (td_sched 0x8000042399d8, pid
> > 10, idle: cpu0)
> > 
> > And that's all that came out, really not very much at all.  
> 
> Ok, that seems odd.
> 
> Can you apply this patch and run with the KTR output still:
> 
> Index: sched_ule.c
> ===================================================================
> --- sched_ule.c	(revision 303397)
> +++ sched_ule.c	(working copy)
> _at__at_ -1904,6 +1904,13 _at__at_ sched_switch(struct thread *td, struct thread *new
>  	td->td_owepreempt = 0;
>  	if (!TD_IS_IDLETHREAD(td))
>  		tdq->tdq_switchcnt++;
> +
> +	if (td == &thread0 && cold) {
> +		printf("thread0 switching out (ts_cpu %d):\n", ts->ts_cpu);
> +		kdb_backtrace();
> +		MPASS(TD_IS_RUNNING(td));
> +	}
> +	
>  	/*
>  	 * The lock pointer in an idle thread should never change.  Reset it
>  	 * to CAN_RUN as well.
> _at__at_ -1920,6 +1927,9 _at__at_ sched_switch(struct thread *td, struct thread *new
>  		if (THREAD_CAN_MIGRATE(td) && !THREAD_CAN_SCHED(td, ts->ts_cpu))
>  			ts->ts_cpu = sched_pickcpu(td, 0);
>  #endif
> +		if (td == &thread0 && cold)
> +			printf("thread0 ts_cpu %d, cpuid %d\n", ts->ts_cpu,
> +			    cpuid);
>  		if (ts->ts_cpu == cpuid)
>  			tdq_runq_add(tdq, td, srqflag);
>  		else {
> 
> 

Well, now I know that ULE is a prerequiste for EARLY_AP_STARTUP!  I
wasn't aware of that.  I prefer BSD and that's the scheduler I did
the first tests with.

But with the ULE scheduler the system comes up all the way.

It would be nice if the BSD scheduler could also be modified to
work with EARLY_AP_STARTUP.

-- 
Gary Jennejohn