[转帖]谁写的!? - 调试I/O源头的通用逻辑

调试,源头,通用,逻辑 · 浏览次数 : 0

小编点评

# 生成内容时需要带简单的排版 ## 1. 动态跟踪使用trace命令行可以轻松观察动态跟踪的运行过程。例如，以下代码可以观察__mark_inode_dirty kprobe的运行过程： ```bash trace -Ct -M 1000 -K -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' 'iput(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) \"%d\" inode->i_ino' '__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) \"%d\" inode->i_ino'配合getfn重点看inode 354:8.699010 31 125990 125990 vim iput 354 iput+0x1 [kernel] d_delete+0xb7 [kernel] vfs_unlink+0x150 [kernel] do_unlinkat+0x286 [kernel] do_syscall_64+0x55 [kernel] entry_SYSCALL_64_after_hwframe+0x44 [kernel]8.698990 31 125990 125990 vim iput 354 iput+0x1 [kernel] do_unlinkat+0x13f [kernel] do_syscall_64+0x55 [kernel] entry_SYSCALL_64_after_hwframe+0x44 [kernel]8.698984 31 125990 125990 vim iput 354 iput+0x1 [kernel] ``` ## 2. 编译工具使用bpftrace等工具可以更加简洁地观察动态跟踪： ```bash bpftrace -Ct -M 1000 -K -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' 'iput(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) \"%d\" inode->i_ino' '__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) \"%d\" inode->i_ino'配合getfn重点看inode 354:8.699010 31 125990 125990 vim iput 354 iput+0x1 [kernel] d_delete+0xb7 [kernel] vfs_unlink+0x150 [kernel] do_unlinkat+0x286 [kernel] do_syscall_64+0x55 [kernel] entry_SYSCALL_64_after_hwframe+0x44 [kernel]8.698990 31 125990 125990 vim iput 354 iput+0x1 [kernel] do_unlinkat+0x13f [kernel] do_syscall_64+0x55 [kernel] entry_SYSCALL_64_after_hwframe+0x44 [kernel]8.698984 31 125990 125990 vim iput 354 iput+0x1 [kernel] ``` ## 3. 总结希望以上信息可以帮助您更轻松地观察动态跟踪。

正文

https://zhuanlan.zhihu.com/p/511093857

本文从一个实际例子触发, 总结了5种定位I/O来源的方法.

现象描述

客户环境报dd写入速度慢, 写入10M数据花了30秒钟

#dd if=/dev/zero of=test bs=1M count=10 conv=fdatasync

通过strace可以发现时间都花在了系统调用fdatasync上

fdatasync(1) = 0 <30.669612>

此时I/O性能有重大嫌疑.

环境描述

系统中存在12块HDD盘, 包括dd测试的这块. 为了提高调试效率, 需要进行一定的信息过滤.

#lsblk -t /dev/sdd
NAME    ALIGNMENT MIN-IO OPT-IO PHY-SEC LOG-SEC ROTA SCHED       RQ-SIZE  RA WSAME
sdd             0   4096      0    4096     512    1 mq-deadline     256 128    0B  
`-sdd1          0   4096      0    4096     512    1 mq-deadline     256 128    0B

文件系统为ext4, 分析过程中不需要考虑其他文件系统.

确认问题

上面的慢盘iostat显示的util一直在80%以上, iops在300以上, 只有write请求. 初步结论是hdd上的I/O基本打满了. 为了确保在分析的时候I/O慢的问题一直存在, 需要一个实时监控工具, 这里使用dstat并通过时间戳进行关联. (以下命令在自己环境运行, 只用于展示工具的输出.)

----system---- ----total-cpu-usage---- ---paging-- ---load-avg--- ---procs--- ---io/sdd-- --dsk/sdd-- sdd-
     time     |usr sys idl wai hiq siq|  in   out | 1m   5m  15m |run blk new| read  writ| read  writ|util
08-05 08:13:41| 27  11  59   3   0   1|2496B 3088B|42.0 47.9 48.2|  0   0 814| 1.32  394 | 180k 3774k|25.0
08-05 08:13:42| 25  11  60   3   0   1|   0     0 |42.0 47.9 48.2| 33 1.0 1.1|   0   839 |   0    12M|24.4
08-05 08:13:43| 27  12  59   2   0   0|   0     0 |42.0 47.9 48.2| 41 2.0 1.1|   0   394 |   0  2644k|13.6

明确目标

基于上面的分析, 系统中的I/O超过了资源的能力, 我们要么改用性能更好的SSD盘, 要么找到I/O的来源, 并优化掉不必要的I/O, 本文的重点就是怎么抓到I/O的来源. 我们可以考虑2种方法:

应用角度. 如果上层应用非常清楚自己写了什么文件, 怎么写得文件, 那会很有帮助, 但是注意系统中不只有一种应用, 所以并不简单.
系统角度. 既然有人往底层写东西了, 底层应该有能力找到是谁写的. 我们主要采用这种方法.

我们以找到导致I/O的进程为目标, 可以尝试:

抓住引起I/O的进程. 一般来说, 抓住了进程就找到源头了.
抓住I/O对应的文件. 知道文件路径了, 通过lsof等工具可以容易找到对应的进程.

在开始调试之前, 有必要对I/O路径有个基本了解, 这直接决定了后面的方法, 本案例中所有的I/O都经过文件系统, 没有直接写裸盘的情况.

方法1 - 抓住发I/O的任务

为了抓住谁发的I/O, 最简单的方法就是blktrace, 先收集5秒钟的数据:

#blktrace -d /dev/sdd -w 5
#blkparse sdd -d sdd.bin > sdd.log

这里只关注Q事件, 注意Q不只是读写请求, 还有Flush等.

#grep Q sdd.log > q 
#head q
  8,48   36        3     0.000156800 30917  Q   W 3997372328 + 8 [kworker/u133:15]
  8,48   36        6     0.000171300 30917  Q   W 3997372632 + 8 [kworker/u133:15]
  8,48   36        9     0.000178860 30917  Q   W 3997372984 + 8 [kworker/u133:15]
  8,48   36       12     0.000192780 30917  Q   W 3997373416 + 16 [kworker/u133:15]
  8,48   36       15     0.000203620 30917  Q   W 3997373472 + 8 [kworker/u133:15]
  8,48   36       18     0.000210960 30917  Q   W 3997373704 + 8 [kworker/u133:15]
  8,48   36       21     0.000238280 30917  Q   W 3997373800 + 8 [kworker/u133:15]
  8,48   36       24     0.000247440 30917  Q   W 3997373856 + 8 [kworker/u133:15]
  8,48   29        4     0.001352942 73889  Q   W 3998349336 + 8 [kworker/u132:3]
  8,48   29        7     0.001374982 73889  Q   W 3998349368 + 8 [kworker/u132:3]

看看都是哪些进程在下发I/O, 可以看出大部分I/O都是文件系统刷脏引起:

#awk '{print $NF}' q | sort | uniq -c | sort -n | tail
    147 [dockerd]
    163 [kworker/u131:14]
    231 [kworker/u132:3]
    270 [kworker/u133:0]
    332 [kworker/u131:2]
    378 [kworker/u132:22]
    419 [kworker/u132:4]
    749 [jbd2/sdd1-8]
    850 [kworker/u131:12]
   1260 [kworker/u131:5]

再确认下这些kworker都是刷脏任务, 为了抓到对应的栈, 直接用Q对应的tracepoing, sdd对应的设备号是(8, 48), 其中trace命令来自bcc-tools, 全路径为/usr/share/bcc/tools/trace

#trace -tuKM 1000 't:block:block_bio_queue (args->dev == (8u << 20) + 48)'

输出的格式如下:

TIME              PID       TID     COMM        FUNC
1619748698.514071 33745     13457   dockerd     block_bio_queue
        generic_make_request_checks+0x6e0 [kernel]
        generic_make_request_checks+0x6e0 [kernel]
        generic_make_request+0x70 [kernel]
        submit_bio+0x40 [kernel]
        ext4_io_submit+0x78 [ext4]
        ext4_writepages+0x314 [ext4]
        do_writepages+0x5c [kernel]
        __filemap_fdatawrite_range+0xcc [kernel]
        file_write_add_wait_range+0x74 [kernel]
        ext4_sync_file+0x88 [ext4]
        vfs_fsync_range+0x38 [kernel]
        do_fsync+0x40 [kernel]
        __arm64_sys_fdatasync+0x1c [kernel]
        el0_svc_common+0x90 [kernel]
        el0_svc_handler+0x70 [kernel]
        el0_svc+0x8 [kernel]

为了使用FlameGraph处理, 针对这个格式定制一个stackcollapse脚本:

use strict;

my %collapsed;

sub remember_stack {
    my ($stack, $count) = @_; 
    $collapsed{$stack} += $count;
}

my @stack;
my $cmd;

foreach (<>) {
    if (/^[0-9]+/) {
        my @items = split;
        $cmd = $items[3];
        next;
    } elsif (/^\S/) {
        next;
    } elsif (/^\s*$/) {
        if (defined $cmd) {
            unshift @stack, $cmd;
            remember_stack(join(";", @stack), 1); 
            undef @stack;
            undef $mcd;
        }   
        next;
    }   

    my $frame = $_; 
    $frame =~ s/^\s*//;
    $frame =~ s/\+[^+]*$//;
    unshift @stack, $frame;
}

foreach my $k (sort { $a cmp $b } keys %collapsed) {
    printf "$k $collapsed{$k}\n";
}

执行stackcollapse脚本, 确定是writeback触发的:

#stackcollapse-trace.pl q.trace | sort -k2 -n | tail -3
kworker/u131:20;kthread;worker_thread;process_one_work;wb_workfn;wb_do_writeback;wb_writeback;writeback_sb_inodes;__writeback_single_inode;do_writepages;ext4_writepages;mpage_prepare_extent_io_map;mpage_process_page_bufs;mpage_submit_page;ext4_bio_write_page;ext4_io_submit;submit_bio;generic_make_request;generic_make_request_checks; generic_make_request_checks 156
kworker/u131:20;kthread;worker_thread;process_one_work;wb_workfn;wb_do_writeback;wb_writeback;writeback_sb_inodes;__writeback_single_inode;do_writepages;ext4_writepages;mpage_prepare_extent_io_map;mpage_process_page_bufs;mpage_submit_page;ext4_bio_write_page;ext4_io_submit;submit_bio;generic_make_request;generic_make_request_checks; generic_make_request_checks 189
jbd2/sdd1-8;kthread;kjournald2;jbd2_journal_commit_transaction;submit_bh;submit_bh_wbc;submit_bio;generic_make_request;generic_make_request_checks;generic_make_request_checks 230

那么新问题来了, 我们需要抓住的是I/O的根源, 而不是下发I/O的刷脏任务.

方法2 - 通过LBA找文件

因为blktrace可以看到I/O的LBA, 逻辑上可以很容易找到该LBA对应的文件路径, 文件系统肯定保存了该信息. 先做个试验, 使用dd在一个相对空闲的盘上写入数据:

#trace -tuM 1000 't:block:block_bio_queue (args->dev == (8u << 20) + 0 && args->comm[0] == 0x64 && args->comm[1] == 0x64) "%d %d", args->sector, args->nr_sector'
#dd if=/dev/zero of=c2 bs=1k count=1 conv=fdatasync
#df -h .
Filesystem      Size  Used Avail Use% Mounted on
/dev/sda2       976M   77M  833M   9% /boot

看下trace的结果:

TIME              PID       TID     COMM        FUNC             -
1619753477.919236 130779    130779  dd          block_bio_queue  577544 8

继续看sda2的开始地址:

#cat /sys/block/sda/sda2/start
8192

可以找到blktrace日志中577544 sector在文件系统中对应的block num:

(gdb) p (577544 - 8192) / 8
$6 = 71169

在debugfs中看下它对应的文件:

#debugfs /dev/sda2
debugfs 1.43.5 (04-Aug-2017)
debugfs:  icheck 71169
Block   Inode number
71169   350
debugfs:  ncheck 350
Inode   Pathname
350     /over/upper/c2

可以看到, 确实可以从blktrace的输出日志中, 根据盘的LBA找到对应的文件路径.

但是这里还有个问题, 在hdd盘上, debugfs的查找会非常慢, 特别地我们可能需要查找很多LBA.

方法3 - 从系统调用开始

任何写入的数据都跟系统调用有一定的关系, 可以尝试去抓写操作相关的系统调用, 而且上面已经明确写I/O来源于buffer I/O, 暂时不考虑异步I/O的情况.

相关系统调用包括write, pwrite, pwritev, writev, pwritev2以及compat版本, 通过阅读源码, 都会经过以下2个函数之一:

vfs_write
do_iter_write

还需要拿到文件及其offset等, 比如多次overwrite同一个offset并不会导致多个I/O
因为系统中有多块盘, 最好能够过滤掉其他不相干的盘, 可以通过struct file找到对应的gendisk
系统中除了ext4文件系统, 还有overlayfs. 对于overlayfs, 它的struct file并没有指向我们想要监控的盘, 但我们可以通过底下的ext4来获得, 只需要在函数do_iter_write上监控

这样我们有如下trace命令:

#trace -tu -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' 'do_iter_write(struct file *file, struct iov_iter *iter, loff_t *pos) (file->f_inode->i_sb->s_bdev->bd_disk->major == 8 && file->f_inode->i_sb->s_bdev->bd_disk->first_minor == 48) "%d %d %d %s", iter->count, *pos, file->f_inode->i_ino, file->f_path.dentry->d_name.name' 'vfs_write(struct file *file, const char __user *buf, size_t count, loff_t *pos) (file->f_inode->i_sb->s_bdev->bd_disk->major == 8 && file->f_inode->i_sb->s_bdev->bd_disk->first_minor == 48) "%d %d %d %s", count, *pos, file->f_inode->i_ino, file->f_path.dentry->d_name.name'
TIME              PID       TID     COMM        FUNC            -
1619762722.929989 50316     59199   java        do_iter_write   8192 0 43911392 xxx
1619762722.932870 50316     59199   java        do_iter_write   8192 0 43911392 xxx

但是这里还有个问题, 那就是通过mmap的文件操作, 调用mmap之后, 所有的写操作是直接的内存操作, 并没有额外的系统调用, 这样也就抓不到对应的写操作.

方法4 - 谁脏了页

文件系统刷脏的本质是系统存在dirty page cache, 那么只要抓住是谁dirty page了, 也就找到I/O的根源. 这里选择监控函数__mark_inode_dirty:

#trace -tuM 10 -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' '__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 48) "%d" inode->i_ino'
TIME              PID       TID     COMM        FUNC            -
1619764701.738380 50316     59199   java        __mark_inode_dirty 43911392
1619764701.740205 50316     59199   java        __mark_inode_dirty 43911392

有了上面的PID/COMM就可以找到是谁写入了, 如果发现PID已经不存在而且COMM并没有具体的执行文件, 可以考虑在运行期间通过execsnoop等工具来捕获, 或者改进trace来输出更完整的COMM.

如果看下代码, 可以发现__mark_inode_dirty里面其实已经预埋了一个tracepoint:

writeback:writeback_mark_inode_dirty

验证下是不是有进程在使用mmap方式写文件:

#trace -tuM 1000 -K -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' '__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 48) "%d" inode->i_ino'
1620270873.692863 21210  21210  systemd-journal     __mark_inode_dirty 19923961
        __mark_inode_dirty+0x0 [kernel]
        __block_commit_write.isra.0+0xac [kernel]
        block_page_mkwrite+0x150 [kernel]
        ext4_page_mkwrite+0x410 [ext4]
        do_page_mkwrite+0x50 [kernel]
        wp_page_shared+0x78 [kernel]
        do_wp_page+0x360 [kernel]
        handle_pte_fault+0x254 [kernel] 
        __handle_mm_fault+0x1e0 [kernel]
        handle_mm_fault+0x108 [kernel]
        do_page_fault+0x18c [kernel]
        do_mem_abort+0x5c [kernel]
        el0_da+0x24 [kernel]

现在可以明确看到systemd-journal会通过mmap方式来写文件, 如果这样的栈频繁出现, 需要去看看这日志, 很可能系统那里出了问题导致大量的日志写入.

我们继续可能下__mark_inode_dirty的行为, 什么时候会被调用, 来确定跟踪它是合适的. 写个小的测试程序:

  fd = open("/boot/over/upper/mfile", O_RDWR);
  assert(fd >= 0); 
  addr = mmap(NULL, PAGE_SIZE * PAGE_NUM, PROT_READ | PROT_WRITE, MAP_SHARED, fd, 0); 
  assert(addr != MAP_FAILED);
  while (1) {
      for (int j = 0; j < 2; ++j) {
          for (int i = 0; i < 2; ++i) {
              addr[PAGE_SIZE * i] = 0;
          }   
      }   
      sleep(1);
  }

这个程序会每秒钟写2个page, 并且每个page都会连着写2遍.

#trace -tuM 1000 -K -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h'
'__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) "%d %x" inode->i_ino, flags'

我们可以看到2类栈, 一类是页表还没建立导致的page fault, 一类是写保护导致的page fault, 符合常理.

1620271687.566203 30382  30382  mmap        __mark_inode_dirty 351 801
        __mark_inode_dirty+0x1 [kernel]
        generic_update_time+0x6a [kernel]
        file_update_time+0xc6 [kernel]
        ext4_page_mkwrite+0x77 [ext4]
        do_page_mkwrite+0x2a [kernel]
        __handle_mm_fault+0x9e9 [kernel]
        handle_mm_fault+0xfc [kernel]
        __do_page_fault+0x244 [kernel]
        do_page_fault+0x32 [kernel]
        page_fault+0x1e [kernel]

1620271693.566688 30382  30382  mmap        __mark_inode_dirty 351 801
        __mark_inode_dirty+0x1 [kernel]
        generic_update_time+0x6a [kernel]
        file_update_time+0xc6 [kernel]
        ext4_page_mkwrite+0x77 [ext4]
        do_page_mkwrite+0x2a [kernel]
        do_wp_page+0x1ad [kernel]
        __handle_mm_fault+0x753 [kernel]
        handle_mm_fault+0xfc [kernel]
        __do_page_fault+0x244 [kernel]
        do_page_fault+0x32 [kernel]
        page_fault+0x1e [kernel]

在看刷脏时序之前, 先确定ext4 mount options, 逻辑上每5秒钟刷metadata的话, 因为ordered模式, 会将data也一起刷出去:

#cat /proc/fs/ext4/sda2/options | grep 'data\|commit'
commit=5
data=ordered

再来看刷脏时序, 因为mmap程序每秒会写, 只要刷脏成功了, 下次再写的时候就会调用__mark_inode_dirty:

每次刷脏间隔在30s多一点
801表示I_DIRTY_TIME | I_DIRTY_SYNC, 也就是fdatasync()时并不需要刷. 可以看到, commit=5并不会导致这类dirty inode 5s就会expire
mmap程序里每次写了2遍, 但可以看到__mark_inode_dirty只会执行一次, 这是我们预期的, 因为这样的写并不会导致额外的I/O

#trace -tuM 1000 -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' '__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) "%d %x" inode->i_ino, flags'
TIME              PID       TID     COMM        FUNC            -
1620283471.011334 117165    117165  mmap        __mark_inode_dirty 351 801
1620283471.011365 117165    117165  mmap        __mark_inode_dirty 351 801
1620283488.012401 117165    117165  mmap        __mark_inode_dirty 351 801
1620283488.012425 117165    117165  mmap        __mark_inode_dirty 351 4
1620283488.012434 117165    117165  mmap        __mark_inode_dirty 351 4 
1620283519.014224 117165    117165  mmap        __mark_inode_dirty 351 801
1620283519.014249 117165    117165  mmap        __mark_inode_dirty 351 4
1620283519.014258 117165    117165  mmap        __mark_inode_dirty 351 4
1620283550.015955 117165    117165  mmap        __mark_inode_dirty 351 801
1620283550.015983 117165    117165  mmap        __mark_inode_dirty 351 4
1620283550.015991 117165    117165  mmap        __mark_inode_dirty 351 4
1620283581.017752 117165    117165  mmap        __mark_inode_dirty 351 801
1620283581.017784 117165    117165  mmap        __mark_inode_dirty 351 4
1620283581.017795 117165    117165  mmap        __mark_inode_dirty 351 4

如有兴趣, 可以调整这2个配置再看看:

/proc/sys/vm/dirty_expire_centisecs
/proc/sys/vm/dirty_writeback_centisecs

方案5 - 脏页是谁的

脏页总是关联到文件的, 我们只要找出这种对应关系, 比如通过page->mapping, 另外刷脏的过程一般是以文件组织的, 为了减少trace的输出, 这里跟踪函数__writeback_signle_indoe, 最根本的问题是要通过inode找到文件名,

inode和dentry是一对多的关系, 通过hlist把dentry连起来, 为了定位问题只需拿到其中的一个dentry即可. 因为这里面有个转换, bcc-tools自带的工具不太适合, 这里手动写一个.

#! /usr/bin/python2

from bcc import BPF 
import argparse

parser = argparse.ArgumentParser()

parser.add_argument("-p", "--pid", help="trace this PID only")
parser.add_argument("-d", "--dev", help="trace device(major,first_minor,partno) only")
args = parser.parse_args()

bpf_text = """ 
#include <uapi/linux/ptrace.h>
#include <linux/fs.h>
#include <linux/genhd.h>

int getfn(struct pt_regs *ctx) {
    u32 pid = bpf_get_current_id_tgid();
    FILTER_PID

    struct inode *in = (struct inode *)PT_REGS_PARM1(ctx);
    FILTER_DEV

    struct hlist_node *fi = in->i_dentry.first;
    struct dentry *de = (void *)fi - offsetof(struct dentry, d_u.d_alias);
    bpf_trace_printk("inode:  %d, fn: %s\\n", in->i_ino, de->d_name.name);
    return 0;
}
"""

if args.pid:
    bpf_text = bpf_text.replace('FILTER_PID',
            'if (pid != %s) { return 0; }' % args.pid)
else:
    bpf_text = bpf_text.replace('FILTER_PID', '') 

if args.dev:
    (major, first_minor, partno) = args.dev.split(',')
    bpf_text = bpf_text.replace('FILTER_DEV',
            """if (in->i_sb->s_bdev->bd_disk->major != %s ||
                   in->i_sb->s_bdev->bd_disk->first_minor != %s ||
                   in->i_sb->s_bdev->bd_partno != %s) { return 0; }"""
                   % (major, first_minor, partno))
else:
    bpf_text = bpf_text.replace('FILTER_DEV', '') 

b = BPF(text=bpf_text, debug=0)
b.attach_kprobe(event="__writeback_single_inode", fn_name="getfn")
b.trace_print()

我们打开vim并执行写入操作, 或者执行上面的mmap命令, 通过该ebpf程序可以抓到对应的文件名.

#./getfn -d 8,0,2
           <...>-85086 [013] .... 1722004.787942: 0: inode:  355, fn: .text.swp
           <...>-85086 [014] .... 1722015.027959: 0: inode:  355, fn: .text.swp
           <...>-85086 [014] .... 1722015.027985: 0: inode:  354, fn: text
           <...>-108973 [060] .... 1722047.283986: 0: inode:  337, fn: upper
           <...>-85086 [060] .... 1722052.403941: 0: inode:  351, fn: mfile
           <...>-108973 [061] .... 1722058.035940: 0: inode:  351, fn: mfile

关于从inode获取dentry(文件名), 稍微发散点, 比如把上面getfn的kprobe event改成__mark_inode_dirty, 然后通过vim写入一个文件并保存:

#./getfn -d 8,0,2
           <...>-125990 [031] .... 1723728.302387: 0: inode:  356, fn: 4913
           <...>-125990 [031] .... 1723728.302476: 0: inode:  355, fn: .text.swp
           <...>-125990 [031] .... 1723728.303011: 0: inode:  356, fn: text
           <...>-125990 [031] .... 1723728.303020: 0: inode:  356, fn: text
           <...>-125990 [031] .... 1723728.303032: 0: inode:  356, fn: text
           <...>-125990 [031] .... 1723728.303338: 0: inode:  356, fn: text
           <...>-125990 [031] .... 1723728.303441: 0: inode:  354, fn:
           <...>-125990 [031] .... 1723732.307684: 0: inode:  355, fn: .text.swp
           <...>-125990 [031] .... 1723732.307703: 0: inode:  355, fn: .text.swp

可以看到有一行中fn里面是空的, 使用strace看下, 估计是对应unlink("text~")的情况:

rename("text", "text~")                 = 0
open("text", O_WRONLY|O_CREAT|O_TRUNC, 0644) = 3
write(3, "abc\n", 4)                    = 4
fsync(3)                                = 0
unlink("text~")                         = 0

跟踪一下unlink会调用的iput:

#trace -Ct -M 1000 -K -I 'linux/uio.h' -I 'linux/fs.h' -I 'linux/genhd.h' 'iput(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) "%d" inode->i_ino' '__mark_inode_dirty(struct inode *inode) (inode->i_sb->s_bdev->bd_disk->major == 8 && inode->i_sb->s_bdev->bd_disk->first_minor == 0 && inode->i_sb->s_bdev->bd_partno == 2) "%d" inode->i_ino'

配合getfn重点看inode 354:

8.699010 31  125990  125990  vim            __mark_inode_dirty 354
        __mark_inode_dirty+0x1 [kernel]
        ext4_free_blocks+0x911 [ext4]
        ext4_ext_remove_space+0xb2a [ext4]
        ext4_truncate+0x340 [ext4]
        ext4_evict_inode+0x28f [ext4]
        evict+0xbe [kernel]
        do_unlinkat+0x13f [kernel]
        do_syscall_64+0x55 [kernel]
        entry_SYSCALL_64_after_hwframe+0x44 [kernel]

8.698984 31  125990  125990  vim            iput            354
        iput+0x1 [kernel]
        d_delete+0xb7 [kernel]
        vfs_unlink+0x150 [kernel]
        do_unlinkat+0x286 [kernel]
        do_syscall_64+0x55 [kernel]
        entry_SYSCALL_64_after_hwframe+0x44 [kernel]

8.698990 31  125990  125990  vim            iput            354
        iput+0x1 [kernel]
        do_unlinkat+0x13f [kernel]
        do_syscall_64+0x55 [kernel]
        entry_SYSCALL_64_after_hwframe+0x44 [kernel]

这个输出其实有些奇怪的地方, 但可以确定在调用__mark_inode_dirty的时候, dentry已经删掉了, 所以__mark_inode_dirty的kprobe的地方已经读不到dentry的信息了. 这里也说明了另外一个问题, 也就是bcc其实会修改BPF(text)的代码, 因为那个脚本里并没有检查相应的指针, 也没有调用bpf_probe_read函数就直接读取相应的内容.

后记

从上面的分析过程可以看出, 动态跟踪让验证想法变得简单. 这里使用的trace命令行还是略显复杂和混乱, 通过现在的bpftrace等工具会更加简洁.