arch/x86/include/asm/trace/common.h | 18 ++++++++++---- arch/x86/include/asm/trace/exceptions.h | 32 ++++++++++++++++++++----- arch/x86/kernel/tracepoint.c | 22 +++++++++++++---- arch/x86/mm/fault.c | 21 +++++++++++++--- 4 files changed, 75 insertions(+), 18 deletions(-)
Rename page_fault_{user,kernel} to page_fault_{user,kernel}_enter, and
add the exit counterparts. This might be useful for measuring page fault
handling latencies.
The exit tracepoints use a separate static key.
Signed-off-by: Junxuan Liao <ljx@cs.wisc.edu>
Link: https://lore.kernel.org/9e2ac1e3-d07d-4f17-970e-6b7a5248a5bb@cs.wisc.edu
---
arch/x86/include/asm/trace/common.h | 18 ++++++++++----
arch/x86/include/asm/trace/exceptions.h | 32 ++++++++++++++++++++-----
arch/x86/kernel/tracepoint.c | 22 +++++++++++++----
arch/x86/mm/fault.c | 21 +++++++++++++---
4 files changed, 75 insertions(+), 18 deletions(-)
diff --git a/arch/x86/include/asm/trace/common.h b/arch/x86/include/asm/trace/common.h
index f0f9bcdb74d9..4b289be75173 100644
--- a/arch/x86/include/asm/trace/common.h
+++ b/arch/x86/include/asm/trace/common.h
@@ -2,11 +2,21 @@
#define _ASM_TRACE_COMMON_H
#ifdef CONFIG_TRACING
-DECLARE_STATIC_KEY_FALSE(trace_pagefault_key);
-#define trace_pagefault_enabled() \
- static_branch_unlikely(&trace_pagefault_key)
+DECLARE_STATIC_KEY_FALSE(trace_pagefault_enter_key);
+DECLARE_STATIC_KEY_FALSE(trace_pagefault_exit_key);
+#define trace_pagefault_enter_enabled() \
+ static_branch_unlikely(&trace_pagefault_enter_key)
+#define trace_pagefault_exit_enabled() \
+ static_branch_unlikely(&trace_pagefault_exit_key)
#else
-static inline bool trace_pagefault_enabled(void) { return false; }
+static inline bool trace_pagefault_enter_enabled(void)
+{
+ return false;
+}
+static inline bool trace_pagefault_exit_enabled(void)
+{
+ return false;
+}
#endif
#endif
diff --git a/arch/x86/include/asm/trace/exceptions.h b/arch/x86/include/asm/trace/exceptions.h
index 6b1e87194809..76729fcdb249 100644
--- a/arch/x86/include/asm/trace/exceptions.h
+++ b/arch/x86/include/asm/trace/exceptions.h
@@ -8,8 +8,10 @@
#include <linux/tracepoint.h>
#include <asm/trace/common.h>
-extern int trace_pagefault_reg(void);
-extern void trace_pagefault_unreg(void);
+extern int trace_pagefault_enter_reg(void);
+extern void trace_pagefault_enter_unreg(void);
+extern int trace_pagefault_exit_reg(void);
+extern void trace_pagefault_exit_unreg(void);
DECLARE_EVENT_CLASS(x86_exceptions,
@@ -34,15 +36,33 @@ DECLARE_EVENT_CLASS(x86_exceptions,
(void *)__entry->address, (void *)__entry->ip,
__entry->error_code) );
-#define DEFINE_PAGE_FAULT_EVENT(name) \
+#define DEFINE_PAGE_FAULT_EVENT(name, reg, unreg) \
DEFINE_EVENT_FN(x86_exceptions, name, \
TP_PROTO(unsigned long address, struct pt_regs *regs, \
unsigned long error_code), \
TP_ARGS(address, regs, error_code), \
- trace_pagefault_reg, trace_pagefault_unreg);
+ reg, unreg)
-DEFINE_PAGE_FAULT_EVENT(page_fault_user);
-DEFINE_PAGE_FAULT_EVENT(page_fault_kernel);
+DEFINE_PAGE_FAULT_EVENT(
+ page_fault_user_enter,
+ trace_pagefault_enter_reg,
+ trace_pagefault_enter_unreg
+);
+DEFINE_PAGE_FAULT_EVENT(
+ page_fault_user_exit,
+ trace_pagefault_exit_reg,
+ trace_pagefault_exit_unreg
+);
+DEFINE_PAGE_FAULT_EVENT(
+ page_fault_kernel_enter,
+ trace_pagefault_enter_reg,
+ trace_pagefault_enter_unreg
+);
+DEFINE_PAGE_FAULT_EVENT(
+ page_fault_kernel_exit,
+ trace_pagefault_exit_reg,
+ trace_pagefault_exit_unreg
+);
#undef TRACE_INCLUDE_PATH
#undef TRACE_INCLUDE_FILE
diff --git a/arch/x86/kernel/tracepoint.c b/arch/x86/kernel/tracepoint.c
index 03ae1caaa878..108285046226 100644
--- a/arch/x86/kernel/tracepoint.c
+++ b/arch/x86/kernel/tracepoint.c
@@ -7,15 +7,27 @@
#include <asm/trace/exceptions.h>
-DEFINE_STATIC_KEY_FALSE(trace_pagefault_key);
+DEFINE_STATIC_KEY_FALSE(trace_pagefault_enter_key);
+DEFINE_STATIC_KEY_FALSE(trace_pagefault_exit_key);
-int trace_pagefault_reg(void)
+int trace_pagefault_enter_reg(void)
{
- static_branch_inc(&trace_pagefault_key);
+ static_branch_inc(&trace_pagefault_enter_key);
return 0;
}
-void trace_pagefault_unreg(void)
+void trace_pagefault_enter_unreg(void)
{
- static_branch_dec(&trace_pagefault_key);
+ static_branch_dec(&trace_pagefault_enter_key);
+}
+
+int trace_pagefault_exit_reg(void)
+{
+ static_branch_inc(&trace_pagefault_exit_key);
+ return 0;
+}
+
+void trace_pagefault_exit_unreg(void)
+{
+ static_branch_dec(&trace_pagefault_exit_key);
}
diff --git a/arch/x86/mm/fault.c b/arch/x86/mm/fault.c
index 296d294142c8..cd933edf1e19 100644
--- a/arch/x86/mm/fault.c
+++ b/arch/x86/mm/fault.c
@@ -1455,13 +1455,26 @@ static __always_inline void
trace_page_fault_entries(struct pt_regs *regs, unsigned long error_code,
unsigned long address)
{
- if (!trace_pagefault_enabled())
+ if (!trace_pagefault_enter_enabled())
return;
if (user_mode(regs))
- trace_page_fault_user(address, regs, error_code);
+ trace_page_fault_user_enter(address, regs, error_code);
else
- trace_page_fault_kernel(address, regs, error_code);
+ trace_page_fault_kernel_enter(address, regs, error_code);
+}
+
+static __always_inline void
+trace_page_fault_exits(struct pt_regs *regs, unsigned long error_code,
+ unsigned long address)
+{
+ if (!trace_pagefault_exit_enabled())
+ return;
+
+ if (user_mode(regs))
+ trace_page_fault_user_exit(address, regs, error_code);
+ else
+ trace_page_fault_kernel_exit(address, regs, error_code);
}
static __always_inline void
@@ -1487,6 +1500,8 @@ handle_page_fault(struct pt_regs *regs, unsigned long error_code,
*/
local_irq_disable();
}
+
+ trace_page_fault_exits(regs, error_code, address);
}
DEFINE_IDTENTRY_RAW_ERRORCODE(exc_page_fault)
--
2.48.1On Mon, Apr 14, 2025 at 03:35:41PM -0500, Junxuan Liao wrote:
> Rename page_fault_{user,kernel} to page_fault_{user,kernel}_enter, and
> add the exit counterparts. This might be useful for measuring page fault
^^^^^^^^^^^^^^^^
Well, come back when it really becomes useful.
--
Regards/Gruss,
Boris.
https://people.kernel.org/tglx/notes-about-netiquette
On Mon, 14 Apr 2025 22:54:41 +0200
Borislav Petkov <bp@alien8.de> wrote:
> On Mon, Apr 14, 2025 at 03:35:41PM -0500, Junxuan Liao wrote:
> > Rename page_fault_{user,kernel} to page_fault_{user,kernel}_enter, and
> > add the exit counterparts. This might be useful for measuring page fault
> ^^^^^^^^^^^^^^^^
>
> Well, come back when it really becomes useful.
It's useful for me ;-)
# cd /sys/kernel/tracing
# echo 's:user_faults u64 delta;' >> dynamic_events
# echo 'hist:keys=common_pid:ts0=common_timestamp.usecs' >> events/exceptions/page_fault_user_enter/trigger
# echo 'hist:keys=common_pid:delta=common_timestamp.usecs-$ts0:onmatch(exceptions.page_fault_user_enter).trace(user_faults,$delta)' >> events/exceptions/page_fault_user_exit/trigger
# cd /work/git/trace-cmd.git
# echo 'hist:keys=delta.log2:sort=delta if COMM == "cc1"' > /sys/kernel/tracing/events/synthetic/user_faults/trigger
# make
[..]
# cat /sys/kernel/tracing/events/synthetic/user_faults/hist
# event histogram
#
# trigger info: hist:keys=delta.log2:vals=hitcount:sort=delta.log2:size=2048 if COMM == "cc1" [active]
#
{ delta: ~ 2^0 } hitcount: 1
{ delta: ~ 2^1 } hitcount: 334
{ delta: ~ 2^2 } hitcount: 4090
{ delta: ~ 2^3 } hitcount: 86037
{ delta: ~ 2^4 } hitcount: 108790
{ delta: ~ 2^5 } hitcount: 27387
{ delta: ~ 2^6 } hitcount: 6015
{ delta: ~ 2^7 } hitcount: 481
{ delta: ~ 2^8 } hitcount: 134
{ delta: ~ 2^9 } hitcount: 74
{ delta: ~ 2^10 } hitcount: 54
{ delta: ~ 2^11 } hitcount: 6
Totals:
Hits: 233403
Entries: 12
Dropped: 0
The above shows a histogram in microseconds where the buckets increase in a
power of two. The biggest bucket is between 2^4 (16) and 2^5 (32) microseconds
with 108790 hits.
The longest bucket of 2^11 (2ms) to 2^12 (4ms) had 6 hits.
And when sframes is supported, it will be able to show the user space stack
trace of where the longest page faults occur.
-- Steve
On Mon, Apr 14, 2025 at 06:20:50PM -0400, Steven Rostedt wrote:
> It's useful for me ;-)
That's why I CCed you.
I suspected you'd have "your mustard to share". :-P
> # cd /sys/kernel/tracing
> # echo 's:user_faults u64 delta;' >> dynamic_events
> # echo 'hist:keys=common_pid:ts0=common_timestamp.usecs' >> events/exceptions/page_fault_user_enter/trigger
> # echo 'hist:keys=common_pid:delta=common_timestamp.usecs-$ts0:onmatch(exceptions.page_fault_user_enter).trace(user_faults,$delta)' >> events/exceptions/page_fault_user_exit/trigger
>
> # cd /work/git/trace-cmd.git
> # echo 'hist:keys=delta.log2:sort=delta if COMM == "cc1"' > /sys/kernel/tracing/events/synthetic/user_faults/trigger
OMG, this tracing thing has turned into a language almost. I hope you're
documenting those fancy use cases...
> # make
> [..]
>
> # cat /sys/kernel/tracing/events/synthetic/user_faults/hist
> # event histogram
> #
> # trigger info: hist:keys=delta.log2:vals=hitcount:sort=delta.log2:size=2048 if COMM == "cc1" [active]
> #
>
> { delta: ~ 2^0 } hitcount: 1
> { delta: ~ 2^1 } hitcount: 334
> { delta: ~ 2^2 } hitcount: 4090
> { delta: ~ 2^3 } hitcount: 86037
> { delta: ~ 2^4 } hitcount: 108790
> { delta: ~ 2^5 } hitcount: 27387
> { delta: ~ 2^6 } hitcount: 6015
> { delta: ~ 2^7 } hitcount: 481
> { delta: ~ 2^8 } hitcount: 134
> { delta: ~ 2^9 } hitcount: 74
> { delta: ~ 2^10 } hitcount: 54
> { delta: ~ 2^11 } hitcount: 6
>
> Totals:
> Hits: 233403
> Entries: 12
> Dropped: 0
>
>
> The above shows a histogram in microseconds where the buckets increase in a
> power of two. The biggest bucket is between 2^4 (16) and 2^5 (32) microseconds
> with 108790 hits.
>
> The longest bucket of 2^11 (2ms) to 2^12 (4ms) had 6 hits.
>
> And when sframes is supported, it will be able to show the user space stack
> trace of where the longest page faults occur.
Ok, so AFAIU, this gives you how long user page faults take and apparently for
someone this is important info.
Now if only that info were in the commit message along with the usage scenario
so that people can *actually* do what you guys are bragging about...
:-P
Thx.
--
Regards/Gruss,
Boris.
https://people.kernel.org/tglx/notes-about-netiquette
On Wed, 16 Apr 2025 19:47:14 +0200
Borislav Petkov <bp@alien8.de> wrote:
> On Mon, Apr 14, 2025 at 06:20:50PM -0400, Steven Rostedt wrote:
> > It's useful for me ;-)
>
> That's why I CCed you.
>
> I suspected you'd have "your mustard to share". :-P
:-)
>
> > # cd /sys/kernel/tracing
> > # echo 's:user_faults u64 delta;' >> dynamic_events
> > # echo 'hist:keys=common_pid:ts0=common_timestamp.usecs' >> events/exceptions/page_fault_user_enter/trigger
> > # echo 'hist:keys=common_pid:delta=common_timestamp.usecs-$ts0:onmatch(exceptions.page_fault_user_enter).trace(user_faults,$delta)' >> events/exceptions/page_fault_user_exit/trigger
> >
> > # cd /work/git/trace-cmd.git
> > # echo 'hist:keys=delta.log2:sort=delta if COMM == "cc1"' > /sys/kernel/tracing/events/synthetic/user_faults/trigger
>
> OMG, this tracing thing has turned into a language almost. I hope you're
> documenting those fancy use cases...
The above was created by:
# trace-cmd sqlhist -e -n user_faults SELECT TIMESTAMP_DELTA_USECS as delta FROM page_fault_user_enter as start JOIN \
page_fault_user_exit as end ON start.common_pid = end.common_pid
It also shows the kernel commands, which I took and sanitized a bit.
;-)
>
> > # make
> > [..]
> >
> > # cat /sys/kernel/tracing/events/synthetic/user_faults/hist
> > # event histogram
> > #
> > # trigger info: hist:keys=delta.log2:vals=hitcount:sort=delta.log2:size=2048 if COMM == "cc1" [active]
> > #
> >
> > { delta: ~ 2^0 } hitcount: 1
> > { delta: ~ 2^1 } hitcount: 334
> > { delta: ~ 2^2 } hitcount: 4090
> > { delta: ~ 2^3 } hitcount: 86037
> > { delta: ~ 2^4 } hitcount: 108790
> > { delta: ~ 2^5 } hitcount: 27387
> > { delta: ~ 2^6 } hitcount: 6015
> > { delta: ~ 2^7 } hitcount: 481
> > { delta: ~ 2^8 } hitcount: 134
> > { delta: ~ 2^9 } hitcount: 74
> > { delta: ~ 2^10 } hitcount: 54
> > { delta: ~ 2^11 } hitcount: 6
> >
> > Totals:
> > Hits: 233403
> > Entries: 12
> > Dropped: 0
> >
> >
> > The above shows a histogram in microseconds where the buckets increase in a
> > power of two. The biggest bucket is between 2^4 (16) and 2^5 (32) microseconds
> > with 108790 hits.
> >
> > The longest bucket of 2^11 (2ms) to 2^12 (4ms) had 6 hits.
> >
> > And when sframes is supported, it will be able to show the user space stack
> > trace of where the longest page faults occur.
>
> Ok, so AFAIU, this gives you how long user page faults take and apparently for
> someone this is important info.
This was just a simple example. I rather see where in the kernel it happens.
I can still use the synthetic events and user stack trace to find where the
big faults occur.
>
> Now if only that info were in the commit message along with the usage scenario
> so that people can *actually* do what you guys are bragging about...
I plan on adding things like this to Documentation/trace/debugging.rst
I need to get time out to add a bunch of helpful tricks there.
-- Steve
On Wed, Apr 16, 2025 at 02:01:15PM -0400, Steven Rostedt wrote:
> The above was created by:
>
> # trace-cmd sqlhist -e -n user_faults SELECT TIMESTAMP_DELTA_USECS as delta FROM page_fault_user_enter as start JOIN \
> page_fault_user_exit as end ON start.common_pid = end.common_pid
Pfff, that's SQL.
You're too old fashioned - you need an AI thing now :-P
So tell me: I as a silly user, how do I figure out how to use trace-cmd?
I guess it has docs somewhere...
And apparently I need trace-cmd now - I can't type all that into sysfs... Or
I guess I can use trace-cmd to generate the commands and then I can echo them
into the target machine.
I.e., ftrace still doesn't need a special tool to be used...
> This was just a simple example. I rather see where in the kernel it happens.
> I can still use the synthetic events and user stack trace to find where the
> big faults occur.
Right, so it would be great to have the actual use case in a patch's commit
message... i.e., why is a patch important.
> > Now if only that info were in the commit message along with the usage scenario
> > so that people can *actually* do what you guys are bragging about...
>
> I plan on adding things like this to Documentation/trace/debugging.rst
>
> I need to get time out to add a bunch of helpful tricks there.
Yap, please.
I have to admit I was able to catch a trace for tglx using only the ftrace
documentation we have so it must be good. But moar is better. :-P
Thx man!
--
Regards/Gruss,
Boris.
https://people.kernel.org/tglx/notes-about-netiquette
On Wed, 16 Apr 2025 14:01:15 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:
> > Ok, so AFAIU, this gives you how long user page faults take and apparently for
> > someone this is important info.
>
> This was just a simple example. I rather see where in the kernel it happens.
^^^^^^^^^^^^
user space
> I can still use the synthetic events and user stack trace to find where the
> big faults occur.
On 4/14/25 5:20 PM, Steven Rostedt wrote:
> It's useful for me ;-)
> The above shows a histogram in microseconds where the buckets increase in a
> power of two. The biggest bucket is between 2^4 (16) and 2^5 (32) microseconds
> with 108790 hits.
With patch v2, I can do something similar in bpftrace too. :)
tracepoint:exceptions:page_fault_enter
/ args.user_mode == true /
{
@start[tid] = nsecs;
}
tracepoint:exceptions:page_fault_exit
/ args.user_mode == true /
{
@lat[tid] = hist(nsecs - @start[tid]);
}
Junxuan
On 4/14/25 13:35, Junxuan Liao wrote:
> Rename page_fault_{user,kernel} to page_fault_{user,kernel}_enter, and
> add the exit counterparts. This might be useful for measuring page fault
> handling latencies.
Is there a reason kprobes don't work for this?
Sorry I forgot to reply to the list. :( It's my first time doing this.
On 4/14/25 4:56 PM, Dave Hansen wrote:
> On 4/14/25 13:52, Junxuan Liao wrote:
>> On 4/14/25 3:42 PM, Dave Hansen wrote:
>>> Is there a reason kprobes don't work for this?
>>
>> In this code path it's either noinstr or inline functions, so I believe
>> explicit tracepoints are necessary?
>
> It'd be great to turn this "??" into some more certainty. ;)
>
>> As Steven has mentioned, there are similar tracepoints for irq and it's
>> nice to have them for page faults too.
>
> So, that code is:
>
>> trace_irq_handler_entry(irq, action);
>> res = action->handler(irq, action->dev_id);
>> trace_irq_handler_exit(irq, action, res);
>
> ... I think.
>
> That's a heck of a lot simpler than a couple static keys and new
> conditionals.
>
> Also, I honestly don't think we need separate user and kernel fault
> trace points. Maybe we should just zap that in the process.
>
> Is there a reason we couldn't get this down to something dirt simple like:
>
> DEFINE_IDTENTRY_RAW_ERRORCODE(exc_page_fault)
> {
> instrumentation_begin();
> + trace_page_fault_entry(...);
> handle_page_fault(regs, error_code, address);
> + trace_page_fault_exit(...);
> instrumentation_end();
>
> ??
If we don't need to separate user and kernel tracepoints, we won't need
those static keys anyway, and it's indeed much simpler.
Do people find separate user/kernel tracepoints useful? For me, I can
check regs in eBPF tracing code instead.
Junxuan
On 4/14/25 6:14 PM, Junxuan Liao wrote: > Do people find separate user/kernel tracepoints useful? For me, I can > check regs in eBPF tracing code instead. I think it might be good to add a field to the tracepoints to indicate whether it's in user space or not.
On 4/14/25 16:22, Junxuan Liao wrote:
> On 4/14/25 6:14 PM, Junxuan Liao wrote:
>> Do people find separate user/kernel tracepoints useful? For me, I can
>> check regs in eBPF tracing code instead.
> I think it might be good to add a field to the tracepoints to indicate
> whether it's in user space or not.
Sounds sane to me. Doing something like this:
TP_STRUCT__entry(
__field( unsigned long, address )
__field( unsigned long, ip )
+ __field( bool , user_mode)
__field( unsigned long, error_code )
),
TP_fast_assign(
__entry->address = address;
__entry->ip = regs->ip;
+ __entry->user_mode = user_mode(regs);
__entry->error_code = error_code;
),
seems highly superior to having two sets of tracepoints and static keys.
On Mon, 14 Apr 2025 16:37:19 -0700 Dave Hansen <dave.hansen@intel.com> wrote: > On 4/14/25 16:22, Junxuan Liao wrote: > > On 4/14/25 6:14 PM, Junxuan Liao wrote: > >> Do people find separate user/kernel tracepoints useful? For me, I can > >> check regs in eBPF tracing code instead. > > I think it might be good to add a field to the tracepoints to indicate > > whether it's in user space or not. > > Sounds sane to me. Doing something like this: > > TP_STRUCT__entry( > __field( unsigned long, address ) > __field( unsigned long, ip ) > + __field( bool , user_mode) > __field( unsigned long, error_code ) > ), > > TP_fast_assign( > __entry->address = address; > __entry->ip = regs->ip; > + __entry->user_mode = user_mode(regs); > __entry->error_code = error_code; > ), > > seems highly superior to having two sets of tracepoints and static keys. I agree. Acked-by: Steven Rostedt (Google) <rostedt@goodmis.org> -- Steve
>>> I think it might be good to add a field to the tracepoints to indicate >>> whether it's in user space or not. >> >> seems highly superior to having two sets of tracepoints and static keys. > > I agree. I'll implement this and delete the extra stuff then. Thanks, Junxuan
On Mon, 14 Apr 2025 13:42:23 -0700
Dave Hansen <dave.hansen@intel.com> wrote:
> On 4/14/25 13:35, Junxuan Liao wrote:
> > Rename page_fault_{user,kernel} to page_fault_{user,kernel}_enter, and
> > add the exit counterparts. This might be useful for measuring page fault
> > handling latencies.
>
> Is there a reason kprobes don't work for this?
Kprobes is not always easy to add, and it does add more overhead.
I use to have measurements by using function graph tracing of all timings
into the kernel, but when the noinstr was added, that broke. I still do
timings but that's by manually adding hacks into the kernel. I haven't done
timings on a vanilla kernel for some time. It would be nice to be able to
do that again.
-- Steve
© 2016 - 2025 Red Hat, Inc.