Skip to content

Commit

Permalink
Merge tag 'trace-v5.15' of git://git.kernel.org/pub/scm/linux/kernel/…
Browse files Browse the repository at this point in the history
…git/rostedt/linux-trace

Pull tracing updates from Steven Rostedt:

 - simplify the Kconfig use of FTRACE and TRACE_IRQFLAGS_SUPPORT

 - bootconfig can now start histograms

 - bootconfig supports group/all enabling

 - histograms now can put values in linear size buckets

 - execnames can be passed to synthetic events

 - introduce "event probes" that attach to other events and can retrieve
   data from pointers of fields, or record fields as different types (a
   pointer to a string as a string instead of just a hex number)

 - various fixes and clean ups

* tag 'trace-v5.15' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace: (35 commits)
  tracing/doc: Fix table format in histogram code
  selftests/ftrace: Add selftest for testing duplicate eprobes and kprobes
  selftests/ftrace: Add selftest for testing eprobe events on synthetic events
  selftests/ftrace: Add test case to test adding and removing of event probe
  selftests/ftrace: Fix requirement check of README file
  selftests/ftrace: Add clear_dynamic_events() to test cases
  tracing: Add a probe that attaches to trace events
  tracing/probes: Reject events which have the same name of existing one
  tracing/probes: Have process_fetch_insn() take a void * instead of pt_regs
  tracing/probe: Change traceprobe_set_print_fmt() to take a type
  tracing/probes: Use struct_size() instead of defining custom macros
  tracing/probes: Allow for dot delimiter as well as slash for system names
  tracing/probe: Have traceprobe_parse_probe_arg() take a const arg
  tracing: Have dynamic events have a ref counter
  tracing: Add DYNAMIC flag for dynamic events
  tracing: Replace deprecated CPU-hotplug functions.
  MAINTAINERS: Add an entry for os noise/latency
  tracepoint: Fix kerneldoc comments
  bootconfig/tracing/ktest: Update ktest example for boot-time tracing
  tools/bootconfig: Use per-group/all enable option in ftrace2bconf script
  ...
  • Loading branch information
torvalds committed Sep 5, 2021
2 parents e07af26 + 4420f5b commit 58ca241
Show file tree
Hide file tree
Showing 63 changed files with 2,149 additions and 275 deletions.
85 changes: 80 additions & 5 deletions Documentation/trace/boottime-trace.rst
Original file line number Diff line number Diff line change
Expand Up @@ -125,6 +125,71 @@ Note that kprobe and synthetic event definitions can be written under
instance node, but those are also visible from other instances. So please
take care for event name conflict.

Ftrace Histogram Options
------------------------

Since it is too long to write a histogram action as a string for per-event
action option, there are tree-style options under per-event 'hist' subkey
for the histogram actions. For the detail of the each parameter,
please read the event histogram document [3]_.

.. [3] See :ref:`Documentation/trace/histogram.rst <histogram>`
ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]keys = KEY1[, KEY2[...]]
Set histogram key parameters. (Mandatory)
The 'N' is a digit string for the multiple histogram. You can omit it
if there is one histogram on the event.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]values = VAL1[, VAL2[...]]
Set histogram value parameters.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]sort = SORT1[, SORT2[...]]
Set histogram sort parameter options.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]size = NR_ENTRIES
Set histogram size (number of entries).

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]name = NAME
Set histogram name.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]var.VARIABLE = EXPR
Define a new VARIABLE by EXPR expression.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]<pause|continue|clear>
Set histogram control parameter. You can set one of them.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onmatch.[M.]event = GROUP.EVENT
Set histogram 'onmatch' handler matching event parameter.
The 'M' is a digit string for the multiple 'onmatch' handler. You can omit it
if there is one 'onmatch' handler on this histogram.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onmatch.[M.]trace = EVENT[, ARG1[...]]
Set histogram 'trace' action for 'onmatch'.
EVENT must be a synthetic event name, and ARG1... are parameters
for that event. Mandatory if 'onmatch.event' option is set.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onmax.[M.]var = VAR
Set histogram 'onmax' handler variable parameter.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]onchange.[M.]var = VAR
Set histogram 'onchange' handler variable parameter.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]<onmax|onchange>.[M.]save = ARG1[, ARG2[...]]
Set histogram 'save' action parameters for 'onmax' or 'onchange' handler.
This option or below 'snapshot' option is mandatory if 'onmax.var' or
'onchange.var' option is set.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.[N.]<onmax|onchange>.[M.]snapshot
Set histogram 'snapshot' action for 'onmax' or 'onchange' handler.
This option or above 'save' option is mandatory if 'onmax.var' or
'onchange.var' option is set.

ftrace.[instance.INSTANCE.]event.GROUP.EVENT.hist.filter = FILTER_EXPR
Set histogram filter expression. You don't need 'if' in the FILTER_EXPR.

Note that this 'hist' option can conflict with the per-event 'actions'
option if the 'actions' option has a histogram action.


When to Start
=============
Expand Down Expand Up @@ -159,13 +224,23 @@ below::
}
synthetic.initcall_latency {
fields = "unsigned long func", "u64 lat"
actions = "hist:keys=func.sym,lat:vals=lat:sort=lat"
hist {
keys = func.sym, lat
values = lat
sort = lat
}
}
initcall.initcall_start {
actions = "hist:keys=func:ts0=common_timestamp.usecs"
initcall.initcall_start.hist {
keys = func
var.ts0 = common_timestamp.usecs
}
initcall.initcall_finish {
actions = "hist:keys=func:lat=common_timestamp.usecs-$ts0:onmatch(initcall.initcall_start).initcall_latency(func,$lat)"
initcall.initcall_finish.hist {
keys = func
var.lat = common_timestamp.usecs - $ts0
onmatch {
event = initcall.initcall_start
trace = initcall_latency, func, $lat
}
}
}

Expand Down
110 changes: 95 additions & 15 deletions Documentation/trace/histogram.rst
Original file line number Diff line number Diff line change
Expand Up @@ -70,15 +70,16 @@ Documentation written by Tom Zanussi
modified by appending any of the following modifiers to the field
name:

=========== ==========================================
.hex display a number as a hex value
.sym display an address as a symbol
.sym-offset display an address as a symbol and offset
.syscall display a syscall id as a system call name
.execname display a common_pid as a program name
.log2 display log2 value rather than raw number
.usecs display a common_timestamp in microseconds
=========== ==========================================
============= =================================================
.hex display a number as a hex value
.sym display an address as a symbol
.sym-offset display an address as a symbol and offset
.syscall display a syscall id as a system call name
.execname display a common_pid as a program name
.log2 display log2 value rather than raw number
.buckets=size display grouping of values rather than raw number
.usecs display a common_timestamp in microseconds
============= =================================================

Note that in general the semantics of a given field aren't
interpreted when applying a modifier to it, but there are some
Expand Down Expand Up @@ -228,7 +229,7 @@ Extended error information
that lists the total number of bytes requested for each function in
the kernel that made one or more calls to kmalloc::

# echo 'hist:key=call_site:val=bytes_req' > \
# echo 'hist:key=call_site:val=bytes_req.buckets=32' > \
/sys/kernel/debug/tracing/events/kmem/kmalloc/trigger

This tells the tracing system to create a 'hist' trigger using the
Expand Down Expand Up @@ -1823,20 +1824,99 @@ and variables defined on other events (see Section 2.2.3 below on
how that is done using hist trigger 'onmatch' action). Once that is
done, the 'wakeup_latency' synthetic event instance is created.

A histogram can now be defined for the new synthetic event::

# echo 'hist:keys=pid,prio,lat.log2:sort=pid,lat' >> \
/sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger

The new event is created under the tracing/events/synthetic/ directory
and looks and behaves just like any other event::

# ls /sys/kernel/debug/tracing/events/synthetic/wakeup_latency
enable filter format hist id trigger

A histogram can now be defined for the new synthetic event::

# echo 'hist:keys=pid,prio,lat.log2:sort=lat' >> \
/sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger

The above shows the latency "lat" in a power of 2 grouping.

Like any other event, once a histogram is enabled for the event, the
output can be displayed by reading the event's 'hist' file.

# cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist

# event histogram
#
# trigger info: hist:keys=pid,prio,lat.log2:vals=hitcount:sort=lat.log2:size=2048 [active]
#

{ pid: 2035, prio: 9, lat: ~ 2^2 } hitcount: 43
{ pid: 2034, prio: 9, lat: ~ 2^2 } hitcount: 60
{ pid: 2029, prio: 9, lat: ~ 2^2 } hitcount: 965
{ pid: 2034, prio: 120, lat: ~ 2^2 } hitcount: 9
{ pid: 2033, prio: 120, lat: ~ 2^2 } hitcount: 5
{ pid: 2030, prio: 9, lat: ~ 2^2 } hitcount: 335
{ pid: 2030, prio: 120, lat: ~ 2^2 } hitcount: 10
{ pid: 2032, prio: 120, lat: ~ 2^2 } hitcount: 1
{ pid: 2035, prio: 120, lat: ~ 2^2 } hitcount: 2
{ pid: 2031, prio: 9, lat: ~ 2^2 } hitcount: 176
{ pid: 2028, prio: 120, lat: ~ 2^2 } hitcount: 15
{ pid: 2033, prio: 9, lat: ~ 2^2 } hitcount: 91
{ pid: 2032, prio: 9, lat: ~ 2^2 } hitcount: 125
{ pid: 2029, prio: 120, lat: ~ 2^2 } hitcount: 4
{ pid: 2031, prio: 120, lat: ~ 2^2 } hitcount: 3
{ pid: 2029, prio: 120, lat: ~ 2^3 } hitcount: 2
{ pid: 2035, prio: 9, lat: ~ 2^3 } hitcount: 41
{ pid: 2030, prio: 120, lat: ~ 2^3 } hitcount: 1
{ pid: 2032, prio: 9, lat: ~ 2^3 } hitcount: 32
{ pid: 2031, prio: 9, lat: ~ 2^3 } hitcount: 44
{ pid: 2034, prio: 9, lat: ~ 2^3 } hitcount: 40
{ pid: 2030, prio: 9, lat: ~ 2^3 } hitcount: 29
{ pid: 2033, prio: 9, lat: ~ 2^3 } hitcount: 31
{ pid: 2029, prio: 9, lat: ~ 2^3 } hitcount: 31
{ pid: 2028, prio: 120, lat: ~ 2^3 } hitcount: 18
{ pid: 2031, prio: 120, lat: ~ 2^3 } hitcount: 2
{ pid: 2028, prio: 120, lat: ~ 2^4 } hitcount: 1
{ pid: 2029, prio: 9, lat: ~ 2^4 } hitcount: 4
{ pid: 2031, prio: 120, lat: ~ 2^7 } hitcount: 1
{ pid: 2032, prio: 120, lat: ~ 2^7 } hitcount: 1

Totals:
Hits: 2122
Entries: 30
Dropped: 0


The latency values can also be grouped linearly by a given size with
the ".buckets" modifier and specify a size (in this case groups of 10).

# echo 'hist:keys=pid,prio,lat.buckets=10:sort=lat' >> \
/sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger

# event histogram
#
# trigger info: hist:keys=pid,prio,lat.buckets=10:vals=hitcount:sort=lat.buckets=10:size=2048 [active]
#

{ pid: 2067, prio: 9, lat: ~ 0-9 } hitcount: 220
{ pid: 2068, prio: 9, lat: ~ 0-9 } hitcount: 157
{ pid: 2070, prio: 9, lat: ~ 0-9 } hitcount: 100
{ pid: 2067, prio: 120, lat: ~ 0-9 } hitcount: 6
{ pid: 2065, prio: 120, lat: ~ 0-9 } hitcount: 2
{ pid: 2066, prio: 120, lat: ~ 0-9 } hitcount: 2
{ pid: 2069, prio: 9, lat: ~ 0-9 } hitcount: 122
{ pid: 2069, prio: 120, lat: ~ 0-9 } hitcount: 8
{ pid: 2070, prio: 120, lat: ~ 0-9 } hitcount: 1
{ pid: 2068, prio: 120, lat: ~ 0-9 } hitcount: 7
{ pid: 2066, prio: 9, lat: ~ 0-9 } hitcount: 365
{ pid: 2064, prio: 120, lat: ~ 0-9 } hitcount: 35
{ pid: 2065, prio: 9, lat: ~ 0-9 } hitcount: 998
{ pid: 2071, prio: 9, lat: ~ 0-9 } hitcount: 85
{ pid: 2065, prio: 9, lat: ~ 10-19 } hitcount: 2
{ pid: 2064, prio: 120, lat: ~ 10-19 } hitcount: 2

Totals:
Hits: 2112
Entries: 16
Dropped: 0

2.2.3 Hist trigger 'handlers' and 'actions'
-------------------------------------------

Expand Down
14 changes: 14 additions & 0 deletions MAINTAINERS
Original file line number Diff line number Diff line change
Expand Up @@ -18973,6 +18973,20 @@ F: arch/x86/mm/testmmiotrace.c
F: include/linux/mmiotrace.h
F: kernel/trace/trace_mmiotrace.c

TRACING OS NOISE / LATENCY TRACERS
M: Steven Rostedt <[email protected]>
M: Daniel Bristot de Oliveira <[email protected]>
S: Maintained
F: kernel/trace/trace_osnoise.c
F: include/trace/events/osnoise.h
F: kernel/trace/trace_hwlat.c
F: kernel/trace/trace_irqsoff.c
F: kernel/trace/trace_sched_wakeup.c
F: Documentation/trace/osnoise-tracer.rst
F: Documentation/trace/timerlat-tracer.rst
F: Documentation/trace/hwlat_detector.rst
F: arch/*/kernel/trace.c

TRADITIONAL CHINESE DOCUMENTATION
M: Hu Haowen <[email protected]>
L: [email protected]
Expand Down
3 changes: 3 additions & 0 deletions arch/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -197,6 +197,9 @@ config HAVE_FUNCTION_ERROR_INJECTION
config HAVE_NMI
bool

config TRACE_IRQFLAGS_SUPPORT
bool

#
# An arch should select this if it provides all these things:
#
Expand Down
4 changes: 1 addition & 3 deletions arch/arc/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -49,9 +49,7 @@ config ARC
select PERF_USE_VMALLOC if ARC_CACHE_VIPT_ALIASING
select HAVE_ARCH_JUMP_LABEL if ISA_ARCV2 && !CPU_ENDIAN_BE32
select SET_FS

config TRACE_IRQFLAGS_SUPPORT
def_bool y
select TRACE_IRQFLAGS_SUPPORT

config LOCKDEP_SUPPORT
def_bool y
Expand Down
5 changes: 1 addition & 4 deletions arch/arm/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -126,6 +126,7 @@ config ARM
select RTC_LIB
select SET_FS
select SYS_SUPPORTS_APM_EMULATION
select TRACE_IRQFLAGS_SUPPORT if !CPU_V7M
# Above selects are sorted alphabetically; please add new ones
# according to that. Thanks.
help
Expand Down Expand Up @@ -189,10 +190,6 @@ config LOCKDEP_SUPPORT
bool
default y

config TRACE_IRQFLAGS_SUPPORT
bool
default !CPU_V7M

config ARCH_HAS_ILOG2_U32
bool

Expand Down
4 changes: 1 addition & 3 deletions arch/arm64/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -220,6 +220,7 @@ config ARM64
select SYSCTL_EXCEPTION_TRACE
select THREAD_INFO_IN_TASK
select HAVE_ARCH_USERFAULTFD_MINOR if USERFAULTFD
select TRACE_IRQFLAGS_SUPPORT
help
ARM 64-bit (AArch64) Linux support.

Expand Down Expand Up @@ -287,9 +288,6 @@ config ILLEGAL_POINTER_VALUE
config LOCKDEP_SUPPORT
def_bool y

config TRACE_IRQFLAGS_SUPPORT
def_bool y

config GENERIC_BUG
def_bool y
depends on BUG
Expand Down
4 changes: 1 addition & 3 deletions arch/csky/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -82,6 +82,7 @@ config CSKY
select PCI_SYSCALL if PCI
select PCI_MSI if PCI
select SET_FS
select TRACE_IRQFLAGS_SUPPORT

config LOCKDEP_SUPPORT
def_bool y
Expand Down Expand Up @@ -139,9 +140,6 @@ config STACKTRACE_SUPPORT
config TIME_LOW_RES
def_bool y

config TRACE_IRQFLAGS_SUPPORT
def_bool y

config CPU_TLB_SIZE
int
default "128" if (CPU_CK610 || CPU_CK807 || CPU_CK810)
Expand Down
4 changes: 1 addition & 3 deletions arch/hexagon/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@ config HEXAGON
select GENERIC_CPU_DEVICES
select SET_FS
select ARCH_WANT_LD_ORPHAN_WARN
select TRACE_IRQFLAGS_SUPPORT
help
Qualcomm Hexagon is a processor architecture designed for high
performance and low power across a wide variety of applications.
Expand All @@ -53,9 +54,6 @@ config EARLY_PRINTK
config MMU
def_bool y

config TRACE_IRQFLAGS_SUPPORT
def_bool y

config GENERIC_CSUM
def_bool y

Expand Down
1 change: 1 addition & 0 deletions arch/microblaze/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,7 @@ config MICROBLAZE
select SPARSE_IRQ
select SET_FS
select ZONE_DMA
select TRACE_IRQFLAGS_SUPPORT

# Endianness selection
choice
Expand Down
5 changes: 0 additions & 5 deletions arch/microblaze/Kconfig.debug
Original file line number Diff line number Diff line change
@@ -1,6 +1 @@
# SPDX-License-Identifier: GPL-2.0-only
# For a description of the syntax of this configuration file,
# see Documentation/kbuild/kconfig-language.rst.

config TRACE_IRQFLAGS_SUPPORT
def_bool y
1 change: 1 addition & 0 deletions arch/mips/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -98,6 +98,7 @@ config MIPS
select PCI_MSI_ARCH_FALLBACKS if PCI_MSI
select RTC_LIB
select SYSCTL_EXCEPTION_TRACE
select TRACE_IRQFLAGS_SUPPORT
select VIRT_TO_BUS
select ARCH_HAS_ELFCORE_COMPAT

Expand Down
4 changes: 0 additions & 4 deletions arch/mips/Kconfig.debug
Original file line number Diff line number Diff line change
@@ -1,9 +1,5 @@
# SPDX-License-Identifier: GPL-2.0

config TRACE_IRQFLAGS_SUPPORT
bool
default y

config EARLY_PRINTK
bool "Early printk" if EXPERT
depends on SYS_HAS_EARLY_PRINTK
Expand Down
Loading

0 comments on commit 58ca241

Please sign in to comment.