From patchwork Sun Oct 16 16:23:05 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Joel Fernandes X-Patchwork-Id: 3067 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:a5d:4ac7:0:0:0:0:0 with SMTP id y7csp1078261wrs; Sun, 16 Oct 2022 09:26:18 -0700 (PDT) X-Google-Smtp-Source: AMsMyM4zUWwWJST4j78sJlZfvCcGg8Xx0s/kZ81ZFammBO1pUkANFRn4xozi+skWxP1aWwDROWIT X-Received: by 2002:a17:902:e885:b0:183:dcb7:c4f8 with SMTP id w5-20020a170902e88500b00183dcb7c4f8mr7707886plg.160.1665937578127; Sun, 16 Oct 2022 09:26:18 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1665937578; cv=none; d=google.com; s=arc-20160816; b=yvy/9VXxPpB0larh6qmYE1hvT9t/URRj+5O9kKYBqwuFQj8spk1TovZw4A7MymzSpl S/MUY4jrnlxm9hWuSYBQuS+LnogLG6mMu06LQwtRbHawfsLZIO2td0TAkrDQP0QD2POO IGsvY9m8pvn70GMY1cz5FERCsL9+AMu/A+b1pRCagrJryFqROenMc3/v5P9xwjkBY6cK C6Ofo1l5qwVEeB3wv5ZAxaJiP+lIrpLtQHjS+TIejYaeV/YoCwBACSWTFdYyQOVw0oGU 9C9f2k1QofuUrSlGWAk2+RJ3ThkQDipM7HJUMq78JnKBap6vOfQv9p24Z+xCsJflrGRp FrKw== 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=hZ9x4BtDFYUfED6r9s6odmQcYTViF4DPSlxHT+KcbOI=; b=sr+nkbORN04oIQAPiQT15NW3j3LmRfoAGxKB2/wXRzoNNUXmMtvANKy9al9fgbjCzd fx8wlWVZDewTEz+9ifKSC9Rl6OpLsX3zGVLzFp8hcBg0trfTXNaDXC5w4dzsxsqCU0Zy GB3tY8l6XKgxRZDqjxdDj5cZ1rzOJBuiYjokk0MbAJyvjrIYFv3yBjWsxrIzfLKVjKVc WmYJtdzmvIdS+FLSqHrYo8tbACxIdkdUfq8TqR9RzPF2jwU4Hht/joOW7nbv+VmzStWn qb7drhtsPLqBAbvNE8LS+aGuuh575znenjTqy8zIAsESDuDeVgSyfyMn/yp6ozGSORwR mESQ== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@joelfernandes.org header.s=google header.b="G8RD/qSK"; 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 Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id w4-20020a656944000000b0044b5e15db73si9516088pgq.249.2022.10.16.09.26.05; Sun, 16 Oct 2022 09:26:18 -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=@joelfernandes.org header.s=google header.b="G8RD/qSK"; 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 Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229835AbiJPQYt (ORCPT + 99 others); Sun, 16 Oct 2022 12:24:49 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:58044 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229954AbiJPQXz (ORCPT ); Sun, 16 Oct 2022 12:23:55 -0400 Received: from mail-qk1-x733.google.com (mail-qk1-x733.google.com [IPv6:2607:f8b0:4864:20::733]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 1119A3ECD0 for ; Sun, 16 Oct 2022 09:23:43 -0700 (PDT) Received: by mail-qk1-x733.google.com with SMTP id m6so5404796qkm.4 for ; Sun, 16 Oct 2022 09:23:43 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=joelfernandes.org; s=google; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:from:to:cc:subject:date :message-id:reply-to; bh=hZ9x4BtDFYUfED6r9s6odmQcYTViF4DPSlxHT+KcbOI=; b=G8RD/qSKPtxPvy/bEl8swbr0PqqVAiFSkvohygiXh0Ahx4dGPQGb7L77Bo2KfBq4dK 9M63FYIMMRoR+tVGQPiXiWRSo7L6Idn4ui2khvMugG4yRA/G+URk0zwsMdofH/sHdTyw 2RcCmANQL7maNSO6o1Cqos0t0MOqYgAg3lIGE= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=hZ9x4BtDFYUfED6r9s6odmQcYTViF4DPSlxHT+KcbOI=; b=54BcrWlPWJUpskyx+BgT+nki+PY+gIc4/WOSbtxusp0EZHwD70pYS7c8B8VF6yF02a 9DvxEVJ7udH43E2v3649RknzrllAM4V8+H+XV2wTHfYAZZ3DRcrnYRaXFU2SuydBUWVy qpwol9S16QFpoDtyN/nDhFb/cq9szL5S/a1KPlZ1wJNZnmlYZ/o1JbZ/N8etEoBHhGPX gyx4e9Eq9vS5VrcheIsUR/BHoiqPte+NctPY/Q5j/4MrBG0n5HKS+nU2oxgMkZhTLvUA EkeFmgFLj6/jHwoejO4jfoj4q2wUgnU6GCqLPaxUbqfZ0b1qLEPaVBUIxPOqNBhATg48 P3vw== X-Gm-Message-State: ACrzQf376agGS7YlDFFmPkhBfXa0XYCXav2iRNo2RZSNUWz6LExN6IPj bmtEhjUp3Ee7eLpa+VqlyyMdDvj6TsuGtQ== X-Received: by 2002:a05:620a:d8c:b0:6a7:91a2:c827 with SMTP id q12-20020a05620a0d8c00b006a791a2c827mr4887021qkl.407.1665937422501; Sun, 16 Oct 2022 09:23:42 -0700 (PDT) Received: from joelboxx.c.googlers.com.com (228.221.150.34.bc.googleusercontent.com. [34.150.221.228]) by smtp.gmail.com with ESMTPSA id x19-20020ac87ed3000000b003436103df40sm6001207qtj.8.2022.10.16.09.23.42 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Sun, 16 Oct 2022 09:23:42 -0700 (PDT) From: "Joel Fernandes (Google)" To: rcu@vger.kernel.org Cc: linux-kernel@vger.kernel.org, frederic@kernel.org, paulmck@kernel.org, "Joel Fernandes (Google)" Subject: [PATCH v9 13/13] rcu/debug: Add wake-up debugging for lazy callbacks Date: Sun, 16 Oct 2022 16:23:05 +0000 Message-Id: <20221016162305.2489629-14-joel@joelfernandes.org> X-Mailer: git-send-email 2.38.0.413.g74048e4d9e-goog In-Reply-To: <20221016162305.2489629-1-joel@joelfernandes.org> References: <20221016162305.2489629-1-joel@joelfernandes.org> MIME-Version: 1.0 X-Spam-Status: No, score=-0.4 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,RCVD_IN_DNSWL_NONE, SPF_HELO_NONE,SPF_PASS,URIBL_BLACK autolearn=no 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?1746862162254535878?= X-GMAIL-MSGID: =?utf-8?q?1746862162254535878?= This patch adds initial debugging for lazy callback: whether the callback does a wake up or not. We see that callbacks doing wake ups are usually associated with synchronous use cases (SCSI, rcu_sync, synchronize_rcu() etc). The code is not very intrusive as almost all the logic is in 'lazy-debug.h' with just a few calls from tree.c In the future, we will add more functionalities such as ensuring callbacks execute in bounded time. Signed-off-by: Joel Fernandes (Google) --- kernel/rcu/Kconfig | 7 ++ kernel/rcu/lazy-debug.h | 154 ++++++++++++++++++++++++++++++++++++++++ kernel/rcu/tree.c | 9 +++ 3 files changed, 170 insertions(+) create mode 100644 kernel/rcu/lazy-debug.h diff --git a/kernel/rcu/Kconfig b/kernel/rcu/Kconfig index edd632e68497..08c06f739187 100644 --- a/kernel/rcu/Kconfig +++ b/kernel/rcu/Kconfig @@ -322,4 +322,11 @@ config RCU_LAZY To save power, batch RCU callbacks and flush after delay, memory pressure or callback list growing too big. +config RCU_LAZY_DEBUG + bool "RCU callback lazy invocation debugging" + depends on RCU_LAZY + default n + help + Debugging to catch issues caused by delayed RCU callbacks. + endmenu # "RCU Subsystem" diff --git a/kernel/rcu/lazy-debug.h b/kernel/rcu/lazy-debug.h new file mode 100644 index 000000000000..b8399b51d06a --- /dev/null +++ b/kernel/rcu/lazy-debug.h @@ -0,0 +1,154 @@ +#include +#include + +#ifdef CONFIG_RCU_LAZY_DEBUG +#include +#include + +static DEFINE_PER_CPU(bool, rcu_lazy_cb_exec) = false; +static DEFINE_PER_CPU(void *, rcu_lazy_ip) = NULL; + +static DEFINE_RAW_SPINLOCK(lazy_funcs_lock); + +#define FUNC_SIZE 1024 +static unsigned long lazy_funcs[FUNC_SIZE]; +static int nr_funcs; + +static void __find_func(unsigned long ip, int *B, int *E, int *N) +{ + unsigned long *p; + int b, e, n; + + b = n = 0; + e = nr_funcs - 1; + + while (b <= e) { + n = (b + e) / 2; + p = &lazy_funcs[n]; + if (ip > *p) { + b = n + 1; + } else if (ip < *p) { + e = n - 1; + } else + break; + } + + *B = b; + *E = e; + *N = n; + + return; +} + +static bool lazy_func_exists(void* ip_ptr) +{ + int b, e, n; + unsigned long flags; + unsigned long ip = (unsigned long)ip_ptr; + + raw_spin_lock_irqsave(&lazy_funcs_lock, flags); + __find_func(ip, &b, &e, &n); + raw_spin_unlock_irqrestore(&lazy_funcs_lock, flags); + + return b <= e; +} + +static int lazy_func_add(void* ip_ptr) +{ + int b, e, n; + unsigned long flags; + unsigned long ip = (unsigned long)ip_ptr; + + raw_spin_lock_irqsave(&lazy_funcs_lock, flags); + if (nr_funcs >= FUNC_SIZE) { + raw_spin_unlock_irqrestore(&lazy_funcs_lock, flags); + return -1; + } + + __find_func(ip, &b, &e, &n); + + if (b > e) { + if (n != nr_funcs) + memmove(&lazy_funcs[n+1], &lazy_funcs[n], + (sizeof(*lazy_funcs) * (nr_funcs - n))); + + lazy_funcs[n] = ip; + nr_funcs++; + } + + raw_spin_unlock_irqrestore(&lazy_funcs_lock, flags); + return 0; +} + +static void rcu_set_lazy_context(void *ip_ptr) +{ + bool *flag = this_cpu_ptr(&rcu_lazy_cb_exec); + *flag = lazy_func_exists(ip_ptr); + + if (*flag) { + *this_cpu_ptr(&rcu_lazy_ip) = ip_ptr; + } else { + *this_cpu_ptr(&rcu_lazy_ip) = NULL; + } +} + +static void rcu_reset_lazy_context(void) +{ + bool *flag = this_cpu_ptr(&rcu_lazy_cb_exec); + *flag = false; +} + +static bool rcu_is_lazy_context(void) +{ + return *(this_cpu_ptr(&rcu_lazy_cb_exec)); +} + +static void +probe_waking(void *ignore, struct task_struct *p) +{ + // kworker wake ups don't appear to cause performance issues. + // Ignore for now. + if (!strncmp(p->comm, "kworker", 7)) + return; + + if (WARN_ON(!in_nmi() && !in_hardirq() && rcu_is_lazy_context())) { + pr_err("*****************************************************\n"); + pr_err("RCU: A wake up has been detected from a lazy callback!\n"); + pr_err("The callback name is: %ps\n", *this_cpu_ptr(&rcu_lazy_ip)); + pr_err("The task it woke up is: %s (%d)\n", p->comm, p->pid); + pr_err("This could cause performance issues! Check the stack.\n"); + pr_err("*****************************************************\n"); + } +} + +static void rcu_lazy_debug_init(void) +{ + int ret; + pr_info("RCU Lazy CB debugging is turned on, system may be slow.\n"); + + ret = register_trace_sched_waking(probe_waking, NULL); + if (ret) + pr_info("RCU: Lazy debug ched_waking probe could not be registered."); +} + +#else + +static int lazy_func_add(void* ip_ptr) +{ + return -1; +} + + +static void rcu_set_lazy_context(void *ip_ptr) +{ +} + +static void rcu_reset_lazy_context(void) +{ +} + +static void rcu_lazy_debug_init(void) +{ +} + +#endif diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c index f4b390f86865..2b2a8d84896d 100644 --- a/kernel/rcu/tree.c +++ b/kernel/rcu/tree.c @@ -67,6 +67,7 @@ #include "tree.h" #include "rcu.h" +#include "lazy-debug.h" #ifdef MODULE_PARAM_PREFIX #undef MODULE_PARAM_PREFIX @@ -2245,7 +2246,10 @@ static void rcu_do_batch(struct rcu_data *rdp) f = rhp->func; WRITE_ONCE(rhp->func, (rcu_callback_t)0L); + + rcu_set_lazy_context(f); f(rhp); + rcu_reset_lazy_context(); rcu_lock_release(&rcu_callback_map); @@ -2770,6 +2774,10 @@ __call_rcu_common(struct rcu_head *head, rcu_callback_t func, bool lazy) } check_cb_ovld(rdp); + + if (lazy) + lazy_func_add(func); + if (rcu_nocb_try_bypass(rdp, head, &was_alldone, flags, lazy)) return; // Enqueued onto ->nocb_bypass, so just leave. // If no-CBs CPU gets here, rcu_nocb_try_bypass() acquired ->nocb_lock. @@ -4805,6 +4813,7 @@ void __init rcu_init(void) rcu_early_boot_tests(); kfree_rcu_batch_init(); + rcu_lazy_debug_init(); rcu_bootup_announce(); sanitize_kthread_prio(); rcu_init_geometry();