From: Masami Hiramatsu (Google) <[email protected]>
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 <[email protected]>
Closes:
https://lore.kernel.org/all/[email protected]/
Signed-off-by: Masami Hiramatsu (Google) <[email protected]>
---
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);
