LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
From: Steven Rostedt <rostedt@goodmis.org>
To: linux-trace-devel@vger.kernel.org
Cc: linux-kernel@vger.kernel.org, Tom Zanussi <zanussi@kernel.org>,
	Daniel Bristot de Oliveira <bristot@redhat.com>,
	Masami Hiramatsu <mhiramat@kernel.org>,
	Namhyung Kim <namhyung@kernel.org>,
	linux-rt-users <linux-rt-users@vger.kernel.org>,
	Clark Williams <williams@redhat.com>,
	"Steven Rostedt (VMware)" <rostedt@goodmis.org>
Subject: [PATCH 7/7] libtracefs: Make a man page for the sqlhist man page example
Date: Thu, 12 Aug 2021 22:16:55 -0400	[thread overview]
Message-ID: <20210813021655.939819-8-rostedt@goodmis.org> (raw)
In-Reply-To: <20210813021655.939819-1-rostedt@goodmis.org>

From: "Steven Rostedt (VMware)" <rostedt@goodmis.org>

As the sqlhist example in the tracefs_sql(3) man page is becoming quite
the tool to use, give it its own man page!

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 Documentation/Makefile                 |  53 +++-
 Documentation/libtracefs-sql.txt       |   2 +-
 Documentation/libtracefs-sqlhist.txt.1 | 351 +++++++++++++++++++++++++
 3 files changed, 397 insertions(+), 9 deletions(-)
 create mode 100644 Documentation/libtracefs-sqlhist.txt.1

diff --git a/Documentation/Makefile b/Documentation/Makefile
index efe7b09d4e68..0c00505852b5 100644
--- a/Documentation/Makefile
+++ b/Documentation/Makefile
@@ -10,6 +10,9 @@ MAN3_TXT= \
 	$(wildcard libtracefs-*.txt) \
 	libtracefs.txt
 
+MAN1_TEXT= \
+	$(wildcard libtracefs-*.txt.1)
+
 MAN_TXT = $(MAN3_TXT)
 _MAN_XML=$(patsubst %.txt,%.xml,$(MAN_TXT))
 _MAN_HTML=$(patsubst %.txt,%.html,$(MAN_TXT))
@@ -19,6 +22,15 @@ MAN_XML=$(addprefix $(OUTPUT),$(_MAN_XML))
 MAN_HTML=$(addprefix $(OUTPUT),$(_MAN_HTML))
 DOC_MAN3=$(addprefix $(OUTPUT),$(_DOC_MAN3))
 
+_MAN1_XML=$(patsubst %.txt.1,%.xml,$(MAN1_TEXT))
+_MAN1_HTML=$(patsubst %.txt.1,%.html,$(MAN1_TEXT))
+_DOC_MAN1=$(patsubst %.txt.1,%.m,$(MAN1_TEXT))
+
+MAN1_XML=$(addprefix $(OUTPUT),$(_MAN1_XML))
+MAN1_HTML=$(addprefix $(OUTPUT),$(_MAN1_HTML))
+DOC_MAN1=$(addprefix $(OUTPUT),$(_DOC_MAN1))
+
+
 # Make the path relative to DESTDIR, not prefix
 ifndef DESTDIR
 prefix?=$(HOME)
@@ -28,6 +40,7 @@ htmldir?=$(prefix)/share/doc/libtracefs-doc
 pdfdir?=$(prefix)/share/doc/libtracefs-doc
 mandir?=$(prefix)/share/man
 man3dir=$(mandir)/man3
+man1dir=$(mandir)/man1
 
 ASCIIDOC=asciidoc
 ASCIIDOC_EXTRA = --unsafe -f asciidoc.conf
@@ -131,12 +144,13 @@ endif
 
 all: check-man-tools html man
 
-man: man3
+man: man3 man1
 man3: $(DOC_MAN3)
+man1: $(DOC_MAN1)
 
-html: $(MAN_HTML)
+html: $(MAN_HTML) $(MAN1_HTML)
 
-$(MAN_HTML) $(DOC_MAN3): asciidoc.conf
+$(MAN_HTML) $(MAN1_HTML) $(DOC_MAN3) $(DOC_MAN1): asciidoc.conf
 
 install: check-man-tools install-man install-html
 
@@ -148,7 +162,10 @@ endif
 install-%.3: $(OUTPUT)%.3
 	$(Q)$(call do_install,$<,$(man3dir),644);
 
-do-install-man: man $(addprefix install-,$(wildcard $(OUTPUT)*.3))
+install-%.1: $(OUTPUT)%.1
+	$(Q)$(call do_install,$<,$(man1dir),644);
+
+do-install-man: man $(addprefix install-,$(wildcard $(OUTPUT)*.3)) $(addprefix install-,$(wildcard $(OUTPUT)*.1))
 
 install-man: man
 	$(Q)$(MAKE) -C . do-install-man
@@ -156,17 +173,20 @@ install-man: man
 install-%.txt: $(OUTPUT)%.html
 	$(Q)$(call do_install,$<,$(htmldir),644);
 
-do-install-html: html $(addprefix install-,$(wildcard *.txt))
+install-%.txt.1: $(OUTPUT)%.html
+	$(Q)$(call do_install,$<,$(htmldir),644);
+
+do-install-html: html $(addprefix install-,$(wildcard *.txt)) $(addprefix install-,$(wildcard *.txt.1))
 
 install-html: html do-install-html
 
 uninstall: uninstall-man uninstall-html
 
 uninstall-man:
-	$(Q)$(RM) $(addprefix $(DESTDIR)$(man3dir)/,$(DOC_MAN3))
+	$(Q)$(RM) $(addprefix $(DESTDIR)$(man3dir)/,$(DOC_MAN3)) $(addprefix $(DESTDIR)$(man1dir)/,$(DOC_MAN1))
 
 uninstall-html:
-	$(Q)$(RM) $(addprefix $(DESTDIR)$(htmldir)/,$(MAN_HTML))
+	$(Q)$(RM) $(addprefix $(DESTDIR)$(htmldir)/,$(MAN_HTML)) $(addprefix $(DESTDIR)$(htmldir)/,$(MAN1_HTML))
 
 ifdef missing_tools
   DO_INSTALL_MAN = $(warning Please install $(missing_tools) to have the man pages installed)
@@ -177,7 +197,7 @@ endif
 CLEAN_FILES =					\
 	$(MAN_XML) $(addsuffix +,$(MAN_XML))	\
 	$(MAN_HTML) $(addsuffix +,$(MAN_HTML))	\
-	$(DOC_MAN3) *.3 *.m
+	$(DOC_MAN3) *.3 *.1 *.m
 
 clean:
 	$(Q) $(RM) $(CLEAN_FILES)
@@ -188,6 +208,11 @@ $(OUTPUT)%.3 : $(OUTPUT)%.txt
 	$(ASCIIDOC) -b manpage -d manpage \
 		$(ASCIIDOC_EXTRA) -alibtracefs_version=$(TRACEFS_VERSION) -o $@+ $< && \
 	mv $@+ $@
+$(OUTPUT)%.1 : $(OUTPUT)%.txt.1
+	$(QUIET_ASCIIDOC)$(RM) $@+ $@ && \
+	$(ASCIIDOC) -b manpage -d manpage \
+		$(ASCIIDOC_EXTRA) -alibtracefs_version=$(TRACEFS_VERSION) -o $@+ $< && \
+	mv $@+ $@
 endif
 
 $(OUTPUT)%.m : $(OUTPUT)%.xml
@@ -201,8 +226,20 @@ $(OUTPUT)%.xml : %.txt
 		$(ASCIIDOC_EXTRA) -alibtracefs_version=$(TRACEFS_VERSION) -o $@+ $< && \
 	mv $@+ $@
 
+$(OUTPUT)%.xml : %.txt.1
+	$(QUIET_ASCIIDOC)$(RM) $@+ $@ && \
+	$(ASCIIDOC) -b docbook -d manpage \
+		$(ASCIIDOC_EXTRA) -alibtracefs_version=$(TRACEFS_VERSION) -o $@+ $< && \
+	mv $@+ $@
+
 $(MAN_HTML): $(OUTPUT)%.html : %.txt
 	$(QUIET_ASCIIDOC)$(RM) $@+ $@ && \
 	$(ASCIIDOC) -b $(ASCIIDOC_HTML) -d manpage \
 		$(ASCIIDOC_EXTRA) -alibtracefs_version=$(TRACEFS_VERSION) -o $@+ $< && \
 	mv $@+ $@
+
+$(MAN1_HTML): $(OUTPUT)%.html : %.txt.1
+	$(QUIET_ASCIIDOC)$(RM) $@+ $@ && \
+	$(ASCIIDOC) -b $(ASCIIDOC_HTML) -d manpage \
+		$(ASCIIDOC_EXTRA) -alibtracefs_version=$(TRACEFS_VERSION) -o $@+ $< && \
+	mv $@+ $@
diff --git a/Documentation/libtracefs-sql.txt b/Documentation/libtracefs-sql.txt
index 95625157590e..e762eaea28c2 100644
--- a/Documentation/libtracefs-sql.txt
+++ b/Documentation/libtracefs-sql.txt
@@ -290,7 +290,6 @@ Then you can run the above examples:
                   JOIN sched_switch as end ON start.pid = end.next_pid
                   WHERE start.prio < 100 || end.prev_prio < 100'
 --
-
 EXAMPLE
 -------
 [source,c]
@@ -548,6 +547,7 @@ FILES
 
 SEE ALSO
 --------
+_sqlhist(1)_,
 _libtracefs(3)_,
 _libtraceevent(3)_,
 _trace-cmd(1)_,
diff --git a/Documentation/libtracefs-sqlhist.txt.1 b/Documentation/libtracefs-sqlhist.txt.1
new file mode 100644
index 000000000000..1e94ea4cd138
--- /dev/null
+++ b/Documentation/libtracefs-sqlhist.txt.1
@@ -0,0 +1,351 @@
+SQLHIST(1)
+==========
+
+NAME
+----
+sqlhist - Tool that uses SQL language to create / show creation of tracefs histograms and synthetic events.
+
+SYNOPSIS
+--------
+*sqlhist* ['OPTIONS'] ['SQL-select-command']
+
+DESCRIPTION
+-----------
+The sqlhist(1) will take an SQL like statement to create tracefs histograms and
+synthetic events that can perform various actions for various handling of the
+data.
+
+The tracefs file system interfaces with the Linux tracing infrastructure that
+has various dynamic and static events through out the kernel. Each of these
+events can have a "histogram" attached to it, where the fields of the event
+will define the buckets of the histogram.
+
+A synthetic event is a way to attach two separate events and use the fields
+and time stamps of those events to create a new dynamic event. This new
+dynamic event is call a synthetic event. The fields of each event can have
+simple calculations done on them where, for example, the delta between
+a field of one event to a field of the other event can be taken. This also
+works for the time stamps of the events where the time delta between the
+two events can also be extracted and placed into the synthetic event.
+
+Other actions can be done from the fields of the events. A snapshot can
+be taken of the kernel ring buffer a variable used in the synthetic
+event creating hits a max, or simply changes.
+
+The commands to create histograms and synthetic events are complex and
+not easy to remember. *sqlhist* is used to convert SQL syntax into the
+commands needed to create the histogram or synthetic event.
+
+The *SQL-select-command* is a SQL string defined by *tracefs_sql*(3).
+
+Note, this must be run as root (or sudo) as interacting with the tracefs
+directory requires root privilege, unless the *-t* option is given with
+a copy of the _tracefs_ directory and its events.
+
+The *sqlhist* is a simple program where its code actual exists in the
+*tracefs_sql*(3) man page.
+
+OPTIONS
+-------
+*-n* 'name'::
+    The name of the synthetic event to create. This event can then be
+    used like any other event, and enabled via *trace-cmd*(1).
+
+*-t* 'tracefs-dir'::
+    In order to test this out as non root user, a copy of the tracefs directory
+    can be used, and passing that directory with this option will allow
+    the program to work. Obviously, *-e* will not work as non-root because
+    it will not be able to execute.
+
+    # mkdir /tmp/tracing
+    # cp -r /sys/kernel/tracing/events /tmp/tracing
+    # exit
+    $ ./sqlhist -t /tmp/tracing ...
+
+*-e*::
+    Not only display the commands to create the histogram, but also execute them.
+    This requires root privilege.
+
+*-f* 'file'::
+    Instead of reading the SQL commands from the command line, read them from
+    _file_. If _file_ is '-' then read from standard input.
+
+*-m* 'var'::
+    Do the given action when the variable _var_ hits a new maximum. This can
+    not be used with *-c*.
+
+*-c* 'var'::
+    Do the given action when the variable _var_ changes its value. This can
+    not be used with *-m*.
+
+*-s*::
+    Perform a snapshot instead of calling the synthetic event.
+
+*-T*::
+    Perform both a snapshot and trace the synthetic event.
+
+*-S* 'fields[,fields]'::
+    Save the given fields. The fields must be fields of the "end" event given
+    in the *SQL-select-command*
+
+
+EXAMPLES
+--------
+
+Create the sqlhist executable:
+
+[source, c]
+--
+   man tracefs_sql | sed -ne '/^EXAMPLE/,/FILES/ { /EXAMPLE/d ; /FILES/d ; p}' > sqlhist.c
+   gcc -o sqlhist sqlhist.c `pkg-config --cflags --libs libtracefs`
+--
+
+As described above, for testing purposes, make a copy of the event directory:
+[source, c]
+--
+   $ mkdir /tmp/tracing
+   $ sudo cp -r /sys/kernel/tracing/events /tmp/tracing/
+   $ sudo chmod -R 0644 /tmp/tracing/
+--
+
+For an example of simple histogram output using the copy of the tracefs directory.
+[source, c]
+--
+   $ ./sqlhist -t /tmp/tracing/ 'SELECT CAST(call_site as SYM-OFFSET), bytes_req, CAST(bytes_alloc AS _COUNTER_) FROM kmalloc'
+--
+
+Produces the output:
+[source, c]
+--
+   echo 'hist:keys=call_site.sym-offset,bytes_req:vals=bytes_alloc' > /sys/kernel/tracing/events/kmem/kmalloc/trigger
+--
+
+Which could be used by root:
+[source, c]
+--
+   # echo 'hist:keys=call_site.sym-offset,bytes_req:vals=bytes_alloc' > /sys/kernel/tracing/events/kmem/kmalloc/trigger
+   # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
+# event histogram
+#
+# trigger info: hist:keys=call_site.sym-offset,bytes_req:vals=hitcount,bytes_alloc:sort=hitcount:size=2048 [active]
+#
+
+{ call_site: [ffffffff813f8d8a] load_elf_phdrs+0x4a/0xb0                               , bytes_req:        728 } hitcount:          1  bytes_alloc:       1024
+{ call_site: [ffffffffc0c69e74] nf_ct_ext_add+0xd4/0x1d0 [nf_conntrack]                , bytes_req:        128 } hitcount:          1  bytes_alloc:        128
+{ call_site: [ffffffff818355e6] dma_resv_get_fences+0xf6/0x440                         , bytes_req:          8 } hitcount:          1  bytes_alloc:          8
+{ call_site: [ffffffffc06dc73f] intel_gt_get_buffer_pool+0x15f/0x290 [i915]            , bytes_req:        424 } hitcount:          1  bytes_alloc:        512
+{ call_site: [ffffffff813f8d8a] load_elf_phdrs+0x4a/0xb0                               , bytes_req:        616 } hitcount:          1  bytes_alloc:       1024
+{ call_site: [ffffffff8161a44c] __sg_alloc_table+0x11c/0x180                           , bytes_req:         32 } hitcount:          1  bytes_alloc:         32
+{ call_site: [ffffffffc070749d] shmem_get_pages+0xad/0x5d0 [i915]                      , bytes_req:         16 } hitcount:          1  bytes_alloc:         16
+{ call_site: [ffffffffc07507f5] intel_framebuffer_create+0x25/0x60 [i915]              , bytes_req:        408 } hitcount:          1  bytes_alloc:        512
+{ call_site: [ffffffffc06fc20f] eb_parse+0x34f/0x910 [i915]                            , bytes_req:        408 } hitcount:          1  bytes_alloc:        512
+{ call_site: [ffffffffc0700ebd] i915_gem_object_get_pages_internal+0x5d/0x270 [i915]   , bytes_req:         16 } hitcount:          1  bytes_alloc:         16
+{ call_site: [ffffffffc0771188] intel_frontbuffer_get+0x38/0x220 [i915]                , bytes_req:        400 } hitcount:          1  bytes_alloc:        512
+{ call_site: [ffffffff8161a44c] __sg_alloc_table+0x11c/0x180                           , bytes_req:        128 } hitcount:          1  bytes_alloc:        128
+{ call_site: [ffffffff813f8f45] load_elf_binary+0x155/0x1680                           , bytes_req:         28 } hitcount:          1  bytes_alloc:         32
+{ call_site: [ffffffffc07038c8] __assign_mmap_offset+0x208/0x3d0 [i915]                , bytes_req:        288 } hitcount:          1  bytes_alloc:        512
+{ call_site: [ffffffff813737b2] alloc_bprm+0x32/0x2f0                                  , bytes_req:        416 } hitcount:          1  bytes_alloc:        512
+{ call_site: [ffffffff813f9027] load_elf_binary+0x237/0x1680                           , bytes_req:         64 } hitcount:          1  bytes_alloc:         64
+{ call_site: [ffffffff8161a44c] __sg_alloc_table+0x11c/0x180                           , bytes_req:         64 } hitcount:          1  bytes_alloc:         64
+{ call_site: [ffffffffc040ffe7] drm_vma_node_allow+0x27/0xe0 [drm]                     , bytes_req:         40 } hitcount:          2  bytes_alloc:        128
+{ call_site: [ffffffff813cda98] __do_sys_timerfd_create+0x58/0x1c0                     , bytes_req:        336 } hitcount:          2  bytes_alloc:       1024
+{ call_site: [ffffffff818355e6] dma_resv_get_fences+0xf6/0x440                         , bytes_req:         40 } hitcount:          2  bytes_alloc:        128
+{ call_site: [ffffffff8139b75a] single_open+0x2a/0xa0                                  , bytes_req:         32 } hitcount:          2  bytes_alloc:         64
+{ call_site: [ffffffff815df715] bio_kmalloc+0x25/0x80                                  , bytes_req:        136 } hitcount:          2  bytes_alloc:        384
+{ call_site: [ffffffffc071e5cd] i915_vma_work+0x1d/0x50 [i915]                         , bytes_req:        416 } hitcount:          3  bytes_alloc:       1536
+{ call_site: [ffffffff81390d0d] alloc_fdtable+0x4d/0x100                               , bytes_req:         56 } hitcount:          3  bytes_alloc:        192
+{ call_site: [ffffffffc06ff65f] i915_gem_do_execbuffer+0x158f/0x2440 [i915]            , bytes_req:         16 } hitcount:          4  bytes_alloc:         64
+{ call_site: [ffffffff8137713c] alloc_pipe_info+0x5c/0x230                             , bytes_req:        384 } hitcount:          5  bytes_alloc:       2560
+{ call_site: [ffffffff813771b4] alloc_pipe_info+0xd4/0x230                             , bytes_req:        640 } hitcount:          5  bytes_alloc:       5120
+{ call_site: [ffffffff81834cdb] dma_resv_list_alloc+0x1b/0x40                          , bytes_req:         40 } hitcount:          6  bytes_alloc:        384
+{ call_site: [ffffffff81834cdb] dma_resv_list_alloc+0x1b/0x40                          , bytes_req:         56 } hitcount:          9  bytes_alloc:        576
+{ call_site: [ffffffff8120086e] tracing_map_sort_entries+0x9e/0x3e0                    , bytes_req:         24 } hitcount:         60  bytes_alloc:       1920
+
+Totals:
+    Hits: 122
+    Entries: 30
+    Dropped: 0
+--
+
+Note, although the examples use uppercase for the SQL keywords, they do not have
+to be. 'SELECT' could also be 'select' or even 'sElEcT'.
+
+By using the full SQL language, synthetic events can be made and processed.
+For example, using *sqlhist* along with *trace-cmd*(1), wake up latency can
+be recorded by creating a synthetic event by attaching the _sched_waking_
+and the _sched_switch_ events.
+
+[source, c]
+--
+  # sqlhist -n wakeup_lat -e -T -m lat 'SELECT end.next_comm AS comm, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS lat FROM ' \
+    'sched_waking AS start JOIN sched_switch AS end ON start.pid = end.next_pid WHERE end.next_prio < 100 && end.next_comm == "cyclictest"'
+  # trace-cmd start -e all -e wakeup_lat -R stacktrace
+  # cyclictest -l 1000 -p80 -i250  -a -t -q -m -d 0 -b 1000 --tracemark
+  # trace-cmd show -s | tail -30
+          <idle>-0       [002] dNh4 23454.902246: sched_wakeup: comm=cyclictest pid=12272 prio=120 target_cpu=002
+          <idle>-0       [005] ...1 23454.902246: cpu_idle: state=4294967295 cpu_id=5
+          <idle>-0       [007] d..1 23454.902246: cpu_idle: state=0 cpu_id=7
+          <idle>-0       [002] dNh1 23454.902247: hrtimer_expire_exit: hrtimer=0000000037956dc2
+          <idle>-0       [005] d..1 23454.902248: cpu_idle: state=0 cpu_id=5
+          <idle>-0       [002] dNh1 23454.902248: write_msr: 6e0, value 4866ce957272
+          <idle>-0       [006] ...1 23454.902248: cpu_idle: state=4294967295 cpu_id=6
+          <idle>-0       [002] dNh1 23454.902249: local_timer_exit: vector=236
+          <idle>-0       [006] d..1 23454.902250: cpu_idle: state=0 cpu_id=6
+          <idle>-0       [002] .N.1 23454.902250: cpu_idle: state=4294967295 cpu_id=2
+          <idle>-0       [002] dN.1 23454.902251: rcu_utilization: Start context switch
+          <idle>-0       [002] dN.1 23454.902252: rcu_utilization: End context switch
+          <idle>-0       [001] ...1 23454.902252: cpu_idle: state=4294967295 cpu_id=1
+          <idle>-0       [002] dN.3 23454.902253: prandom_u32: ret=3692516021
+          <idle>-0       [001] d..1 23454.902254: cpu_idle: state=0 cpu_id=1
+          <idle>-0       [002] d..2 23454.902254: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=cyclictest next_pid=12275 next_prio=19
+          <idle>-0       [002] d..4 23454.902256: wakeup_lat: next_comm=cyclictest lat=17
+          <idle>-0       [002] d..5 23454.902258: <stack trace>
+ => trace_event_raw_event_synth
+ => action_trace
+ => event_hist_trigger
+ => event_triggers_call
+ => trace_event_buffer_commit
+ => trace_event_raw_event_sched_switch
+ => __traceiter_sched_switch
+ => __schedule
+ => schedule_idle
+ => do_idle
+ => cpu_startup_entry
+ => secondary_startup_64_no_verify
+--
+
+Here's the options for *sqlhist* explained:
+
+ *-n wakeup_lat* ::
+     Name the synthetic event to use *wakeup_lat*.
+
+ *-e*::
+     Execute the commands that are printed.
+
+ *-T*::
+     Perform both a trace action and then a snapshot action (swap the buffer into the static 'snapshot' buffer).
+
+ *-m lat*::
+     Trigger the actions whenever 'lat' hits a new maximum value.
+
+Now a breakdown of the SQL statement:
+[source, c]
+--
+ 'SELECT end.next_comm AS comm, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS lat FROM ' \
+    'sched_waking AS start JOIN sched_switch AS end ON start.pid = end.next_pid WHERE end.next_prio < 100 && end.next_comm == "cyclictest"'
+--
+ *end.next_comm AS comm*::
+   Save the 'sched_switch' field *next_comm* and place it into the *comm* field of the 'wakeup_lat' synthetic event.
+
+ *(end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS lat*::
+   Take the delta of the time stamps from the 'sched_switch' event and the 'sched_waking' event.
+   As time stamps are usually recorded in nanoseconds, *TIMESTAMP* would give the full nanosecond time stamp,
+   but here, the *TIMESTAMP_USECS* will truncate it into microseconds. The value is saved in the
+   variable *lat*, which will also be recorded in the synthetic event.
+
+ *FROM 'sched_waking' AS start JOIN sched_switch AS end ON start.pid = end.next_pid*::
+   Create the synthetic event by joining _sched_waking_ to _sched_switch_, matching
+   the _sched_waking_ 'pid' field with the _sched_switch_ 'next_pid' field.
+   Also make *start* an alias for _sched_waking_ and *end* an alias for _sched_switch_
+   which then an use *start* and *end* as a subsitute for _sched_waking_ and _sched_switch_
+   respectively through out the rest of the SQL statement.
+
+ *WHERE end.next_prio < 100 && end.next_comm == "cyclictest"*::
+   Filter the logic where it executes only if _sched_waking_ 'next_prio' field
+   is less than 100. (Note, in the Kernel, priorities are inverse, and the real-time
+   priorities are represented from 0-100 where 0 is the highest priority).
+   Also only trace when the 'next_comm' (the task scheduling in) of the _sched_switch_
+   event has the name "cyclictest".
+
+For the *trace-cmd*(3) command:
+[source, c]
+--
+   trace-cmd start -e all -e wakeup_lat -R stacktrace
+--
+
+ *trace-cmd start*::
+   Enables tracing (does not record to a file).
+
+ *-e all*::
+   Enable all events
+
+ *-e wakeup_lat -R stacktrace*::
+   have the "wakeup_lat" event (our synthetic event) enable the *stacktrace* trigger, were
+   for every instance of the "wakeup_lat" event, a kernel stack trace will be recorded
+   in the ring buffer.
+
+After calling *cyclictest* (a real-time tool to measure wakeup latency), read the snapshot
+buffer.
+
+ *trace-cmd show -s*::
+   *trace-cmd show* reads the kernel ring buffer, and the *-s* option will read the *snapshot*
+   buffer instead of the normal one.
+
+[source, c]
+--
+ <idle>-0       [002] d..4 23454.902256: wakeup_lat: next_comm=cyclictest lat=17
+--
+  We see on the "wakeup_lat" event happened on CPU 2, with a wake up latency 17 microseconds.
+
+This can be extracted into a *trace.dat* file that *trace-cmd*(3) can read and do further
+analysis, as well as *kernelshark*.
+
+[source, c]
+--
+    # trace-cmd extract -s
+    # trace-cmd report --cpu 2 | tail -30
+          <idle>-0     [002] 23454.902238: prandom_u32:          ret=1633425088
+          <idle>-0     [002] 23454.902239: sched_wakeup:         cyclictest:12275 [19] CPU:002
+          <idle>-0     [002] 23454.902241: hrtimer_expire_exit:  hrtimer=0xffffbbd68286fe60
+          <idle>-0     [002] 23454.902241: hrtimer_cancel:       hrtimer=0xffffbbd6826efe70
+          <idle>-0     [002] 23454.902242: hrtimer_expire_entry: hrtimer=0xffffbbd6826efe70 now=23455294430750 function=hrtimer_wakeup/0x0
+          <idle>-0     [002] 23454.902243: sched_waking:         comm=cyclictest pid=12272 prio=120 target_cpu=002
+          <idle>-0     [002] 23454.902244: prandom_u32:          ret=1102749734
+          <idle>-0     [002] 23454.902246: sched_wakeup:         cyclictest:12272 [120] CPU:002
+          <idle>-0     [002] 23454.902247: hrtimer_expire_exit:  hrtimer=0xffffbbd6826efe70
+          <idle>-0     [002] 23454.902248: write_msr:            6e0, value 4866ce957272
+          <idle>-0     [002] 23454.902249: local_timer_exit:     vector=236
+          <idle>-0     [002] 23454.902250: cpu_idle:             state=4294967295 cpu_id=2
+          <idle>-0     [002] 23454.902251: rcu_utilization:      Start context switch
+          <idle>-0     [002] 23454.902252: rcu_utilization:      End context switch
+          <idle>-0     [002] 23454.902253: prandom_u32:          ret=3692516021
+          <idle>-0     [002] 23454.902254: sched_switch:         swapper/2:0 [120] R ==> cyclictest:12275 [19]
+          <idle>-0     [002] 23454.902256: wakeup_lat:           next_comm=cyclictest lat=17
+          <idle>-0     [002] 23454.902258: kernel_stack:         <stack trace >
+=> trace_event_raw_event_synth (ffffffff8121a0db)
+=> action_trace (ffffffff8121e9fb)
+=> event_hist_trigger (ffffffff8121ca8d)
+=> event_triggers_call (ffffffff81216c72)
+=> trace_event_buffer_commit (ffffffff811f7618)
+=> trace_event_raw_event_sched_switch (ffffffff8110fda4)
+=> __traceiter_sched_switch (ffffffff8110d449)
+=> __schedule (ffffffff81c02002)
+=> schedule_idle (ffffffff81c02c86)
+=> do_idle (ffffffff8111e898)
+=> cpu_startup_entry (ffffffff8111eba9)
+=> secondary_startup_64_no_verify (ffffffff81000107)
+--
+
+BUGS
+----
+
+As *sqlhist* is just example code from a man page, it is guaranteed to contain
+lots of bugs. For one thing, not all error paths are covered properly.
+
+SEE ALSO
+--------
+trace-cmd(1), tracefs_sql(3)
+
+AUTHOR
+------
+Written by Steven Rostedt, <rostedt@goodmis.org>
+
+RESOURCES
+---------
+https://git.kernel.org/pub/scm/utils/trace-cmd/trace-cmd.git/
+
+COPYING
+-------
+Copyright \(C) 2021 , Inc. Free use of this software is granted under
+the terms of the GNU Public License (GPL).
+
-- 
2.30.2


      parent reply	other threads:[~2021-08-13  2:17 UTC|newest]

Thread overview: 8+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2021-08-13  2:16 [PATCH 0/7] libtracefs: Add handlers 'onmax' and 'onchange' and actions 'snapshot' and 'save' Steven Rostedt
2021-08-13  2:16 ` [PATCH 1/7] libtracefs: Move creating of onmatch handler and trace action into helper functions Steven Rostedt
2021-08-13  2:16 ` [PATCH 2/7] libtracefs: Add logic to apply actions to synthetic events Steven Rostedt
2021-08-13  2:16 ` [PATCH 3/7] libtracefs: Add API tracefs_synth_trace() Steven Rostedt
2021-08-13  2:16 ` [PATCH 4/7] libtracefs: Add API tracefs_synth_snapshot() Steven Rostedt
2021-08-13  2:16 ` [PATCH 5/7] libtracefs: Add API tracefs_synth_save() Steven Rostedt
2021-08-13  2:16 ` [PATCH 6/7] libtracefs: Update the libtracefs-sql man page for the new tracefs_synth APIs Steven Rostedt
2021-08-13  2:16 ` Steven Rostedt [this message]

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=20210813021655.939819-8-rostedt@goodmis.org \
    --to=rostedt@goodmis.org \
    --cc=bristot@redhat.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-rt-users@vger.kernel.org \
    --cc=linux-trace-devel@vger.kernel.org \
    --cc=mhiramat@kernel.org \
    --cc=namhyung@kernel.org \
    --cc=williams@redhat.com \
    --cc=zanussi@kernel.org \
    --subject='Re: [PATCH 7/7] libtracefs: Make a man page for the sqlhist man page example' \
    /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

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).