RFC: Hiding per-CPU kernel output behind bootverbose

[Warner Losh]

On Sat, Apr 21, 2018 at 2:30 PM, Colin Percival <cperciva at tarsnap.com>
wrote:

> On 04/21/18 12:52, Warner Losh wrote:
> >     On Sat, 21 Apr 2018 12:20:49 +0300
> >     Konstantin Belousov <kib at freebsd.org <mailto:kib at freebsd.org>>
> wrote:
> >     > On Sat, Apr 21, 2018 at 12:11:07AM +0000, Colin Percival wrote:
> >     > > Would it be sufficient for debugging purposes if I change the
> !bootverbose
> >     > > case from printing many lines of
> >     > >
> >     > > SMP: AP CPU #N Launched!
> >     > >
> >     > > to instead have a single
> >     > >
> >     > > SMP: Launching AP CPUs: 86 73 111 21 8 77 100 28 57 42 10 60 87
> [...]
> >     > >
> >     > > ?  (With each AP printing its number as it reaches the
> appropriate point?)
> >     > I am fine with the behaviour, but I am not sure how would you
> implement
> >     > this.  printf(9) buffers the output, you need to flush it somehow.
> >
> > I don't think either of these is true (the double buffered part,. nor the
> > buffered part). Well, they are both kinda true, but they don't matter.
> It's
> > all to make dmesg and friends work. There's other issues, but at this
> stage of
> > the boot we're single threaded and the CPUs that are launching take out
> a spin
> > lock.
>
> I just checked (by adding a 500 ms delay after each CPU prints its ID) and
> I
> can definitely see the individual numbers being printed on the console.
>
> > diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
> > index 3fcf7aa25152..06973b1ea6d5 100644
> > --- a/sys/x86/x86/mp_x86.c
> > +++ b/sys/x86/x86/mp_x86.c
> > @@ -1020,7 +1020,7 @@ init_secondary_tail(void)
> >         smp_cpus++;
> >
> >         CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
> > -       printf("SMP: AP CPU #%d Launched!\n", cpuid);
> > +       printf("%d%s", cpuid, smp_cpus == mp_ncpus ? "\n" : " ");
> >
> >         /* Determine if we are a logical CPU. */
> >         if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
> >
> > is enough to give them all to me on a single line. We'd need another
> printf
> > that says 'Starting APs: ' since otherwise we see:
> >
> > andom: unblocking device.
> > ioapic0 <Version 2.0> irqs 0-23 on motherboard
> > ioapic1 <Version 2.0> irqs 24-47 on motherboard
> > 1 8 10 20 2 19 11 12 22 4 14 23 16 13 3 18 5 17 21 9 15 6 7
> > Timecounter "TSC-low" frequency 1350029824 Hz quality 1000
> >
> > which doesn't make a lot of sense.
> >
> > Comments?
>
> Here's the patch I have, which prints a header before the CPU IDs:
>
> Index: sys/x86/x86/mp_x86.c
> ===================================================================
> --- sys/x86/x86/mp_x86.c        (revision 332638)
> +++ sys/x86/x86/mp_x86.c        (working copy)
> @@ -1020,7 +1020,9 @@
>         smp_cpus++;
>
>         CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
> -       printf("SMP: AP CPU #%d Launched!\n", cpuid);
> +       printf(" %d", cpuid);
> +       if (smp_cpus == mp_ncpus)
> +               printf("\n");
>
>         /* Determine if we are a logical CPU. */
>         if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)
> @@ -1508,6 +1510,7 @@
>
>         if (mp_ncpus == 1)
>                 return;
> +       printf("SMP: Launching AP CPUs:");
>         atomic_store_rel_int(&aps_ready, 1);
>         while (smp_started == 0)
>                 ia32_pause();
>
>
Here's the one that I have:

diff --git a/sys/x86/x86/mp_x86.c b/sys/x86/x86/mp_x86.c
index 3fcf7aa25152..4637243c4274 100644
--- a/sys/x86/x86/mp_x86.c
+++ b/sys/x86/x86/mp_x86.c
@@ -1020,7 +1020,8 @@ init_secondary_tail(void)
        smp_cpus++;

        CTR1(KTR_SMP, "SMP: AP CPU #%d Launched", cpuid);
-       printf("SMP: AP CPU #%d Launched!\n", cpuid);
+       printf("%s%d%s", smp_cpus == 1 ? "Launching APs: " : "",
+           cpuid, smp_cpus == mp_ncpus ? "\n" : " ");

        /* Determine if we are a logical CPU. */
        if (cpu_info[PCPU_GET(apic_id)].cpu_hyperthread)

which will print the results one at a time. Except when PRINTF_BUFR_SIZE is
defined (which is in the GENERIC config). Do you have it in the kernel
you're booting in the cloud?

Warner