From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-0.8 required=3.0 tests=DKIMWL_WL_HIGH,DKIM_SIGNED, DKIM_VALID,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,SPF_HELO_NONE, SPF_PASS autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 35AD6C3F2CD for ; Fri, 28 Feb 2020 13:41:41 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 02115246AF for ; Fri, 28 Feb 2020 13:41:40 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=default; t=1582897301; bh=TwfUtvkPqqYOcGsx/f4gNJx4/RSolDsZEeC2Q8LWQ9A=; h=Date:From:To:Cc:Subject:References:In-Reply-To:List-ID:From; b=S14IAJD7OLloWMisSotCxPi6gcxZotwyQyNbZvvY4oPbJxY7UkcUV6086Cu1wOXIe gdD4bdfFxTjU8QrRu9sUifI9Xp6pUsDQ61NzyKV4B20R2bZSw+HRfT+F7ckziFFo0h FHb/+SuvLqhBu20plj1YbXPR68Kar9MqXlpBUJ8M= Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1726860AbgB1Nlj (ORCPT ); Fri, 28 Feb 2020 08:41:39 -0500 Received: from mail.kernel.org ([198.145.29.99]:48158 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1725796AbgB1Nlj (ORCPT ); Fri, 28 Feb 2020 08:41:39 -0500 Received: from localhost (83-86-89-107.cable.dynamic.v4.ziggo.nl [83.86.89.107]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPSA id 245CE246AE; Fri, 28 Feb 2020 13:41:38 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=default; t=1582897298; bh=TwfUtvkPqqYOcGsx/f4gNJx4/RSolDsZEeC2Q8LWQ9A=; h=Date:From:To:Cc:Subject:References:In-Reply-To:From; b=mjDjFSZs3r7nBI2753b2lN/umKAxd2sNUTh5C7OXp0IWKu6Trx3RoxLpgpmDa9REu 79o0TX4PrVKMIjFhE1EMvItQ4ZwbuS/nKTgaZQPsiZ5FqjdQw9BEfYWGQ0Efqr5OY9 qABrr+rzOmtkoILb43SWO6hhdSI6jRqv0rWqPRak= Date: Fri, 28 Feb 2020 14:41:36 +0100 From: Greg Kroah-Hartman To: Petr Mladek Cc: Sergey Senozhatsky , Lech Perczak , Steven Rostedt , "linux-kernel@vger.kernel.org" , Theodore Ts'o , Arnd Bergmann , Krzysztof =?utf-8?Q?Drobi=C5=84ski?= , Pawel Lenkow , John Ogness , Tejun Heo , Peter Zijlstra Subject: Re: Regression in v4.19.106 breaking waking up of readers of /proc/kmsg and /dev/kmsg Message-ID: <20200228134136.GB3048814@kroah.com> References: <20200227123633.GB962932@kroah.com> <42d3ce5c-5ffe-8e17-32a3-5127a6c7c7d8@camlintechnologies.com> <20200228031306.GO122464@google.com> <20200228100416.6bwathdtopwat5wy@pathway.suse.cz> <20200228105836.GA2913504@kroah.com> <20200228113214.kew4xi5tkbo7bpou@pathway.suse.cz> <20200228130217.rj6qge2en26bdp7b@pathway.suse.cz> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: <20200228130217.rj6qge2en26bdp7b@pathway.suse.cz> Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Fri, Feb 28, 2020 at 02:02:17PM +0100, Petr Mladek wrote: > On Fri 2020-02-28 12:32:14, Petr Mladek wrote: > > On Fri 2020-02-28 11:58:36, Greg Kroah-Hartman wrote: > > > On Fri, Feb 28, 2020 at 11:04:16AM +0100, Petr Mladek wrote: > > > > On Fri 2020-02-28 12:13:06, Sergey Senozhatsky wrote: > > > > > Cc-ing Petr, Steven, John > > > > > > > > > > https://lore.kernel.org/lkml/e9358218-98c9-2866-8f40-5955d093dc1b@camlintechnologies.com > > > > > > > > > > On (20/02/27 14:08), Lech Perczak wrote: > > > > > > W dniu 27.02.2020 o 13:39, Lech Perczak pisze: > > > > > > > W dniu 27.02.2020 o 13:36, Greg Kroah-Hartman pisze: > > > > > > >> On Thu, Feb 27, 2020 at 11:09:49AM +0000, Lech Perczak wrote: > > > > > > >>> Hello, > > > > > > >>> > > > > > > >>> After upgrading kernel on our boards from v4.19.105 to v4.19.106 we found out that syslog fails to read the messages after ones read initially after opening /proc/kmsg just after booting. > > > > > > >>> I also found out, that output of 'dmesg --follow' also doesn't react on new printks appearing for whatever reason - to read new messages, reopening /proc/kmsg or /dev/kmsg was needed. > > > > > > >>> I bisected this down to commit 15341b1dd409749fa5625e4b632013b6ba81609b ("char/random: silence a lockdep splat with printk()"), and reverting it on top of v4.19.106 restored correct behaviour. > > > > > > >> That is really really odd. > > > > > > > Very odd it is indeed. > > > > > > >>> My test scenario for bisecting was: > > > > > > >>> 1. run 'dmesg --follow' as root > > > > > > >>> 2. run 'echo t > /proc/sysrq-trigger' > > > > > > >>> 3. If trace appears in dmesg output -> good, otherwise, bad. If trace doesn't appear in output of 'dmesg --follow', re-running it will show the trace. > > > > > > >>> > > > > > > > > I have reproduced the problem with a kernel based on v4.19.106 > > > > and I see the following in the log: > > > > > > > > [ 0.028250] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns > > > > [ 0.028263] random: get_random_bytes called from start_kernel+0x9e/0x4f6 with crng_init=0 > > > > [ 0.028268] setup_percpu: NR_CPUS:8192 nr_cpumask_bits:4 nr_cpu_ids:4 nr_node_ids:1 > > > > [ 0.028407] percpu: Embedded 44 pages/cpu s142216 r8192 d29816 u524288 > > > > [ 0.028411] pcpu-alloc: s142216 r8192 d29816 u524288 alloc=1*2097152 > > > > [ 0.028412] pcpu-alloc: [0] 0 1 2 3 > > > > > > > > Note that percpu stuff is initialized after printk_deferred(). And the > > > > deferred console is scheduled by: > > > > > > > > void defer_console_output(void) > > > > { > > > > preempt_disable(); > > > > __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT); > > > > irq_work_queue(this_cpu_ptr(&wake_up_klogd_work)); > > > > preempt_enable(); > > > > } > > > > > > > > I am afraid that the patch creates some mess via the non-initialized > > > > per-cpu variable. > > > > > > > > I see that x86 has some support for EARLY_PER_CPU stuff but it seems > > > > to be arch-specific. > > > > > > > > I do not see a reliable way to detect when per-cpu variables are > > > > initialized. Adding Tejun and PeterZ into CC if they have any > > > > idea. > > > > > > > > I suggest to revert the patch until we have some easy and safe solution. > > > > > > Ok, I'll do so, but why is this not an issue in 5.4.y and newer kernels? > > > > Good question. Well, there have been many changes in the random number > > subsystem initialization recently. My bet is that it is much harder to > > hit the warning there. > > OK, the problem has gone after I cherry-picked the commit > d55535232c3dbde9a523 ("random: move rand_initialize() earlier"). > I still see the warning but it is printed much later: > > [ 0.051846] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4 > [ 0.054070] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16 > [ 0.054281] random: get_random_bytes called from start_kernel+0x308/0x4fe with crng_init=0 > [ 0.054430] Console: colour dummy device 80x25 > > But I am not sure if it is safe to backport this patch into the old > stable kernel. > > Anyway, this fix would not be enough. The commit message mentions: > > Note that this warning may still remain for machines that do not have > UEFI RNG support (which initializes the RNG pools during setup_arch()), > or for x86 machines without RDRAND (or booting without "random.trust=on" > or CONFIG_RANDOM_TRUST_CPU=y). > > > So, I would still prefer to _revert_ the commit 15341b1dd409749f > ("char/random: silence a lockdep splat with printk()"). It calmed > down lockdep report. The real life danger is dubious. The warning > is printed early when the system is running on single CPU where > it could not race. Yeah, good idea, it's now reverted in my tree and will show up in the next release. thanks everyone for finding and working on this. greg k-h