[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20250416140115.5b836b33@gandalf.local.home>
Date: Wed, 16 Apr 2025 14:01:15 -0400
From: Steven Rostedt <rostedt@...dmis.org>
To: Borislav Petkov <bp@...en8.de>
Cc: Junxuan Liao <ljx@...wisc.edu>, linux-trace-kernel@...r.kernel.org,
linux-kernel@...r.kernel.org, x86@...nel.org, Thomas Gleixner
<tglx@...utronix.de>, Ingo Molnar <mingo@...hat.com>, Dave Hansen
<dave.hansen@...ux.intel.com>, "H. Peter Anvin" <hpa@...or.com>, Masami
Hiramatsu <mhiramat@...nel.org>, Mathieu Desnoyers
<mathieu.desnoyers@...icios.com>, "Paul E. McKenney" <paulmck@...nel.org>
Subject: Re: [PATCH] x86/tracing: introduce enter/exit tracepoint pairs for
page faults
On Wed, 16 Apr 2025 19:47:14 +0200
Borislav Petkov <bp@...en8.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
Powered by blists - more mailing lists