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=-2.2 required=3.0 tests=HEADER_FROM_DIFFERENT_DOMAINS, MAILING_LIST_MULTI,SPF_HELO_NONE,SPF_PASS,URIBL_BLOCKED,USER_AGENT_SANE_1 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 EF189CA9EAF for ; Thu, 24 Oct 2019 12:46:38 +0000 (UTC) Received: from kanga.kvack.org (kanga.kvack.org [205.233.56.17]) by mail.kernel.org (Postfix) with ESMTP id AC6D6205C9 for ; Thu, 24 Oct 2019 12:46:38 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org AC6D6205C9 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=suse.com Authentication-Results: mail.kernel.org; spf=pass smtp.mailfrom=owner-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix) id 334A36B0005; Thu, 24 Oct 2019 08:46:38 -0400 (EDT) Received: by kanga.kvack.org (Postfix, from userid 40) id 2E4176B0006; Thu, 24 Oct 2019 08:46:38 -0400 (EDT) X-Delivered-To: int-list-linux-mm@kvack.org Received: by kanga.kvack.org (Postfix, from userid 63042) id 1F9E26B0007; Thu, 24 Oct 2019 08:46:38 -0400 (EDT) X-Delivered-To: linux-mm@kvack.org Received: from forelay.hostedemail.com (smtprelay0210.hostedemail.com [216.40.44.210]) by kanga.kvack.org (Postfix) with ESMTP id F3F916B0005 for ; Thu, 24 Oct 2019 08:46:37 -0400 (EDT) Received: from smtpin21.hostedemail.com (10.5.19.251.rfc1918.com [10.5.19.251]) by forelay03.hostedemail.com (Postfix) with SMTP id 9315D8249980 for ; Thu, 24 Oct 2019 12:46:37 +0000 (UTC) X-FDA: 76078652034.21.store07_1cb1f49351325 X-HE-Tag: store07_1cb1f49351325 X-Filterd-Recvd-Size: 3904 Received: from mx1.suse.de (mx2.suse.de [195.135.220.15]) by imf37.hostedemail.com (Postfix) with ESMTP for ; Thu, 24 Oct 2019 12:46:37 +0000 (UTC) X-Virus-Scanned: by amavisd-new at test-mx.suse.de Received: from relay2.suse.de (unknown [195.135.220.254]) by mx1.suse.de (Postfix) with ESMTP id 7CC71B1E5; Thu, 24 Oct 2019 12:46:35 +0000 (UTC) Date: Thu, 24 Oct 2019 14:46:34 +0200 From: Petr Mladek To: Alexander Potapenko Cc: Vegard Nossum , Sergey Senozhatsky , Steven Rostedt , Dmitry Vyukov , Linux Memory Management List Subject: Re: [PATCH RFC v1 05/26] printk_safe: externalize printk_context Message-ID: <20191024124634.hzsn74l7q4nl4mti@pathway.suse.cz> References:<20191018094304.37056-1-glider@google.com> <20191018094304.37056-6-glider@google.com> <20191021090925.3dcqukovauqsyw5w@pathway.suse.cz> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: NeoMutt/20170912 (1.9.0) X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4 Sender: owner-linux-mm@kvack.org Precedence: bulk X-Loop: owner-majordomo@kvack.org List-ID: On Wed 2019-10-23 19:57:39, Alexander Potapenko wrote: > On Mon, Oct 21, 2019 at 11:09 AM Petr Mladek wrote: > > > > On Fri 2019-10-18 11:42:43, glider@google.com wrote: > > > Petr Mladek suggested we use > > > this_cpu_read(printk_context) & PRINTK_SAFE_CONTEXT_MASK > > > instead of checking the spinlock status in kmsan_pr_err() > > > > I would like to understand why the check is needed. > > > > My guess is that it prevents a infinite recursion. > > Is this the case? It might be possible to debug this using > > trace_printk(). > This indeed used to prevent infinite recursion, however looks like the > check isn't needed anymore. > When I remove it, KMSAN doesn't hang, probably because printk is doing > a better job at deadlock prevention. Great. > What I'm seeing now is that e.g. in the following case: > ptr = kmalloc(sizeof(int), GFP_KERNEL); > if (ptr) > pr_info("true\n"); > else > pr_info("false\n"); > > KMSAN detects errors within pr_info(), namely in vprintk_store(). > If I understand correctly, printing from that point causes printk to > use the per-cpu buffer, which is flushed once we're done with the > original printing: > > [ 58.984971][ T8390] BUG: KMSAN: uninit-value in > kmsan_handle_vprintk+0xa0/0xf0 > ... > [ 59.061976][ C0] BUG: KMSAN: uninit-value in vsnprintf+0x3276/0x32b0 > ... > [ 59.062457][ C0] BUG: KMSAN: uninit-value in format_decode+0x17f/0x1900 > ... > [ 59.062961][ C0] BUG: KMSAN: uninit-value in format_decode+0x17f/0x1900 Please, do you have an explanation where the uninitialized values come from? Is it a false positive? Or is there really a bug how the printk() parameters are passed? > ... > [ 59.063338][ C0] Lost 6207 message(s)! This message comes from report_message_lost(). It means that many recursive messages did not fit into the limited per-CPU buffers. > So it turns out we'd better disable reporting under logbuf_lock, > otherwise these lost messages will confuse the developers. > Because the first pr_info() isn't called by KMSAN itself, the tool > still needs a way to know it's running inside printk. OK. Well, I still would like to understand why the recursive messages are printed at all. Is it a bug in the printk() code or a false positive? There should be no recursive messages if we fix the bug or make some annotations to prevent the false positives. That said, I am not completely against disabling the recursive messages. But it would be pity to hide some real bugs. Best Regards, Petr