All of lore.kernel.org
 help / color / mirror / Atom feed
From: Steven Rostedt <rostedt@goodmis.org>
To: linux-kernel@vger.kernel.org
Cc: Ingo Molnar <mingo@kernel.org>,
	Andrew Morton <akpm@linux-foundation.org>,
	Masami Hiramatsu <mhiramat@kernel.org>,
	Tom Zanussi <zanussi@kernel.org>
Subject: [PATCH 0/4] tracing: Have filters and histograms use a call table instead of pointers
Date: Tue, 23 Aug 2022 17:46:06 -0400	[thread overview]
Message-ID: <20220823214606.344269352@goodmis.org> (raw)

While looking at the histogram and filter code, I realized that it's filled
with function pointers. With retpolines causing a big slowdown, I thought
that was problematic. Thus, I decided to see what would happen if I changed
the function pointers into enums, and instead called a single function
that did a switch on those enums and called the necessary functions
directly. The results were pretty clear.

The first patch was to update the trace event benchmark event to include
a integer value "delta" of the delta that it took to complete
(it currently only shows the delta as part of a string). By doing
so, I could benchmark the histogram and filter logic with it.

Before this series, the histogram with a single filter (to ignore the
first event, which has a delta of zero), had:

# event histogram
#
# trigger info: hist:keys=delta:vals=hitcount:sort=delta:size=2048 if delta > 0 [active]
#

{ delta:        129 } hitcount:       2213
{ delta:        130 } hitcount:     285965
{ delta:        131 } hitcount:    1146545
{ delta:        132 } hitcount:    5185432
{ delta:        133 } hitcount:   19896215
{ delta:        134 } hitcount:   53118616
{ delta:        135 } hitcount:   83816709
{ delta:        136 } hitcount:   68329562
{ delta:        137 } hitcount:   41859349
{ delta:        138 } hitcount:   46257797
{ delta:        139 } hitcount:   54400831
{ delta:        140 } hitcount:   72875007
{ delta:        141 } hitcount:   76193272
{ delta:        142 } hitcount:   49504263
{ delta:        143 } hitcount:   38821072
{ delta:        144 } hitcount:   47702679
{ delta:        145 } hitcount:   41357297
{ delta:        146 } hitcount:   22058238
{ delta:        147 } hitcount:    9720002
{ delta:        148 } hitcount:    3193542
{ delta:        149 } hitcount:     927030
{ delta:        150 } hitcount:     850772
{ delta:        151 } hitcount:    1477380
{ delta:        152 } hitcount:    2687977
{ delta:        153 } hitcount:    2865985
{ delta:        154 } hitcount:    1977492
{ delta:        155 } hitcount:    2475607
{ delta:        156 } hitcount:    3403612
{ delta:        157 } hitcount:    2264011
{ delta:        158 } hitcount:    1096214
{ delta:        159 } hitcount:     504653
{ delta:        160 } hitcount:     218869
{ delta:        161 } hitcount:     103246
[..]

Where the bulk was around 142ns, and the fastest time was 129ns.

After this series:

# event histogram
#
# trigger info: hist:keys=delta:vals=hitcount:sort=delta:size=2048 if delta > 0 [active]
#

{ delta:        103 } hitcount:         60
{ delta:        104 } hitcount:      16966
{ delta:        105 } hitcount:     396625
{ delta:        106 } hitcount:    3223400
{ delta:        107 } hitcount:   12053754
{ delta:        108 } hitcount:   20241711
{ delta:        109 } hitcount:   14850200
{ delta:        110 } hitcount:    4946599
{ delta:        111 } hitcount:    3479315
{ delta:        112 } hitcount:   18698299
{ delta:        113 } hitcount:   62388733
{ delta:        114 } hitcount:   95803834
{ delta:        115 } hitcount:   58278130
{ delta:        116 } hitcount:   15364800
{ delta:        117 } hitcount:    5586866
{ delta:        118 } hitcount:    2346880
{ delta:        119 } hitcount:    1131091
{ delta:        120 } hitcount:     620896
{ delta:        121 } hitcount:     236652
{ delta:        122 } hitcount:     105957
{ delta:        123 } hitcount:     119107
{ delta:        124 } hitcount:      54494
{ delta:        125 } hitcount:      63856
{ delta:        126 } hitcount:      64454
{ delta:        127 } hitcount:      34818
{ delta:        128 } hitcount:      41446
{ delta:        129 } hitcount:      51242
{ delta:        130 } hitcount:      28361
{ delta:        131 } hitcount:      23926
{ delta:        132 } hitcount:      22253
{ delta:        133 } hitcount:      16994
{ delta:        134 } hitcount:      14970
{ delta:        135 } hitcount:      13464
{ delta:        136 } hitcount:      11452
{ delta:        137 } hitcount:      12212
{ delta:        138 } hitcount:      12280
{ delta:        139 } hitcount:       9127
{ delta:        140 } hitcount:       9553

Where the bulk was around 114ns and the fast time was 103ns.

That's almost a 20% speedup!!!


Steven Rostedt (Google) (4):
      tracing: Add numeric delta time to the trace event benchmark
      tracing/hist: Call hist functions directly via a switch statement
      tracing: Move struct filter_pred into trace_events_filter.c
      tracing/filter: Call filter predicate functions directly via a switch statement

----
 kernel/trace/trace.h               |  13 --
 kernel/trace/trace_benchmark.c     |   2 +-
 kernel/trace/trace_benchmark.h     |   8 +-
 kernel/trace/trace_events_filter.c | 239 +++++++++++++++++++++++++-----------
 kernel/trace/trace_events_hist.c   | 244 +++++++++++++++++++++++++------------
 5 files changed, 342 insertions(+), 164 deletions(-)

             reply	other threads:[~2022-08-23 21:51 UTC|newest]

Thread overview: 8+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2022-08-23 21:46 Steven Rostedt [this message]
2022-08-23 21:46 ` [PATCH 1/4] tracing: Add numeric delta time to the trace event benchmark Steven Rostedt
2022-08-23 21:46 ` [PATCH 2/4] tracing/hist: Call hist functions directly via a switch statement Steven Rostedt
2022-09-05 13:48   ` Masami Hiramatsu
2022-09-05 15:29     ` Steven Rostedt
2022-09-06 21:38     ` Steven Rostedt
2022-08-23 21:46 ` [PATCH 3/4] tracing: Move struct filter_pred into trace_events_filter.c Steven Rostedt
2022-08-23 21:46 ` [PATCH 4/4] tracing/filter: Call filter predicate functions directly via a switch statement Steven Rostedt

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20220823214606.344269352@goodmis.org \
    --to=rostedt@goodmis.org \
    --cc=akpm@linux-foundation.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mhiramat@kernel.org \
    --cc=mingo@kernel.org \
    --cc=zanussi@kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.