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 Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id 912E4C4332F for ; Wed, 9 Nov 2022 20:31:50 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S231599AbiKIUbs (ORCPT ); Wed, 9 Nov 2022 15:31:48 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:37522 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S231572AbiKIUbe (ORCPT ); Wed, 9 Nov 2022 15:31:34 -0500 Received: from relay10.mail.gandi.net (relay10.mail.gandi.net [217.70.178.230]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 8B6A5303DE; Wed, 9 Nov 2022 12:31:32 -0800 (PST) Received: (Authenticated sender: alexandre.belloni@bootlin.com) by mail.gandi.net (Postfix) with ESMTPSA id 2D9A4240006; Wed, 9 Nov 2022 20:31:27 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=bootlin.com; s=gm1; t=1668025890; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=8ETbXvYBEg/yFeCJeEL3kpLNlGNar65IVNcGJHPKe/k=; b=jlmmtfINw0vPXlA+sXdDn828teotLJMLzUB2TIMMRvLOXEz5LVAUuOhICrEhAyyAuHzI0C 1H0NoF3Uj8B10hI41fyElJGADvVxiGmV9SUkcmPGLQl6ISZ+lpWEOeFa1VRvJohF10u1jj qKqX/oNf4H6yPWCT5SW7Xxb+0aItmxZFUbl1oIc6C6uMyYIME02TJIW7r6jEI36DyWj42S 5pnSXTXxFEWjVnPaT3UnvKVrdqZqvItDqY0twx+O1b8ikENzAsX/OeL3imrnPMfztiWvKB 0eVRvVTB892r3m4poWJ6cYIX1R+Ge1WLB3eywTH0nSFXDpnphIL0WxzWvVtqnw== Date: Wed, 9 Nov 2022 21:31:27 +0100 From: Alexandre Belloni To: Alexandru Elisei Cc: a.zummo@towertech.it, linux-rtc@vger.kernel.org, linux-kernel@vger.kernel.org, ardb@kernel.org, linux-efi@vger.kernel.org, catalin.marinas@arm.com, will@kernel.org, linux-arm-kernel@lists.infradead.org Subject: Re: [BUG] rtc-efi: Error in efi.get_time() spams dmesg with error message Message-ID: References: MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 09/11/2022 14:51:19+0000, Alexandru Elisei wrote: > Hi, > > On Tue, Nov 08, 2022 at 10:41:18PM +0100, Alexandre Belloni wrote: > > On 08/11/2022 10:55:15+0000, Alexandru Elisei wrote: > > > Hi, > > > > > > Commit d3549a938b73 ("efi/arm64: libstub: avoid SetVirtualAddressMap() when > > > possible") exposed a firmware error on an Ampere Altra machine that was > > > causing the machine to panic. Then commit 23715a26c8d8 ("arm64: efi: > > > Recover from synchronous exceptions occurring in firmware") made the EFI > > > exception non-fatal, and disabled runtime services when the exception > > > happens. The interaction between those two patches are being discussed in a > > > separate thread [1], but that should be orthogonal to this. > > > > > > Now efi.get_time() fails and each time an error message is printed to > > > dmesg, which happens several times a second and clutters dmesg > > > unnecessarily, to the point it becomes unusable. > > > > > > I was wondering if it would be possible to turn dev_err() into a > > > dev_WARN_ONCE() or do something to avoid this issue. Tried to replace > > > dev_err() with dev_err_ratelimited(), and the error message was displayed > > > less often (about once per second), but dmesg was still being cluttered. > > > > > > > The question this raise is what is actually trying to read the RTC this > > often? > > > > This should be read once at boot and maybe every time you wake up from > > suspend but there is no real reason to read it multiple times per > > seconds. > > Reverted the commit the exposed the firmware bug, which means rtc-efi works as > it should. Added these debug statements to check how many times efi_read_time() > is called if there are no errors: > > --- a/drivers/rtc/rtc-efi.c > +++ b/drivers/rtc/rtc-efi.c > @@ -154,6 +154,7 @@ static int efi_set_alarm(struct device *dev, struct rtc_wkalrm *wkalrm) > return status == EFI_SUCCESS ? 0 : -EINVAL; > } > > +static unsigned long i = 0; > static int efi_read_time(struct device *dev, struct rtc_time *tm) > { > efi_status_t status; > @@ -162,6 +163,9 @@ static int efi_read_time(struct device *dev, struct rtc_time *tm) > > status = efi.get_time(&eft, &cap); > > + i++; > + pr_info("%s: Call number %lu\n", __func__, i); > + > if (status != EFI_SUCCESS) { > /* should never happen */ > dev_err(dev, "can't read time\n"); > > The function gets called 3 times, twice during boot and once after. I would say > that efi_read_time() gets called so many times because it fails. > It should really get called only once, at device registration when CONFIG_RTC_HCTOSYS is set (which I despise): https://elixir.bootlin.com/linux/latest/source/drivers/rtc/class.c#L431 Could you maybe use dump_stack() ? -- Alexandre Belloni, co-owner and COO, Bootlin Embedded Linux and Kernel engineering https://bootlin.com 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 Received: from bombadil.infradead.org (bombadil.infradead.org [198.137.202.133]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.lore.kernel.org (Postfix) with ESMTPS id 5F0F7C4332F for ; Wed, 9 Nov 2022 20:32:40 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=lists.infradead.org; s=bombadil.20210309; h=Sender: Content-Transfer-Encoding:Content-Type:List-Subscribe:List-Help:List-Post: List-Archive:List-Unsubscribe:List-Id:In-Reply-To:MIME-Version:References: Message-ID:Subject:Cc:To:From:Date:Reply-To:Content-ID:Content-Description: Resent-Date:Resent-From:Resent-Sender:Resent-To:Resent-Cc:Resent-Message-ID: List-Owner; bh=ZDVhPGzkOsDjClXQVfErYwcViZNzttTjZm5BH2lgQ4U=; b=ONugRp/t8Lql04 47ju1oIicy/DOVnm3FF1WIAXu9XSLd8Uez/0RElRhGHcNOtOCyRc4mtS8A/ZRo+2TqnRvj7swqBOc 7HE/50yJbtH3dBfXcGWNPxPpuqf438AxyFbL6UGwOgsIZbJ7f6gCP32G/EFMbSgRzq1jL/2gbt2qY DkMVNfBDG3uZ2TVus4ZXlJfnuyoThiaqwHQc/z4deev9dT/MtqOyH/I/7ZvuqeMrtPxeRPteI1QGo onswGuseRWgsKvqP3UJw7e35bY7gDeGX5rCbSoSntMN47wYP0z3L2Mp05qAVrMJUqmT2COqMC+U/c R/kokTLq3rD+LXoO4z2g==; Received: from localhost ([::1] helo=bombadil.infradead.org) by bombadil.infradead.org with esmtp (Exim 4.94.2 #2 (Red Hat Linux)) id 1osrjX-00H1as-6t; Wed, 09 Nov 2022 20:31:39 +0000 Received: from relay10.mail.gandi.net ([217.70.178.230]) by bombadil.infradead.org with esmtps (Exim 4.94.2 #2 (Red Hat Linux)) id 1osrjT-00H1Ym-GS for linux-arm-kernel@lists.infradead.org; Wed, 09 Nov 2022 20:31:37 +0000 Received: (Authenticated sender: alexandre.belloni@bootlin.com) by mail.gandi.net (Postfix) with ESMTPSA id 2D9A4240006; Wed, 9 Nov 2022 20:31:27 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=bootlin.com; s=gm1; t=1668025890; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: in-reply-to:in-reply-to:references:references; bh=8ETbXvYBEg/yFeCJeEL3kpLNlGNar65IVNcGJHPKe/k=; b=jlmmtfINw0vPXlA+sXdDn828teotLJMLzUB2TIMMRvLOXEz5LVAUuOhICrEhAyyAuHzI0C 1H0NoF3Uj8B10hI41fyElJGADvVxiGmV9SUkcmPGLQl6ISZ+lpWEOeFa1VRvJohF10u1jj qKqX/oNf4H6yPWCT5SW7Xxb+0aItmxZFUbl1oIc6C6uMyYIME02TJIW7r6jEI36DyWj42S 5pnSXTXxFEWjVnPaT3UnvKVrdqZqvItDqY0twx+O1b8ikENzAsX/OeL3imrnPMfztiWvKB 0eVRvVTB892r3m4poWJ6cYIX1R+Ge1WLB3eywTH0nSFXDpnphIL0WxzWvVtqnw== Date: Wed, 9 Nov 2022 21:31:27 +0100 From: Alexandre Belloni To: Alexandru Elisei Cc: a.zummo@towertech.it, linux-rtc@vger.kernel.org, linux-kernel@vger.kernel.org, ardb@kernel.org, linux-efi@vger.kernel.org, catalin.marinas@arm.com, will@kernel.org, linux-arm-kernel@lists.infradead.org Subject: Re: [BUG] rtc-efi: Error in efi.get_time() spams dmesg with error message Message-ID: References: MIME-Version: 1.0 Content-Disposition: inline In-Reply-To: X-CRM114-Version: 20100106-BlameMichelson ( TRE 0.8.0 (BSD) ) MR-646709E3 X-CRM114-CacheID: sfid-20221109_123135_974876_A4D10202 X-CRM114-Status: GOOD ( 31.64 ) X-BeenThere: linux-arm-kernel@lists.infradead.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit Sender: "linux-arm-kernel" Errors-To: linux-arm-kernel-bounces+linux-arm-kernel=archiver.kernel.org@lists.infradead.org On 09/11/2022 14:51:19+0000, Alexandru Elisei wrote: > Hi, > > On Tue, Nov 08, 2022 at 10:41:18PM +0100, Alexandre Belloni wrote: > > On 08/11/2022 10:55:15+0000, Alexandru Elisei wrote: > > > Hi, > > > > > > Commit d3549a938b73 ("efi/arm64: libstub: avoid SetVirtualAddressMap() when > > > possible") exposed a firmware error on an Ampere Altra machine that was > > > causing the machine to panic. Then commit 23715a26c8d8 ("arm64: efi: > > > Recover from synchronous exceptions occurring in firmware") made the EFI > > > exception non-fatal, and disabled runtime services when the exception > > > happens. The interaction between those two patches are being discussed in a > > > separate thread [1], but that should be orthogonal to this. > > > > > > Now efi.get_time() fails and each time an error message is printed to > > > dmesg, which happens several times a second and clutters dmesg > > > unnecessarily, to the point it becomes unusable. > > > > > > I was wondering if it would be possible to turn dev_err() into a > > > dev_WARN_ONCE() or do something to avoid this issue. Tried to replace > > > dev_err() with dev_err_ratelimited(), and the error message was displayed > > > less often (about once per second), but dmesg was still being cluttered. > > > > > > > The question this raise is what is actually trying to read the RTC this > > often? > > > > This should be read once at boot and maybe every time you wake up from > > suspend but there is no real reason to read it multiple times per > > seconds. > > Reverted the commit the exposed the firmware bug, which means rtc-efi works as > it should. Added these debug statements to check how many times efi_read_time() > is called if there are no errors: > > --- a/drivers/rtc/rtc-efi.c > +++ b/drivers/rtc/rtc-efi.c > @@ -154,6 +154,7 @@ static int efi_set_alarm(struct device *dev, struct rtc_wkalrm *wkalrm) > return status == EFI_SUCCESS ? 0 : -EINVAL; > } > > +static unsigned long i = 0; > static int efi_read_time(struct device *dev, struct rtc_time *tm) > { > efi_status_t status; > @@ -162,6 +163,9 @@ static int efi_read_time(struct device *dev, struct rtc_time *tm) > > status = efi.get_time(&eft, &cap); > > + i++; > + pr_info("%s: Call number %lu\n", __func__, i); > + > if (status != EFI_SUCCESS) { > /* should never happen */ > dev_err(dev, "can't read time\n"); > > The function gets called 3 times, twice during boot and once after. I would say > that efi_read_time() gets called so many times because it fails. > It should really get called only once, at device registration when CONFIG_RTC_HCTOSYS is set (which I despise): https://elixir.bootlin.com/linux/latest/source/drivers/rtc/class.c#L431 Could you maybe use dump_stack() ? -- Alexandre Belloni, co-owner and COO, Bootlin Embedded Linux and Kernel engineering https://bootlin.com _______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel