kprobes to DLT

Initial example for setting a kernel tracepoint and forward the trace output over DLT (Autosar Diagnostic Log and Trace).

Howto set a kprobe

This example is taken straight out of the Linux kernel documentation at [1]. For details about the kprobes internals, see [2].

# The tracing facility is in the /sys/kernel folder:
cd /sys/kernel/debug/tracing/

# Set a kernel probe on 'do_sys_open':
echo 'p:myprobe do_sys_open dfd=%ax filename=%dx flags=%cx mode=+4($stack)' > kprobe_events

# Show current probes:
cat kprobe_events
p:kprobes/myprobe do_sys_open dfd=%ax filename=%dx flags=%cx mode=+4($stack)

# Enable 'myprobe':
echo 1 > events/kprobes/myprobe/enable

# Get trace result:
cat /sys/kernel/debug/tracing/trace
# tracer: nop
#
# entries-in-buffer/entries-written: 67/67   #P:4
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
           <...>-852   [003] d...   649.627573: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0x1 mode=0x202ffffffff
           <...>-852   [003] d...   649.627662: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0x51a8 mode=0x246ffffffff
           <...>-852   [003] d...   649.628910: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0xd628 mode=0x246ffffffff
           <...>-852   [003] d...   649.629016: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0x1b6 mode=0x202ffffffff
           <...>-852   [003] d...   649.629413: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0xd628 mode=0x202ffffffff
           <...>-852   [003] d...   649.629435: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0xd628 mode=0x202ffffffff
           <...>-852   [003] d...   649.629445: myprobe: (do_sys_open+0x0/0x220) dfd=0x2 filename=0x88000 flags=0xd628 mode=0x202ffffffff

There is now a kernel tracepoint on the function do_sys_open with trace output on /sys/kernel/debug/tracing/trace.

Howto trace over DLT with via a Linux pipe

Build DLT daemon and tools from sources (sources are available at [3]):

sudo apt-get install cmake pkg-config zlib1g-dev libdbus-glib-1-dev
mkdir build
cd build
cmake ../dlt-daemon-master/     # archive from GitHub
make -j4
ls src/adaptor
[...]  dlt-adaptor-stdin  dlt-adaptor-udp

Along with the dlt-daemon which hangles the ring buffer and wait for traces, dlt-adaptor-* where built. dlt-adaptor-stdin is especially interesting here because sends over DLT anything piped to stdin.

Run dlt-daemon in background:

./daemon/dlt-daemon &
[1] 10193
Cannot open configuration file: /usr/local/etc/dlt.conf
[ 4618.025414]~DLT~10193~NOTICE   ~Starting DLT Daemon; DLT Package Version: 2.17.0 UNSTABLE, Package Revision: , build on Dec 28 2016 10:49:45
-SYSTEMD -SYSTEMD_WATCHDOG -TEST -SHM

[ 4618.025982]~DLT~10193~INFO     ~FIFO size: 65536
[ 4618.026110]~DLT~10193~INFO     ~Activate connection type: 3
[ 4618.026332]~DLT~10193~INFO     ~dlt_daemon_socket_open: Socket created - socket_family:10, socket_type:1, protocol:6
[ 4618.026503]~DLT~10193~INFO     ~dlt_daemon_socket_open: Listening on port: 3490
[ 4618.026601]~DLT~10193~INFO     ~dlt_daemon_socket_open: Socket send queue size: 16384
[ 4618.026741]~DLT~10193~INFO     ~Activate connection type: 0
[ 4618.027049]~DLT~10193~INFO     ~Activate connection type: 7
[ 4618.027260]~DLT~10193~WARNING  ~DLT runtime-application load, cannot open file /tmp/dlt-runtime-application.cfg: No such file or directory
[ 4618.027414]~DLT~10193~WARNING  ~Cannot open configuration file: /tmp/dlt-runtime.cfg
[ 4618.027507]~DLT~10193~INFO     ~Ringbuffer configuration: 500000/10000000/500000
[ 4618.028777]~DLT~10193~NOTICE   ~Failed to open ECU Software version file.
[ 4618.028958]~DLT~10193~INFO     ~<Timing packet> initialized with 1 timer
[ 4618.029062]~DLT~10193~INFO     ~Activate connection type: 4
[ 4618.029145]~DLT~10193~INFO     ~Switched to buffer state for socket connections.

There is now a DLT daemon waiting for trace input and clients for output.

kprobes and DLT together

The magic command to bridge the kprobes trace over DLT to dlt-viewer is:

cat /sys/kernel/debug/tracing/trace_pipe | ./adaptor/dlt-adaptor-stdin
[ 4756.037164]~DLT~10193~NOTICE   ~Send log-level to context: SINA:SINC [-1 -> 4] [-1 -> 0]

By default, the Application Id and Context Id are SINA and SINC.

If you compiled dlt_viewer manually from sources [4]:

~/dlt/build-BuildDltViewer-Desktop-Release/release$ LD_LIBRARY_PATH=. ./dlt_viewer

Final result:

But wait...

How does kprobes knows the address of the symbol do_sys_open?

See [5], at section "Getting the address of a kernel routine". I surmise that kprobes makes use of kallsyms_lookup_name() internally. The list of all available symbols can be found in /proc/kallsyms. This method only works if the kernel was built with CONFIG_KALLSYMS. How are they generated? See [6].

# uname -a
Linux inabox 3.16.0-4-amd64 #1 SMP Debian 3.16.36-1+deb8u2 (2016-10-19) x86_64 GNU/Linux
# cat /proc/kallsyms | wc
39084  128745 1634169

39084 symbols are exported.

References for kprobes

[1]Linux kernel, kprobes trace docs, https://www.kernel.org/doc/Documentation/trace/kprobetrace.txt
[2]Linux kernel, kprobes docs, https://www.kernel.org/doc/Documentation/kprobes.txt

References for DLT

[3]dlt-daemon, git repository, https://github.com/GENIVI/dlt-daemon
[4]dlt-viewer, git repository, https://github.com/GENIVI/dlt-viewer