* [PATCH 1/3] samples/kprobes: Use trace_printk() in probe handlers
2026-11-02 7:10 [PATCH 0/3] probes: Use trace_printk() in probe handlers Masami Hiramatsu (Google)
@ 2026-11-02 7:11 ` Masami Hiramatsu (Google)
2026-11-02 7:11 ` [PATCH 2/3] samples/fprobe: Use trace_printk() and trace_dump_stack() Masami Hiramatsu (Google)
` (2 subsequent siblings)
3 siblings, 0 replies; 6+ messages in thread
From: Masami Hiramatsu (Google) @ 2026-11-02 7:11 UTC (permalink / raw)
To: Steven Rostedt, Masami Hiramatsu, Jonathan Corbet, Naveen N Rao,
David S . Miller
Cc: Mathieu Desnoyers, Shuah Khan, Randy Dunlap, Tiezhu Yang,
linux-kernel, linux-trace-kernel, linux-doc
From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Probe handlers execute in atomic/non-preemptible contexts. Furthermore,
unless hit via an unoptimized breakpoint on certain architectures,
they do not run with in_nmi() set (e.g. jump-optimized kprobes,
ftrace-based kprobes, or kretprobe return handlers). Calling printk()
from probe handlers can directly attempt to acquire console and
scheduler locks (via console_unlock()), risking a deadlock if the
probed context or interrupted code already holds one of those locks.
Replace printk() (pr_info) in handler_pre(), handler_post(), and
ret_handler() with trace_printk(), and update the comments to direct
users to /sys/kernel/tracing/trace. Also update the stack backtrace
comment in kprobe_example to reference trace_dump_stack(0).
Also fix a minor format string typo ("p->addr," -> "p->addr =") in the
S390 pre and post handlers while touching those lines.
Additionally, update CONFIG_SAMPLE_KPROBES in samples/Kconfig to
depend on EVENT_TRACING so that the tracing subsystem is enabled
when building the samples.
Reported-by: Tiezhu Yang <yangtiezhu@loongson.cn>
Closes: https://lore.kernel.org/all/d179086d-78d8-d0e3-e113-9072cffa55f4@loongson.cn/
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
samples/Kconfig | 2 +
samples/kprobes/kprobe_example.c | 69 ++++++++++++++++++-----------------
samples/kprobes/kretprobe_example.c | 10 +++--
3 files changed, 41 insertions(+), 40 deletions(-)
diff --git a/samples/Kconfig b/samples/Kconfig
index 00eed83c07df..54414e57ff75 100644
--- a/samples/Kconfig
+++ b/samples/Kconfig
@@ -71,7 +71,7 @@ config SAMPLE_KOBJECT
config SAMPLE_KPROBES
tristate "Build kprobes examples -- loadable modules only"
- depends on KPROBES && m
+ depends on KPROBES && EVENT_TRACING && m
help
This build several kprobes example modules.
diff --git a/samples/kprobes/kprobe_example.c b/samples/kprobes/kprobe_example.c
index 53ec6c8b8c40..0f516a2b04be 100644
--- a/samples/kprobes/kprobe_example.c
+++ b/samples/kprobes/kprobe_example.c
@@ -6,7 +6,7 @@
* For more information on theory of operation of kprobes, see
* Documentation/trace/kprobes.rst
*
- * You will see the trace data in /var/log/messages and on the console
+ * You will see the trace data in /sys/kernel/tracing/trace
* whenever kernel_clone() is invoked to create a new process.
*/
@@ -15,6 +15,7 @@
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>
+#include <linux/trace_printk.h>
static char symbol[KSYM_NAME_LEN] = "kernel_clone";
module_param_string(symbol, symbol, KSYM_NAME_LEN, 0644);
@@ -28,39 +29,39 @@ static struct kprobe kp = {
static int __kprobes handler_pre(struct kprobe *p, struct pt_regs *regs)
{
#ifdef CONFIG_X86
- pr_info("<%s> p->addr = 0x%p, ip = %lx, flags = 0x%lx\n",
- p->symbol_name, p->addr, regs->ip, regs->flags);
+ trace_printk("<%s> p->addr = 0x%p, ip = %lx, flags = 0x%lx\n",
+ p->symbol_name, p->addr, regs->ip, regs->flags);
#endif
#ifdef CONFIG_PPC
- pr_info("<%s> p->addr = 0x%p, nip = 0x%lx, msr = 0x%lx\n",
- p->symbol_name, p->addr, regs->nip, regs->msr);
+ trace_printk("<%s> p->addr = 0x%p, nip = 0x%lx, msr = 0x%lx\n",
+ p->symbol_name, p->addr, regs->nip, regs->msr);
#endif
#ifdef CONFIG_MIPS
- pr_info("<%s> p->addr = 0x%p, epc = 0x%lx, status = 0x%lx\n",
- p->symbol_name, p->addr, regs->cp0_epc, regs->cp0_status);
+ trace_printk("<%s> p->addr = 0x%p, epc = 0x%lx, status = 0x%lx\n",
+ p->symbol_name, p->addr, regs->cp0_epc, regs->cp0_status);
#endif
#ifdef CONFIG_ARM64
- pr_info("<%s> p->addr = 0x%p, pc = 0x%lx, pstate = 0x%lx\n",
- p->symbol_name, p->addr, (long)regs->pc, (long)regs->pstate);
+ trace_printk("<%s> p->addr = 0x%p, pc = 0x%lx, pstate = 0x%lx\n",
+ p->symbol_name, p->addr, (long)regs->pc, (long)regs->pstate);
#endif
#ifdef CONFIG_ARM
- pr_info("<%s> p->addr = 0x%p, pc = 0x%lx, cpsr = 0x%lx\n",
- p->symbol_name, p->addr, (long)regs->ARM_pc, (long)regs->ARM_cpsr);
+ trace_printk("<%s> p->addr = 0x%p, pc = 0x%lx, cpsr = 0x%lx\n",
+ p->symbol_name, p->addr, (long)regs->ARM_pc, (long)regs->ARM_cpsr);
#endif
#ifdef CONFIG_RISCV
- pr_info("<%s> p->addr = 0x%p, pc = 0x%lx, status = 0x%lx\n",
- p->symbol_name, p->addr, regs->epc, regs->status);
+ trace_printk("<%s> p->addr = 0x%p, pc = 0x%lx, status = 0x%lx\n",
+ p->symbol_name, p->addr, regs->epc, regs->status);
#endif
#ifdef CONFIG_S390
- pr_info("<%s> p->addr, 0x%p, ip = 0x%lx, flags = 0x%lx\n",
- p->symbol_name, p->addr, regs->psw.addr, regs->flags);
+ trace_printk("<%s> p->addr = 0x%p, ip = 0x%lx, flags = 0x%lx\n",
+ p->symbol_name, p->addr, regs->psw.addr, regs->flags);
#endif
#ifdef CONFIG_LOONGARCH
- pr_info("<%s> p->addr = 0x%p, era = 0x%lx, estat = 0x%lx\n",
- p->symbol_name, p->addr, regs->csr_era, regs->csr_estat);
+ trace_printk("<%s> p->addr = 0x%p, era = 0x%lx, estat = 0x%lx\n",
+ p->symbol_name, p->addr, regs->csr_era, regs->csr_estat);
#endif
- /* A dump_stack() here will give a stack backtrace */
+ /* A trace_dump_stack(0) here will give a stack backtrace */
return 0;
}
@@ -69,36 +70,36 @@ static void __kprobes handler_post(struct kprobe *p, struct pt_regs *regs,
unsigned long flags)
{
#ifdef CONFIG_X86
- pr_info("<%s> p->addr = 0x%p, flags = 0x%lx\n",
- p->symbol_name, p->addr, regs->flags);
+ trace_printk("<%s> p->addr = 0x%p, flags = 0x%lx\n",
+ p->symbol_name, p->addr, regs->flags);
#endif
#ifdef CONFIG_PPC
- pr_info("<%s> p->addr = 0x%p, msr = 0x%lx\n",
- p->symbol_name, p->addr, regs->msr);
+ trace_printk("<%s> p->addr = 0x%p, msr = 0x%lx\n",
+ p->symbol_name, p->addr, regs->msr);
#endif
#ifdef CONFIG_MIPS
- pr_info("<%s> p->addr = 0x%p, status = 0x%lx\n",
- p->symbol_name, p->addr, regs->cp0_status);
+ trace_printk("<%s> p->addr = 0x%p, status = 0x%lx\n",
+ p->symbol_name, p->addr, regs->cp0_status);
#endif
#ifdef CONFIG_ARM64
- pr_info("<%s> p->addr = 0x%p, pstate = 0x%lx\n",
- p->symbol_name, p->addr, (long)regs->pstate);
+ trace_printk("<%s> p->addr = 0x%p, pstate = 0x%lx\n",
+ p->symbol_name, p->addr, (long)regs->pstate);
#endif
#ifdef CONFIG_ARM
- pr_info("<%s> p->addr = 0x%p, cpsr = 0x%lx\n",
- p->symbol_name, p->addr, (long)regs->ARM_cpsr);
+ trace_printk("<%s> p->addr = 0x%p, cpsr = 0x%lx\n",
+ p->symbol_name, p->addr, (long)regs->ARM_cpsr);
#endif
#ifdef CONFIG_RISCV
- pr_info("<%s> p->addr = 0x%p, status = 0x%lx\n",
- p->symbol_name, p->addr, regs->status);
+ trace_printk("<%s> p->addr = 0x%p, status = 0x%lx\n",
+ p->symbol_name, p->addr, regs->status);
#endif
#ifdef CONFIG_S390
- pr_info("<%s> p->addr, 0x%p, flags = 0x%lx\n",
- p->symbol_name, p->addr, regs->flags);
+ trace_printk("<%s> p->addr = 0x%p, flags = 0x%lx\n",
+ p->symbol_name, p->addr, regs->flags);
#endif
#ifdef CONFIG_LOONGARCH
- pr_info("<%s> p->addr = 0x%p, estat = 0x%lx\n",
- p->symbol_name, p->addr, regs->csr_estat);
+ trace_printk("<%s> p->addr = 0x%p, estat = 0x%lx\n",
+ p->symbol_name, p->addr, regs->csr_estat);
#endif
}
diff --git a/samples/kprobes/kretprobe_example.c b/samples/kprobes/kretprobe_example.c
index 65d6dcafd742..9dd5cf9a7432 100644
--- a/samples/kprobes/kretprobe_example.c
+++ b/samples/kprobes/kretprobe_example.c
@@ -14,9 +14,8 @@
* Documentation/trace/kprobes.rst
*
* Build and insert the kernel module as done in the kprobe example.
- * You will see the trace data in /var/log/messages and on the console
- * whenever the probed function returns. (Some messages may be suppressed
- * if syslogd is configured to eliminate duplicate messages.)
+ * You will see the trace data in /sys/kernel/tracing/trace
+ * whenever the probed function returns.
*/
#include <linux/kernel.h>
@@ -24,6 +23,7 @@
#include <linux/kprobes.h>
#include <linux/ktime.h>
#include <linux/sched.h>
+#include <linux/trace_printk.h>
static char func_name[KSYM_NAME_LEN] = "kernel_clone";
module_param_string(func, func_name, KSYM_NAME_LEN, 0644);
@@ -63,8 +63,8 @@ static int ret_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
now = ktime_get();
delta = ktime_to_ns(ktime_sub(now, data->entry_stamp));
- pr_info("%s returned %lu and took %lld ns to execute\n",
- func_name, retval, (long long)delta);
+ trace_printk("%s returned %lu and took %lld ns to execute\n",
+ func_name, retval, (long long)delta);
return 0;
}
NOKPROBE_SYMBOL(ret_handler);
^ permalink raw reply related [flat|nested] 6+ messages in thread* [PATCH 2/3] samples/fprobe: Use trace_printk() and trace_dump_stack()
2026-11-02 7:10 [PATCH 0/3] probes: Use trace_printk() in probe handlers Masami Hiramatsu (Google)
2026-11-02 7:11 ` [PATCH 1/3] samples/kprobes: " Masami Hiramatsu (Google)
@ 2026-11-02 7:11 ` Masami Hiramatsu (Google)
2026-11-02 7:11 ` [PATCH 3/3] docs: trace: Warn against using printk() in probe handlers Masami Hiramatsu (Google)
2026-11-02 17:34 ` [PATCH 0/3] probes: Use trace_printk() " Steven Rostedt
3 siblings, 0 replies; 6+ messages in thread
From: Masami Hiramatsu (Google) @ 2026-11-02 7:11 UTC (permalink / raw)
To: Steven Rostedt, Masami Hiramatsu, Jonathan Corbet, Naveen N Rao,
David S . Miller
Cc: Mathieu Desnoyers, Shuah Khan, Randy Dunlap, Tiezhu Yang,
linux-kernel, linux-trace-kernel, linux-doc
From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Fprobe entry and exit callbacks execute in atomic context with
preemption disabled under ftrace recursion protection. Calling
printk() directly inside handlers can lead to deadlocks if console
or scheduler locks are already held by the probed or interrupted context.
Drop the use_trace module parameter and always use trace_printk()
for handler logging. In addition, replace stack_trace_print() (which
uses printk()) with trace_dump_stack(0) to output backtraces safely
to the ftrace buffer. Also update the module header comment to
reference /sys/kernel/tracing/trace.
Additionally, update CONFIG_SAMPLE_FPROBE in samples/Kconfig to
depend on EVENT_TRACING so that the tracing subsystem is enabled
when building the sample.
Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
samples/Kconfig | 2 +-
samples/fprobe/fprobe_example.c | 49 ++++++++-------------------------------
2 files changed, 11 insertions(+), 40 deletions(-)
diff --git a/samples/Kconfig b/samples/Kconfig
index 54414e57ff75..744d991ea620 100644
--- a/samples/Kconfig
+++ b/samples/Kconfig
@@ -88,7 +88,7 @@ config SAMPLE_HW_BREAKPOINT
config SAMPLE_FPROBE
tristate "Build fprobe examples -- loadable modules only"
- depends on FPROBE && m
+ depends on FPROBE && EVENT_TRACING && m
help
This builds a fprobe example module. This module has an option 'symbol'.
You can specify a probed symbol or symbols separated with ','.
diff --git a/samples/fprobe/fprobe_example.c b/samples/fprobe/fprobe_example.c
index bfe98ce826f3..3b94839b3199 100644
--- a/samples/fprobe/fprobe_example.c
+++ b/samples/fprobe/fprobe_example.c
@@ -1,12 +1,12 @@
// SPDX-License-Identifier: GPL-2.0-only
/*
* Here's a sample kernel module showing the use of fprobe to dump a
- * stack trace and selected registers when kernel_clone() is called.
+ * stack trace and function entry/exit when kernel_clone() is called.
*
- * For more information on theory of operation of kprobes, see
- * Documentation/trace/kprobes.rst
+ * For more information on theory of operation of fprobe, see
+ * Documentation/trace/fprobe.rst
*
- * You will see the trace data in /var/log/messages and on the console
+ * You will see the trace data in /sys/kernel/tracing/trace
* whenever kernel_clone() is invoked to create a new process.
*/
@@ -15,10 +15,9 @@
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/fprobe.h>
-#include <linux/sched/debug.h>
#include <linux/slab.h>
+#include <linux/trace_printk.h>
-#define BACKTRACE_DEPTH 16
#define MAX_SYMBOL_LEN 4096
static struct fprobe sample_probe;
static unsigned long nhit;
@@ -35,34 +34,14 @@ static bool stackdump = true;
module_param(stackdump, bool, 0644);
MODULE_PARM_DESC(stackdump, "Enable stackdump.");
-static bool use_trace = false;
-module_param(use_trace, bool, 0644);
-MODULE_PARM_DESC(use_trace, "Use trace_printk instead of printk. This is only for debugging.");
-
-static void show_backtrace(void)
-{
- unsigned long stacks[BACKTRACE_DEPTH];
- unsigned int len;
-
- len = stack_trace_save(stacks, BACKTRACE_DEPTH, 2);
- stack_trace_print(stacks, len, 24);
-}
-
static int sample_entry_handler(struct fprobe *fp, unsigned long ip,
unsigned long ret_ip,
struct ftrace_regs *fregs, void *data)
{
- if (use_trace)
- /*
- * This is just an example, no kernel code should call
- * trace_printk() except when actively debugging.
- */
- trace_printk("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
- else
- pr_info("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
+ trace_printk("Enter <%pS> ip = 0x%p\n", (void *)ip, (void *)ip);
nhit++;
if (stackdump)
- show_backtrace();
+ trace_dump_stack(0);
return 0;
}
@@ -72,19 +51,11 @@ static void sample_exit_handler(struct fprobe *fp, unsigned long ip,
{
unsigned long rip = ret_ip;
- if (use_trace)
- /*
- * This is just an example, no kernel code should call
- * trace_printk() except when actively debugging.
- */
- trace_printk("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
- (void *)ip, (void *)ip, (void *)rip, (void *)rip);
- else
- pr_info("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
- (void *)ip, (void *)ip, (void *)rip, (void *)rip);
+ trace_printk("Return from <%pS> ip = 0x%p to rip = 0x%p (%pS)\n",
+ (void *)ip, (void *)ip, (void *)rip, (void *)rip);
nhit++;
if (stackdump)
- show_backtrace();
+ trace_dump_stack(0);
}
static int __init fprobe_init(void)
^ permalink raw reply related [flat|nested] 6+ messages in thread