From patchwork Wed May 23 02:35:16 2012 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: Anton Vorontsov X-Patchwork-Id: 8892 Return-Path: X-Original-To: patchwork@peony.canonical.com Delivered-To: patchwork@peony.canonical.com Received: from fiordland.canonical.com (fiordland.canonical.com [91.189.94.145]) by peony.canonical.com (Postfix) with ESMTP id 9D97423E49 for ; Wed, 23 May 2012 02:36:58 +0000 (UTC) Received: from mail-gg0-f180.google.com (mail-gg0-f180.google.com [209.85.161.180]) by fiordland.canonical.com (Postfix) with ESMTP id 44B9DA18DA1 for ; Wed, 23 May 2012 02:36:58 +0000 (UTC) Received: by ggnf1 with SMTP id f1so7520434ggn.11 for ; Tue, 22 May 2012 19:36:57 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20120113; h=x-forwarded-to:x-forwarded-for:delivered-to:received-spf:date:from :to:cc:subject:message-id:references:mime-version:content-type :content-disposition:content-transfer-encoding:in-reply-to :user-agent:x-gm-message-state; bh=wtSNL5QMCXOpMmhVK4ZiIcdC5PjnzoNinFXbTclPta4=; b=Tfjo3Hl0/ApR9bzihfVuPTI0fHrNQiw/4TfLxoZcbhMRNVIlasNFD98QBNWA2gM8iU XJki23lxVkP6bjW2KhPUG9UhSx42Bl0XWwCYcYMGr0cDocjStL46oKzvDbBB3q4jidkU bPIEIAox/vqbAsxb40JyHmkqO3mE2cmG+J3nH+dNWwDu9JB4+s/zkLipOfeVTd7Oh/Wl LaAT/Vn0Yq2C4i8sYUZRN/gWByFfl5umLqXWFgPfy5443Jr1j+isx2zaaN+RP2yECnio n1BDgtvtWRqmWVkgP+Qs49Z2egQEX/Ul0qSnX9CEwBHHE9fSIqWi5uzsj4YYkl+q+ya7 +cYA== Received: by 10.42.89.72 with SMTP id f8mr16589371icm.33.1337740617385; Tue, 22 May 2012 19:36:57 -0700 (PDT) X-Forwarded-To: linaro-patchwork@canonical.com X-Forwarded-For: patch@linaro.org linaro-patchwork@canonical.com Delivered-To: patches@linaro.org Received: by 10.231.35.72 with SMTP id o8csp409323ibd; Tue, 22 May 2012 19:36:56 -0700 (PDT) Received: by 10.68.196.201 with SMTP id io9mr4743219pbc.126.1337740615780; Tue, 22 May 2012 19:36:55 -0700 (PDT) Received: from mail-pz0-f50.google.com (mail-pz0-f50.google.com [209.85.210.50]) by mx.google.com with ESMTPS id ny9si168651pbb.117.2012.05.22.19.36.55 (version=TLSv1/SSLv3 cipher=OTHER); Tue, 22 May 2012 19:36:55 -0700 (PDT) Received-SPF: neutral (google.com: 209.85.210.50 is neither permitted nor denied by best guess record for domain of anton.vorontsov@linaro.org) client-ip=209.85.210.50; Authentication-Results: mx.google.com; spf=neutral (google.com: 209.85.210.50 is neither permitted nor denied by best guess record for domain of anton.vorontsov@linaro.org) smtp.mail=anton.vorontsov@linaro.org Received: by danh15 with SMTP id h15so10794467dan.37 for ; Tue, 22 May 2012 19:36:55 -0700 (PDT) Received: by 10.68.235.102 with SMTP id ul6mr4022380pbc.152.1337740615129; Tue, 22 May 2012 19:36:55 -0700 (PDT) Received: from localhost (ip-64-134-232-104.public.wayport.net. [64.134.232.104]) by mx.google.com with ESMTPS id mt9sm196625pbb.14.2012.05.22.19.36.51 (version=TLSv1/SSLv3 cipher=OTHER); Tue, 22 May 2012 19:36:54 -0700 (PDT) Date: Tue, 22 May 2012 19:35:16 -0700 From: Anton Vorontsov To: Linus Torvalds , Colin Cross Cc: Greg Kroah-Hartman , Kees Cook , Tony Luck , Arnd Bergmann , John Stultz , Shuah Khan , arve@android.com, Rebecca Schultz Zavin , Jesper Juhl , Randy Dunlap , Stephen Boyd , Thomas Meyer , Andrew Morton , Marco Stornelli , WANG Cong , linux-kernel@vger.kernel.org, devel@driverdev.osuosl.org, linaro-kernel@lists.linaro.org, patches@linaro.org, kernel-team@android.com, Ingo Molnar , Peter Zijlstra , Rusty Russell Subject: [PATCH/RFC] Make sure linux_banner is the first message in log_buf Message-ID: <20120523023513.GA22235@lizard> References: <20120522141717.GA31574@lizard> <1337696279-8994-3-git-send-email-anton.vorontsov@linaro.org> MIME-Version: 1.0 Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.5.21 (2010-09-15) X-Gm-Message-State: ALoCoQkyAzFzZj7ZDviledIRFrY3Db6rfg2hycrfWig12FW5lCiqeyDv/lp/NXqeRjfR+tNfOk9Y For scripting it is important to have a consistent header that tells where the kernel log starts. At least to me it always seemed that linux_banner served this purpose. Though, an early kernel code may print things before the Linux banner. When we parse logs from multiple boots grabbed from serial or pstore consoles, we might miss these messages. The only bulletproof, arch-independent and whatnot way to ensure that we have the banner printed first is to print it from the printk itself. The resulting code looks quite obvious. Sure, this doesn't address bootloader or low-level very early arch- dependent console output that goes to the HW directly, but there's nothing we can do about it (in pstore console we don't see them anyway). Signed-off-by: Anton Vorontsov --- On Tue, May 22, 2012 at 11:06:29AM -0700, Colin Cross wrote: > > > > Now to get the only most recent messages we can do: > > > >        tac ramoops-console | sed '/^Linux version.*(.*@.*)/ q' | tac > > Lots of problems with this. > "Linux version ..." is not the first line in the console log on my > devices, there are messages before it that shouldn't be dropped by > automated logs collectors using this regexp. Ouch. This seems not right. And the same issue exist if we collect logs from e.g. serial console, there (unlike to just reading /proc/kmsg) we don't know where current kernel's messages start, and more than that, in serial console case we don't know where the messages end (unlike to pstore). So it's a general problem, not only related to pstore. But we can fix this. How about the patch below? > There is a timestamp before "Linux version", so the regexp never matches. This is also fixable. tac ramoops-console | sed '/\(^\|] \)Linux version.*(.*@.*)/ q' | tac > There is often no newline at the end of the old log, so if "Linux > version" was the first line in the log, it would still not get > matched. Yeah, true. We will have to add at least a new line in pstore. > Relying on the first line in the log to not change seems likely to > cause problems for scripts in the future. Why not separate them where > the code knows for sure that the old log is ending and the new log is > starting? I'm not opposed to a header (or a footer) at all, and you're right, one of them is obviously needed. I just don't like introducing yet another ad-hoc header format that we will only use for pstore/console. We have "start of the Linux kernel log" header, so let's try to use it?.. If it is not suitable for us today, let's think how to fix that, and if anything, we can fall-back to your plan, i.e. adding our own footer (or zapping prz) at boot time. But so far I can see this solution: 1. Make sure we printk linux_banner as the first string in the log_buf (this patch). This is an improvement not only for pstore; 2. In pstore, add a newline to previous' boot log (we'll add it unconditinally, so that it we won't loose the information about the last new line :-). init/main.c | 1 - kernel/printk.c | 3 +++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/init/main.c b/init/main.c index 44b2433..df3711d 100644 --- a/init/main.c +++ b/init/main.c @@ -492,7 +492,6 @@ asmlinkage void __init start_kernel(void) tick_init(); boot_cpu_init(); page_address_init(); - printk(KERN_NOTICE "%s", linux_banner); setup_arch(&command_line); mm_init_owner(&init_mm, &init_task); mm_init_cpumask(&init_mm); diff --git a/kernel/printk.c b/kernel/printk.c index b663c2c..1e1461b 100644 --- a/kernel/printk.c +++ b/kernel/printk.c @@ -749,6 +749,9 @@ asmlinkage int printk(const char *fmt, ...) va_list args; int r; + /* Make sure linux_banner is kernel's first message. */ + printk_once(KERN_NOTICE "%s", linux_banner); + #ifdef CONFIG_KGDB_KDB if (unlikely(kdb_trap_printk)) { va_start(args, fmt);