Date: Sat, 21 Apr 2018 14:35:42 -0600 From: Warner Losh <imp@bsdimp.com> To: Colin Percival <cperciva@tarsnap.com> Cc: gljennjohn@gmail.com, Konstantin Belousov <kib@freebsd.org>, "freebsd-hackers@freebsd.org" <freebsd-hackers@freebsd.org>, Conrad Meyer <cem@freebsd.org> Subject: Re: RFC: Hiding per-CPU kernel output behind bootverbose Message-ID: <CANCZdfr1fXa6KCW8YV_i2737X9K3Sp=seLwjEerU_wrkmgHhgQ@mail.gmail.com> In-Reply-To: <01000162e9e66255-b8ae47df-b48c-4512-a042-48df5604914b-000000@email.amazonses.com> References: <01000162df15f856-1e5d2641-2a72-4250-8d8e-adcd47bc5db4-000000@email.amazonses.com> <20180419204405.GE6887@kib.kiev.ua> <CAG6CVpUerOo%2B55nJq61Hy83RYpbOZS6puEDuemspfNS12urZZw@mail.gmail.com> <20180419214550.GF6887@kib.kiev.ua> <01000162e58a466e-98f0305b-1723-467a-bc49-342c3fa9fc5b-000000@email.amazonses.com> <20180421092049.GM6887@kib.kiev.ua> <20180421123544.56d7e690@ernst.home> <CANCZdfpi7fZky9VC_TZWhm4uuwnV1N=m3pO1MmDs9GKYJZgSwg@mail.gmail.com> <01000162e9e66255-b8ae47df-b48c-4512-a042-48df5604914b-000000@email.amazonses.com>
next in thread | previous in thread | raw e-mail | index | archive | help
On Sat, Apr 21, 2018 at 2:30 PM, Colin Percival <cperciva@tarsnap.com>
wrote:
> On 04/21/18 12:52, Warner Losh wrote:
> > On Sat, 21 Apr 2018 12:20:49 +0300
> > Konstantin Belousov <kib@freebsd.org <mailto:kib@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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CANCZdfr1fXa6KCW8YV_i2737X9K3Sp=seLwjEerU_wrkmgHhgQ>