Received: by 2002:a05:6358:16cc:b0:ea:6187:17c9 with SMTP id r12csp13321573rwl; Wed, 4 Jan 2023 06:40:26 -0800 (PST) X-Google-Smtp-Source: AMrXdXtGYE43iV+4ZzuPR2L6w98yNnc8bI8tE4wHlXn+j47/W350GHBg7zF1JzsNXJH+oycWUfrY X-Received: by 2002:aa7:de08:0:b0:472:7c75:832 with SMTP id h8-20020aa7de08000000b004727c750832mr40316617edv.16.1672843226640; Wed, 04 Jan 2023 06:40:26 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1672843226; cv=none; d=google.com; s=arc-20160816; b=mIUeypIbMsxpAmJB4UYLkMJa+0wPFMFf92MQted3JrmLUkehiOVX0TopiHOl2yoLTp 5ZhsNO07Kzd58ARQ1dQIX8Kkj0VidsfoGeDPABpkiNmxLlyotPdwFiIvFBKMGAxoIaIY yB6RWDW8aW150EUokuiT6IUJk3xTOM7AfwarmcOy3/UcIE2TSrKUSbvukA7FVoRFyLV1 0Ez6Um7M19WQulddv3LSgzZVoBvWMc0cDEiYJHxmh5vKSoQ99LqiVrYCJqvGjaoxg/+b uG9QQoJGPWO1ptowOVuBP4mCAbglCkX9Lacqyf9h2mGAXJAeArKDF8f0H7Y3QsuDw/y6 EDyw== 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:subject:cc:to:from:date :dkim-signature; bh=6tPKIMTDVm1p1Bg5DUswZ+BgnmPog2Tz6L/Oq+MUK9Q=; b=yNfXKJl7u9IzNnXDq20+R9m6RlYqLCWMUWVtwHkNpudHO31T1VfibrJ9jQh3cvlBOt DdmB/cUpTzwrOeM5axth2T6p95MW3EZF6h+D9iISwanty8FtMm3B6hX2ncWK1xlirq/T Pb4ba3niaZ59ET53QxA8ZdVwIzXMRSztiGsNyPrmxXnrjGOIQZJzzi/dBkYZRpqrLOoQ H9R3ecaLtcBfq0jiBXxX0tRj/URqsZIvypM8sMxLlaVWUD+foZ9v66UDmLfJEcCNhO2B rGhjCnz+Rgg+wgu+JwrJ+pMsisM+Db1I5d08PzKryOVFHq3n4YQrBbO9NrVYZqTQFq+0 7Bag== ARC-Authentication-Results: i=1; mx.google.com; dkim=pass header.i=@kernel.org header.s=k20201202 header.b="Y4p2M/AC"; 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 Return-Path: Received: from out1.vger.email (out1.vger.email. [2620:137:e000::1:20]) by mx.google.com with ESMTP id t25-20020a056402241900b00484cd38e00dsi22918072eda.629.2023.01.04.06.40.12; Wed, 04 Jan 2023 06:40:26 -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="Y4p2M/AC"; 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 S239271AbjADO3l (ORCPT + 57 others); Wed, 4 Jan 2023 09:29:41 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:51434 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S235017AbjADO3Y (ORCPT ); Wed, 4 Jan 2023 09:29:24 -0500 Received: from dfw.source.kernel.org (dfw.source.kernel.org [139.178.84.217]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 658DA1B1D0 for ; Wed, 4 Jan 2023 06:29:23 -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 dfw.source.kernel.org (Postfix) with ESMTPS id F09126174F for ; Wed, 4 Jan 2023 14:29:22 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 32078C433D2; Wed, 4 Jan 2023 14:29:20 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1672842562; bh=/UI6QPvD3oCrqOgTxaQlYrA8PAA4phdFzEfI7uMdEvo=; h=Date:From:To:Cc:Subject:In-Reply-To:References:From; b=Y4p2M/AC+xTfh9JFLOMmjjroaBF3QwtYvCH5KjtB0/sm6k5hW9/vKgaPLWfZ3VjkI r+ndxwc4O3N3AnKqzI7vz8OsBv8ceG72Kfxuvzm6OwdkbRwfeIVevthhKz2L5mMwBd BEYyMuRPJvxqRdq1UGQqxaJ5+7S8yihDiugny7HbFC2GP6xPCCZBSUzmx5uEikZ4WJ PucHYplNX7IHTwdGI1mW6wEGHPxQNohatS7M5ijIdFXZPOu5l+6kTsPmt6GhNxDyjU uIpd4R+KKpLmbsZCzEk1FRvHe9IaOKzrk9wh+HQFKCuDWqhN8NHvMVX5hh8m4A81+M tP0bGUK0uzd3A== Date: Wed, 4 Jan 2023 23:29:18 +0900 From: Masami Hiramatsu (Google) To: Steven Rostedt Cc: John Stultz , LKML , Lingutla Chandrasekhar , Masami Hiramatsu , Thomas Gleixner , "Paul E. McKenney" , "Connor O'Brien" , kernel-team@android.com, "J . Avila" Subject: Re: [PATCH] trace: Add trace points for tasklet entry/exit Message-Id: <20230104232918.2791484c39ac54c59a7110f4@kernel.org> In-Reply-To: <20230103151554.5c0a6c6f@gandalf.local.home> References: <20230103185408.2874345-1-jstultz@google.com> <20230103151554.5c0a6c6f@gandalf.local.home> X-Mailer: Sylpheed 3.8.0beta1 (GTK+ 2.24.33; x86_64-pc-linux-gnu) Mime-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=-8.8 required=5.0 tests=BAYES_00,DKIMWL_WL_HIGH, DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,NICE_REPLY_A, 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 On Tue, 3 Jan 2023 15:15:54 -0500 Steven Rostedt wrote: > On Tue, 3 Jan 2023 18:54:08 +0000 > John Stultz wrote: > > > 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. > > > > 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 > > --- > > include/trace/events/irq.h | 43 ++++++++++++++++++++++++++++++++++++++ > > kernel/softirq.c | 9 ++++++-- > > 2 files changed, 50 insertions(+), 2 deletions(-) > > > > diff --git a/include/trace/events/irq.h b/include/trace/events/irq.h > > index eeceafaaea4c..da85851d4ec1 100644 > > --- a/include/trace/events/irq.h > > +++ b/include/trace/events/irq.h > > @@ -160,6 +160,49 @@ DEFINE_EVENT(softirq, softirq_raise, > > TP_ARGS(vec_nr) > > ); > > > > +DECLARE_EVENT_CLASS(tasklet, > > + > > + TP_PROTO(void *func), > > + > > + TP_ARGS(func), > > + > > + TP_STRUCT__entry( > > Could you also add a pointer to the tasklet too? > > __field( void *, tasklet) > > > + __field( void *, func) > > + ), > > + > > + TP_fast_assign( > > __entry->tasklet = t; > > > + __entry->func = func; > > + ), > > + > > + TP_printk("function=%ps", __entry->func) > > This way if we wanted more information, we could use event probes: > > # echo 'e:tasklet_info tasklet/tasklet_entry state=+8($tasklet):u64' > dynamic_events Hmm, what about saving 'state' and 'count' instead of 'tasklet'? I have a question about the basic policy of making a new tracepoint. Of course we can expand the event with eprobes as you said, but without eprobe, this 'tasklet' field of this event just exposing a kernel internal object address. That is useless in most cases. And also the offset (layout) in the kernel data structure can be changed by some debug options. We need an external tool to find correct offset (e.g. perf probe). So my question is when adding a new event, whether it should expose a (address of) related data structure, or expose some value fields of the structure. IMHO, the basic policy is latter. Of course if the data structure is enough big and most of its fields are usually not interesting, it may be better to save the data structure itself. Thank you, > > -- Steve > > > > +); > > + > > +/** > > + * tasklet_entry - called immediately before the tasklet is run > > + * @func: tasklet callback or function being run > > + * > > + * Used to find individual tasklet execution time > > + */ > > +DEFINE_EVENT(tasklet, tasklet_entry, > > + > > + TP_PROTO(void *func), > > + > > + TP_ARGS(func) > > +); > > + > > +/** > > + * tasklet_exit - called immediately after the tasklet is run > > + * @func: tasklet callback or function being run > > + * > > + * Used to find individual tasklet execution time > > + */ > > +DEFINE_EVENT(tasklet, tasklet_exit, > > + > > + TP_PROTO(void *func), > > + > > + TP_ARGS(func) > > +); > > + > > #endif /* _TRACE_IRQ_H */ > > > > /* This part must be outside protection */ > > diff --git a/kernel/softirq.c b/kernel/softirq.c > > index c8a6913c067d..dbd322524171 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->callback); > > t->callback(t); > > - else > > + trace_tasklet_exit(t->callback); > > + } else { > > + trace_tasklet_entry(t->func); > > t->func(t->data); > > + trace_tasklet_exit(t->func); > > + } > > } > > tasklet_unlock(t); > > continue; > -- Masami Hiramatsu (Google)