Skip to content

Commit

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

Pull tracing updates from Steven Rostedt:
 "New tracing features:

   - The ring buffer is no longer disabled when reading the trace file.

     The trace_pipe file was made to be used for live tracing and
     reading as it acted like the normal producer/consumer. As the trace
     file would not consume the data, the easy way of handling it was to
     just disable writes to the ring buffer.

     This came to a surprise to the BPF folks who complained about lost
     events due to reading. This is no longer an issue. If someone wants
     to keep the old disabling there's a new option "pause-on-trace"
     that can be set.

   - New set_ftrace_notrace_pid file. PIDs in this file will not be
     traced by the function tracer.

     Similar to set_ftrace_pid, which makes the function tracer only
     trace those tasks with PIDs in the file, the set_ftrace_notrace_pid
     does the reverse.

   - New set_event_notrace_pid file. PIDs in this file will cause events
     not to be traced if triggered by a task with a matching PID.

     Similar to the set_event_pid file but will not be traced. Note,
     sched_waking and sched_switch events may still be traced if one of
     the tasks referenced by those events contains a PID that is allowed
     to be traced.

  Tracing related features:

   - New bootconfig option, that is attached to the initrd file.

     If bootconfig is on the command line, then the initrd file is
     searched looking for a bootconfig appended at the end.

   - New GPU tracepoint infrastructure to help the gfx drivers to get
     off debugfs (acked by Greg Kroah-Hartman)

  And other minor updates and fixes"

* tag 'trace-v5.7' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace: (27 commits)
  tracing: Do not allocate buffer in trace_find_next_entry() in atomic
  tracing: Add documentation on set_ftrace_notrace_pid and set_event_notrace_pid
  selftests/ftrace: Add test to test new set_event_notrace_pid file
  selftests/ftrace: Add test to test new set_ftrace_notrace_pid file
  tracing: Create set_event_notrace_pid to not trace tasks
  ftrace: Create set_ftrace_notrace_pid to not trace tasks
  ftrace: Make function trace pid filtering a bit more exact
  ftrace/kprobe: Show the maxactive number on kprobe_events
  tracing: Have the document reflect that the trace file keeps tracing enabled
  ring-buffer/tracing: Have iterator acknowledge dropped events
  tracing: Do not disable tracing when reading the trace file
  ring-buffer: Do not disable recording when there is an iterator
  ring-buffer: Make resize disable per cpu buffer instead of total buffer
  ring-buffer: Optimize rb_iter_head_event()
  ring-buffer: Do not die if rb_iter_peek() fails more than thrice
  ring-buffer: Have rb_iter_head_event() handle concurrent writer
  ring-buffer: Add page_stamp to iterator for synchronization
  ring-buffer: Rename ring_buffer_read() to read_buffer_iter_advance()
  ring-buffer: Have ring_buffer_empty() not depend on tracing stopped
  tracing: Save off entry when peeking at next entry
  ...
  • Loading branch information
torvalds committed Apr 5, 2020
2 parents 4c205c8 + 8e99cf9 commit aa1a8ce
Show file tree
Hide file tree
Showing 28 changed files with 1,194 additions and 256 deletions.
82 changes: 66 additions & 16 deletions Documentation/trace/ftrace.rst
Original file line number Diff line number Diff line change
Expand Up @@ -125,10 +125,13 @@ of ftrace. Here is a list of some of the key files:
trace:

This file holds the output of the trace in a human
readable format (described below). Note, tracing is temporarily
disabled when the file is open for reading. Once all readers
are closed, tracing is re-enabled. Opening this file for
readable format (described below). Opening this file for
writing with the O_TRUNC flag clears the ring buffer content.
Note, this file is not a consumer. If tracing is off
(no tracer running, or tracing_on is zero), it will produce
the same output each time it is read. When tracing is on,
it may produce inconsistent results as it tries to read
the entire buffer without consuming it.

trace_pipe:

Expand All @@ -142,9 +145,7 @@ of ftrace. Here is a list of some of the key files:
will not be read again with a sequential read. The
"trace" file is static, and if the tracer is not
adding more data, it will display the same
information every time it is read. Unlike the
"trace" file, opening this file for reading will not
temporarily disable tracing.
information every time it is read.

trace_options:

Expand Down Expand Up @@ -262,6 +263,20 @@ of ftrace. Here is a list of some of the key files:
traced by the function tracer as well. This option will also
cause PIDs of tasks that exit to be removed from the file.

set_ftrace_notrace_pid:

Have the function tracer ignore threads whose PID are listed in
this file.

If the "function-fork" option is set, then when a task whose
PID is listed in this file forks, the child's PID will
automatically be added to this file, and the child will not be
traced by the function tracer as well. This option will also
cause PIDs of tasks that exit to be removed from the file.

If a PID is in both this file and "set_ftrace_pid", then this
file takes precedence, and the thread will not be traced.

set_event_pid:

Have the events only trace a task with a PID listed in this file.
Expand All @@ -273,6 +288,19 @@ of ftrace. Here is a list of some of the key files:
cause the PIDs of tasks to be removed from this file when the task
exits.

set_event_notrace_pid:

Have the events not trace a task with a PID listed in this file.
Note, sched_switch and sched_wakeup will trace threads not listed
in this file, even if a thread's PID is in the file if the
sched_switch or sched_wakeup events also trace a thread that should
be traced.

To have the PIDs of children of tasks with their PID in this file
added on fork, enable the "event-fork" option. That option will also
cause the PIDs of tasks to be removed from this file when the task
exits.

set_graph_function:

Functions listed in this file will cause the function graph
Expand Down Expand Up @@ -1125,6 +1153,12 @@ Here are the available options:
the trace displays additional information about the
latency, as described in "Latency trace format".

pause-on-trace
When set, opening the trace file for read, will pause
writing to the ring buffer (as if tracing_on was set to zero).
This simulates the original behavior of the trace file.
When the file is closed, tracing will be enabled again.

record-cmd
When any event or tracer is enabled, a hook is enabled
in the sched_switch trace point to fill comm cache
Expand Down Expand Up @@ -1176,6 +1210,8 @@ Here are the available options:
tasks fork. Also, when tasks with PIDs in set_event_pid exit,
their PIDs will be removed from the file.

This affects PIDs listed in set_event_notrace_pid as well.

function-trace
The latency tracers will enable function tracing
if this option is enabled (default it is). When
Expand All @@ -1190,6 +1226,8 @@ Here are the available options:
set_ftrace_pid exit, their PIDs will be removed from the
file.

This affects PIDs in set_ftrace_notrace_pid as well.

display-graph
When set, the latency tracers (irqsoff, wakeup, etc) will
use function graph tracing instead of function tracing.
Expand Down Expand Up @@ -2126,19 +2164,27 @@ periodically make a CPU constantly busy with interrupts disabled.
# cat trace
# tracer: hwlat
#
# entries-in-buffer/entries-written: 13/13 #P:8
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
<...>-3638 [001] d... 19452.055471: #1 inner/outer(us): 12/14 ts:1499801089.066141940
<...>-3638 [003] d... 19454.071354: #2 inner/outer(us): 11/9 ts:1499801091.082164365
<...>-3638 [002] dn.. 19461.126852: #3 inner/outer(us): 12/9 ts:1499801098.138150062
<...>-3638 [001] d... 19488.340960: #4 inner/outer(us): 8/12 ts:1499801125.354139633
<...>-3638 [003] d... 19494.388553: #5 inner/outer(us): 8/12 ts:1499801131.402150961
<...>-3638 [003] d... 19501.283419: #6 inner/outer(us): 0/12 ts:1499801138.297435289 nmi-total:4 nmi-count:1
<...>-1729 [001] d... 678.473449: #1 inner/outer(us): 11/12 ts:1581527483.343962693 count:6
<...>-1729 [004] d... 689.556542: #2 inner/outer(us): 16/9 ts:1581527494.889008092 count:1
<...>-1729 [005] d... 714.756290: #3 inner/outer(us): 16/16 ts:1581527519.678961629 count:5
<...>-1729 [001] d... 718.788247: #4 inner/outer(us): 9/17 ts:1581527523.889012713 count:1
<...>-1729 [002] d... 719.796341: #5 inner/outer(us): 13/9 ts:1581527524.912872606 count:1
<...>-1729 [006] d... 844.787091: #6 inner/outer(us): 9/12 ts:1581527649.889048502 count:2
<...>-1729 [003] d... 849.827033: #7 inner/outer(us): 18/9 ts:1581527654.889013793 count:1
<...>-1729 [007] d... 853.859002: #8 inner/outer(us): 9/12 ts:1581527658.889065736 count:1
<...>-1729 [001] d... 855.874978: #9 inner/outer(us): 9/11 ts:1581527660.861991877 count:1
<...>-1729 [001] d... 863.938932: #10 inner/outer(us): 9/11 ts:1581527668.970010500 count:1 nmi-total:7 nmi-count:1
<...>-1729 [007] d... 878.050780: #11 inner/outer(us): 9/12 ts:1581527683.385002600 count:1 nmi-total:5 nmi-count:1
<...>-1729 [007] d... 886.114702: #12 inner/outer(us): 9/12 ts:1581527691.385001600 count:1


The above output is somewhat the same in the header. All events will have
Expand All @@ -2148,19 +2194,23 @@ interrupts disabled 'd'. Under the FUNCTION title there is:
This is the count of events recorded that were greater than the
tracing_threshold (See below).

inner/outer(us): 12/14
inner/outer(us): 11/11

This shows two numbers as "inner latency" and "outer latency". The test
runs in a loop checking a timestamp twice. The latency detected within
the two timestamps is the "inner latency" and the latency detected
after the previous timestamp and the next timestamp in the loop is
the "outer latency".

ts:1499801089.066141940
ts:1581527483.343962693

The absolute timestamp that the first latency was recorded in the window.

count:6

The absolute timestamp that the event happened.
The number of times a latency was detected during the window.

nmi-total:4 nmi-count:1
nmi-total:7 nmi-count:1

On architectures that support it, if an NMI comes in during the
test, the time spent in NMI is reported in "nmi-total" (in
Expand Down
2 changes: 2 additions & 0 deletions drivers/Kconfig
Original file line number Diff line number Diff line change
Expand Up @@ -200,6 +200,8 @@ source "drivers/thunderbolt/Kconfig"

source "drivers/android/Kconfig"

source "drivers/gpu/trace/Kconfig"

source "drivers/nvdimm/Kconfig"

source "drivers/dax/Kconfig"
Expand Down
1 change: 1 addition & 0 deletions drivers/gpu/Makefile
Original file line number Diff line number Diff line change
Expand Up @@ -5,3 +5,4 @@
obj-$(CONFIG_TEGRA_HOST1X) += host1x/
obj-y += drm/ vga/
obj-$(CONFIG_IMX_IPUV3_CORE) += ipu-v3/
obj-$(CONFIG_TRACE_GPU_MEM) += trace/
4 changes: 4 additions & 0 deletions drivers/gpu/trace/Kconfig
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
# SPDX-License-Identifier: GPL-2.0-only

config TRACE_GPU_MEM
bool
3 changes: 3 additions & 0 deletions drivers/gpu/trace/Makefile
Original file line number Diff line number Diff line change
@@ -0,0 +1,3 @@
# SPDX-License-Identifier: GPL-2.0

obj-$(CONFIG_TRACE_GPU_MEM) += trace_gpu_mem.o
13 changes: 13 additions & 0 deletions drivers/gpu/trace/trace_gpu_mem.c
Original file line number Diff line number Diff line change
@@ -0,0 +1,13 @@
// SPDX-License-Identifier: GPL-2.0
/*
* GPU memory trace points
*
* Copyright (C) 2020 Google, Inc.
*/

#include <linux/module.h>

#define CREATE_TRACE_POINTS
#include <trace/events/gpu_mem.h>

EXPORT_TRACEPOINT_SYMBOL(gpu_mem_total);
3 changes: 2 additions & 1 deletion include/linux/bootconfig.h
Original file line number Diff line number Diff line change
Expand Up @@ -216,7 +216,8 @@ static inline int __init xbc_node_compose_key(struct xbc_node *node,
}

/* XBC node initializer */
int __init xbc_init(char *buf);
int __init xbc_init(char *buf, const char **emsg, int *epos);


/* XBC cleanup data structures */
void __init xbc_destroy_all(void);
Expand Down
4 changes: 2 additions & 2 deletions include/linux/ring_buffer.h
Original file line number Diff line number Diff line change
Expand Up @@ -135,10 +135,10 @@ void ring_buffer_read_finish(struct ring_buffer_iter *iter);

struct ring_buffer_event *
ring_buffer_iter_peek(struct ring_buffer_iter *iter, u64 *ts);
struct ring_buffer_event *
ring_buffer_read(struct ring_buffer_iter *iter, u64 *ts);
void ring_buffer_iter_advance(struct ring_buffer_iter *iter);
void ring_buffer_iter_reset(struct ring_buffer_iter *iter);
int ring_buffer_iter_empty(struct ring_buffer_iter *iter);
bool ring_buffer_iter_dropped(struct ring_buffer_iter *iter);

unsigned long ring_buffer_size(struct trace_buffer *buffer, int cpu);

Expand Down
2 changes: 2 additions & 0 deletions include/linux/trace_events.h
Original file line number Diff line number Diff line change
Expand Up @@ -85,6 +85,8 @@ struct trace_iterator {
struct mutex mutex;
struct ring_buffer_iter **buffer_iter;
unsigned long iter_flags;
void *temp; /* temp holder */
unsigned int temp_size;

/* trace_seq for __print_flags() and __print_symbolic() etc. */
struct trace_seq tmp_seq;
Expand Down
57 changes: 57 additions & 0 deletions include/trace/events/gpu_mem.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,57 @@
/* SPDX-License-Identifier: GPL-2.0 */
/*
* GPU memory trace points
*
* Copyright (C) 2020 Google, Inc.
*/

#undef TRACE_SYSTEM
#define TRACE_SYSTEM gpu_mem

#if !defined(_TRACE_GPU_MEM_H) || defined(TRACE_HEADER_MULTI_READ)
#define _TRACE_GPU_MEM_H

#include <linux/tracepoint.h>

/*
* The gpu_memory_total event indicates that there's an update to either the
* global or process total gpu memory counters.
*
* This event should be emitted whenever the kernel device driver allocates,
* frees, imports, unimports memory in the GPU addressable space.
*
* @gpu_id: This is the gpu id.
*
* @pid: Put 0 for global total, while positive pid for process total.
*
* @size: Virtual size of the allocation in bytes.
*
*/
TRACE_EVENT(gpu_mem_total,

TP_PROTO(uint32_t gpu_id, uint32_t pid, uint64_t size),

TP_ARGS(gpu_id, pid, size),

TP_STRUCT__entry(
__field(uint32_t, gpu_id)
__field(uint32_t, pid)
__field(uint64_t, size)
),

TP_fast_assign(
__entry->gpu_id = gpu_id;
__entry->pid = pid;
__entry->size = size;
),

TP_printk("gpu_id=%u pid=%u size=%llu",
__entry->gpu_id,
__entry->pid,
__entry->size)
);

#endif /* _TRACE_GPU_MEM_H */

/* This part must be outside protection */
#include <trace/define_trace.h>
14 changes: 10 additions & 4 deletions init/main.c
Original file line number Diff line number Diff line change
Expand Up @@ -353,6 +353,8 @@ static int __init bootconfig_params(char *param, char *val,
static void __init setup_boot_config(const char *cmdline)
{
static char tmp_cmdline[COMMAND_LINE_SIZE] __initdata;
const char *msg;
int pos;
u32 size, csum;
char *data, *copy;
u32 *hdr;
Expand Down Expand Up @@ -400,10 +402,14 @@ static void __init setup_boot_config(const char *cmdline)
memcpy(copy, data, size);
copy[size] = '\0';

ret = xbc_init(copy);
if (ret < 0)
pr_err("Failed to parse bootconfig\n");
else {
ret = xbc_init(copy, &msg, &pos);
if (ret < 0) {
if (pos < 0)
pr_err("Failed to init bootconfig: %s.\n", msg);
else
pr_err("Failed to parse bootconfig: %s at %d.\n",
msg, pos);
} else {
pr_info("Load bootconfig: %d bytes %d nodes\n", size, ret);
/* keys starting with "kernel." are passed via cmdline */
extra_command_line = xbc_make_cmdline("kernel");
Expand Down
Loading

0 comments on commit aa1a8ce

Please sign in to comment.