如何跟踪 Linux 内核中的 write 系统调用？

Question

我正在尝试这样做： 我正在通过 iperf（一种开源工具）将数据包从一台机器发送到另一台机器，我想跟踪写入系统或发送调用。 请帮助我做到这一点，如果有人可以通过 Ftrace 框架来跟踪系统调用，否则任何其他跟踪工具都会很棒。

Answer 1

困难的部分是确切地知道要跟踪什么，这样你就可以只看到你想要的结果，但是跟踪本身很容易：

• 首先，您的内核必须配置为 CONFIG_FTRACE=y

• 确定要跟踪的事件

  cat /sys/kernel/debug/tracing/available_events

• 将你选择的事件写入 set_event

  echo sys_enter_write > /sys/kernel/debug/tracing/set_event

• 确定要跟踪的跟踪类型

  cat /sys/kernel/debug/tracing/available_tracers

• 在 current_tracer 文件中写入您想要的跟踪类型

  echo function_graph > /sys/kernel/debug/tracing/current_tracer

• 启用跟踪：

  echo 1 > /sys/kernel/debug/tracing/tracing_on

• 现在您可以根据需要运行“iperf -c...”，并在完成后禁用跟踪。

  echo 0 > /sys/kernel/debug/tracing/tracing_on

查看结果：

vi /sys/kernel/debug/tracing/trace

Answer 2

strace

如果您只想跟踪一个进程，为什么不直接使用strace？它甚至可以连接到正在运行的进程：How does strace connect to an already running process?

对于 ftrace，使用 echo none > /sys/kernel/debug/tracing/current_tracer 仅跟踪系统调用

至少从 Linux 4.15 开始，如果您改用 function_graph，那么除了系统调用之外，它还会显示大量函数。

您可以通过过滤来解决这个问题，但使用nop 更简单：How to trace just system call events with ftrace without showing any other functions in the Linux kernel?

使用sudo 运行：

#!/bin/sh
set -eux

d=debug/tracing

mkdir -p debug
if ! mountpoint -q debug; then
  mount -t debugfs nodev debug
fi

# Stop tracing.
echo 0 > "${d}/tracing_on"

# Clear previous traces.
echo > "${d}/trace"

# Find the tracer name.
cat "${d}/available_tracers"

# Disable tracing functions, show only system call events.
echo nop > "${d}/current_tracer"

# Find the event name with.
grep write "${d}/available_events"

# Enable tracing write.
# Both statements below seem to do the exact same thing,
# just with different interfaces.
# https://www.kernel.org/doc/html/v4.18/trace/events.html
echo sys_enter_write > "${d}/set_event"
# echo 1 > "${d}/events/syscalls/sys_enter_write/enable"

# Start tracing.
echo 1 > "${d}/tracing_on"

# Generate two write calls by two different processes.
rm -rf /tmp/a /tmp/b
printf a > /tmp/a
printf b > /tmp/b

# View the trace.
cat "${d}/trace"

# Stop tracing.
echo 0 > "${d}/tracing_on"

umount debug

和一个示例输出：

# tracer: nop
#
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
            a.sh-18135 [004] .... 11152.454767: sys_write(fd: 2, buf: 5558769acc00, count: 2)
            a.sh-18135 [004] .... 11152.454777: sys_write(fd: 2, buf: 555877f6a968, count: 2)
            a.sh-18135 [004] .... 11152.454785: sys_write(fd: 2, buf: 555877f6a968, count: 4)
            a.sh-18135 [004] .... 11152.454793: sys_write(fd: 2, buf: 555877f6a968, count: 7)
            a.sh-18135 [004] .... 11152.454801: sys_write(fd: 2, buf: 555877f6a968, count: 7)
            a.sh-18135 [004] .... 11152.454807: sys_write(fd: 2, buf: 7ffc5f3f2be7, count: 1)
 gnome-terminal--3419  [005] .... 11152.454833: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
 gnome-terminal--3419  [005] .... 11152.454862: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
 gnome-terminal--3419  [005] .... 11152.454887: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
 gnome-terminal--3419  [005] .... 11152.454894: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
           gmain-3193  [002] .... 11152.456141: sys_write(fd: 4, buf: 7fbfe5a93c40, count: 8)
           gmain-3193  [002] .... 11152.456168: sys_write(fd: 4, buf: 7fbfe5a92bd0, count: 8)
           gmain-3193  [002] .... 11152.456172: sys_write(fd: 4, buf: 7fbfe5a93c40, count: 8)
            a.sh-18135 [004] .... 11152.456534: sys_write(fd: 2, buf: 5558769acbd8, count: 2)
            a.sh-18135 [004] .... 11152.456547: sys_write(fd: 2, buf: 555877f6a968, count: 6)
            a.sh-18135 [004] .... 11152.456555: sys_write(fd: 2, buf: 555877f6a968, count: 2)
            a.sh-18135 [004] .... 11152.456561: sys_write(fd: 2, buf: 7ffc5f3f2be7, count: 1)
            a.sh-18135 [004] .... 11152.456578: sys_write(fd: 1, buf: 555877f6af00, count: 1)
 gnome-terminal--3419  [005] .... 11152.456651: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
 gnome-terminal--3419  [005] .... 11152.456660: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
            a.sh-18135 [004] .... 11152.456674: sys_write(fd: 2, buf: 5558769acbd8, count: 2)
            a.sh-18135 [004] .... 11152.456683: sys_write(fd: 2, buf: 555877f6a968, count: 6)
            a.sh-18135 [004] .... 11152.456690: sys_write(fd: 2, buf: 555877f6a968, count: 2)
            a.sh-18135 [004] .... 11152.456694: sys_write(fd: 2, buf: 7ffc5f3f2be7, count: 1)
            a.sh-18135 [004] .... 11152.456703: sys_write(fd: 1, buf: 555877f6af00, count: 1)
            a.sh-18135 [004] .... 11152.456738: sys_write(fd: 2, buf: 5558769acb88, count: 2)
            a.sh-18135 [004] .... 11152.456745: sys_write(fd: 2, buf: 555877f6a968, count: 3)
            a.sh-18135 [004] .... 11152.456750: sys_write(fd: 2, buf: 555877f6a968, count: 14)
            a.sh-18135 [004] .... 11152.456756: sys_write(fd: 2, buf: 7ffc5f3f2be7, count: 1)
 gnome-terminal--3419  [005] .... 11152.456816: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)
 gnome-terminal--3419  [005] .... 11152.456845: sys_write(fd: 4, buf: 7ffe4f3a61c0, count: 8)

如您所见，write 是一个非常常见的系统调用，因此很难隔离我们的两个写调用。使用不太常见的调用会更容易看到事情，例如mkdir:How do I trace a system call in Linux?

在 Ubuntu 18.04、Linux 内核 4.15 上测试。