用strace做debug

-- TOC --

kernel debug有很多种实现方式,strace是一种,它可以用来跟踪用户态进程执行的系统调用。

我还是用最新的mychar驱动来做测试。

$ strace echo '123abc456hjk' > mychar-5
execve("/usr/bin/echo", ["echo", "123abc456hjk"], 0x7ffdf29dfab8 /* 59 vars */) = 0
brk(NULL)                               = 0x55d5fcd2b000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffc86477f40) = -1 EINVAL (Invalid argument)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=67120, ...}) = 0
mmap(NULL, 67120, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb732527000
close(3)                                = 0
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360q\2\0\0\0\0\0"..., 832) = 832
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
pread64(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32, 848) = 32
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\t\233\222%\274\260\320\31\331\326\10\204\276X>\263"..., 68, 880) = 68
fstat(3, {st_mode=S_IFREG|0755, st_size=2029224, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb732525000
pread64(3, "\6\0\0\0\4\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0@\0\0\0\0\0\0\0"..., 784, 64) = 784
pread64(3, "\4\0\0\0\20\0\0\0\5\0\0\0GNU\0\2\0\0\300\4\0\0\0\3\0\0\0\0\0\0\0", 32, 848) = 32
pread64(3, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0\t\233\222%\274\260\320\31\331\326\10\204\276X>\263"..., 68, 880) = 68
mmap(NULL, 2036952, PROT_READ, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb732333000
mprotect(0x7fb732358000, 1847296, PROT_NONE) = 0
mmap(0x7fb732358000, 1540096, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x25000) = 0x7fb732358000
mmap(0x7fb7324d0000, 303104, PROT_READ, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19d000) = 0x7fb7324d0000
mmap(0x7fb73251b000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1e7000) = 0x7fb73251b000
mmap(0x7fb732521000, 13528, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb732521000
close(3)                                = 0
arch_prctl(ARCH_SET_FS, 0x7fb732526580) = 0
mprotect(0x7fb73251b000, 12288, PROT_READ) = 0
mprotect(0x55d5fcacb000, 4096, PROT_READ) = 0
mprotect(0x7fb732565000, 4096, PROT_READ) = 0
munmap(0x7fb732527000, 67120)           = 0
brk(NULL)                               = 0x55d5fcd2b000
brk(0x55d5fcd4c000)                     = 0x55d5fcd4c000
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=14537584, ...}) = 0
mmap(NULL, 14537584, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb731555000
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0666, st_rdev=makedev(0xed, 0x5), ...}) = 0
ioctl(1, TCGETS, 0x7ffc86477cc0)        = -1 ENOTTY (Inappropriate ioctl for device)
write(1, "123abc456hjk\n", 13)          = 13
close(1)                                = 0
close(2)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

一大推不知从哪里发起的系统调用,看到最后的那个write,才是echo命令写入的动作。比较奇怪的是,write使用的fd=1,但是在strace的log中,没有对应fd=1的open或openat调用。

-e参数可以指定跟踪某个具体的系统调用:

$ strace -e openat echo '123abc456hjk' > mychar-5
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
+++ exited with 0 +++
$ strace -e write echo '123abc456hjk' > mychar-5
write(1, "123abc456hjk\n", 13)          = 13
+++ exited with 0 +++
$ cat mychar-5
123abc456hjk
$ strace -e read cat mychar-5
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360q\2\0\0\0\0\0"..., 832) = 832
read(3, "123abc456hjk\n", 131072)       = 13
123abc456hjk
read(3, "", 131072)                     = 0
+++ exited with 0 +++
$ strace -e openat cat mychar-5
openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3
openat(AT_FDCWD, "mychar-5", O_RDONLY)  = 3
123abc456hjk
+++ exited with 0 +++

用strace跟踪cat命令,就能够跟踪到openat系统调用。

还有几个strace命令比较有用的参数:

-t,显示每个系统调用的时间;

-T,显示每个系统调用花费的时间;

-o,将strace的打印保存的指定文件。

本文链接:https://cs.pynote.net/sf/linux/dd/202201171/

-- EOF --

-- MORE --