[RFC,v3,00/19] tracing: skc: Boot-time tracing and Supplemental Kernel Cmdline

Message

Masami Hiramatsu (Google) Aug. 26, 2019, 3:15 a.m. UTC

Hello,

This is the 3rd version of RFC series for the boot-time tracing.

Previous thread is here.

https://lkml.kernel.org/r/156316746861.23477.5815110570539190650.stgit@devnote2

On that thread and offline talk with Frank Rowand at OSS Japan2019
last month, we agreed that the devicetree is only for hardware
description and should not expand it for software settings.

Thus, in this version, I introduced a new extended command line
feature called Supplemental Kernel Cmdline (SKC) instead of
devicetree, and rewrote the boot-time tracing part based on that.

Supplemental Kernel Cmdline
===========================

Supplemental kernel command line (SKC) allows admin to pass a
tree-structured supplemental kernel commandline file (SKC file)
when boot up kernel. This expands the kernel command line in
efficient way.

Each key is described as a dot-jointed-words. And user can write
the key-words in tree stlye.
For example,

 feature.option.foo = 1;
 feature.option.bar = 2;

can be also written in

 feature.option {
    foo = 1;
    bar = 2;
 }

(Note that in both style, the same words are merged automatically
 and make a single tree)
All values are treated as a string, or array of strings, e.g.

 feature.options = "foo", "bar";

User can see the loaded SKC key-value list via /proc/skc.
The size of SKC is limited upto 32KB and 512 key-words and values
in total.

SKC and Bootloader
==================

To play with SKC, you need to use patched qemu or patched grub.
Please checkout below for x86 support. (for PoC, I implemented it
only for x86, but it is not so hard to do same on other archs)

https://github.com/mhiramat/qemu.git skc

https://github.com/mhiramat/grub.git grub-x86-skc

User can pass an skc file when boot the qemu machine with "-skc PATH"
option. Or specify the skc file on grub console by "skc PATH".

Boot-time Tracing
=================

Boot-time tracing side has been updated for SKC, but the difference
is small, because SKC has similar tree-based interfaces to OF APIs.
Currently, it supports following SKC options. Please read
Documentation/trace/boottime-trace.rst for details.

     - ftrace.options = OPT1[,OPT2...];
     - ftrace.trace_clock = CLOCK;
     - ftrace.dump_on_oops [= MODE];
     - ftrace.traceoff_on_warning;
     - ftrace.tp_printk;
     - ftrace.buffer_size = SIZE;
     - ftrace.alloc_snapshot;
     - ftrace.events = EVENT[, EVENT2...];
     - ftrace.tracer = TRACER;
     - ftrace.event.GROUP.EVENT.filter = FILTER;
     - ftrace.event.GROUP.EVENT.actions = ACTION[, ACTION2...];
     - ftrace.event.GROUP.EVENT.enable;
     - ftrace.event.kprobes.EVENT.probes = PROBE[, PROBE2...];
     - ftrace.event.synthetic.EVENT.fields = FIELD[, FIELD2...];
     - ftrace.[instance.INSTANCE.]cpumask = CPUMASK;
     - ftrace.[instance.INSTANCE.]ftrace.filters
     - ftrace.[instance.INSTANCE.]ftrace.notraces
     - ftrace.fgraph.filters = FILTER[, FILTER2...];
     - ftrace.fgraph.notraces = FILTER[, FILTER2...];
     - ftrace.fgraph.max_depth = MAX_DEPTH;

This series can be applied on Steve's tracing tree (ftrace/core) or
available on below

https://github.com/mhiramat/linux.git ftrace-boottrace-v3

Usage
=====

With this series, we can setup new kprobe and synthetic events, more
complicated event filters and trigger actions including histogram
via supplemental kernel cmdline.

We can add filter and actions for each event, define kprobe events,
and synthetic events with histogram like below.

ftrace.event {
	task.task_newtask {
		filter = "pid < 128";
		enable;
	}
	kprobes.vfs_read {
		probes = "vfs_read $arg1 $arg2";
		filter = "common_pid < 200";
		enable;
	}
	synthetic.initcall_latency {
		fields = "unsigned long func", "u64 lat";
		actions = "hist:keys=func.sym,lat:vals=lat:sort=lat";
	}
	initcall.initcall_start {
		actions = "hist:keys=func:ts0=common_timestamp.usecs";
	}
	initcall.initcall_finish {
		actions = "hist:keys=func:lat=common_timestamp.usecs-$ts0:onmatch(initcall.initcall_start).initcall_latency(func,$lat)";
	}
}

Also, this supports "instance" node, which allows us to run several
tracers for different purpose at once. For example, one tracer is for
tracing functions in module alpha, and others tracing module beta,
you can write followings.

ftrace.instance {
	foo {
		tracer = "function";
		ftrace-filters = "*:mod:alpha";
	}
	bar {
		tracer = "function";
		ftrace-filters = "*:mod:beta";
	}
}

The instance node also accepts event nodes so that each instance
can customize its event tracing.

This boot-time trace also supports ftrace kernel parameters.
For example, following kernel parameters

trace_options=sym-addr trace_event=initcall:* tp_printk trace_buf_size=1M ftrace=function ftrace_filter="vfs*"

it can be written in SKC like below.

ftrace {
	options = sym-addr;
	events = "initcall:*";
	tp-printk;
	buffer-size = 1MB;
	ftrace-filters = "vfs*";
}

However, since the initialization timing is different, if you need
to trace very early boot, please use normal kernel parameters.

Some Notes
==========

- For specifying the skc data address, there are 2 ways to pass it
to kernel. One is expanding arch-specific entries (e.g. setup_data
on x86), another is passing it via kernel cmdline. The former may
need to expand devicetree anyway (we need /chosen/skc_addr property
for some arch.) The latter is more generic, but it may not work if
the space on cmdline shorts.
According to Frank's suggestion, I introduced "skc=PADDR,SIZE" option
to kernel cmdline, boot loaders must support it. This is generic, and
I still have some concerns, like memory reservation. In this version,
I used early_param() to reserve SKC memory. If it is too late, we'd
better considering to use arch specific data passing.

- Currently, supplemental kernel cmdline doesn't support __setup()
routine to avoid confusion, but I think it is possible to support it.

- For saving memory consuming after boot, all variables and APIs are
__init and __initdata. Thus runtime memory footprint becomes minimum.
But if some loadable modules wants to use it. We have to keep at least
query interface and tree nodes on memory.

- As you can see, the EVENT.actions value is a bit ugly. Maybe we can
introduce sub-nodes under action node, something like below.

ftrace.event.initcall.initcall_finish.action.hist {
	keys = "func";
	lat = "common_timestamp.usecs-$ts0";
	onmatch = "initcall.initcall_start";
        call = "initcall_latency(func,$lat)";
}

Any suggestions, thoughts?

Thank you,

---

Masami Hiramatsu (19):
      skc: Add supplemental kernel cmdline support
      skc: Add /proc/sup_cmdline to show SKC key-value list
      skc: Add a boot setup routine from cmdline
      Documentation: skc: Add a doc for supplemental kernel cmdline
      tracing: Apply soft-disabled and filter to tracepoints printk
      tracing: kprobes: Output kprobe event to printk buffer
      tracing: Expose EXPORT_SYMBOL_GPL symbol
      tracing: kprobes: Register to dynevent earlier stage
      tracing: Accept different type for synthetic event fields
      tracing: Add NULL trace-array check in print_synth_event()
      tracing/boot: Add boot-time tracing by supplemental kernel cmdline
      tracing/boot: Add per-event settings
      tracing/boot Add kprobe event support
      tracing/boot: Add synthetic event support
      tracing/boot: Add instance node support
      tracing/boot: Add cpu_mask option support
      tracing/boot: Add function tracer filter options
      tracing/boot: Add function-graph tracer options
      Documentation: tracing: Add boot-time tracing document


 Documentation/admin-guide/index.rst             |    1 
 Documentation/admin-guide/kernel-parameters.txt |    6 
 Documentation/admin-guide/skc.rst               |  123 ++++
 Documentation/trace/boottime-trace.rst          |  185 ++++++
 MAINTAINERS                                     |    8 
 arch/Kconfig                                    |    9 
 fs/proc/Makefile                                |    1 
 fs/proc/sup_cmdline.c                           |  106 ++++
 include/linux/skc.h                             |  205 +++++++
 include/linux/trace_events.h                    |    1 
 init/main.c                                     |   54 ++
 kernel/trace/Kconfig                            |    9 
 kernel/trace/Makefile                           |    1 
 kernel/trace/ftrace.c                           |   85 ++-
 kernel/trace/trace.c                            |   90 ++-
 kernel/trace/trace_boot.c                       |  457 +++++++++++++++
 kernel/trace/trace_events.c                     |    3 
 kernel/trace/trace_events_hist.c                |   14 
 kernel/trace/trace_events_trigger.c             |    2 
 kernel/trace/trace_kprobe.c                     |   81 ++-
 lib/Kconfig                                     |    3 
 lib/Makefile                                    |    2 
 lib/skc.c                                       |  694 +++++++++++++++++++++++
 23 files changed, 2044 insertions(+), 96 deletions(-)
 create mode 100644 Documentation/admin-guide/skc.rst
 create mode 100644 Documentation/trace/boottime-trace.rst
 create mode 100644 fs/proc/sup_cmdline.c
 create mode 100644 include/linux/skc.h
 create mode 100644 kernel/trace/trace_boot.c
 create mode 100644 lib/skc.c

--
Masami Hiramatsu (Linaro) <[e-mail]>