11 Commits

Author SHA1 Message Date
Tom Zanussi
2160d6c8a1 tools lib traceevent: Add proper KBUFFER_TYPE_TIME_STAMP handling
Kernel commit dc4e2801d400 (ring-buffer: Redefine the unimplemented
RINGBUF_TYPE_TIME_STAMP) changed the way the ring buffer timestamps work
- after that commit the previously unimplemented RINGBUF_TYPE_TIME_STAMP
type causes the time delta to be used as a timestamp rather than a delta
to be added to the timestamp.

The trace-cmd code didn't get updated to handle this, so misinterprets
the event data for this case, which causes a cascade of errors,
including trace-report not being able to identify synthetic (or any
other) events generated by the histogram code (which uses TIME_STAMP
mode).  For example, the following triggers along with the trace-cmd
shown cause an UNKNOWN_EVENT error and trace-cmd report crash:

  # echo 'wakeup_latency  u64 lat pid_t pid char comm[16]' > /sys/kernel/debug/tracing/synthetic_events

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="ping"' > /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
  # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_wakeup).trace(wakeup_latency,$wakeup_lat,next_pid,next_comm) if next_comm=="ping"' > /sys/kernel/debug/tracing/events/sched/sched_switch/trigger
  # echo 'hist:keys=comm,pid,lat:wakeup_lat=lat:sort=lat' > /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/trigger

  # trace-cmd record -e wakeup_latency -e sched_wakeup -f comm==\"ping\" ping localhost -c 5

  # trace-cmd report
  CPU 0 is empty
  CPU 1 is empty
  CPU 2 is empty
  CPU 3 is empty
  CPU 5 is empty
  CPU 6 is empty
  CPU 7 is empty
  cpus=8
    ug! no event found for type 0
  [UNKNOWN TYPE 0]
    ug! no event found for type 11520
  Segmentation fault (core dumped)

After this patch we get the correct interpretation and the events are
shown properly:

  # trace-cmd report
  CPU 0 is empty
  CPU 1 is empty
  CPU 2 is empty
  CPU 3 is empty
  CPU 5 is empty
  CPU 6 is empty
  CPU 7 is empty
  cpus=8
          <idle>-0     [004] 23284.341392: sched_wakeup:         ping:12031 [120] success=1 CPU:004
          <idle>-0     [004] 23284.341464: wakeup_latency:       lat=58, pid=12031, comm=ping
          <idle>-0     [004] 23285.365303: sched_wakeup:         ping:12031 [120] success=1 CPU:004
          <idle>-0     [004] 23285.365382: wakeup_latency:       lat=64, pid=12031, comm=ping
          <idle>-0     [004] 23286.389290: sched_wakeup:         ping:12031 [120] success=1 CPU:004
          <idle>-0     [004] 23286.389378: wakeup_latency:       lat=72, pid=12031, comm=ping
          <idle>-0     [004] 23287.413213: sched_wakeup:         ping:12031 [120] success=1 CPU:004
          <idle>-0     [004] 23287.413291: wakeup_latency:       lat=64, pid=12031, comm=ping

Link: http://lkml.kernel.org/r/1567628224.13841.4.camel@kernel.org
Link: http://lore.kernel.org/linux-trace-devel/20200625100516.365338-3-tz.stoyanov@gmail.com

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
[ Ported from trace-cmd.git ]
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: linux-trace-devel@vger.kernel.org
Link: http://lore.kernel.org/lkml/20200702185703.785094515@goodmis.org
Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2020-07-03 08:45:38 -03:00
Steven Rostedt (Red Hat)
374855c5e4 tools lib traceevent: Add API to read time information from kbuffer
Add the functions kbuffer_subbuf_timestamp() and kbuffer_ptr_delta() to
get the timing data stored in the ring buffer that is used to produced
the time stamps of the records.

This is useful for tools like trace-cmd to be able to display the
content of the read data to understand why the records show the time
stamps that they do.

Link: http://lore.kernel.org/linux-trace-devel/20200625100516.365338-2-tz.stoyanov@gmail.com

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
[ Ported from trace-cmd.git ]
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: linux-trace-devel@vger.kernel.org
Link: http://lore.kernel.org/lkml/20200702185703.619656282@goodmis.org
Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2020-07-03 08:30:10 -03:00
Zou Wei
eebe80c982 libtraceevent: Remove unneeded semicolon
Fixes coccicheck warning:

 tools/lib/traceevent/kbuffer-parse.c:441:2-3: Unneeded semicolon

Reported-by: Hulk Robot <hulkci@huawei.com>
Signed-off-by: Zou Wei <zou_wei@huawei.com>
Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Link: http://lore.kernel.org/lkml/1588065121-71236-1-git-send-email-zou_wei@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2020-04-30 10:48:32 -03:00
Steven Rostedt (Red Hat)
70df6a7311 tools lib traceevent: Add more debugging to see various internal ring buffer entries
When trace-cmd report --debug is set, show the internal ring buffer
entries like time-extends and padding. This requires adding new kbuffer
API to retrieve these items.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Tzvetomir Stoyanov <tstoyanov@vmware.com>
Link: http://lkml.kernel.org/r/20190401164343.257591565@goodmis.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2019-04-01 15:18:09 -03:00
Steven Rostedt (VMware)
6ab025ed44 tools lib traceevent: Change to SPDX License format
Replace the GPL text with SPDX tags in the tools/lib/traceevent files.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
Cc: Yordan Karadzhov (VMware) <y.karadz@gmail.com>
Cc: linux-trace-devel@vger.kernel.org
Link: http://lkml.kernel.org/r/20180816111015.125e0f25@gandalf.local.home
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2018-08-20 08:54:58 -03:00
Michael Sartain
6d36ce2616 tools lib traceevent: Add UL suffix to MISSING_EVENTS
Add UL suffix to MISSING_EVENTS since ints shouldn't be left shifted by 31.

Signed-off-by: Michael Sartain <mikesart@fastmail.com>
Acked-by: Namhyung Kim <namhyung@kernel.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Link: http://lkml.kernel.org/r/20171016165542.13038-4-mikesart@fastmail.com
Link: http://lkml.kernel.org/r/20180112004822.829533885@goodmis.org
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2018-01-17 10:22:49 -03:00
Steven Rostedt (VMware)
14e4d7e0ab tools lib traceevent: Initialize lenght on OLD_RING_BUFFER_TYPE_TIME_STAMP
A undefined value was being used for the OLD_RING_BUFFER_TYPE_TIME_STAMP
case entry, as the 'length' variable was not being initialized, fix it.

Caught by the reporter when building tools/perf/ using clang, which emmitted
this warning:

  kbuffer-parse.c:312:7: warning: variable 'length' is used uninitialized whenever switch case is taken [-Wsometimes-uninitialized]
          case OLD_RINGBUF_TYPE_TIME_EXTEND:
               ^~~~~~~~~~~~~~~~~~~~~~~~~~~~
  kbuffer-parse.c:339:29: note: uninitialized use occurs here
          kbuf->next = kbuf->index + length;
                                   ^~~~~~
  kbuffer-parse.c:297:21: note: initialize the variable 'length' to silence this warning
          unsigned int length;
                             ^
                              = 0

Reported-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/20170213121418.47f279e8@gandalf.local.home
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2017-02-13 17:22:32 -03:00
Namhyung Kim
a130347973 tools lib traceevent: Fix kbuffer_read_at_offset()
When it's called with an offset less than or equal to the first event,
it'll return a garbage value since the data is not initialized.

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Acked-by: Steven Rostedt <rostedt@goodmis.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20161001101700.29146-1-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-10-05 11:36:22 -03:00
Steven Rostedt (Red Hat)
82ac952be6 tools lib traceevent: Add way to find sub buffer boundary
For debugging purposes, it may be helpful for the kbuffer library to flag
when crossing a sub buffer.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20150324135923.650983637@goodmis.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-03-24 12:22:09 -03:00
Steven Rostedt (Red Hat)
c5e691928b tools lib traceevent kbuffer: Remove extra update to data pointer in PADDING
When a event PADDING is hit (a deleted event that is still in the ring
buffer), translate_data() sets the length of the padding and also updates
the data pointer which is passed back to the caller.

This is unneeded because the caller also updates the data pointer with
the passed back length. translate_data() should not update the pointer,
only set the length.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: stable@vger.kernel.org # 3.12+
Link: http://lkml.kernel.org/r/20150324135923.461431960@goodmis.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-03-24 12:22:04 -03:00
Namhyung Kim
d6c25223f6 tools lib traceevent: Port kbuffer parser routines
kbuffer code is for parsing ftrace ring-buffer binary data and used
for trace-cmd.  Move the code here in order to be used more widely.

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Original-patch-by: Steven Rostedt <rostedt@goodmis.org>
Acked-by: Steven Rostedt <rostedt@goodmis.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Steven Rostedt <rostedt@goodmis.org>
Link: http://lkml.kernel.org/r/1370323231-14022-7-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2013-07-12 13:52:16 -03:00