From patchwork Thu Jan 19 00:51:38 2023 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: John Stultz X-Patchwork-Id: 45554 Return-Path: Delivered-To: ouuuleilei@gmail.com Received: by 2002:adf:eb09:0:0:0:0:0 with SMTP id s9csp73168wrn; Wed, 18 Jan 2023 17:16:12 -0800 (PST) X-Google-Smtp-Source: AMrXdXvm2lvu3s+l7BICm2lDXNlUSHS1t/ybjtNqM+r8Dv1y6QMBHtpK122dGq6zo8B34LQUy5w5 X-Received: by 2002:a17:906:6bc6:b0:7c0:f684:9092 with SMTP id t6-20020a1709066bc600b007c0f6849092mr8836992ejs.37.1674090971949; Wed, 18 Jan 2023 17:16:11 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1674090971; cv=none; d=google.com; s=arc-20160816; b=OfwMAZhLGs83IYXeSz64Qn7rVEWgKKZRJDJKSOpZed910vN4MZkLNn6pRUE1ova8j8 gxdnjZMVg2xht4evXfp03l29UgIS5BbGeVrezqZsWH26AR5FmeXJAqZ+MMjdTT0k36pL hV4jdeEBxv+nWkXgLDQPs6zxFFkkDF1D42mFw8YBUP+8abBlDobsZyELcqBv8Wst6bRk A2gFQcAlAP8XIpIUA5qBB7+HY3Mw0/YIIDOGyYREMZtJTTlKKBkTm17Lddw5mLpPjt+U 7XcLC+1wmfPhwG+tGrw29Y0X4sWG9mEA4zIn5KKlhhc/kNMiVKu+vPuA0SPS4pHHA4ri PpRQ== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:cc:to:from:subject:message-id:mime-version:date :dkim-signature; bh=SILF59q15LnVQh8plXcv+E/BH5WNM7aTOCdlXngaCY0=; b=AaATTE3cmnokR30XJG+L+pzUsdOIy6ldK84IjfaipPw1oFnZHfviB4O3GKhqY3CigG W+kRjnzrsnZF6ovac4OwNuXnordjVfngeNrkTpdiqFB159U+hDq6Zk7ydwwfQ3JvB652 nkjxOHmyoT8/7CoHS8wHDyN+tyL/lx4m+7WL178F8BMlrIxYrWT4lQ6llva1PUo/PwZ8 a1h7LpYxSFixIiq5L3cdUUehrjvkCEkeddRK+0damC1moFLYuZmH0cipf3zCqEPiRlTa vqMmbHENaB6eyJPrYjBJbohhPreZ1Se1c2KbSd6J42qt1hT8rSDz8kOv9VwDfwGsTrOW e8NQ== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@google.com header.s=20210112 header.b=StxTGeFH; 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=REJECT sp=REJECT dis=NONE) header.from=google.com Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id xh10-20020a170906da8a00b007c0ea5a7ca4si15560461ejb.858.2023.01.18.17.15.47; Wed, 18 Jan 2023 17:16:11 -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=@google.com header.s=20210112 header.b=StxTGeFH; 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=REJECT sp=REJECT dis=NONE) header.from=google.com Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S229802AbjASAvo (ORCPT + 99 others); Wed, 18 Jan 2023 19:51:44 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:57872 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S229658AbjASAvn (ORCPT ); Wed, 18 Jan 2023 19:51:43 -0500 Received: from mail-pj1-x1049.google.com (mail-pj1-x1049.google.com [IPv6:2607:f8b0:4864:20::1049]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 9B370613C8 for ; Wed, 18 Jan 2023 16:51:42 -0800 (PST) Received: by mail-pj1-x1049.google.com with SMTP id o16-20020a17090ac71000b00229ba85bc63so265967pjt.7 for ; Wed, 18 Jan 2023 16:51:42 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20210112; h=cc:to:from:subject:message-id:mime-version:date:from:to:cc:subject :date:message-id:reply-to; bh=SILF59q15LnVQh8plXcv+E/BH5WNM7aTOCdlXngaCY0=; b=StxTGeFH9g3spsNheciX6sSviGPedGFhgWqUlo5a7VSNR2BNRGAsgi2FMiHvAsvfkd hcDQveWxTy3Qk1P2GHTf+mkfdUx/OOfHtJuoe01Lb0iAKLUOhTVkSR/mpPxJV+sWPZY4 mPhoPzrWKQclAIHDLtSaEcN3ctZ7t1Zbcrj81e/kPjVKxyfgtebUYjJPNjFsaeMN1aAJ BlPOGIput9CnBYA6Z+z1lsK/k1mtA+2PvhnoVi0i9KGPCIw2Z8DxOacTpUBrjxJFVpNQ YKu0Uv8eNiy8ym2jBkz1CLYNAmJRbKrRe/+Wx/SP1lA5tDK6ndzHp4N53wyaQAUoKTL8 FIlg== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=cc:to:from:subject:message-id:mime-version:date:x-gm-message-state :from:to:cc:subject:date:message-id:reply-to; bh=SILF59q15LnVQh8plXcv+E/BH5WNM7aTOCdlXngaCY0=; b=cZWxl7I6lf2QMvfyEUuzJBBFbPo9DInSPDaiGdeFDTLuUIYgWbqZop/K7rDfIBTc90 phsu2LSe8jeBLd+UwOw63HMMplkLCqZUbmZDRdv5hn9c4UXUZ6NqXFpsVMlbvsTmYAbL f83NLimllc54gu59Sgb0A4QyO/VT1Am/p9Xp+7DqzaNhsXXPF2Aq61jNQ07hQD6GV+mO Dy6TPamHJDwXRZhvxo1StNIoe4F2d9Tg7e1rTZJHbc/D/prxzlQC3bsJ9ByzctCTB2zN rbpp+Kq1e2ktynAtgUiqDL0SxyttHGKKooJT9l7ZtCR19sfRBAynjYz2aTySs2A0FQxi qOvg== X-Gm-Message-State: AFqh2kqoxaDSshwn1lzPJxfgNbp5As+tV+Sgc6igtYiIMTK7Ci3qsoiC +M+Vx4Yq5Pq0iY3qc5RdmJ+/ATN7mF0/2HVjG/JQ7jvQQNuSIMEYhKs3B6MxTm3X3TDJWkN9Gyk ilt3N/KQFzoGxTBm9FKabmW6aepIbsD3Dalm7G1cBFNrvLZtS1TeAcfLHFcU1GRoWEt4w5ro= X-Received: from jstultz-noogler2.c.googlers.com ([fda3:e722:ac3:cc00:24:72f4:c0a8:600]) (user=jstultz job=sendgmr) by 2002:a17:90b:1d05:b0:227:1217:9f1d with SMTP id on5-20020a17090b1d0500b0022712179f1dmr999573pjb.196.1674089502005; Wed, 18 Jan 2023 16:51:42 -0800 (PST) Date: Thu, 19 Jan 2023 00:51:38 +0000 Mime-Version: 1.0 X-Mailer: git-send-email 2.39.0.246.g2a6d74b583-goog Message-ID: <20230119005138.759086-1-jstultz@google.com> Subject: [PATCH v3] trace: Add trace points for tasklet entry/exit From: John Stultz To: LKML Cc: Lingutla Chandrasekhar , Steven Rostedt , Masami Hiramatsu , Thomas Gleixner , "Paul E. McKenney" , "Connor O'Brien" , kernel-team@android.com, "J . Avila" , John Stultz X-Spam-Status: No, score=-9.6 required=5.0 tests=BAYES_00,DKIMWL_WL_MED, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,RCVD_IN_DNSWL_NONE, SPF_HELO_NONE,SPF_PASS,USER_IN_DEF_DKIM_WL 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?1755411614795250651?= X-GMAIL-MSGID: =?utf-8?q?1755411614795250651?= From: Lingutla Chandrasekhar Tasklets are supposed to finish their work quickly and should not block the current running process, but it is not guaranteed that. Currently softirq_entry/exit can be used to know total tasklets execution time, but not helpful to track individual tasklet's execution time. With that we can't find any culprit tasklet function, which is taking more time. Add tasklet_entry/exit trace point support to track individual tasklet execution. Trivial usage example: # echo 1 > /sys/kernel/debug/tracing/events/irq/tasklet_entry/enable # echo 1 > /sys/kernel/debug/tracing/events/irq/tasklet_exit/enable # cat /sys/kernel/debug/tracing/trace # tracer: nop # # entries-in-buffer/entries-written: 4/4 #P:4 # # _-----=> irqs-off/BH-disabled # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / _-=> migrate-disable # |||| / delay # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | -0 [003] ..s1. 314.011428: tasklet_entry: tasklet=0xffffa01ef8db2740 function=tcp_tasklet_func -0 [003] ..s1. 314.011432: tasklet_exit: tasklet=0xffffa01ef8db2740 function=tcp_tasklet_func -0 [003] ..s1. 314.017369: tasklet_entry: tasklet=0xffffa01ef8db2740 function=tcp_tasklet_func -0 [003] ..s1. 314.017371: tasklet_exit: tasklet=0xffffa01ef8db2740 function=tcp_tasklet_func This patch has been carried in the Android tree for awhile so I wanted to submit it for review upstream. Feedback would be appreciated! Cc: Steven Rostedt Cc: Masami Hiramatsu Cc: Thomas Gleixner Cc: "Paul E. McKenney" Cc: Connor O'Brien Cc: kernel-team@android.com Reviewed-by: Steven Rostedt (Google) Signed-off-by: Lingutla Chandrasekhar [elavila: Port to android-mainline] Signed-off-by: J. Avila [jstultz: Rebased to upstream, cut unused trace points, added comments for the tracepoints, reworded commit] Signed-off-by: John Stultz --- v2: * Added tasklet pointer to the trace event as suggested by Steven v3: * Minor tweak to commit to show usage and output example --- include/trace/events/irq.h | 47 ++++++++++++++++++++++++++++++++++++++ kernel/softirq.c | 9 ++++++-- 2 files changed, 54 insertions(+), 2 deletions(-) diff --git a/include/trace/events/irq.h b/include/trace/events/irq.h index eeceafaaea4c..a07b4607b663 100644 --- a/include/trace/events/irq.h +++ b/include/trace/events/irq.h @@ -160,6 +160,53 @@ DEFINE_EVENT(softirq, softirq_raise, TP_ARGS(vec_nr) ); +DECLARE_EVENT_CLASS(tasklet, + + TP_PROTO(struct tasklet_struct *t, void *func), + + TP_ARGS(t, func), + + TP_STRUCT__entry( + __field( void *, tasklet) + __field( void *, func) + ), + + TP_fast_assign( + __entry->tasklet = t; + __entry->func = func; + ), + + TP_printk("tasklet=%ps function=%ps", __entry->tasklet, __entry->func) +); + +/** + * tasklet_entry - called immediately before the tasklet is run + * @t: tasklet pointer + * @func: tasklet callback or function being run + * + * Used to find individual tasklet execution time + */ +DEFINE_EVENT(tasklet, tasklet_entry, + + TP_PROTO(struct tasklet_struct *t, void *func), + + TP_ARGS(t, func) +); + +/** + * tasklet_exit - called immediately after the tasklet is run + * @t: tasklet pointer + * @func: tasklet callback or function being run + * + * Used to find individual tasklet execution time + */ +DEFINE_EVENT(tasklet, tasklet_exit, + + TP_PROTO(struct tasklet_struct *t, void *func), + + TP_ARGS(t, func) +); + #endif /* _TRACE_IRQ_H */ /* This part must be outside protection */ diff --git a/kernel/softirq.c b/kernel/softirq.c index c8a6913c067d..1b725510dd0f 100644 --- a/kernel/softirq.c +++ b/kernel/softirq.c @@ -793,10 +793,15 @@ static void tasklet_action_common(struct softirq_action *a, if (tasklet_trylock(t)) { if (!atomic_read(&t->count)) { if (tasklet_clear_sched(t)) { - if (t->use_callback) + if (t->use_callback) { + trace_tasklet_entry(t, t->callback); t->callback(t); - else + trace_tasklet_exit(t, t->callback); + } else { + trace_tasklet_entry(t, t->func); t->func(t->data); + trace_tasklet_exit(t, t->func); + } } tasklet_unlock(t); continue;