有时需要在blktrace输出中插入一些打印. 由于blktrace是基于ftrace的, 故考虑转用ftrace来实现这个目的.

1. ftrace的过滤

# cat /sys/kernel/debug/tracing/events/block/block_rq_complete/format 
name: block_rq_complete
ID: 828
format:
    field:unsigned short common_type;   offset:0;   size:2; signed:0;
    field:unsigned char common_flags;   offset:2;   size:1; signed:0;
    field:unsigned char common_preempt_count;   offset:3;   size:1; signed:0;
    field:int common_pid;   offset:4;   size:4; signed:1;

    field:dev_t dev;    offset:8;   size:4; signed:0;
    field:sector_t sector;  offset:16;  size:8; signed:0;
    field:unsigned int nr_sector;   offset:24;  size:4; signed:0;
    field:int errors;   offset:28;  size:4; signed:1;
    field:char rwbs[8]; offset:32;  size:8; signed:1;
    field:__data_loc char[] cmd;    offset:40;  size:4; signed:1;

print fmt: "%d,%d %s (%s) %llu + %u [%d]", ((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ((REC->dev) & ((1U << 20) - 1))), REC->rwbs, __get_str(cmd), (unsigned long long)REC->sector, REC->nr_sector, REC->errors

设置过滤条件:

echo 'dev == 264241152' > /sys/kernel/debug/tracing/events/block/filter

设置过滤条件后:

# cat /sys/kernel/debug/tracing/events/block/block_rq_complete/filter 
dev == 264241152

# cat /sys/kernel/debug/tracing/events/block/filter 
### global filter ###
# Use this to set filters for multiple events.
# Only events with the given fields will be affected.
# If no events are modified, an error message will be displayed here

好像没有生效似的, 但已生效:

# cat /sys/kernel/debug/tracing/events/block/block_bio_bounce/filter 
dev == 264241152

由于block_unplug等格式没有dev, 故不会过滤:

# cat /sys/kernel/debug/tracing/events/block/block_unplug/filter 
none

可以使用 或:

echo 'dev == 264241152 || dev == 265289729 || dev ==265289732' > /sys/kernel/debug/tracing/events/block/filter
echo 1 > /sys/kernel/debug/tracing/events/block/enable

效果:

# cat /sys/kernel/debug/tracing/trace_pipe
   systemd-udevd-25619 [000] .... 84980.888417: block_bio_queue: 252,0 R 2056064 + 8 [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.888429: block_bio_queue: 253,4 R 2056064 + 8 [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.888439: block_plug: [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.888441: block_unplug: [systemd-udevd] 1
            sshd-21711 [000] d.H. 84980.888658: block_bio_complete: 253,4 R 2056064 + 8 [0]
            sshd-21711 [000] d.H. 84980.888661: block_bio_complete: 253,4 R 2056064 + 8 [0]
   systemd-udevd-25619 [000] .... 84980.888742: block_bio_queue: 252,0 R 2056064 + 8 [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.888746: block_bio_queue: 253,4 R 2056064 + 8 [systemd-udevd]
            sshd-21711 [000] d.H. 84980.888930: block_bio_complete: 253,4 R 2056064 + 8 [0]
            sshd-21711 [000] d.H. 84980.888932: block_bio_complete: 253,4 R 2056064 + 8 [0]
             fio-25618 [000] .... 84980.988455: block_bio_queue: 252,0 WS 0 + 8 [fio]
        biowr_00-21649 [000] .... 84980.988511: block_bio_queue: 253,1 W 230796 + 9 [biowr_00]
        biowr_00-21649 [000] .... 84980.988526: block_plug: [biowr_00]
        biowr_00-21649 [000] .... 84980.988527: block_unplug: [biowr_00] 1
          <idle>-0     [000] d.h. 84980.998134: block_bio_complete: 253,1 W 230796 + 9 [0]
          <idle>-0     [000] dNh. 84980.998145: block_bio_complete: 252,0 WS 0 + 8 [-2128359984]
        lsync_00-21650 [000] .... 84980.998158: block_bio_queue: 253,4 WS 0 + 8 [lsync_00]
        lsync_00-21650 [000] .... 84980.998164: block_plug: [lsync_00]
        lsync_00-21650 [000] .... 84980.998164: block_unplug: [lsync_00] 1
            sshd-21711 [000] d.H. 84980.998469: block_bio_complete: 253,4 WS 0 + 8 [0]
   systemd-udevd-25619 [000] .... 84980.999310: block_bio_queue: 252,0 R 2056064 + 8 [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.999323: block_bio_queue: 253,4 R 2056064 + 8 [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.999329: block_plug: [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84980.999330: block_unplug: [systemd-udevd] 1
          <idle>-0     [000] d.h. 84980.999668: block_bio_complete: 253,4 R 2056064 + 8 [0]
          <idle>-0     [000] d.h. 84980.999675: block_bio_complete: 253,4 R 2056064 + 8 [0]
   systemd-udevd-25619 [000] .... 84981.000032: block_bio_queue: 252,0 R 2056064 + 8 [systemd-udevd]
   systemd-udevd-25619 [000] .N.. 84981.000045: block_bio_queue: 253,4 R 2056064 + 8 [systemd-udevd]
            sshd-21711 [000] d.H. 84981.000366: block_bio_complete: 253,4 R 2056064 + 8 [0]
            sshd-21711 [000] d.H. 84981.000370: block_bio_complete: 253,4 R 2056064 + 8 [0]

2. 效果

不含有trace printk时, ftrace的输出:

<idle>-0     [000] dNh. 84980.998145: block_bio_complete: 252,0 WS 0 + 8 [-2128359984]

添加 trace printk后, 比如, my_read_endio()有代码:

if(wrapper->err)
    trace_printk("%s error:%d\n", __func__, wrapper->err);
trace_block_bio_complete(bdev_get_queue(wrapper->bio->bi_bdev), wrapper->bio, wrapper->err);

ftrace的输出效果:

sshd-2911  [000] d.H.   246.153491: my_read_endio: my_read_endio error:1935632128
sshd-2911  [000] d.H.   246.153491: block_bio_complete: 252,0 R 2056064 + 8 [1935632128]

本文地址: https://awakening-fong.github.io/posts/debug/blktrace_insert_print

转载请注明出处: https://awakening-fong.github.io