From patchwork Wed Nov 2 18:40:08 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: 14449 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a5d:6687:0:0:0:0:0 with SMTP id l7csp74499wru; Wed, 2 Nov 2022 11:41:23 -0700 (PDT) X-Google-Smtp-Source: AMsMyM6cK1EWCdBkicqBHgggqikHGJb3SKi5P2aZq0/OMshQzcTOdyHke5yIS9dloH9sqlplXTM6 X-Received: by 2002:a63:f47:0:b0:46a:e00c:24c7 with SMTP id 7-20020a630f47000000b0046ae00c24c7mr22964444pgp.239.1667414483507; Wed, 02 Nov 2022 11:41:23 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1667414483; cv=none; d=google.com; s=arc-20160816; b=ewqhQP4HYK5BA1HiLX5DXngoCqBmjgHgDPmbkF6bqyy87Jm5jFe6CtNqSrYhbNjWvk QV+DbezQpvRjdMxOyRRpBh2FBZlgTBIKg/G7cAH7G6w/NSCQZygQlCsCSMAT7uUgxvAf Tfucw7bxD95zqopcDUglxGKr831LyzzUO0O8/1kM3hW07+/UFeVI0pR4QR61rp+VBo6K 2LVCL59MGqdz7O2uEj3YUTrnWaNQ3qbdzJ8WE7Vqc4gn8qvPN2Fp5LBtMurqdq+V9VX3 gUUvWY93143m1f0wJzdl1whZEsj1mm5/6aNQvSr7NFHMCH6SsjjVKiaQbT5PsUfbtdlI 2AHA== 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=pfJ2mPlz7LSG8r7QIqweVCqQzuN2sKCXJEtbT5SBnCo=; b=o9rysRCWxAiTFocjsMTNldhMScwELg5j4T64p0Y+F+OXMVEftAfilUMgh6CsU8PR2t oncIYdTSFssXrz7uNcw2zLggPMgxewVUMxLxY3GKtLPCTr5EKhYmKXmNN+LQxOktEgDK 1f6rbrFtHJ/7Ghlcnj7KfgJrAx6IaQWutZx73Xliaq6sB2HMrHjOi/KhNZYJzLuAmrJq X9ftmIhUxRUf/+suyoA9pDEdPWkOkjkOUqBGBXv+CTwJsEO4JG/yhvdq/EB/uXPAkR3H IiC+4/5oxUG+qGLDktCw/OjKZMHe66wgbqCzjsKXOiaNyv7tsDF6+BmkeuJSnhY8xdS3 DGRw== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b="oOPiGX/M"; 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 b5-20020a170902e94500b001870c4d4378si13452508pll.498.2022.11.02.11.41.10; Wed, 02 Nov 2022 11:41:23 -0700 (PDT) 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="oOPiGX/M"; 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 S231237AbiKBSkQ (ORCPT + 99 others); Wed, 2 Nov 2022 14:40:16 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35234 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S230526AbiKBSkO (ORCPT ); Wed, 2 Nov 2022 14:40:14 -0400 Received: from ams.source.kernel.org (ams.source.kernel.org [145.40.68.75]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 526D42FA for ; Wed, 2 Nov 2022 11:40:13 -0700 (PDT) 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 DC822B82433 for ; Wed, 2 Nov 2022 18:40:11 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 84177C433D6; Wed, 2 Nov 2022 18:40:10 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1667414410; bh=QDzLlEsdJgBZfwCe8fdmspQ4lio25AEQNSzuvHZI6ZU=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=oOPiGX/M5djAqWhXtUaku0rxJ5mAilaYczj6k7j7MtJo6Tmkwc1sYfYOlgYiI27Nk VnRB6Maz1sSNTubTnml6bEBh90vY+rh5txbOgv8DEOfj2d/sAXLCww17SYH82X5YkS yXO2z8MApivd7vyuDAsZyf1c/JtHoatzZ3Rv0V/K+O26jcejH8sdHtSnpUJXbbgx6K dfJuyj2Sk9+/eGw+y+Gi88/Y8eVCGOpxTwyKKU8SkAWirAk7Gk8rgGFnA+Tj7iPbk1 RywLpHvtNsuL9+Si2Vmeb8Bny9cjpkAlPviby8mubnG22nkQ0D0IJilU0j3O62GT/U E/Fc5tBi0PiOw== Received: by paulmck-ThinkPad-P17-Gen-1.home (Postfix, from userid 1000) id 3F37B5C1813; Wed, 2 Nov 2022 11:40:10 -0700 (PDT) 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" , John Stultz , Waiman Long Subject: [PATCH clocksource 1/2] clocksource: Add comments to classify bogus measurements Date: Wed, 2 Nov 2022 11:40:08 -0700 Message-Id: <20221102184009.1306751-1-paulmck@kernel.org> X-Mailer: git-send-email 2.31.1.189.g2e36527f23 In-Reply-To: <20221102184001.GA1306489@paulmck-ThinkPad-P17-Gen-1> References: <20221102184001.GA1306489@paulmck-ThinkPad-P17-Gen-1> MIME-Version: 1.0 X-Spam-Status: No, score=-8.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?1748410809517151739?= X-GMAIL-MSGID: =?utf-8?q?1748410809517151739?= An extremely busy system can delay the clocksource watchdog, so that the corresponding too-long bogus-measurement error does not necessarily imply an error in the system. However, a too-short bogus-measurement error likely indicates a bug in hardware, firmware or software. Therefore, add comments clarifying these bogus-measurement pr_warn()s. Reported-by: Feng Tang Signed-off-by: Paul E. McKenney Cc: John Stultz Cc: Thomas Gleixner Cc: Stephen Boyd Cc: Feng Tang Cc: Waiman Long Reviewed-by: Waiman Long Reviewed-by: Feng Tang --- kernel/time/clocksource.c | 2 ++ 1 file changed, 2 insertions(+) diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c index dcaf38c062161..3f5317faf891f 100644 --- a/kernel/time/clocksource.c +++ b/kernel/time/clocksource.c @@ -443,10 +443,12 @@ 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); 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); continue; } From patchwork Wed Nov 2 18:40:09 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: 14450 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a5d:6687:0:0:0:0:0 with SMTP id l7csp74661wru; Wed, 2 Nov 2022 11:41:46 -0700 (PDT) X-Google-Smtp-Source: AMsMyM7lSvsxMqnonPecMVHQLi2biXnIe59LsqjCB8+hJwNmoRn4SIBy5hJ9aC54FI8ON76motTr X-Received: by 2002:a17:902:ea03:b0:187:30ec:2b9e with SMTP id s3-20020a170902ea0300b0018730ec2b9emr12671360plg.75.1667414506610; Wed, 02 Nov 2022 11:41:46 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1667414506; cv=none; d=google.com; s=arc-20160816; b=qpFFZxoD+HEu9kNDv4Dx1Tbynxyo5B1pWC2jiJt0dQBCFmXiXxzxmBK9MA88r/ViIy P3f1Tg9BLe49oZhlS9tWibmga0qr4BiEdMipeCKa8n0xUF61DxE+67KN+37NjgFornpT vWAmdhgM6iepX/mmzscmeY/x0yJbSdUbvWIW8AfnrpcsjXd6GCVePa4a4m5OO3WylqFK DQsutP29FDWBBo6LfxJBm12hbOnu9VCzLTFjYfrTM6LhiOuj5S9VFlNVW/mZvJN665Np N0EChBheDfC5oFOQ6cN2ZJr9rle08gYnVx3oG3FehQ2bCwcNz83p9Gh4VrXTWaKBezRt rCyA== 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=bGhZu1zlDrMXZs5FwJmwokVVd20jO/qjJwh0TLJj5Pc=; b=AD2vNjAKfK4C639lvwNlgDPIbblofmqp3uboVdiVVxUlt2fQu+D7YNVQNA6eQOF9d1 y0Qk1JMFpV9NPZ/I6lk2ZgceqaKNlmK7PaYunrtih6aUUZFoJjVnAox8W4JB5Qy/Vpya fcyWTvLZTzgCthusqAeWfm3rpSXfFUAtOXG/Rw0N+1CP5pemu+WyJJAslSjHs9KoWgdz iPATDuZ5bwYt2LTrmDJe0F56VxQYhGbrb9Q9QeNjQFB7M96GrwDKk3S8h7/cqGtJfYDO KHvwONk6NfIzEz3EInejOT6YkhQMz39wVb5MGRf6JF9aIc9gbFgCstDk1KbOOP5oI5kV 91+w== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b=Kov6kfM7; 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 32-20020a630c60000000b0044034f2c3b8si15832957pgm.310.2022.11.02.11.41.33; Wed, 02 Nov 2022 11:41:46 -0700 (PDT) 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=Kov6kfM7; 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 S231327AbiKBSkT (ORCPT + 99 others); Wed, 2 Nov 2022 14:40:19 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:35244 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S231211AbiKBSkP (ORCPT ); Wed, 2 Nov 2022 14:40:15 -0400 Received: from ams.source.kernel.org (ams.source.kernel.org [IPv6:2604:1380:4601:e00::1]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 5293831A for ; Wed, 2 Nov 2022 11:40:13 -0700 (PDT) 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 E89DFB82437 for ; Wed, 2 Nov 2022 18:40:11 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 886BFC433C1; Wed, 2 Nov 2022 18:40:10 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1667414410; bh=SaIxDonz7jxIjNGEnJ7dwqSnqRS3l2440YhJ0ssJuBw=; h=From:To:Cc:Subject:Date:In-Reply-To:References:From; b=Kov6kfM75q2SWRX1ME+CRswKJu3gMjUkIPttchOTUJmiWdjGywmC5DZOozwtM1ifP mTkaZddazjVVesBcV2Ha+G93BUI4LAdnsgI1iItRo4JES9GatHV5SZZLgVT1AxvXGA bFPUDn8/Ym3Jx+KYXZD90JWTV6q5mh5KDL2700RLTkkcaqzuoxWJUeCTtOk3Yge1gA VeHchcw4DsR4edRDmz2PnmUg01rYCwVuzQT6Vv0Nik7SxjSRIDZ+ZGYJlkH0QDRGhY /JeKgDro1PnkiI6e+RryEbkZYE0w1zj9m7FYRlJzcRm/X1pCzm31xjmBmEtEqr7qPg dMHpaCMOlx4EQ== Received: by paulmck-ThinkPad-P17-Gen-1.home (Postfix, from userid 1000) id 41F415C18FC; Wed, 2 Nov 2022 11:40:10 -0700 (PDT) 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 2/2] clocksource: Exponential backoff for load-induced bogus watchdog reads Date: Wed, 2 Nov 2022 11:40:09 -0700 Message-Id: <20221102184009.1306751-2-paulmck@kernel.org> X-Mailer: git-send-email 2.31.1.189.g2e36527f23 In-Reply-To: <20221102184001.GA1306489@paulmck-ThinkPad-P17-Gen-1> References: <20221102184001.GA1306489@paulmck-ThinkPad-P17-Gen-1> MIME-Version: 1.0 X-Spam-Status: No, score=-8.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?1748410834059213080?= X-GMAIL-MSGID: =?utf-8?q?1748410834059213080?= 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. ] Reported-by: Waiman Long Reported-by: Feng Tang Signed-off-by: Paul E. McKenney Cc: John Stultz Cc: Thomas Gleixner Cc: Stephen Boyd Cc: Feng Tang Cc: Waiman Long Reviewed-by: Feng Tang Reviewed-by: Waiman Long --- include/linux/clocksource.h | 4 ++++ kernel/time/clocksource.c | 31 +++++++++++++++++++++++++------ 2 files changed, 29 insertions(+), 6 deletions(-) diff --git a/include/linux/clocksource.h b/include/linux/clocksource.h index 1d42d4b173271..daac05aedf56a 100644 --- a/include/linux/clocksource.h +++ b/include/linux/clocksource.h @@ -125,6 +125,10 @@ 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; + unsigned long wd_bogus_count_last; #endif struct module *owner; }; diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c index 3f5317faf891f..de8047b6720f5 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 additional), probable CPU overutilization, skipping watchdog check.\n", smp_processor_id(), watchdog->name, wd_nsec, WATCHDOG_INTERVAL, cs->wd_bogus_count - cs->wd_bogus_count_last); + cs->wd_last_bogus = wdnow; + if (cs->wd_bogus_shift < 10) + cs->wd_bogus_shift++; + cs->wd_bogus_count_last = cs->wd_bogus_count; + } 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; }