From nobody Sun Sep 14 09:00:29 2025 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id D936DC27C76 for ; Wed, 25 Jan 2023 17:14:20 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S236175AbjAYROT (ORCPT ); Wed, 25 Jan 2023 12:14:19 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:38470 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S235610AbjAYRNz (ORCPT ); Wed, 25 Jan 2023 12:13:55 -0500 Received: from ams.source.kernel.org (ams.source.kernel.org [145.40.68.75]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id E1D31B45D for ; Wed, 25 Jan 2023 09:13:42 -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 6BD16B81B4D for ; Wed, 25 Jan 2023 17:13:41 +0000 (UTC) Received: by smtp.kernel.org (Postfix) with ESMTPSA id 0A2E7C433A4; Wed, 25 Jan 2023 17:13:40 +0000 (UTC) Received: from rostedt by gandalf.local.home with local (Exim 4.96) (envelope-from ) id 1pKjL9-004Nqn-0B; Wed, 25 Jan 2023 12:13:39 -0500 Message-ID: <20230125171338.871383998@goodmis.org> User-Agent: quilt/0.66 Date: Wed, 25 Jan 2023 12:12:55 -0500 From: Steven Rostedt To: linux-kernel@vger.kernel.org Cc: Masami Hiramatsu , Andrew Morton , Florent Revest , Mark Rutland Subject: [for-next][PATCH 03/12] ftrace: Add sample with custom ops References: <20230125171252.431857411@goodmis.org> MIME-Version: 1.0 Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset="utf-8" From: Mark Rutland When reworking core ftrace code or architectural ftrace code, it's often necessary to test/analyse/benchmark a number of ftrace_ops configurations. This patch adds a module which can be used to explore some of those configurations. I'm using this to benchmark various options for changing the way trampolines and handling of ftrace_ops work on arm64, and ensuring other architectures aren't adversely affected. For example, in a QEMU+KVM VM running on a 2GHz Xeon E5-2660 workstation, loading the module in various configurations produces: | # insmod ftrace-ops.ko | ftrace_ops: registering: | relevant ops: 1 | tracee: tracee_relevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | irrelevant ops: 0 | tracee: tracee_irrelevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | saving registers: NO | assist recursion: NO | assist RCU: NO | ftrace_ops: Attempted 100000 calls to tracee_relevant [ftrace_ops] in 168= 1558ns (16ns / call) | # insmod ftrace-ops.ko nr_ops_irrelevant=3D5 | ftrace_ops: registering: | relevant ops: 1 | tracee: tracee_relevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | irrelevant ops: 5 | tracee: tracee_irrelevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | saving registers: NO | assist recursion: NO | assist RCU: NO | ftrace_ops: Attempted 100000 calls to tracee_relevant [ftrace_ops] in 169= 3042ns (16ns / call) | # insmod ftrace-ops.ko nr_ops_relevant=3D2 | ftrace_ops: registering: | relevant ops: 2 | tracee: tracee_relevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | irrelevant ops: 0 | tracee: tracee_irrelevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | saving registers: NO | assist recursion: NO | assist RCU: NO | ftrace_ops: Attempted 100000 calls to tracee_relevant [ftrace_ops] in 119= 65582ns (119ns / call) | # insmod ftrace-ops.ko save_regs=3Dtrue | ftrace_ops: registering: | relevant ops: 1 | tracee: tracee_relevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | irrelevant ops: 0 | tracee: tracee_irrelevant [ftrace_ops] | tracer: ops_func_nop [ftrace_ops] | saving registers: YES | assist recursion: NO | assist RCU: NO | ftrace_ops: Attempted 100000 calls to tracee_relevant [ftrace_ops] in 445= 9624ns (44ns / call) Link: https://lkml.kernel.org/r/20230103124912.2948963-4-mark.rutland@arm.c= om Cc: Florent Revest Acked-by: Masami Hiramatsu (Google) Signed-off-by: Mark Rutland Signed-off-by: Steven Rostedt (Google) --- samples/Kconfig | 7 + samples/Makefile | 1 + samples/ftrace/Makefile | 1 + samples/ftrace/ftrace-ops.c | 252 ++++++++++++++++++++++++++++++++++++ 4 files changed, 261 insertions(+) create mode 100644 samples/ftrace/ftrace-ops.c diff --git a/samples/Kconfig b/samples/Kconfig index 0d81c00289ee..daf14c35f071 100644 --- a/samples/Kconfig +++ b/samples/Kconfig @@ -46,6 +46,13 @@ config SAMPLE_FTRACE_DIRECT_MULTI that hooks to wake_up_process and schedule, and prints the function addresses. =20 +config SAMPLE_FTRACE_OPS + tristate "Build custom ftrace ops example" + depends on FUNCTION_TRACER + help + This builds an ftrace ops example that hooks two functions and + measures the time taken to invoke one function a number of times. + config SAMPLE_TRACE_ARRAY tristate "Build sample module for kernel access to Ftrace instance= ss" depends on EVENT_TRACING && m diff --git a/samples/Makefile b/samples/Makefile index 9832ef3f8fcb..7cb632ef88ee 100644 --- a/samples/Makefile +++ b/samples/Makefile @@ -24,6 +24,7 @@ obj-$(CONFIG_SAMPLE_TRACE_CUSTOM_EVENTS) +=3D trace_event= s/ obj-$(CONFIG_SAMPLE_TRACE_PRINTK) +=3D trace_printk/ obj-$(CONFIG_SAMPLE_FTRACE_DIRECT) +=3D ftrace/ obj-$(CONFIG_SAMPLE_FTRACE_DIRECT_MULTI) +=3D ftrace/ +obj-$(CONFIG_SAMPLE_FTRACE_OPS) +=3D ftrace/ obj-$(CONFIG_SAMPLE_TRACE_ARRAY) +=3D ftrace/ subdir-$(CONFIG_SAMPLE_UHID) +=3D uhid obj-$(CONFIG_VIDEO_PCI_SKELETON) +=3D v4l/ diff --git a/samples/ftrace/Makefile b/samples/ftrace/Makefile index faf8cdb79c5f..589baf2ec4e3 100644 --- a/samples/ftrace/Makefile +++ b/samples/ftrace/Makefile @@ -5,6 +5,7 @@ obj-$(CONFIG_SAMPLE_FTRACE_DIRECT) +=3D ftrace-direct-too.o obj-$(CONFIG_SAMPLE_FTRACE_DIRECT) +=3D ftrace-direct-modify.o obj-$(CONFIG_SAMPLE_FTRACE_DIRECT_MULTI) +=3D ftrace-direct-multi.o obj-$(CONFIG_SAMPLE_FTRACE_DIRECT_MULTI) +=3D ftrace-direct-multi-modify.o +obj-$(CONFIG_SAMPLE_FTRACE_OPS) +=3D ftrace-ops.o =20 CFLAGS_sample-trace-array.o :=3D -I$(src) obj-$(CONFIG_SAMPLE_TRACE_ARRAY) +=3D sample-trace-array.o diff --git a/samples/ftrace/ftrace-ops.c b/samples/ftrace/ftrace-ops.c new file mode 100644 index 000000000000..24deb51c7261 --- /dev/null +++ b/samples/ftrace/ftrace-ops.c @@ -0,0 +1,252 @@ +// SPDX-License-Identifier: GPL-2.0-only + +#define pr_fmt(fmt) KBUILD_MODNAME ": " fmt + +#include +#include +#include + +#include + +/* + * Arbitrary large value chosen to be sufficiently large to minimize noise= but + * sufficiently small to complete quickly. + */ +unsigned int nr_function_calls =3D 100000; +module_param(nr_function_calls, uint, 0); +MODULE_PARM_DESC(nr_function_calls, "How many times to call the relevant t= racee"); + +/* + * The number of ops associated with a call site affects whether a tracer = can + * be called directly or whether it's necessary to go via the list func, w= hich + * can be significantly more expensive. + */ +unsigned int nr_ops_relevant =3D 1; +module_param(nr_ops_relevant, uint, 0); +MODULE_PARM_DESC(nr_ops_relevant, "How many ftrace_ops to associate with t= he relevant tracee"); + +/* + * On architectures where all call sites share the same trampoline, having + * tracers enabled for distinct functions can force the use of the list fu= nc + * and incur overhead for all call sites. + */ +unsigned int nr_ops_irrelevant =3D 0; +module_param(nr_ops_irrelevant, uint, 0); +MODULE_PARM_DESC(nr_ops_irrelevant, "How many ftrace_ops to associate with= the irrelevant tracee"); + +/* + * On architectures with DYNAMIC_FTRACE_WITH_REGS, saving the full pt_regs= can + * be more expensive than only saving the minimal necessary regs. + */ +bool save_regs =3D false; +module_param(save_regs, bool, 0); +MODULE_PARM_DESC(save_regs, "Register ops with FTRACE_OPS_FL_SAVE_REGS (sa= ve all registers in the trampoline)"); + +bool assist_recursion =3D false; +module_param(assist_recursion, bool, 0); +MODULE_PARM_DESC(assist_reursion, "Register ops with FTRACE_OPS_FL_RECURSI= ON"); + +bool assist_rcu =3D false; +module_param(assist_rcu, bool, 0); +MODULE_PARM_DESC(assist_reursion, "Register ops with FTRACE_OPS_FL_RCU"); + +/* + * By default, a trivial tracer is used which immediately returns to mimim= ize + * overhead. Sometimes a consistency check using a more expensive tracer is + * desireable. + */ +bool check_count =3D false; +module_param(check_count, bool, 0); +MODULE_PARM_DESC(check_count, "Check that tracers are called the expected = number of times\n"); + +/* + * Usually it's not interesting to leave the ops registered after the test + * runs, but sometimes it can be useful to leave them registered so that t= hey + * can be inspected through the tracefs 'enabled_functions' file. + */ +bool persist =3D false; +module_param(persist, bool, 0); +MODULE_PARM_DESC(persist, "Successfully load module and leave ftrace ops r= egistered after test completes\n"); + +/* + * Marked as noinline to ensure that an out-of-line traceable copy is + * generated by the compiler. + * + * The barrier() ensures the compiler won't elide calls by determining the= re + * are no side-effects. + */ +static noinline void tracee_relevant(void) +{ + barrier(); +} + +/* + * Marked as noinline to ensure that an out-of-line traceable copy is + * generated by the compiler. + * + * The barrier() ensures the compiler won't elide calls by determining the= re + * are no side-effects. + */ +static noinline void tracee_irrelevant(void) +{ + barrier(); +} + +struct sample_ops { + struct ftrace_ops ops; + unsigned int count; +}; + +static void ops_func_nop(unsigned long ip, unsigned long parent_ip, + struct ftrace_ops *op, + struct ftrace_regs *fregs) +{ + /* do nothing */ +} + +static void ops_func_count(unsigned long ip, unsigned long parent_ip, + struct ftrace_ops *op, + struct ftrace_regs *fregs) +{ + struct sample_ops *self; + + self =3D container_of(op, struct sample_ops, ops); + self->count++; +} + +struct sample_ops *ops_relevant; +struct sample_ops *ops_irrelevant; + +static struct sample_ops *ops_alloc_init(void *tracee, ftrace_func_t func, + unsigned long flags, int nr) +{ + struct sample_ops *ops; + + ops =3D kcalloc(nr, sizeof(*ops), GFP_KERNEL); + if (WARN_ON_ONCE(!ops)) + return NULL; + + for (unsigned int i =3D 0; i < nr; i++) { + ops[i].ops.func =3D func; + ops[i].ops.flags =3D flags; + WARN_ON_ONCE(ftrace_set_filter_ip(&ops[i].ops, (unsigned long)tracee, 0,= 0)); + WARN_ON_ONCE(register_ftrace_function(&ops[i].ops)); + } + + return ops; +} + +static void ops_destroy(struct sample_ops *ops, int nr) +{ + if (!ops) + return; + + for (unsigned int i =3D 0; i < nr; i++) { + WARN_ON_ONCE(unregister_ftrace_function(&ops[i].ops)); + ftrace_free_filter(&ops[i].ops); + } + + kfree(ops); +} + +static void ops_check(struct sample_ops *ops, int nr, + unsigned int expected_count) +{ + if (!ops || !check_count) + return; + + for (unsigned int i =3D 0; i < nr; i++) { + if (ops->count =3D=3D expected_count) + continue; + pr_warn("Counter called %u times (expected %u)\n", + ops->count, expected_count); + } +} + +ftrace_func_t tracer_relevant =3D ops_func_nop; +ftrace_func_t tracer_irrelevant =3D ops_func_nop; + +static int __init ftrace_ops_sample_init(void) +{ + unsigned long flags =3D 0; + ktime_t start, end; + u64 period; + + if (!IS_ENABLED(CONFIG_DYNAMIC_FTRACE_WITH_REGS) && save_regs) { + pr_info("this kernel does not support saving registers\n"); + save_regs =3D false; + } else if (save_regs) { + flags |=3D FTRACE_OPS_FL_SAVE_REGS; + } + + if (assist_recursion) + flags |=3D FTRACE_OPS_FL_RECURSION; + + if (assist_rcu) + flags |=3D FTRACE_OPS_FL_RCU; + + if (check_count) { + tracer_relevant =3D ops_func_count; + tracer_irrelevant =3D ops_func_count; + } + + pr_info("registering:\n" + " relevant ops: %u\n" + " tracee: %ps\n" + " tracer: %ps\n" + " irrelevant ops: %u\n" + " tracee: %ps\n" + " tracer: %ps\n" + " saving registers: %s\n" + " assist recursion: %s\n" + " assist RCU: %s\n", + nr_ops_relevant, tracee_relevant, tracer_relevant, + nr_ops_irrelevant, tracee_irrelevant, tracer_irrelevant, + save_regs ? "YES" : "NO", + assist_recursion ? "YES" : "NO", + assist_rcu ? "YES" : "NO"); + + ops_relevant =3D ops_alloc_init(tracee_relevant, tracer_relevant, + flags, nr_ops_relevant); + ops_irrelevant =3D ops_alloc_init(tracee_irrelevant, tracer_irrelevant, + flags, nr_ops_irrelevant); + + start =3D ktime_get(); + for (unsigned int i =3D 0; i < nr_function_calls; i++) + tracee_relevant(); + end =3D ktime_get(); + + ops_check(ops_relevant, nr_ops_relevant, nr_function_calls); + ops_check(ops_irrelevant, nr_ops_irrelevant, 0); + + period =3D ktime_to_ns(ktime_sub(end, start)); + + pr_info("Attempted %u calls to %ps in %lluns (%lluns / call)\n", + nr_function_calls, tracee_relevant, + period, period / nr_function_calls); + + if (persist) + return 0; + + ops_destroy(ops_relevant, nr_ops_relevant); + ops_destroy(ops_irrelevant, nr_ops_irrelevant); + + /* + * The benchmark completed sucessfully, but there's no reason to keep + * the module around. Return an error do the user doesn't have to + * manually unload the module. + */ + return -EINVAL; +} +module_init(ftrace_ops_sample_init); + +static void __exit ftrace_ops_sample_exit(void) +{ + ops_destroy(ops_relevant, nr_ops_relevant); + ops_destroy(ops_irrelevant, nr_ops_irrelevant); +} +module_exit(ftrace_ops_sample_exit); + +MODULE_AUTHOR("Mark Rutland"); +MODULE_DESCRIPTION("Example of using custom ftrace_ops"); +MODULE_LICENSE("GPL"); --=20 2.39.0