Linux内核 eBPF Hacking Linux USDT with Ftrace

Hacking Linux USDT with Ftrace
usdt (ftrace) · GitHub
lttng-ust

1. Hacking Linux USDT with Ftrace

I previously thought it was impossible to use user-level statically defined tracing (USDT) probes on Linux, without adding SystemTap or LTTng. Linux’s built-in tracers, ftrace and perf_events, don’t support USDT.

But I’ve found a way to hack them in. This is not recommended. Do not try this at home!

# ./usdt -l /opt/node/node
PROBE
node:gc__start
node:gc__done
node:http__client__request
node:http__client__response
[...]
# ./usdt node:gc__start
Tracing uprobe node_gc__start (p:node_gc__start /opt/node/node:0x7f44b4). Ctrl-C to end.node-23467 [001] d... 19993502.867548: node_gc__start: (0xbf44b4)node-23484 [003] d... 19993502.983719: node_gc__start: (0xbf44b4)node-23484 [003] d... 19993503.354810: node_gc__start: (0xbf44b4)node-23484 [000] d... 19993503.433517: node_gc__start: (0xbf44b4)
[...]

My usdt tool (in this example, running on Node.js) is a proof of concept. What’s important is not this tool, but that this is even possible on an unmodified Linux kernel. In this post I’ll show how it’s done, although I don’t encourage anyone to try this until we have a better front-end.

(Update 2017: since this post, we now do have better front-ends: perf now supports USDT in recent Linux versions, and now so does bcc/eBPF USDT.)

2. User-Level Dynamic Tracing

USDT should not be confused with user-level dynamic tracing, where any user-level code can be instrumented. For example, tracing MySQL server queries by instrumenting the server’s dispatch_command() function:

# ./uprobe 'p:cmd /opt/bin/mysqld:_Z16dispatch_command19enum_server_commandP3THDPcj +0(%dx):string'
Tracing uprobe cmd (p:cmd /opt/bin/mysqld:0x2dbd40 +0(%dx):string). Ctrl-C to end.mysqld-2855  [001] d... 19957757.590926: cmd: (0x6dbd40) arg1="show tables"mysqld-2855  [001] d... 19957759.703497: cmd: (0x6dbd40) arg1="SELECT * FROM numbers"
[...]

I’m using my uprobe tool, which in turn uses built-in Linux capabilities: ftrace (tracer) and uprobes (user-level dynamic tracing, which you’ll want a recent Linux for, eg, 4.0-ish). Other tracers, including perf_events and SystemTap, can do this as well.

Many other MySQL functions can also be traced for further insight. Listing and counting them:

# ./uprobe -l /opt/bin/mysqld | more
account_hash_get_key
add_collation
add_compiled_collation
add_plugin_noargs
adjust_time_range
[...]
# ./uprobe -l /opt/bin/mysqld | wc -l
21809

That’s 21 thousand functions. We can also trace library functions, and even individual instruction offsets.

User-level dynamic tracing is awesome, and can solve countless problems. But it can also be difficult to work with: figuring out which code to trace, processing function arguments, and dealing with code changes.

3. User-level Statically Defined Tracing

A USDT probe (or user-level “marker”) is where the developer has added tracing macros to their code at interesting locations, with a stable and documented API. It makes tracing easier. (If you are a developer, see Adding User Space Probing for an example of how to add these.)

With USDT, instead of tracing _Z16dispatch_command19enum_server_commandP3THDPcj, the C++ symbol for dispatch_command(), I can simply trace a probe called mysql:query__start.

I can still trace dispatch_command() if I want to, and the 21 thousand other mysqld functions, but only when needed: drilling down when the USDT probes don’t solve an issue.

4. USDT in Linux

Static tracepoints, in one form or another, have existed for decades. It was recently made popular by Sun’s DTrace utility, leading to them being placed in many common applications, including MySQL, PostgreSQL, Node.js, and Java. SystemTap developed a way to consume these DTrace probes.

You may be running a Linux application that already contains USDT probes, or, it may require a recompilation (usually --enable-dtrace). Check using readelf. Eg, for Node.js:

# readelf -n node
[...]
Notes at offset 0x00c43058 with length 0x00000494:Owner                 Data size   Descriptionstapsdt              0x0000003c   NT_STAPSDT (SystemTap probe descriptors)Provider: nodeName: gc__startLocation: 0x0000000000bf44b4, Base: 0x0000000000f22464, Semaphore: 0x0000000001243028Arguments: 4@%esi 4@%edx 8@%rdi
[...]stapsdt              0x00000082       NT_STAPSDT (SystemTap probe descriptors)Provider: nodeName: http__client__requestLocation: 0x0000000000bf48ff, Base: 0x0000000000f22464, Semaphore: 0x0000000001243024Arguments: 8@%rax 8@%rdx 8@-136(%rbp) -4@-140(%rbp) 8@-72(%rbp) 8@-80(%rbp) -4@-144(%rbp)
[...]

This is node recompiled with --enable-dtrace, and with the systemtap-sdt-dev package, which provided a “dtrace” utility to build USDT support. Two probes are shown here: node:gc__start (garbage collection start), and node:http__client__request.

At this point you can use SystemTap or LTTng to trace these. The built-in Linux tracers, ftrace and perf_events, cannot (although support for perf_events is in development). However…

5. Hacking with Ftrace: Tracing Addresses

From the readelf output above, node:gc__start is at 0xbf44b4. What is this address?

$ gdb node
(gdb) print/a 0xbf44b4
$1 = 0xbf44b4 <_ZN4node15dtrace_gc_startEPN2v87IsolateENS0_6GCTypeENS0_15GCCallbackFlagsE+4>
(gdb) disas _ZN4node15dtrace_gc_startEPN2v87IsolateENS0_6GCTypeENS0_15GCCallbackFlagsE
Dump of assembler code for function _ZN4node15dtrace_gc_startEPN2v87IsolateENS0_6GCTypeENS0_15GCCallbackFlagsE:0x0000000000bf44b0 <+0>:     push   %rbp0x0000000000bf44b1 <+1>:     mov    %rsp,%rbp0x0000000000bf44b4 <+4>:     nop0x0000000000bf44b5 <+5>:     pop    %rbp0x0000000000bf44b6 <+6>:     retq
End of assembler dump.

It’s a nop (no-operation). Ftrace and uprobes can instrument instructions, so we can instrument this address.

Since this is not a shared library, we need to know and subtract the base load address:

# objdump -x /opt/node/node | more
/opt/node/node:     file format elf64-x86-64
/opt/node/node
architecture: i386:x86-64, flags 0x00000112:
EXEC_P, HAS_SYMS, D_PAGED
start address 0x0000000000617770Program Header:PHDR off    0x0000000000000040 vaddr 0x0000000000400040 paddr 0x0000000000400040 align 2**3filesz 0x00000000000001f8 memsz 0x00000000000001f8 flags r-xINTERP off    0x0000000000000238 vaddr 0x0000000000400238 paddr 0x0000000000400238 align 2**0filesz 0x000000000000001c memsz 0x000000000000001c flags r--LOAD off    0x0000000000000000 vaddr 0x0000000000400000 paddr 0x0000000000400000 align 2**21filesz 0x0000000000c2ada4 memsz 0x0000000000c2ada4 flags r-xLOAD off    0x0000000000c2bca8 vaddr 0x000000000122bca8 paddr 0x000000000122bca8 align 2**21filesz 0x0000000000017384 memsz 0x0000000000020cb0 flags rw-
[...]

It is 0x400000 (typical for x86_64). The uprobes documentation, uprobetracer.txt, gets this from /proc/PID/maps, however, that technique requires a running process.

Subtracting 0x400000 from 0xbf44b4 = 0x7f44b4, which is the address to use with uprobes (because it is not a shared library). Tracing it using my uprobe tool (mentioned earlier):

WARNING: the address must be correct and instruction-aligned

# ./uprobe 'p:gc_start node:0x7f44b4'
Tracing uprobe gc_start (p:gc_start /opt/node/node:0x7f44b4). Ctrl-C to end.node-23484 [002] d... 19993896.988891: gc_start: (0xbf44b4)node-23467 [003] d... 19993897.079658: gc_start: (0xbf44b4)node-23484 [003] d... 19993897.326284: gc_start: (0xbf44b4)node-23484 [003] d... 19993897.402107: gc_start: (0xbf44b4)node-23467 [001] d... 19993897.605167: gc_start: (0xbf44b4)
[...]

Neat. I gave it the alias “gc_start”. We can see GC from two node processes occurring.

This is something we’d prefer a better front-end for, one that has more safety checks (eg, perf_events). Ftrace assumes you know what you’re doing.

perf_events> look
YOU SEE A CUP OF POISON.perf_events> drink cup
I'M AFRAID I WON'T DO THAT. BECAUSE IT IS POISON.ftrace> drink cup
GLUG GLUG GLUG!

If you get the address wrong, and you’re lucky, the target process will immediately crash (“illegal instruction”). If you’re unlucky, it will be in an unknown corrupted state.

6. Hacking with Ftrace: Is-Enabled

Let’s use the previous technique with the second probe I highlighted: node:http__client__request:

# ./uprobe p:node:0x7f48ff
Tracing uprobe node_0x7f48ff (p:node_0x7f48ff /opt/node/node:0x7f48ff). Ctrl-C to end.
^C
Ending tracing...

Nothing. This probe should be firing (there is load), but isn’t. The reason was in the readelf output:

Location: 0x0000000000bf48ff, Base: 0x0000000000f22464, Semaphore: 0x0000000001243024

This probe uses a semaphore for the implementation of is-enabled: a feature from DTrace where the tracer can inform the target process that a particular event is being traced. The target process can then choose to do some more expensive processing, usually fetching and formatting arguments for a USDT probe.

We need to set the semaphore. The current value should be zero, and is:

# dd if=/proc/12647/mem bs=1 count=1 skip=$(( 0x1243026 )) 2>/dev/null | xxd
0000000: 00

Let’s set this to 1 (given it was zero to start with):

WARNING: This is a proof of concept, and not intended for real use

# printf "\x1" | dd of=/proc/12647/mem bs=1 count=1 seek=$(( 0x1243024 ))
1+0 records in
1+0 records out
1 byte (1 B) copied, 3.5286e-05 s, 28.3 kB/s
# dd if=/proc/12647/mem bs=1 count=1 skip=$(( 0x1243024 )) 2>/dev/null | xxd
0000000: 01

Yes, I’m piping the output of bash directly over target memory. You should probably never, ever, do this!

It did work, and I can now trace the probe:

# ./uprobe 'p:client_request /opt/node/node:0x7f48ff' | head -5
Tracing uprobe client_request (p:client_request /opt/node/node:0x7f48ff). Ctrl-C to end.node-12647 [001] d... 20025472.106062: client_request: (0xbf48ff)node-12647 [001] d... 20025472.106601: client_request: (0xbf48ff)node-12647 [001] d... 20025472.107240: client_request: (0xbf48ff)node-12647 [001] d... 20025472.107813: client_request: (0xbf48ff)

Good. I should decrement the semaphore when done.

This needs a better front-end to do semaphores properly. My bash one-liner has no error checking.

bash|dd|/dev/mem> look
YOU ARE STANDING IN A FOREST. YOU SEE THE TARGET PROCESS TO THE NORTH.bash|dd|/dev/mem> northh
I DON'T UNDERSTAND "NORTHH". YOU DIE.

If you get the address wrong, you will corrupt memory.

7. Hacking with Ftrace: Arguments

Now that we can trace USDT probes, how about their arguments? They were shown in readelf as well, eg:

    Name: gc__startArguments: 4@%esi 4@%edx 8@%rdiName: http__client__requestArguments: 8@%rax 8@%rdx 8@-136(%rbp) -4@-140(%rbp) 8@-72(%rbp) 8@-80(%rbp) -4@-144(%rbp)

This shows their register and stack locations.

The arguments to gc__start can be determined from the node source that builds the USDT probe. Eg:

src/node_provider.d:54 provider node {[...]78         probe gc__start(int t, int f, void *isolate);src/node_dtrace.cc:
293 void dtrace_gc_start(Isolate* isolate, GCType type, GCCallbackFlags flags) {294   // Previous versions of this probe point only logged type and flags.
295   // That's why for reasons of backwards compatibility the isolate goes last.
296   NODE_GC_START(type, flags, isolate);
297 }

So the first argument is “type”, and is stored in 4@%esi: size 4, and register %esi. (Here’s the reference for the syntax, which is based on assembly.) Tracing it, and naming it “gctype”:

# ./uprobe 'p:client_request /opt/node/node:0x7f44b4 gctype=%si:u32'
Tracing uprobe client_request (p:client_request /opt/node/node:0x7f44b4 gctype=%si:u32). Ctrl-C to end.node-12617 [000] d... 20031814.978011: client_request: (0xbf44b4) gctype=0x1node-12647 [002] d... 20031814.985857: client_request: (0xbf44b4) gctype=0x1node-12647 [001] d... 20031815.323407: client_request: (0xbf44b4) gctype=0x1node-12647 [001] d... 20031815.412093: client_request: (0xbf44b4) gctype=0x2node-12617 [000] d... 20031815.535844: client_request: (0xbf44b4) gctype=0x1
[...]

Great! From deps/v8/include/v8.h: type 1 is scavange, and type 2 is mark-sweep-compact.

Other arguments can get a lot tricker, but are still possible for the really determined. For example, fetching the url and method for node:http__client__request:

# ./uprobe 'p:client_request /opt/node/node:0x7f48ff +0(+0(%ax)):string' | head -5
Tracing uprobe client_request (p:client_request /opt/node/node:0x7f48ff +0(+0(%ax)):string). Ctrl-C to end.node-12647 [003] d... 20031007.438200: client_request: (0xbf48ff) arg1="/"node-12647 [003] d... 20031007.438776: client_request: (0xbf48ff) arg1="/"node-12647 [003] d... 20031007.439322: client_request: (0xbf48ff) arg1="/"node-12647 [003] d... 20031007.439921: client_request: (0xbf48ff) arg1="/"# ./uprobe 'p:client_request /opt/node/node:0x7f48ff +0(+8(%ax)):string' | head -5
Tracing uprobe client_request (p:client_request /opt/node/node:0x7f48ff +0(+8(%ax)):string). Ctrl-C to end.node-12647 [000] d... 20032205.934697: client_request: (0xbf48ff) arg1="GET"node-12647 [000] d... 20032205.935255: client_request: (0xbf48ff) arg1="GET"node-12647 [000] d... 20032205.935832: client_request: (0xbf48ff) arg1="GET"node-12647 [000] d... 20032205.936367: client_request: (0xbf48ff) arg1="GET"

Thy argument +0(+8(%ax)):string begins with a register (%ax), then dereferences offsets (+8(), then +0), then casts it (:string). This syntax is similar to the earlier argument notation, but is still basically brainf*ck. It is documented in uprobetracer.txt and kprobetrace.txt (see FETCHARGS), but I don’t know if it has a real name.

But the real point, as with the other hacking, is that I am getting this to work without modifying the kernel. What we want is a better front end.

8. Safer Hacking

Now that I’ve shown that this possible, I’ll summarize a few different ways to make this safer.

Rewrite the above in C. Include error and safety checks.
Tracing of the parent function. The earlier node::gc__start was called directly by dtrace_gc_start(), which we could just trace using user-level dynamic tracing, as supported by ftrace, perf_events, and other tracers. Check the code: this works when there are no branches between the probe macro and function entry, so that tracing them is essentially the same.
Tracing of another canary function. If the parent function isn’t suitable, there may be a prior unique function call in the code that is, and can be traced using user-level dynamic tracing.
Tracing via the function offset. A USDT probe location can be traced using the offset from the parent function. Eg, with perf_events, using perf probe -x binary ‘func+offset’. This may be safer as it can involve more error checking (depending on the tracer), including ensuring the offset is in the bounds of the function, and that it is instruction-aligned.
Tracing USDT using another tracer. SystemTap or LTTng support USDT.
Wait for perf_events or ftrace support. At least two people have worked on proper perf_events USDT support so far. Can’t wait!
As for my prototype usdt tool:

#./usdt -ip 12647 'node:http__client__request +0(+0(%ax)):string'
Tracing uprobe node_http__client__request (p:node_http__client__request /opt/node/node:0x7f48ff +0(+0(%ax)):string). Ctrl-C to end.node-12647 [001] d... 20047728.328532: node_http__client__request: (0xbf48ff) arg1="/"node-12647 [001] d... 20047728.329050: node_http__client__request: (0xbf48ff) arg1="/"node-12647 [001] d... 20047728.329577: node_http__client__request: (0xbf48ff) arg1="/"node-12647 [001] d... 20047728.330153: node_http__client__request: (0xbf48ff) arg1="/"node-12647 [001] d... 20047728.330689: node_http__client__request: (0xbf48ff) arg1="/"
[...]
# ./usdt -h
USAGE: usdt [-FhHisv] [-d secs] [-p PID] {[-lL] target |usdt_probe [filter]}-F              # force. trace despite warnings.-d seconds      # trace duration, and use buffers-i              # enable isenabled probes. Needs -p.# WARNING: writes to target memory.-l target       # list usdt probes from this executable-L target       # list usdt probes and arguments-p PID          # PID to match-v              # view format file (don't trace)-H              # include column headers-s              # show user stack traces-h              # this usage message
[...]

For the warnings described earlier, I figured it would be reckless to share this in its current form. I’ll consider improving its safety once my company is on a newer kernel, and we’re more likely to use it (it uses uprobes, which aren’t stable on the kernels we are running: a lot of 3.13).

perf_events USDT support might arrive later this year, and I can rewrite uprobe to use it. That will be nice, but in the meantime there are other options, including SystemTap for USDT, and both ftrace and perf_events for user-level dynamic tracing. It’s not like we’re missing out.

9. Conclusion

There is a way to access USDT probes using built-in Linux kernel functionality: ftrace and uprobes. Right now it’s a proof of concept, and we lack a decent front-end tool with error and safety checking. (But you may have a desperate need, and this is useful to know anyway; although, if so, do check out SystemTap and LTTng.) In the future, built-in USDT support can only get better from here!

Linux内核 eBPF：Hacking Linux USDT with Ftrace相关推荐

Linux内核 eBPF基础: 探索USDT探针
目录 Motivation Tracing System Overview Terminology术语 Evoluction of Linux Tracing Linux Tracing Techni ...
Linux内核 eBPF基础：ftrace源码分析：过滤函数和开启追踪
Linux内核 eBPF基础 ftrace基础:过滤函数和开启追踪荣涛 2021年5月12日本文相关注释代码:https://github.com/Rtoax/linux-5.10.13 上篇文章 ...
Linux内核 eBPF基础：ftrace基础-ftrace_init初始化
Linux内核 eBPF基础 ftrace基础:ftrace_init初始化荣涛 2021年5月12日本文相关注释代码:https://github.com/Rtoax/linux-5.10.13 ...
Linux内核 eBPF基础：kprobe原理源码分析：基本介绍与使用示例
Linux内核 eBPF基础 kprobe原理源码分析:基本介绍与使用示例荣涛 2021年5月11日 kprobe调试技术是为了便于跟踪内核函数执行状态所设计的一种轻量级内核调试技术. 利用kpro ...
Linux内核 eBPF基础：Tracepoint原理源码分析
Linux内核 eBPF基础 Tracepoint原理源码分析荣涛 2021年5月10日 1. 基本原理需要注意的几点: 本文将从sched_switch相关的tracepoint展开: 关于st ...
Linux内核 eBPF基础：perf（4）perf_event_open系统调用与用户手册详解
Linux内核 eBPF基础 perf(4)perf_event_open系统调用与用户手册详解荣涛 2021年5月19日本文相关注释代码:https://github.com/Rtoax/lin ...
Linux内核 eBPF基础：kprobe原理源码分析：源码分析
Linux内核 eBPF基础 kprobe原理源码分析:源码分析荣涛 2021年5月11日在 <Linux内核 eBPF基础:kprobe原理源码分析:基本介绍与使用>中已经介绍了kp ...
Linux内核 eBPF基础：perf（1）：perf_event在内核中的初始化
Linux内核 eBPF基础 perf(1):perf_event在内核中的初始化荣涛 2021年5月12日本文相关注释代码:https://github.com/Rtoax/linux-5.10 ...
Linux内核 eBPF基础：perf（2）：perf性能管理单元PMU的注册
Linux内核 eBPF基础 perf(2):性能管理单元PMU的注册荣涛 2021年5月18日本文相关注释代码:https://github.com/Rtoax/linux-5.10.13 Li ...

Linux内核 eBPF：Hacking Linux USDT with Ftrace