blktrace 工具集使用 及其实现原理

最近使用blktrace 工具集来分析I/O 在磁盘上的一些瓶颈问题，特此做一个简单的记录。

工具用起来很简单，但越向底层看，越复杂。。。。。。越发现自己的无知

工具使用

blktrace 拥有如下几个工具集合:

安装的话也很简单：

sudo yum install blktrace iowatcher -y

• 其中blktrace 工具 主要根据用户输入的磁盘设备，收集这个设备上每个IO调度情况，收集的过程是交给当前服务器的每一个core来做的，最后每一个core将各自处理的请求 收集到的结果保存在一个binary文件中。

  sudo blktrace -d /dev/nvme0n1 -o nvme-trace -w 60 收集设备/dev/nvme0n1上的io 情况 60秒，将结果保存到nvme-trace文件中

  

• blkparse 工具 主要是将之前抓取的多个core的binary文件合并为一个文件

  blkparse -i nvme-trace -d nvme-trace.bin -o nvme-trace.txt ，将nvme-trace开头的所有文件合并为一个nvme-trace.bin，这个过程中的输出放在nvme-trace.txt中。

• btt工具，blkparse 解析的数据文件 虽然已经有了一些汇总信息，但还是不易读，比如我们想知道磁盘I/O在每一个阶段耗时分布，从blkparse的解析中很难看出来的。

  blkparse 的汇总信息如下：
  

  通过btt工具来进行计算:
  btt -i nvme-trace.bin -o btt.txt
  

  其中btt.txt.avg就是我们想要的请求信息分布情况
  

  也可以通过btt -A -i nvme-trace.bin | less看到每一个I/O线程各个阶段的IO延时情况

  
  计算blktrace工具抓到的分位数指标(p50,p99,p995,p9999 等)脚本如下，输入的参数是通过btt -i nvme-trace.bin -l d2c_data 生成的请求全集文件：

  #!/bin/bash
  input=$1num=`cat $input |wc -l`
  if [ $num -eq 0 ];thenecho "input is null "exit -1
  fip50=$(echo "$num * 0.5" | bc)
  p50=${p50%.*} # to int
  p99=$(echo "$num * 0.99" | bc)
  p99=${p99%.*}
  p995=$(echo "$num * 0.995" | bc)
  p995=${p995%.*}
  p9999=$(echo "$num * 0.9999" | bc)
  p9999=${p9999%.*}echo "lines -- p50: $p50 p99 : $p99 p995: $p995 p9999: $p9999 total: $num "cat "$input" | awk -F. '{print $3}' | sort > buff.txtecho "p50 "
  sed -n " $p50 p" buff.txt
  echo "p99"
  sed -n " $p99 p" buff.txt
  echo "p995 "
  sed -n "$p995 p" buff.txt
  echo "p9999 "
  sed -n "$p9999 p" buff.txt
  

• 我们有抓取的I/O的历史数据，那同样可以用iowather来将历史的io变化情况用图形展示出来，包括磁盘带宽、延时等
  iowatcher -t nvme-trace.bin -o nvme-trace.svg 解析blkparse合并的文件，输出到nvme-trace.svg中
  

• 如果你仅仅想看看磁盘的I/O块大小，都是一些什么I/O，不想这么麻烦，可以直接btrace /dev/nvme0n1这样，会将打印输出到标准输出中
  

• 如果你想在块基础上看看磁盘延时/块大小的分布，那blkiomon就比较适用了
  blktrace /dev/nvme0n1 -a issue -a complete -w 3600 -o - | blkiomon -I 1 -h test ,这里只抓取complete的io，请求的结果分析（延时/块大小）就以直方图的形态非常方便得被展示出来。

当然，以上blktrace,blkparse,btrace 都可以仅仅抓单独类似的io请求，包括只抓取write, read, sync, issue等（可以通过man blktrace查看masks支持的action。），这样我们就能够更近一步得区分每一种类型的请求，方便我们从底层排查问题。

关于传统的btrace, blkparse等解析data文件之后的输出 含义内容，直接看网友们贴的这张图就可以了：

主要的几个Event信息含义如下：

• Q: 即将生成I/O
• G: 生成I/O 请求
• I: I/O 请求进入scheduler 队列
• D: I/O 请求进入driver
• C: I/O 执行完毕

原理分析

洋洋洒洒，工具如何使用，介绍了一大串，能够节省一丢丢大家的时间，man手册已经很通用了，使用上就没什么需要探索的了。但是能够真正让大家看到收获的其实是工具背后的原理，为什么blktrace能够实时得追踪到每一个io请求，它追踪的请求个数/大小是否准确，是否有请求会被遗漏？这一些请求在操作系统I/O架构中每一个阶段处于什么样的位置，内核在做什么事情？这一些问题如果我们每一个都仔细去探索，背后则是整个操作系统内核I/O栈的庞大调度逻辑，都会让我们对内核I/O有更为深刻的理解，有了底层架构的知识才能帮助我们更好得设计上层应用。 毕竟，底层架构的每一行代码，每一个算法都是无数开发者精心雕琢的表现。

不多说，直接进入正题。

内核I/O栈

blktrace 抓取的IO 内核栈的层级如下：

blktrace统计的主要是I/O进入通用块层 --> I/O 调度层 --> 块设备驱动层 完成落盘返回的整个过程，上图并未体现通用块层，其实是在I/O Scheduler之上的一层I/O封装。

• 通用块层 ： 接受direct_io/ page_cache flush下来的请求，做一层请求封装，一般是4k大小。
• I/O 调度层: 将请求加入调度队列，通过一系列调度算法来调度封装好的I/O请求 到对应的device-driver(sata/nvme/iscsi等)
• 块设备驱动层：这里就是每一个物理块设备封装好的对接自己物理磁盘空间的内核驱动，请求到这里会按照对应设备的逻辑进入到底层物理磁盘中

知道了大体的I/O栈，也就清楚了大概一个I/O请求从page-cache或者direct_io 到磁盘所经历的大体层，这个时候也就对blktrace输出信息的Event的几个字段有一定的理解了（Q，G，I，D，C），都是对应的请求进入到了I/O栈中的哪一层。

Blktrace 追踪过程大体可以用如下这张官方的图来描述：

blktrace 启动追踪的时候会让每一个cpu（每一个请求都是由对应的cpu来调度处理的）绑定一个relay-channel，通过ioctl下发的触发信息会让内核将每一个请求的信息通过trace函数添加到relay-channel对应的trace文件，当blktrace停止追踪时会告知内核将relay-flush 每一个relay-channel，将trace文件信息拷贝到用户态。

那blktrace 是如何从外部获取到这一些请求的信息的呢？接着往下看，后面的描述会整体从内核代码角度告诉你这个外部工具如何在不影响内核I/O性能的情况下拿到这一些I/O 请求的详细信息的。

blktrace 代码做的事情

源码GitHub: https://github.com/efarrer/blktrace

如果不使用blktrace 网络模式的情况下（是的，blktrace 支持抓取远端服务器的磁盘请求信息，blktrace -l 启动server, blktrace -h ip指定抓取的ip），会走如下调用栈逻辑:

main -- blktrace.crun_tracerssetup_buts -- 初始化一些配置start_tracers -- 为每一个cpu 创建一个tracer线程，获取io信息start_buts -- 开启记录，将请求详细信息记录到初始化的文件中stop_tracers -- 终止追踪

其中的主体操作都是通过ioctl来向内核发送触发信息：

ioctl(dpp->fd, BLKTRACESETUP, &buts) -- 发送 初始化配置
ioctl(dpp->fd, BLKTRACESTART)  -- 发送 启动配置
ioctl(dpp->fd, BLKTRACESTOP) -- 发送终止配置
ioctl(fd, BLKTRACETEARDOWN) -- 发送down 配置，由内核回写结果到trace-data文件

这个时候，每一个触发配置 的ioctl系统调用会进入内核来做一些对应的事情。

这一些逻辑也可以通过strace blktrace -d /dev/nvme0n1命令来追踪：

open("/dev/nvme0n1", O_RDONLY|O_NONBLOCK) = 3
statfs("/sys/kernel/debug", {f_type=DEBUGFS_MAGIC, f_bsize=4096, f_blocks=0, f_bfree=0, f_bavail=0, f_files=0, f_ffree=0, f_fsid={0, 0}, f_namelen=255, f_frsize=4096, f_flags=ST_VALID|ST_RELATIME}) = 0
rt_sigaction(SIGINT, {0x403410, [INT], SA_RESTORER|SA_RESTART, 0x7fa1a4fd0270}, {SIG_DFL, [], 0}, 8) = 0 # strace main函数注册的信号
rt_sigaction(SIGHUP, {0x403410, [HUP], SA_RESTORER|SA_RESTART, 0x7fa1a4fd0270}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGTERM, {0x403410, [TERM], SA_RESTORER|SA_RESTART, 0x7fa1a4fd0270}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGALRM, {0x403410, [ALRM], SA_RESTORER|SA_RESTART, 0x7fa1a4fd0270}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7fa1a4fd0270}, {SIG_DFL, [], 0}, 8) = 0
ioctl(3, BLKTRACESETUP, {act_mask=65535, buf_size=524288, buf_nr=4, start_lba=0, end_lba=0, pid=0, name="nvme0n1"}) = 0
ioctl(3, BLKTRACESTART)
...

内核调用 ioctl 做的事情

这里不讨论ioctl整个系统调用的逻辑，细节还是很多的。主要看一下blktrace 调用ioctl发送相应的state后内核做的事情。

内核代码版本：3.10.1

ioctl 系统调用针对以上state的处理如下：

int blkdev_ioctl(struct block_device *bdev, fmode_t mode, unsigned cmd,unsigned long arg)
{...case BLKTRACESTART:case BLKTRACESTOP:case BLKTRACESETUP:case BLKTRACETEARDOWN:ret = blk_trace_ioctl(bdev, cmd, (char __user *) arg);break;...
}

通过blk_trace_ioctl的逻辑如下：

int blk_trace_ioctl(struct block_device *bdev, unsigned cmd, char __user *arg)
{struct request_queue *q;int ret, start = 0;char b[BDEVNAME_SIZE];q = bdev_get_queue(bdev);if (!q)return -ENXIO;mutex_lock(&bdev->bd_mutex);switch (cmd) {case BLKTRACESETUP:bdevname(bdev, b);// 初始化配置ret = blk_trace_setup(q, b, bdev->bd_dev, bdev, arg);break;
#if defined(CONFIG_COMPAT) && defined(CONFIG_X86_64)case BLKTRACESETUP32:bdevname(bdev, b);ret = compat_blk_trace_setup(q, b, bdev->bd_dev, bdev, arg);break;
#endifcase BLKTRACESTART:start = 1; // 设置启动追踪的标记case BLKTRACESTOP:// 结束追踪ret = blk_trace_startstop(q, start);break;case BLKTRACETEARDOWN:// 将trace文件拷贝到用户目录ret = blk_trace_remove(q);break;default:ret = -ENOTTY;break;}mutex_unlock(&bdev->bd_mutex);return ret;
}

BLKTRACESETUP

启动的时候会进入到这个函数blk_trace_setup，主要创建以下几个文件：

1. 创建/sys/kernel/debug/block 目录
2. 在上面的目录下创建一个设备目录nvme0n1
3. 在设备目录下创建dropped文件，如果需要relay-channel flush的话会将这个文件置为true
4. 为每一个cpu绑定一个trace 文件，接受relay-channel 的请求输出，一般为traceid
5. 注册/sys/kernel/debug/tracing/events/block下的events，也就是我们前面看到的请求输出Event(Q,I,D,C等)，其实就是这一些events

代码如下:

int do_blk_trace_setup(struct request_queue *q, char *name, dev_t dev,struct block_device *bdev,struct blk_user_trace_setup *buts)
{struct blk_trace *old_bt, *bt = NULL;struct dentry *dir = NULL;int ret, i;...mutex_lock(&blk_tree_mutex);if (!blk_tree_root) {blk_tree_root = debugfs_create_dir("block", NULL); // 创建/sys/kernel/debug/block目录if (!blk_tree_root) {mutex_unlock(&blk_tree_mutex);goto err;}}mutex_unlock(&blk_tree_mutex);dir = debugfs_create_dir(buts->name, blk_tree_root); // 创建/sys/kernel/debug/block/nvme0n1目录if (!dir)goto err;bt->dir = dir;bt->dev = dev;atomic_set(&bt->dropped, 0);ret = -EIO;bt->dropped_file = debugfs_create_file("dropped", 0444, dir, bt, // 在创建好的目录下创建dropped文件&blk_dropped_fops);if (!bt->dropped_file)goto err;bt->msg_file = debugfs_create_file("msg", 0222, dir, bt, &blk_msg_fops); // 创建msg文件if (!bt->msg_file)goto err;bt->rchan = relay_open("trace", dir, buts->buf_size, // 为每个cpu创建一个trace文件buts->buf_nr, &blk_relay_callbacks, bt);if (!bt->rchan)goto err;bt->act_mask = buts->act_mask;if (!bt->act_mask)bt->act_mask = (u16) -1;blk_trace_setup_lba(bt, bdev);...if (atomic_inc_return(&blk_probes_ref) == 1)blk_register_tracepoints(); // 注册并追踪/sys/kernel/debug/tracing/events/block 的events,内核开始追踪请求return 0;
err:blk_trace_free(bt);return ret;
}

BLKTRACESTOP

blk_trace_startstop执行blktrace的开关操作，停止过后将per cpu的relay chanel强制flush出来。

int blk_trace_startstop(struct request_queue *q, int start)
{int ret;struct blk_trace *bt = q->blk_trace;
...ret = -EINVAL;if (start) { // 这个标记是BLKTRACESTART的时候设置的，如果没有抓取结束if (bt->trace_state == Blktrace_setup ||bt->trace_state == Blktrace_stopped) {blktrace_seq++;smp_mb();bt->trace_state = Blktrace_running;trace_note_time(bt); // 用户可能会传入一个抓取的时间ret = 0;}} else {if (bt->trace_state == Blktrace_running) {bt->trace_state = Blktrace_stopped;relay_flush(bt->rchan); // relay flush 刷数据到trace文件ret = 0;}}return ret;
}

BLKTRACETEARDOWN

释放blktrace设置创建的buffer、删除相关文件节点，并去注册trace events。

static void blk_trace_cleanup(struct blk_trace *bt)
{blk_trace_free(bt);if (atomic_dec_and_test(&blk_probes_ref))blk_unregister_tracepoints();
}int blk_trace_remove(struct request_queue *q)
{struct blk_trace *bt;bt = xchg(&q->blk_trace, NULL);if (!bt)return -EINVAL;if (bt->trace_state != Blktrace_running)blk_trace_cleanup(bt); // 注销之前注册的/sys/kernel/debug/tracing/events/block 的eventsreturn 0;
}

到此整个blktrace 通过ioctl 调度起来自己的任务，并能够取到自己想要的数据。

总结成如下这一张图来概述整个blktrace的过程：

当然取数据的过程是通过向内核注册一些block的events。

接下来我们核心看一下这一些events是如何让内核将数据给出来的？

内核 调用blk_register_tracepoints 之后做的事情

在这个函数内部会逐个注册每一个/sys/kernel/debug/tracing/events/block下的事件，这里会通过一个宏定义 进入

#define __DECLARE_TRACE(name, proto, args, cond, data_proto, data_args) \extern struct tracepoint __tracepoint_##name;			\    // 这里是声明一些外部的trace point变量static inline void trace_##name(proto)				\        // 定义一些trace point用到的公共函数{								\if (static_key_false(&__tracepoint_##name.key))		\   // 如果打开了trace point__DO_TRACE(&__tracepoint_##name,		\								// 便利trace point中的桩函数（外部声明的桩函数）TP_PROTO(data_proto),			\TP_ARGS(data_args),			\TP_CONDITION(cond),,);			\}								\__DECLARE_TRACE_RCU(name, PARAMS(proto), PARAMS(args),		\ PARAMS(cond), PARAMS(data_proto), PARAMS(data_args))	\static inline int						\register_trace_##name(void (*probe)(data_proto), void *data)	\ // 注册trace point{								\return tracepoint_probe_register(#name, (void *)probe,	\data);			\}								\static inline int						\unregister_trace_##name(void (*probe)(data_proto), void *data)	\{								\return tracepoint_probe_unregister(#name, (void *)probe, \      // 注销trace pointdata);		\}								\static inline void						\check_trace_callback_type_##name(void (*cb)(data_proto))	\{								\}

而在block.h中已经预定义好了一些列trace io需要的桩函数，类似如下：

TRACE_EVENT(block_bio_complete,TP_PROTO(struct request_queue *q, struct bio *bio, int error),TP_ARGS(q, bio, error),TP_STRUCT__entry(__field( dev_t,		dev		)__field( sector_t,	sector		)__field( unsigned,	nr_sector	)__field( int,		error		)__array( char,		rwbs,	RWBS_LEN)),TP_fast_assign(__entry->dev		= bio->bi_bdev->bd_dev;__entry->sector		= bio->bi_sector;__entry->nr_sector	= bio_sectors(bio);__entry->error		= error;blk_fill_rwbs(__entry->rwbs, bio->bi_rw, bio->bi_size);),TP_printk("%d,%d %s %llu + %u [%d]",MAJOR(__entry->dev), MINOR(__entry->dev), __entry->rwbs,(unsigned long long)__entry->sector,__entry->nr_sector, __entry->error)
);

而在我们前面说的blk_register_tracepoints函数中会调用：

ret = register_trace_block_bio_complete(blk_add_trace_bio_complete, NULL); 对block_bio_complete进行注册，注册之后相当于上面宏定义中打开了针对当前name的trace point，然后block_bio_complete这个trace event函数会被放在对应的I/O连路上（已经在主要的I/O连路上了，只是如果我们注册了event,那就会在主体链路打印它的追踪信息），而如果不需要开启的话也就是不注册事件函数则基本不消耗性能。

// 电梯调度算法的入口
void __elv_add_request(struct request_queue *q, struct request *rq, int where)
{trace_block_rq_insert(q, rq);blk_pm_add_request(q, rq);...
}

说到打印，这也就是以上tracepoint 的核心目的，内核模块太多，我们想要将内部调试信息打出来到文件肯定不现实，为了方便调试，这里的trace point就是将内核中各个模块的printk信息 打印到ring_buffer中，这里面的数据只通过debugfs才能够获取到。

blktrace 则会通过blk追踪器将每个cpu 的ring_buffer数据绑定一个trace-data文件，后续完成追踪之后将这一些文件从debugfs拷出来。

到此我们大体知道了内核如何将I/O请求的信息暴漏出来给用户读取，其实就是维护了系列trace-event，用户注册之后就开启追踪，内核会在trace-event函数中打印每个请求的情况到一个ring-buffer中，用户通过debug-fs（这里其实是blktrace 自己去debug-fs）将打印的数据取出来。

当然，内核的trace_event整体的宏设计还是比较复杂的，宏的易读性虽然不是特别好，但人家能够在编译时展开，避免了程序运行时的函数入出栈，对程序执行的效率还是有很大的好处的。

参考

https://blog.csdn.net/geshifei/article/details/94360470