From owner-freebsd-hackers@freebsd.org Sat Apr 21 20:35:45 2018 Return-Path: Delivered-To: freebsd-hackers@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id 42D50FA1848 for ; Sat, 21 Apr 2018 20:35:45 +0000 (UTC) (envelope-from wlosh@bsdimp.com) Received: from mail-it0-x22b.google.com (mail-it0-x22b.google.com [IPv6:2607:f8b0:4001:c0b::22b]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 1B0636D707 for ; Sat, 21 Apr 2018 20:35:44 +0000 (UTC) (envelope-from wlosh@bsdimp.com) Received: by mail-it0-x22b.google.com with SMTP id u62-v6so6274039ita.5 for ; Sat, 21 Apr 2018 13:35:44 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=bsdimp-com.20150623.gappssmtp.com; s=20150623; h=mime-version:sender:in-reply-to:references:from:date:message-id :subject:to:cc; bh=WzgX1/zyKtI7/BYecSEe1U/mZhftQR5XsP4geDN9jbY=; b=NSvSYtxLbeBAI3IThWRLt+8w8L9aaswkNHuDyMYWvUNyFL+WwMSxjOVD3ut9L7mim5 UUQseS8AigvKkuWOaE5zI1nyG8r3qdxDHglBQ7+MiN7TtWQfLLSDbk43OMeU9m5WSFGI dEhKJWzev+3iARnVbF/I34SGEh3Ma3XjhbXNJlcFohRwIpp6JTYsJ/k0tf704QKTusCa 84JqTTY8q36lC9mD60Z8zFp8pjFOI88jZ5lnekU5wmveeVszU1aAJNm7UQqqdaHO5lgF Y6in1LzPd9FqFz/v6jJV7/KLLr5U6gf8B5I7prVFY+b3x3kLjZiG8m5X9EYtgKFQRhZN /Tkw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:sender:in-reply-to:references:from :date:message-id:subject:to:cc; bh=WzgX1/zyKtI7/BYecSEe1U/mZhftQR5XsP4geDN9jbY=; b=LQmWH31FNuIGS/ElxwJHrScGHAzcTQH+J/bzKosxpJ/3LJbxwuO4tr3RRoHm7h+uGo kazEa/zcmqzVSi7bhR/CGXMoIIoH5C9d7m+uiTfESwVJvroq64oTqjA6arpIJlm0TIO5 WYtSHgs8BiMlOMpNEgCXxOeByHuGsQwSFbss3vIoL7805akgekTDN2HYeTtv79LPMkYU sIWebEMOQ2FPjzEyCW8lQzKyeD0xoYjkQvD5q9P37b3qn31hMtFMuOkDl5m98ZEU6siU 79E4P3F7lEO1g3d4dY99PuQTer5Uv2xq/jHlbM8u6Iea8d1+R+uMYTPetvXvjnt+KCX3 bjJA== X-Gm-Message-State: ALQs6tD4JRVuJbWIWAvg6A8BJWSk23kRIHa6FDfmhhauUS1V2urzfHdx X8G9HUpXwxeOo9AfFxpW+VpV1Of5lXntGAlGwdYT9iDn X-Google-Smtp-Source: AIpwx48e4gntTbyQO/84Hg6YbGiHwEJnouvK4zzR3Gt0FICCrzf5KHmL3Um4pjjVVkfQc7rB33csrVeSFRmNwUKWQDQ= X-Received: by 2002:a24:42c6:: with SMTP id i189-v6mr7952849itb.73.1524342942588; Sat, 21 Apr 2018 13:35:42 -0700 (PDT) MIME-Version: 1.0 Sender: wlosh@bsdimp.com Received: by 2002:a4f:a604:0:0:0:0:0 with HTTP; Sat, 21 Apr 2018 13:35:42 -0700 (PDT) X-Originating-IP: [2603:300b:6:5100:1052:acc7:f9de:2b6d] 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> <20180419214550.GF6887@kib.kiev.ua> <01000162e58a466e-98f0305b-1723-467a-bc49-342c3fa9fc5b-000000@email.amazonses.com> <20180421092049.GM6887@kib.kiev.ua> <20180421123544.56d7e690@ernst.home> <01000162e9e66255-b8ae47df-b48c-4512-a042-48df5604914b-000000@email.amazonses.com> From: Warner Losh Date: Sat, 21 Apr 2018 14:35:42 -0600 X-Google-Sender-Auth: Jxef69qiqL8lBeCvWaAqdSTUmMA Message-ID: Subject: Re: RFC: Hiding per-CPU kernel output behind bootverbose To: Colin Percival Cc: gljennjohn@gmail.com, Konstantin Belousov , "freebsd-hackers@freebsd.org" , Conrad Meyer Content-Type: text/plain; charset="UTF-8" X-Content-Filtered-By: Mailman/MimeDel 2.1.25 X-BeenThere: freebsd-hackers@freebsd.org X-Mailman-Version: 2.1.25 Precedence: list List-Id: Technical Discussions relating to FreeBSD List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 21 Apr 2018 20:35:45 -0000 On Sat, Apr 21, 2018 at 2:30 PM, Colin Percival wrote: > On 04/21/18 12:52, Warner Losh wrote: > > On Sat, 21 Apr 2018 12:20:49 +0300 > > Konstantin Belousov > > 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 irqs 0-23 on motherboard > > ioapic1 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