From nobody Wed Apr 1 09:05:44 2026 Received: from smtp.kernel.org (aws-us-west-2-korg-mail-1.web.codeaurora.org [10.30.226.201]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id DC5ED43CEDB; Tue, 31 Mar 2026 18:13:34 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=10.30.226.201 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1774980815; cv=none; b=cvhb+Yiwt9ZSe6en6ug9trWVShlYNfPsv62E7bIZCmuV5Y5xpDk77YJKpplykvKIb6MCtPkULBlc1pjmWmNVeMVM2jRa4/b1gQ48/99sLINrdkzhP73f+9UBLWZp8LbzTBDZr+69klE2NMS+0+YtMNNiflZ7uvPWq/LE+wHWSu0= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1774980815; c=relaxed/simple; bh=jtkhC5zkuWJgsb8bz13hxbtM1cDzFuWpsUa2H68kUu0=; h=Message-ID:Date:From:To:Cc:Subject:References:MIME-Version: Content-Type; b=pvjRD2x4a+Eyk+lLtNnGu5YsyhqesPN7cdD+xiCIXmqcM7AxfV+4slTmXJpXILbgter8w9X+FuqdM7U5EbA8DfDwtCovXWBs2vB74lFfjMSws3RaemLpLmO/Yq8J7ETZejVt/LiOQvIBomx//yF2W4JelnjrsuTG9vVSeRB3rqU= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b=T7BOSFND; arc=none smtp.client-ip=10.30.226.201 Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b="T7BOSFND" Received: by smtp.kernel.org (Postfix) with ESMTPSA id 759ECC2BCB0; Tue, 31 Mar 2026 18:13:34 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1774980814; bh=jtkhC5zkuWJgsb8bz13hxbtM1cDzFuWpsUa2H68kUu0=; h=Date:From:To:Cc:Subject:References:From; b=T7BOSFNDJG8KZCi0MRVuuViN0iO0KWBw0ypqib95lEs8Fm+AiaU3e7L71Zmh3k1w0 66ToA/xWVuq01LNtC8uhJ7GaaIcYv0hl307Z97M+/0lFOSoJFv8rQ/7QSSev9kVIwG m/OlBOVVRYBM5nt1/p15uyd/HFcEuFFfpfHsAu1g/Ku8ExI/Bz9PPolx2mKY44pECY +mtBd3C/DvPwrONs/yFJ/zJGQOdo/qUOd7V+XRLKooV39TMiuSEZqXgj0Pl4XfLoUh +Uyd7QKhS2mNPWIcIZ+xuQ1TI6dWB0zwUCZZDYQ1JcHPDa/fl5kct1RW4tnL/LEEAX P5k6PYP4JUNxQ== Received: from rostedt by gandalf with local (Exim 4.99.1) (envelope-from ) id 1w7dbl-0000000H8t5-0ZQs; Tue, 31 Mar 2026 14:14:33 -0400 Message-ID: <20260331181432.995263521@kernel.org> User-Agent: quilt/0.69 Date: Tue, 31 Mar 2026 14:13:50 -0400 From: Steven Rostedt To: linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org Cc: Masami Hiramatsu , Mark Rutland , Mathieu Desnoyers , Andrew Morton , Thomas Gleixner , Peter Zijlstra , Brian Geffon , John Stultz , Ian Rogers , Suleiman Souhlal Subject: [PATCH v3 1/3] tracing: Have futex syscall trace event show specific user data References: <20260331181349.062575155@kernel.org> Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset="utf-8" From: Steven Rostedt Add specific reporting of the futex system call. This allows for debugging the futex code a bit easier. Instead of just showing the values passed into the futex system call, read the value of the user space memory pointed to by the addr parameter. Also make the op parameter more readable by parsing the values to show what the command is: futex_requeue_p-3251 [002] ..... 2101.068479: sys_futex(uaddr: 0x55e79= a4da834 (0x80000cb1), FUTEX_LOCK_PI|FUTEX_PRIVATE_FLAG, val: 0) futex_requeue_p-3248 [001] ..... 2101.068970: sys_futex(uaddr: 0x7f859= 072f990 (0xcb2), FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, val: 3250) futex_requeue_p-3252 [005] ..... 2101.069108: sys_futex(uaddr: 0x55e79= a4da838 (0), FUTEX_WAIT_REQUEUE_PI|FUTEX_PRIVATE_FLAG, val: 0, timespec: 0x= 7ffe61076aa0, uaddr2: 0x55e79a4da834, uaddr2: 94453214586932, val3: 0) futex_requeue_p-3252 [005] ..... 2101.069410: sys_futex(uaddr: 0x55e79= a4da834 (0x80000cb1), FUTEX_LOCK_PI|FUTEX_PRIVATE_FLAG, val: 0) Signed-off-by: Steven Rostedt (Google) --- Changes since v2: https://patch.msgid.link/20260310201036.542627924@kernel.= org - Removed unused "buf" variable (kernel test robot) - Iterate __futex_cmds[] make the print statement. Note this required exposing __futex_cmds[] to trace_syscall.c - Added back val statement (with the move to futex/syscall.c the third parameter was dropped). include/linux/futex.h | 8 +- kernel/futex/syscalls.c | 97 +++++++++++++++++++++++ kernel/trace/trace_syscalls.c | 144 +++++++++++++++++++++++++++++++++- 3 files changed, 245 insertions(+), 4 deletions(-) diff --git a/include/linux/futex.h b/include/linux/futex.h index 9e9750f04980..7eaf01ff68cf 100644 --- a/include/linux/futex.h +++ b/include/linux/futex.h @@ -82,6 +82,11 @@ long do_futex(u32 __user *uaddr, int op, u32 val, ktime_= t *timeout, u32 __user *uaddr2, u32 val2, u32 val3); int futex_hash_prctl(unsigned long arg2, unsigned long arg3, unsigned long= arg4); =20 +#ifdef CONFIG_FTRACE_SYSCALLS +void futex_print_syscall(struct seq_buf *s, int nr_args, unsigned long *ar= gs, u32 *ptr); +extern const char * __futex_cmds[]; +#endif + #ifdef CONFIG_FUTEX_PRIVATE_HASH int futex_hash_allocate_default(void); void futex_hash_free(struct mm_struct *mm); @@ -114,7 +119,8 @@ static inline int futex_hash_allocate_default(void) } static inline int futex_hash_free(struct mm_struct *mm) { return 0; } static inline int futex_mm_init(struct mm_struct *mm) { return 0; } - +static inline void futex_print_syscall(struct seq_buf *s, int nr_args, + unsigned long *args, u32 *ptr) { } #endif =20 #endif diff --git a/kernel/futex/syscalls.c b/kernel/futex/syscalls.c index 743c7a728237..3ba8ca017c9c 100644 --- a/kernel/futex/syscalls.c +++ b/kernel/futex/syscalls.c @@ -171,6 +171,18 @@ static __always_inline bool futex_cmd_has_timeout(u32 = cmd) return false; } =20 +static __always_inline bool futex_cmd_has_addr2(u32 cmd) +{ + switch (cmd) { + case FUTEX_REQUEUE: + case FUTEX_CMP_REQUEUE: + case FUTEX_WAKE_OP: + case FUTEX_WAIT_REQUEUE_PI: + return true; + } + return false; +} + static __always_inline int futex_init_timeout(u32 cmd, u32 op, struct timespec64 *ts, ktime_t *t) { @@ -207,6 +219,91 @@ SYSCALL_DEFINE6(futex, u32 __user *, uaddr, int, op, u= 32, val, return do_futex(uaddr, op, val, tp, uaddr2, (unsigned long)utime, val3); } =20 +#ifdef CONFIG_FTRACE_SYSCALLS + +/* End with NULL for iterators */ +const char * __futex_cmds[] =3D +{ + "FUTEX_WAIT", "FUTEX_WAKE", "FUTEX_FD", "FUTEX_REQUEUE", + "FUTEX_CMP_REQUEUE", "FUTEX_WAKE_OP", "FUTEX_LOCK_PI", + "FUTEX_UNLOCK_PI", "FUTEX_TRYLOCK_PI", "FUTEX_WAIT_BITSET", + "FUTEX_WAKE_BITSET", "FUTEX_WAIT_REQUEUE_PI", "FUTEX_CMP_REQUEUE_PI", + "FUTEX_LOCK_PI2", NULL +}; + +void futex_print_syscall(struct seq_buf *s, int nr_args, unsigned long *ar= gs, u32 *ptr) +{ + unsigned int op, cmd; + bool done =3D false; + + for (int i =3D 0; !done && i < nr_args; i++) { + + if (seq_buf_has_overflowed(s)) + break; + + switch (i) { + case 0: + seq_buf_printf(s, "uaddr: 0x%lx", args[i]); + if (ptr) { + u32 val =3D *ptr; + if (val < 10) + seq_buf_printf(s, " (%u)", val); + else + seq_buf_printf(s, " (0x%x)", val); + } + continue; + case 1: + op =3D args[i]; + cmd =3D op & FUTEX_CMD_MASK; + if (cmd <=3D FUTEX_LOCK_PI2) + seq_buf_printf(s, ", %s", __futex_cmds[cmd]); + else + seq_buf_puts(s, ", UNKNOWN"); + + if (op & FUTEX_PRIVATE_FLAG) + seq_buf_puts(s, "|FUTEX_PRIVATE_FLAG"); + if (op & FUTEX_CLOCK_REALTIME) + seq_buf_puts(s, "|FUTEX_CLOCK_REALTIME"); + continue; + case 2: + if (args[i] < 10) + seq_buf_printf(s, ", val: %ld", args[i]); + else + seq_buf_printf(s, ", val: 0x%lx", args[i]); + continue; + case 3: + if (!futex_cmd_has_timeout(cmd)) { + + if (!futex_cmd_has_addr2(cmd)) { + done =3D true; + continue; + } + + seq_buf_printf(s, ", val2: 0x%x", (u32)(long)args[i]); + continue; + } + + if (!args[i]) + continue; + + seq_buf_printf(s, ", timespec: 0x%lx", args[i]); + continue; + case 4: + if (!futex_cmd_has_addr2(cmd)) { + done =3D true; + continue; + } + seq_buf_printf(s, ", uaddr2: 0x%lx", args[i]); + continue; + case 5: + seq_buf_printf(s, ", val3: %lu", args[i]); + done =3D true; + continue; + } + } +} +#endif + /** * futex_parse_waitv - Parse a waitv array from userspace * @futexv: Kernel side list of waiters to be filled diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c index 37317b81fcda..f8213d772f89 100644 --- a/kernel/trace/trace_syscalls.c +++ b/kernel/trace/trace_syscalls.c @@ -6,11 +6,13 @@ #include #include #include /* for MODULE_NAME_LEN via KSYM_SYMBOL_LEN */ +#include #include #include #include #include =20 + #include "trace_output.h" #include "trace.h" =20 @@ -237,6 +239,27 @@ sys_enter_openat_print(struct syscall_trace_enter *tra= ce, struct syscall_metadat return trace_handle_return(s); } =20 +static enum print_line_t +sys_enter_futex_print(struct syscall_trace_enter *trace, struct syscall_me= tadata *entry, + struct trace_seq *s, struct trace_event *event, int ent_size) +{ + void *end =3D (void *)trace + ent_size; + void *ptr; + + /* Set ptr to the user space copied area */ + ptr =3D (void *)trace->args + sizeof(unsigned long) * entry->nb_args; + if (ptr + 4 > end) + ptr =3D NULL; + + trace_seq_printf(s, "%s(", entry->name); + + futex_print_syscall(&s->seq, entry->nb_args, trace->args, ptr); + + trace_seq_puts(s, ")\n"); + + return trace_handle_return(s); +} + static enum print_line_t print_syscall_enter(struct trace_iterator *iter, int flags, struct trace_event *event) @@ -267,6 +290,10 @@ print_syscall_enter(struct trace_iterator *iter, int f= lags, if (!tr || !(tr->trace_flags & TRACE_ITER(VERBOSE))) return sys_enter_openat_print(trace, entry, s, event); break; + case __NR_futex: + if (!tr || !(tr->trace_flags & TRACE_ITER(VERBOSE))) + return sys_enter_futex_print(trace, entry, s, event, iter->ent_size); + break; default: break; } @@ -437,6 +464,48 @@ sys_enter_openat_print_fmt(struct syscall_metadata *en= try, char *buf, int len) return pos; } =20 +static int __init +sys_enter_futex_print_fmt(struct syscall_metadata *entry, char *buf, int l= en) +{ + int pos =3D 0; + + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + "\"uaddr: 0x%%lx (0x%%lx) cmd=3D%%s%%s%%s"); + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " val: 0x%%x timeout/val2: 0x%%llx"); + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " uaddr2: 0x%%lx val3: 0x%%x\", "); + + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " REC->uaddr,"); + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " REC->__value,"); + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " __print_symbolic(REC->op & 0x%x, ", FUTEX_CMD_MASK); + + for (int i =3D 0; __futex_cmds[i]; i++) { + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + "%s{%d, \"%s\"} ", + i ? "," : "", i, __futex_cmds[i]); + } + + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, "), "); + + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " (REC->op & %d) ? \"|FUTEX_PRIVATE_FLAG\" : \"\",", + FUTEX_PRIVATE_FLAG); + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " (REC->op & %d) ? \"|FUTEX_CLOCK_REALTIME\" : \"\",", + FUTEX_CLOCK_REALTIME); + + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " REC->val, REC->utime,"); + + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " REC->uaddr, REC->val3"); + return pos; +} + static int __init __set_enter_print_fmt(struct syscall_metadata *entry, char *buf, int len) { @@ -447,6 +516,8 @@ __set_enter_print_fmt(struct syscall_metadata *entry, c= har *buf, int len) switch (entry->syscall_nr) { case __NR_openat: return sys_enter_openat_print_fmt(entry, buf, len); + case __NR_futex: + return sys_enter_futex_print_fmt(entry, buf, len); default: break; } @@ -523,6 +594,21 @@ static void __init free_syscall_print_fmt(struct trace= _event_call *call) kfree(call->print_fmt); } =20 +static int __init futex_fields(struct trace_event_call *call, int offset) +{ + char *arg; + int ret; + + arg =3D kstrdup("__value", GFP_KERNEL); + if (WARN_ON_ONCE(!arg)) + return -ENOMEM; + ret =3D trace_define_field(call, "u32", arg, offset, sizeof(int), 0, + FILTER_OTHER); + if (ret) + kfree(arg); + return ret; +} + static int __init syscall_enter_define_fields(struct trace_event_call *cal= l) { struct syscall_trace_enter trace; @@ -544,6 +630,9 @@ static int __init syscall_enter_define_fields(struct tr= ace_event_call *call) offset +=3D sizeof(unsigned long); } =20 + if (!ret && meta->syscall_nr =3D=3D __NR_futex) + return futex_fields(call, offset); + if (ret || !meta->user_mask) return ret; =20 @@ -689,6 +778,45 @@ static int syscall_copy_user_array(char *buf, const ch= ar __user *ptr, return 0; } =20 +static int +syscall_get_futex(unsigned long *args, char **buffer, int *size, int buf_s= ize) +{ + struct syscall_user_buffer *sbuf; + const char __user *ptr; + + /* buf_size of zero means user doesn't want user space read */ + if (!buf_size) + return -1; + + /* If the syscall_buffer is NULL, tracing is being shutdown */ + sbuf =3D READ_ONCE(syscall_buffer); + if (!sbuf) + return -1; + + ptr =3D (char __user *)args[0]; + + *buffer =3D trace_user_fault_read(&sbuf->buf, ptr, 4, NULL, NULL); + if (!*buffer) + return -1; + + /* Add room for the value */ + *size +=3D 4; + + return 0; +} + +static void syscall_put_futex(struct syscall_metadata *sys_data, + struct syscall_trace_enter *entry, + char *buffer) +{ + u32 *ptr; + + /* Place the futex key into the storage */ + ptr =3D (void *)entry->args + sizeof(unsigned long) * sys_data->nb_args; + + *ptr =3D *(u32 *)buffer; +} + static char *sys_fault_user(unsigned int buf_size, struct syscall_metadata *sys_data, struct syscall_user_buffer *sbuf, @@ -905,6 +1033,9 @@ static void ftrace_syscall_enter(void *data, struct pt= _regs *regs, long id) if (syscall_get_data(sys_data, args, &user_ptr, &size, user_sizes, &uargs, tr->syscall_buf_sz) < 0) return; + } else if (syscall_nr =3D=3D __NR_futex) { + if (syscall_get_futex(args, &user_ptr, &size, tr->syscall_buf_sz) < 0) + return; } =20 size +=3D sizeof(*entry) + sizeof(unsigned long) * sys_data->nb_args; @@ -921,6 +1052,9 @@ static void ftrace_syscall_enter(void *data, struct pt= _regs *regs, long id) if (mayfault) syscall_put_data(sys_data, entry, user_ptr, size, user_sizes, uargs); =20 + else if (syscall_nr =3D=3D __NR_futex) + syscall_put_futex(sys_data, entry, user_ptr); + trace_event_buffer_commit(&fbuffer); } =20 @@ -971,14 +1105,18 @@ static int reg_event_syscall_enter(struct trace_even= t_file *file, { struct syscall_metadata *sys_data =3D call->data; struct trace_array *tr =3D file->tr; + bool enable_faults; int ret =3D 0; int num; =20 num =3D sys_data->syscall_nr; if (WARN_ON_ONCE(num < 0 || num >=3D NR_syscalls)) return -ENOSYS; + + enable_faults =3D sys_data->user_mask || num =3D=3D __NR_futex; + guard(mutex)(&syscall_trace_lock); - if (sys_data->user_mask) { + if (enable_faults) { ret =3D syscall_fault_buffer_enable(); if (ret < 0) return ret; @@ -986,7 +1124,7 @@ static int reg_event_syscall_enter(struct trace_event_= file *file, if (!tr->sys_refcount_enter) { ret =3D register_trace_sys_enter(ftrace_syscall_enter, tr); if (ret < 0) { - if (sys_data->user_mask) + if (enable_faults) syscall_fault_buffer_disable(); return ret; } @@ -1011,7 +1149,7 @@ static void unreg_event_syscall_enter(struct trace_ev= ent_file *file, WRITE_ONCE(tr->enter_syscall_files[num], NULL); if (!tr->sys_refcount_enter) unregister_trace_sys_enter(ftrace_syscall_enter, tr); - if (sys_data->user_mask) + if (sys_data->user_mask || num =3D=3D __NR_futex) syscall_fault_buffer_disable(); } =20 --=20 2.51.0 From nobody Wed Apr 1 09:05:44 2026 Received: from smtp.kernel.org (aws-us-west-2-korg-mail-1.web.codeaurora.org [10.30.226.201]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 2094544CF59; Tue, 31 Mar 2026 18:13:34 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=10.30.226.201 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1774980815; cv=none; b=Q6nRLQaQWuGpr840+08YmkxVgT30Joifa+S6mdQU1bhzMPwT6etWsW6B3KEASSPwhaPdUI0RaybNXSIaBv+HnsNvB67KWkZ5lpTE4V2PaKu5mXqxLIp7Bf7+AYsplSkI2lKrGBOcMidCqXoVIjYq3UYH0/4RkYwNHiKOxtCunV4= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1774980815; c=relaxed/simple; bh=K6u0PspPsS0IqE8W/Ttx61OZoVKvYhh4U0f4jYfu35M=; h=Message-ID:Date:From:To:Cc:Subject:References:MIME-Version: Content-Type; b=KQaOAvkm/0Hjfga0Jc+a1DpcwwdzrlsFdGr934kCqcUOLh9M1DVs4HmE/+2r1hkrPXOpt3YmhvvghWLOyOuFEcxEgRx77MGvlRUlylUqK4cYSWTCooX2o2dwwYR7h4J7XUqMikuAZrK6c0DwlRtspk5iAZ8YMiqFgcdiBwjPBw0= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b=oRFziVgv; arc=none smtp.client-ip=10.30.226.201 Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b="oRFziVgv" Received: by smtp.kernel.org (Postfix) with ESMTPSA id 90570C2BCB3; Tue, 31 Mar 2026 18:13:34 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1774980814; bh=K6u0PspPsS0IqE8W/Ttx61OZoVKvYhh4U0f4jYfu35M=; h=Date:From:To:Cc:Subject:References:From; b=oRFziVgvjRLjw3/Ebt7UIyKv/95MMu6F/DNYRfa8z5F2ESaZZ+DpWa5WrC7v839ZH +aCH5mYX9JVInXdvRw0lsuJGWe9+X+Q+m61n6bVkF8KUl4wePsMHIFqai4qhjC/IgC QHc8WcSPHuJ4R0l+AgRrFWcJvWfwjQpWnjK8vyRkg52H2IeHp+VqAgeJpKIvgUDh47 +ZyCRRFf85As4WoTjdrK/P1wlM0rj0EUp+48hKpBsP+ZW/2qjUX84/BkeD/F4x/S+K MuEUG/bI2v6B7uTSbYD11Pxe3zVmY+NIpg/nev4+SIWP1l8skVUEZUtan3To7a3fAz dyvjyc/EMTOAw== Received: from rostedt by gandalf with local (Exim 4.99.1) (envelope-from ) id 1w7dbl-0000000H8ta-1DQo; Tue, 31 Mar 2026 14:14:33 -0400 Message-ID: <20260331181433.153334366@kernel.org> User-Agent: quilt/0.69 Date: Tue, 31 Mar 2026 14:13:51 -0400 From: Steven Rostedt To: linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org Cc: Masami Hiramatsu , Mark Rutland , Mathieu Desnoyers , Andrew Morton , Thomas Gleixner , Peter Zijlstra , Brian Geffon , John Stultz , Ian Rogers , Suleiman Souhlal Subject: [PATCH v3 2/3] tracing: Update futex syscall trace event to show more commands References: <20260331181349.062575155@kernel.org> Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset="utf-8" From: Steven Rostedt Make the futex syscall trace event a little more smart. Have it read the futex_op instruction to determine what else it can save and print. For the appropriate options, it will read the utime (timespec) parameter and show its output as well as the uaddr2. futex_requeue_p-1154 [004] ..... 144.568339: sys_futex(uaddr: 0x5652b= 178d834 (0x482), FUTEX_UNLOCK_PI|FUTEX_PRIVATE_FLAG, val: 0) futex_requeue_p-1162 [002] ..... 144.568696: sys_futex(uaddr: 0x7f763= b7fece0 (2), FUTEX_WAIT|FUTEX_PRIVATE_FLAG, val: 2) futex_requeue_p-1151 [000] ..... 144.568700: sys_futex(uaddr: 0x7f763= b7fece0 (0), FUTEX_WAKE|FUTEX_PRIVATE_FLAG, val: 1) futex_requeue_p-1162 [002] ..... 144.568705: sys_futex(uaddr: 0x7f763= b7fece0 (0), FUTEX_WAKE|FUTEX_PRIVATE_FLAG, val: 1) futex_requeue_p-1151 [000] ..... 144.568715: sys_futex(uaddr: 0x7f764= 369e990 (0x483), FUTEX_WAIT_BITSET|FUTEX_CLOCK_REALTIME, val: 1155) futex_requeue_p-1155 [005] ..... 144.569420: sys_futex(uaddr: 0x5652b= 178d838 (0), FUTEX_WAIT_REQUEUE_PI|FUTEX_PRIVATE_FLAG, val: 0, timespec: 0x= 7ffdacfba500 (143.890024054), uaddr2: 0x5652b178d834 (0), val3: 0) futex_requeue_p-1155 [005] ..... 144.569454: sys_futex(uaddr: 0x5652b= 178d834 (0), FUTEX_LOCK_PI|FUTEX_PRIVATE_FLAG, val: 0) Reviewed-by: Masami Hiramatsu (Google) Signed-off-by: Steven Rostedt (Google) --- include/linux/futex.h | 35 ++++++++- kernel/futex/syscalls.c | 48 ++++++------- kernel/trace/trace_syscalls.c | 129 +++++++++++++++++++++++++++++----- 3 files changed, 164 insertions(+), 48 deletions(-) diff --git a/include/linux/futex.h b/include/linux/futex.h index 7eaf01ff68cf..ec0d9cfa8a59 100644 --- a/include/linux/futex.h +++ b/include/linux/futex.h @@ -82,8 +82,35 @@ long do_futex(u32 __user *uaddr, int op, u32 val, ktime_= t *timeout, u32 __user *uaddr2, u32 val2, u32 val3); int futex_hash_prctl(unsigned long arg2, unsigned long arg3, unsigned long= arg4); =20 +static __always_inline bool futex_cmd_has_timeout(u32 cmd) +{ + switch (cmd) { + case FUTEX_WAIT: + case FUTEX_LOCK_PI: + case FUTEX_LOCK_PI2: + case FUTEX_WAIT_BITSET: + case FUTEX_WAIT_REQUEUE_PI: + return true; + } + return false; +} + +static __always_inline bool futex_cmd_has_addr2(u32 cmd) +{ + switch (cmd) { + case FUTEX_REQUEUE: + case FUTEX_CMP_REQUEUE: + case FUTEX_WAKE_OP: + case FUTEX_WAIT_REQUEUE_PI: + return true; + } + return false; +} + #ifdef CONFIG_FTRACE_SYSCALLS -void futex_print_syscall(struct seq_buf *s, int nr_args, unsigned long *ar= gs, u32 *ptr); +void futex_print_syscall(struct seq_buf *s, int nr_args, unsigned long *ar= gs, + u32 *ptr1, u32 *ptr2, unsigned long *ts1, + unsigned long *ts2); extern const char * __futex_cmds[]; #endif =20 @@ -120,7 +147,11 @@ static inline int futex_hash_allocate_default(void) static inline int futex_hash_free(struct mm_struct *mm) { return 0; } static inline int futex_mm_init(struct mm_struct *mm) { return 0; } static inline void futex_print_syscall(struct seq_buf *s, int nr_args, - unsigned long *args, u32 *ptr) { } + unsigned long *args, u32 *ptr1, + u32 *ptr2, unsigned long *ts1, + unsigned long *ts2) { } +static __always_inline bool futex_cmd_has_timeout(u32 cmd) { return false;= } +static __always_inline bool futex_cmd_has_addr2(u32 cmd) { return false; } #endif =20 #endif diff --git a/kernel/futex/syscalls.c b/kernel/futex/syscalls.c index 3ba8ca017c9c..265ec0a236d0 100644 --- a/kernel/futex/syscalls.c +++ b/kernel/futex/syscalls.c @@ -158,31 +158,6 @@ long do_futex(u32 __user *uaddr, int op, u32 val, ktim= e_t *timeout, return -ENOSYS; } =20 -static __always_inline bool futex_cmd_has_timeout(u32 cmd) -{ - switch (cmd) { - case FUTEX_WAIT: - case FUTEX_LOCK_PI: - case FUTEX_LOCK_PI2: - case FUTEX_WAIT_BITSET: - case FUTEX_WAIT_REQUEUE_PI: - return true; - } - return false; -} - -static __always_inline bool futex_cmd_has_addr2(u32 cmd) -{ - switch (cmd) { - case FUTEX_REQUEUE: - case FUTEX_CMP_REQUEUE: - case FUTEX_WAKE_OP: - case FUTEX_WAIT_REQUEUE_PI: - return true; - } - return false; -} - static __always_inline int futex_init_timeout(u32 cmd, u32 op, struct timespec64 *ts, ktime_t *t) { @@ -231,7 +206,9 @@ const char * __futex_cmds[] =3D "FUTEX_LOCK_PI2", NULL }; =20 -void futex_print_syscall(struct seq_buf *s, int nr_args, unsigned long *ar= gs, u32 *ptr) +void futex_print_syscall(struct seq_buf *s, int nr_args, unsigned long *ar= gs, + u32 *ptr1, u32 *ptr2, unsigned long *ts1, + unsigned long *ts2) { unsigned int op, cmd; bool done =3D false; @@ -244,8 +221,8 @@ void futex_print_syscall(struct seq_buf *s, int nr_args= , unsigned long *args, u3 switch (i) { case 0: seq_buf_printf(s, "uaddr: 0x%lx", args[i]); - if (ptr) { - u32 val =3D *ptr; + if (ptr1) { + u32 val =3D *ptr1; if (val < 10) seq_buf_printf(s, " (%u)", val); else @@ -287,6 +264,15 @@ void futex_print_syscall(struct seq_buf *s, int nr_arg= s, unsigned long *args, u3 continue; =20 seq_buf_printf(s, ", timespec: 0x%lx", args[i]); + + if (!ts1 || !ts2) + continue; + + if (!*ts1 && !*ts2) { + seq_buf_puts(s, " (0)"); + continue; + } + seq_buf_printf(s, " (%lu.%09lu)", *ts1, *ts2); continue; case 4: if (!futex_cmd_has_addr2(cmd)) { @@ -294,6 +280,12 @@ void futex_print_syscall(struct seq_buf *s, int nr_arg= s, unsigned long *args, u3 continue; } seq_buf_printf(s, ", uaddr2: 0x%lx", args[i]); + + if (!ptr2) + continue; + + seq_buf_printf(s, " (%x)", *ptr2); + continue; case 5: seq_buf_printf(s, ", val3: %lu", args[i]); diff --git a/kernel/trace/trace_syscalls.c b/kernel/trace/trace_syscalls.c index f8213d772f89..0c86986ec7c4 100644 --- a/kernel/trace/trace_syscalls.c +++ b/kernel/trace/trace_syscalls.c @@ -239,21 +239,35 @@ sys_enter_openat_print(struct syscall_trace_enter *tr= ace, struct syscall_metadat return trace_handle_return(s); } =20 +struct futex_data { + u32 val1; + u32 val2; + unsigned long ts1; + unsigned long ts2; +}; + static enum print_line_t sys_enter_futex_print(struct syscall_trace_enter *trace, struct syscall_me= tadata *entry, struct trace_seq *s, struct trace_event *event, int ent_size) { + struct futex_data *data; void *end =3D (void *)trace + ent_size; - void *ptr; + unsigned long *ts1 =3D NULL, *ts2 =3D NULL; + u32 *ptr1 =3D NULL, *ptr2 =3D NULL; =20 /* Set ptr to the user space copied area */ - ptr =3D (void *)trace->args + sizeof(unsigned long) * entry->nb_args; - if (ptr + 4 > end) - ptr =3D NULL; + data =3D (void *)trace->args + sizeof(unsigned long) * entry->nb_args; + if ((void *)data + sizeof(*data) <=3D end) { + ptr1 =3D &data->val1; + ptr2 =3D &data->val2; + ts1 =3D &data->ts1; + ts2 =3D &data->ts2; + } =20 trace_seq_printf(s, "%s(", entry->name); =20 - futex_print_syscall(&s->seq, entry->nb_args, trace->args, ptr); + futex_print_syscall(&s->seq, entry->nb_args, trace->args, ptr1, ptr2, + ts1, ts2); =20 trace_seq_puts(s, ")\n"); =20 @@ -472,9 +486,9 @@ sys_enter_futex_print_fmt(struct syscall_metadata *entr= y, char *buf, int len) pos +=3D snprintf(buf + pos, LEN_OR_ZERO, "\"uaddr: 0x%%lx (0x%%lx) cmd=3D%%s%%s%%s"); pos +=3D snprintf(buf + pos, LEN_OR_ZERO, - " val: 0x%%x timeout/val2: 0x%%llx"); + " val: 0x%%x timeout/val2: 0x%%llx (%%lu.%%lu)"); pos +=3D snprintf(buf + pos, LEN_OR_ZERO, - " uaddr2: 0x%%lx val3: 0x%%x\", "); + " uaddr2: 0x%%lx (0x%%lx) val3: 0x%%x\", "); =20 pos +=3D snprintf(buf + pos, LEN_OR_ZERO, " REC->uaddr,"); @@ -499,10 +513,12 @@ sys_enter_futex_print_fmt(struct syscall_metadata *en= try, char *buf, int len) FUTEX_CLOCK_REALTIME); =20 pos +=3D snprintf(buf + pos, LEN_OR_ZERO, - " REC->val, REC->utime,"); + " REC->val, REC->utime, REC->__ts1, REC->__ts2,"); =20 pos +=3D snprintf(buf + pos, LEN_OR_ZERO, - " REC->uaddr, REC->val3"); + " REC->uaddr,"); + pos +=3D snprintf(buf + pos, LEN_OR_ZERO, + " REC->__value2, REC->val3"); return pos; } =20 @@ -605,7 +621,39 @@ static int __init futex_fields(struct trace_event_call= *call, int offset) ret =3D trace_define_field(call, "u32", arg, offset, sizeof(int), 0, FILTER_OTHER); if (ret) - kfree(arg); + goto free; + offset +=3D sizeof(int); + + arg =3D kstrdup("__value2", GFP_KERNEL); + if (WARN_ON_ONCE(!arg)) + return -ENOMEM; + ret =3D trace_define_field(call, "u32", arg, offset, sizeof(int), 0, + FILTER_OTHER); + if (ret) + goto free; + offset +=3D sizeof(int); + + arg =3D kstrdup("__ts1", GFP_KERNEL); + if (WARN_ON_ONCE(!arg)) + return -ENOMEM; + ret =3D trace_define_field(call, "unsigned long", arg, offset, + sizeof(unsigned long), 0, FILTER_OTHER); + if (ret) + goto free; + offset +=3D sizeof(long); + + arg =3D kstrdup("__ts2", GFP_KERNEL); + if (WARN_ON_ONCE(!arg)) + return -ENOMEM; + ret =3D trace_define_field(call, "unsigned long", arg, offset, + sizeof(unsigned long), 0, FILTER_OTHER); + if (ret) + goto free; + + return 0; + +free: + kfree(arg); return ret; } =20 @@ -778,11 +826,51 @@ static int syscall_copy_user_array(char *buf, const c= har __user *ptr, return 0; } =20 +struct tp_futex_data { + u32 cmd; + const u32 __user *val1; + const u32 __user *val2; + void __user *timeout; +}; + +static int syscall_copy_futex(char *buf, const char __user *ptr, + size_t size, void *data) +{ + struct tp_futex_data *tp_data =3D data; + struct futex_data *fdata =3D (void *)buf; + int cmd =3D tp_data->cmd & FUTEX_CMD_MASK; + int ret; + + memset(fdata, 0, sizeof(*fdata)); + + if (tp_data->val1) { + ret =3D __copy_from_user(&fdata->val1, tp_data->val1, 4); + if (ret) + return -1; + } + + if (tp_data->val2 && futex_cmd_has_addr2(cmd)) { + ret =3D __copy_from_user(&fdata->val2, tp_data->val2, 4); + if (ret) + return -1; + } + + if (tp_data->timeout && futex_cmd_has_timeout(cmd)) { + /* Copies both ts1 and ts2 */ + ret =3D __copy_from_user(&fdata->ts1, tp_data->timeout, + sizeof(long) * 2); + if (ret) + return -1; + } + + return 0; +} + static int syscall_get_futex(unsigned long *args, char **buffer, int *size, int buf_s= ize) { struct syscall_user_buffer *sbuf; - const char __user *ptr; + struct tp_futex_data tp_data; =20 /* buf_size of zero means user doesn't want user space read */ if (!buf_size) @@ -793,14 +881,18 @@ syscall_get_futex(unsigned long *args, char **buffer,= int *size, int buf_size) if (!sbuf) return -1; =20 - ptr =3D (char __user *)args[0]; + tp_data.cmd =3D args[1]; + tp_data.val1 =3D (u32 __user *)args[0]; + tp_data.val2 =3D (u32 __user *)args[4]; + tp_data.timeout =3D (u64 __user *)args[3]; =20 - *buffer =3D trace_user_fault_read(&sbuf->buf, ptr, 4, NULL, NULL); + *buffer =3D trace_user_fault_read(&sbuf->buf, NULL, 0, + syscall_copy_futex, &tp_data); if (!*buffer) return -1; =20 - /* Add room for the value */ - *size +=3D 4; + /* Add room for values */ + *size +=3D sizeof(struct futex_data); =20 return 0; } @@ -809,12 +901,13 @@ static void syscall_put_futex(struct syscall_metadata= *sys_data, struct syscall_trace_enter *entry, char *buffer) { - u32 *ptr; + struct futex_data *fdata =3D (void *)buffer; + struct futex_data *data; =20 /* Place the futex key into the storage */ - ptr =3D (void *)entry->args + sizeof(unsigned long) * sys_data->nb_args; + data =3D (void *)entry->args + sizeof(unsigned long) * sys_data->nb_args; =20 - *ptr =3D *(u32 *)buffer; + *data =3D *fdata; } =20 static char *sys_fault_user(unsigned int buf_size, --=20 2.51.0 From nobody Wed Apr 1 09:05:44 2026 Received: from smtp.kernel.org (aws-us-west-2-korg-mail-1.web.codeaurora.org [10.30.226.201]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.subspace.kernel.org (Postfix) with ESMTPS id 20A4544CF5E; Tue, 31 Mar 2026 18:13:34 +0000 (UTC) Authentication-Results: smtp.subspace.kernel.org; arc=none smtp.client-ip=10.30.226.201 ARC-Seal: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1774980815; cv=none; b=rtXP9F5bJxyzp86voFWw/T6imCaZBIDF1CVx25uniyMN2AIGJJt22Ve2ggWTJ4UMyXiurLNafMZTcd/Mi3sp+hCVB4tgQWhYdBNpeJx0b7tVHsP6TNhgRdygOa0MiB6zcvS/5oFLEZIxeGszcFA4RlxFaH/ksOQ9W/a3GXBpRwY= ARC-Message-Signature: i=1; a=rsa-sha256; d=subspace.kernel.org; s=arc-20240116; t=1774980815; c=relaxed/simple; bh=Tk38+TRw4xkKSFdeekYweRA+YfY9CMW4lNPi/6d0oqs=; h=Message-ID:Date:From:To:Cc:Subject:References:MIME-Version: Content-Type; b=rT5KlN7GwZlqvpZRHw1PH/mMhNfkRHPP2nnceJ9j7a/02R12wsbqaVwU6yF2MCg78b3eS9dZ/8ByYSKU4TU2bOgRiCw8JguOjtAuEdCnYCdPnzG/7UrLwvzwuvaQtK4K2klQ9LjK3Xg20HSLGPiYXtrUp8OBMCm0vBYaXjgSq9k= ARC-Authentication-Results: i=1; smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b=IJZCST7S; arc=none smtp.client-ip=10.30.226.201 Authentication-Results: smtp.subspace.kernel.org; dkim=pass (2048-bit key) header.d=kernel.org header.i=@kernel.org header.b="IJZCST7S" Received: by smtp.kernel.org (Postfix) with ESMTPSA id B1D2CC2BCB5; Tue, 31 Mar 2026 18:13:34 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=kernel.org; s=k20201202; t=1774980814; bh=Tk38+TRw4xkKSFdeekYweRA+YfY9CMW4lNPi/6d0oqs=; h=Date:From:To:Cc:Subject:References:From; b=IJZCST7Sec29/h5dvWdwkzrurTVN8ch2PEXZ/yL/oetWZrXn8c4ydrEiMAMwCA+Sk 3TSlHVJK0HQQfp/d4cHxKvDiA+JG8Ep2FfxD6fm7YZ4jsYMs1t1dr7r3oklnqAuPss rQlqLyYTJF0F6tVPifCVFi25GmENKbYG1FkUSlETNXmrN+ENf1JPzVJksS2wZxG/n6 f+nkUmP2zfCRuBDap0F9azt8k4hQbCozTYcR+qadKVno4RRSRXTVuQzDQaXcwxAlLE i6FwNx2cymFPaMWTuZWhSZ9dYVEkgQdrCigfpB0WpFFRCkzwpN5Xe75D2WlrTzR/++ U0nHzdtaxM9Xg== Received: from rostedt by gandalf with local (Exim 4.99.1) (envelope-from ) id 1w7dbl-0000000H8u4-1u44; Tue, 31 Mar 2026 14:14:33 -0400 Message-ID: <20260331181433.309946057@kernel.org> User-Agent: quilt/0.69 Date: Tue, 31 Mar 2026 14:13:52 -0400 From: Steven Rostedt To: linux-kernel@vger.kernel.org, linux-trace-kernel@vger.kernel.org Cc: Masami Hiramatsu , Mark Rutland , Mathieu Desnoyers , Andrew Morton , Thomas Gleixner , Peter Zijlstra , Brian Geffon , John Stultz , Ian Rogers , Suleiman Souhlal Subject: [PATCH v3 3/3] tracing: Show TID and flags for PI futex system call trace event References: <20260331181349.062575155@kernel.org> Precedence: bulk X-Mailing-List: linux-kernel@vger.kernel.org List-Id: List-Subscribe: List-Unsubscribe: MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset="utf-8" From: Steven Rostedt For the futex system call trace event for FUTEX_LOCK_PI and FUTEX_UNLOCK_PI commands, show the TID from the value (which is usually in hex) as well as translate the flags (DIED and WAITERS). pi_mutex_hammer-1098 [000] ..... 121.876928: sys_futex(uaddr: 0x560f4= 0cc8180 (0x450) tid: 1104, FUTEX_LOCK_PI|FUTEX_PRIVATE_FLAG, val: 0, timesp= ec: 0x7f2f9d4b1e50 (0.000100000)) pi_mutex_hammer-1128 [000] ..... 121.877120: sys_futex(uaddr: 0x560f4= 0cc8180 (0x8000042a) tid: 1066 (WAITERS), FUTEX_LOCK_PI|FUTEX_PRIVATE_FLAG,= val: 0, timespec: 0x7f2f8e493e50 (0.000100000)) pi_mutex_hammer-1106 [000] ..... 121.877242: sys_futex(uaddr: 0x560f4= 0cc8180 (0x80000452) tid: 1106 (WAITERS), FUTEX_UNLOCK_PI|FUTEX_PRIVATE_FLA= G, val: 0) This makes it easier to see the hand off of a mutex and who the owner was. Reviewed-by: Masami Hiramatsu (Google) Signed-off-by: Steven Rostedt (Google) --- kernel/futex/syscalls.c | 26 ++++++++++++++++++++++++-- 1 file changed, 24 insertions(+), 2 deletions(-) diff --git a/kernel/futex/syscalls.c b/kernel/futex/syscalls.c index 265ec0a236d0..8144781a9ff0 100644 --- a/kernel/futex/syscalls.c +++ b/kernel/futex/syscalls.c @@ -213,6 +213,9 @@ void futex_print_syscall(struct seq_buf *s, int nr_args= , unsigned long *args, unsigned int op, cmd; bool done =3D false; =20 + op =3D args[1]; + cmd =3D op & FUTEX_CMD_MASK; + for (int i =3D 0; !done && i < nr_args; i++) { =20 if (seq_buf_has_overflowed(s)) @@ -227,11 +230,30 @@ void futex_print_syscall(struct seq_buf *s, int nr_ar= gs, unsigned long *args, seq_buf_printf(s, " (%u)", val); else seq_buf_printf(s, " (0x%x)", val); + + switch(cmd) { + case FUTEX_LOCK_PI: + case FUTEX_UNLOCK_PI: + seq_buf_printf(s, " tid: %d", + val & FUTEX_TID_MASK); + + if (!(val & (FUTEX_OWNER_DIED|FUTEX_WAITERS))) + break; + + seq_buf_puts(s, " ("); + if (val & FUTEX_WAITERS) + seq_buf_puts(s, "WAITERS"); + if (val & FUTEX_OWNER_DIED) { + if (op & FUTEX_WAITERS) + seq_buf_putc(s, '|'); + seq_buf_puts(s, "DIED"); + } + seq_buf_putc(s, ')'); + break; + } } continue; case 1: - op =3D args[i]; - cmd =3D op & FUTEX_CMD_MASK; if (cmd <=3D FUTEX_LOCK_PI2) seq_buf_printf(s, ", %s", __futex_cmds[cmd]); else --=20 2.51.0