From patchwork Mon Nov 14 23:28:26 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Paul E. McKenney" X-Patchwork-Id: 20091 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a5d:6687:0:0:0:0:0 with SMTP id l7csp2421651wru; Mon, 14 Nov 2022 15:41:15 -0800 (PST) X-Google-Smtp-Source: AA0mqf5nsC9y5yz1p/9lqaoD3f4ri3tcrnH1XCGM6LTNLan1NU+MRFSFHTUa8uWtiiduVUQnqEIV X-Received: by 2002:aa7:dc03:0:b0:462:6a0c:cfa with SMTP id b3-20020aa7dc03000000b004626a0c0cfamr12990947edu.349.1668469275551; Mon, 14 Nov 2022 15:41:15 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1668469275; cv=none; d=google.com; s=arc-20160816; b=K+VYEvlPSMJ7nFm2SzV63XuupjCTZDgWyjyeKf3m0jqQpucjxbLNUrWcjepVdCvU02 kINzJhzGWYqB9XnR0AIi6etgRhyx3LW4V6DpJ6L14nh7kHx7W/o8VyW45OVCEcIKEG/N eoFtTE5yUW6+YEg/or47sWvisAhuVKtOe3ghd2GH7LQljT+1ibM6XtkvleyZJ9abFs29 RJDMgvph51cwwoFyy4KACzNQLSHMPT3caYO2h6sZvGNAP43pLwPab0y/VFGpBu6HWT9s AUHvG5qNr7KiFpqcOL3xhAuosRFKthcj4KEDL0tm4h5ZbHS3JqNGjwMAOZmeIJXit2oX C1dQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:content-transfer-encoding:mime-version :references:in-reply-to:message-id:date:subject:cc:to:from :dkim-signature; bh=z3uRyW9e1y9P6ZGvduzRozd7XFV95okur8nQ8Syr3c4=; b=wKhnLTytpLY8jJ6NFMHAF57KXDhhFPc30sBBSsNZP5YOypC1SCk4HU/0osYGpTsN87 8+JkbvOxtz3x5kV9bxTzZXcz/Y/SxvnH+YYy7K/M8dycHXBN4TAZphaRcY/b9OW3NgiJ mqgZhuF4ob1SQR74M2FqDtitGsBjyPZVrTuhhpUvrtTmfJjYw6Gdx8v0OLx9jR0tApAC Kvk1dy221qcVxWFJA4fDQKmHaE4Z6nL49+OnXbHnW3lvG+ZQMFEvdt58g/k11P65NnlJ XQTS/XSVsDjkThTKgf64i0HJLl8PDj3KZECy4n/ZiEZ//Zdk8ni2ifKpngNjUySmUYTP kNBw== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b=U240jKJW; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id q15-20020a1709064c8f00b0078d550c0272si8377144eju.269.2022.11.14.15.40.51; Mon, 14 Nov 2022 15:41:15 -0800 (PST) Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20; Authentication-Results: mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b=U240jKJW; spf=pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org; dmarc=pass (p=NONE sp=NONE dis=NONE) header.from=kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S237118AbiKNX2s (ORCPT + 99 others); Mon, 14 Nov 2022 18:28:48 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:40338 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S236856AbiKNX2e (ORCPT ); Mon, 14 Nov 2022 18:28:34 -0500 Received: from ams.source.kernel.org (ams.source.kernel.org [IPv6:2604:1380:4601:e00::1]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id AD1E92AB for ; Mon, 14 Nov 2022 15:28:31 -0800 (PST) Received: from smtp.kernel.org (relay.kernel.org [52.25.139.140]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by ams.source.kernel.org (Postfix) with ESMTPS id 4E647B8133B for ; Mon, 14 Nov 2022 23:28:30 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id D9CD9C433C1; Mon, 14 Nov 2022 23:28:28 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1668468508; bh=yWPbFrTyk/Pat7LzvV8D6SH/ODiafdLuMh9HWpa0Mu0=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=U240jKJW3sGDmowlbl/h6Mpt1cLwUTBap5/9nPpthjXqufdIfx3lsVzDx64c4n4U6 lqhJEx33abLRxkuqwVzQ0P+CIA0CtLmgw3pa6ppp9r3SQYG2RZrFPcvunWrMMkT95W iLXI+bL723pmkqztOnufnepz4/RqzkbCmRynMvy62SH7ClaXgmkTNpzHwEUahn/6PE KYXQJtyBlNztfhYW1XsJbTX3Q0w2LK6rUEJu4AmRQWQqtTHjD+x0o70rT5b9MuS836 2z+L/5AI0wxGBRFD34YsWct/iuPJyN2g5d5EV4cXYCqFnGj9mgdfE0grCP0u4rPekl gJFxfBgHRSvng== Received: by paulmck-ThinkPad-P17-Gen-1.home (Postfix, from userid 1000) id 940665C1718; Mon, 14 Nov 2022 15:28:28 -0800 (PST) From: "Paul E. McKenney" To: tglx@linutronix.de Cc: linux-kernel@vger.kernel.org, john.stultz@linaro.org, sboyd@kernel.org, corbet@lwn.net, Mark.Rutland@arm.com, maz@kernel.org, kernel-team@meta.com, neeraju@codeaurora.org, ak@linux.intel.com, feng.tang@intel.com, zhengjun.xing@intel.com, "Paul E. McKenney" , Waiman Long , John Stultz Subject: [PATCH clocksource 3/3] clocksource: Exponential backoff for load-induced bogus watchdog reads Date: Mon, 14 Nov 2022 15:28:26 -0800 Message-Id: <20221114232827.835599-3-paulmck@kernel.org> X-Mailer: git-send-email 2.31.1.189.g2e36527f23 In-Reply-To: <20221114232807.GA834337@paulmck-ThinkPad-P17-Gen-1> References: <20221114232807.GA834337@paulmck-ThinkPad-P17-Gen-1> MIME-Version: 1.0 X-Spam-Status: No, score=-7.1 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,RCVD_IN_DNSWL_HI, SPF_HELO_NONE,SPF_PASS autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on lindbergh.monkeyblade.net Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org X-getmail-retrieved-from-mailbox: =?utf-8?q?INBOX?= X-GMAIL-THRID: =?utf-8?q?1749516839159564580?= X-GMAIL-MSGID: =?utf-8?q?1749516839159564580?= The clocksource watchdog will reject measurements that are excessively delayed, that is, by more than 1.5 seconds beyond the intended 0.5-second watchdog interval. On an extremely busy system, this can result in a console message being printed every two seconds. This is excessively noisy for a non-error condition. Therefore, apply exponential backoff to these messages. This exponential backoff is capped at 1024 times the watchdog interval, which comes to not quite one message per ten minutes. Please note that the bogus watchdog reads that occur when the watchdog interval is less than 0.125 seconds are still printed unconditionally because these likely correspond to a serious error condition in the timer code or hardware. [ paulmck: Apply Feng Tang feedback. ] [ paulmck: Apply Waiman Long feedback. ] Reported-by: Waiman Long Reported-by: Feng Tang Signed-off-by: Paul E. McKenney Reviewed-by: Feng Tang Reviewed-by: Waiman Long Cc: John Stultz Cc: Thomas Gleixner Cc: Stephen Boyd --- include/linux/clocksource.h | 3 +++ kernel/time/clocksource.c | 31 +++++++++++++++++++++++++------ 2 files changed, 28 insertions(+), 6 deletions(-) diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h index 1d42d4b173271..23b73f2293d6d 100644 --- a/include/linux/clocksource.h +++ b/include/linux/clocksource.h @@ -125,6 +125,9 @@ struct clocksource { struct list_head wd_list; u64 cs_last; u64 wd_last; + u64 wd_last_bogus; + int wd_bogus_shift; + unsigned long wd_bogus_count; #endif struct module *owner; }; diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c index 3f5317faf891f..4015ec6503a52 100644 --- a/kernel/time/clocksource.c +++ b/kernel/time/clocksource.c @@ -442,14 +442,33 @@ static void clocksource_watchdog(struct timer_list *unused) /* Check for bogus measurements. */ wdi = jiffies_to_nsecs(WATCHDOG_INTERVAL); - if (wd_nsec < (wdi >> 2)) { - /* This usually indicates broken timer code or hardware. */ - pr_warn("timekeeping watchdog on CPU%d: Watchdog clocksource '%s' advanced only %lld ns during %d-jiffy time interval, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL); + if (wd_nsec > (wdi << 2) || cs_nsec > (wdi << 2)) { + bool needwarn = false; + u64 wd_lb; + + cs->wd_bogus_count++; + if (!cs->wd_bogus_shift) { + needwarn = true; + } else { + delta = clocksource_delta(wdnow, cs->wd_last_bogus, watchdog->mask); + wd_lb = clocksource_cyc2ns(delta, watchdog->mult, watchdog->shift); + if ((1 << cs->wd_bogus_shift) * wdi <= wd_lb) + needwarn = true; + } + if (needwarn) { + /* This can happen on busy systems, which can delay the watchdog. */ + pr_warn("timekeeping watchdog on CPU%d: Watchdog clocksource '%s' advanced an excessive %lld ns during %d-jiffy time interval (%lu since last message), probable CPU overutilization, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL, cs->wd_bogus_count); + cs->wd_last_bogus = wdnow; + if (cs->wd_bogus_shift < 10) + cs->wd_bogus_shift++; + cs->wd_bogus_count = 0; + } continue; } - if (wd_nsec > (wdi << 2)) { - /* This can happen on busy systems, which can delay the watchdog. */ - pr_warn("timekeeping watchdog on CPU%d: Watchdog clocksource '%s' advanced an excessive %lld ns during %d-jiffy time interval, probable CPU overutilization, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL); + /* Check too-short measurements second to handle wrap. */ + if (wd_nsec < (wdi >> 2) || cs_nsec < (wdi >> 2)) { + /* This usually indicates broken timer code or hardware. */ + pr_warn("timekeeping watchdog on CPU%d: Watchdog clocksource '%s' advanced only %lld ns during %d-jiffy time interval, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL); continue; }