Blktrace

来自百问网嵌入式Linux wiki
Zhouyuebiao讨论 | 贡献2019年12月26日 (四) 15:01的版本

Blktrace

文章目的

本文提供了开始使用Linux工具所需的基本信息:blktrace [1 ](块跟踪器)。

简介

下表简要介绍了该工具及其可用性,具体取决于软件包:
  • 是:该工具已经存在(可以使用或激活),也可以在软件包中集成和激活。
  • 没有:该工具不存在且无法集成,或者存在但无法在软件包中激活。
工具
名称 类别 目的
blktrace 追踪工具 blktrace [1 ]生成对块设备(SD卡,USB,eMMC ...) 上的I/O流量的跟踪
STM32MPU嵌入式软件发行版
入门资料包 开发者资料包 发行版资料包
没有
适用于 Android 的STM32MPU嵌入式软件发行版
入门资料包 开发者资料包 发行版资料包
没有 没有


blktrace工具由三个主要组件组成:
  • 一个内核
  • 在用户空间上记录来自内核的 I/O 跟踪信息的实用程序
  • 实用程序来分析和查看跟踪信息。
blkparse [2 ]也与blktrace关联。它从blktrace实用程序获取原始输出,并将其转换为格式良好且易于阅读的格式。

在目标板上安装跟踪和调试工具

它包括将blktrace二进制文件放在rootfs中,并修改Linux内核配置。
为了使用blktrace,Linux内核配置必须使用Linux内核menuconfig工具激活CONFIG_BLK_DEV_ IO _TRACE:
	Symbol: BLK_DEV_IO_TRACE
	Location:
	  Kernel Hacking --->
	    [*] Tracers --->
	      [*] Support for tracing block I/O actions

使用STM32MPU嵌入式软件发行版

默认情况下,所有STM32MPU嵌入式软件包中都提供blktrace二进制文件:
	Board $> which blktrace
	/usr/bin/blktrace
通过openembedded-core软件包将其集成到weston镜像分发中: openembedded-core/meta/recipes-core/packagegroups/packagegroup-core-tools-profile.bb 。
	RRECOMMENDS_${PN} = "\
	   ${PERF} \
	   trace-cmd \
	   blktrace \
	   ${PROFILE_TOOLS_X} \
	   ${PROFILE_TOOLS_SYSTEMD} \
	   "

入门包

不适用,因为无法更新Linux内核配置。

开发人员软件包

要在Linux内核配置中启用CONFIG_BLK_DEV_IO_TRACE,请参考 Menuconfig 或如何配置内核。 本文提供了有关在Developer Package上下文中修改配置和重新编译Linux内核镜像的说明。

分发包

要在Linux内核配置中启用CONFIG_BLK_DEV_IO_TRACE,请参考 Menuconfig 或如何配置内核。 本文提供了有关在“分发程序包”上下文中修改配置和重新编译Linux内核镜像的说明。

使用适用于 Android 的STM32MPU嵌入式软件

该blktrace二进制是默认不可用的的全部Android STM32MPU嵌入式软件的软件包,所以必须加入。

入门包

不适用,因为无法更新Linux内核配置。

开发人员软件包

不适用,因为无法更新Linux内核配置。

分发包

要在Linux内核配置中启用CONFIG_BLK_DEV_IO_TRACE,请参阅如何为Android定制内核。 本文提供了有关在Android分发包中修改配置并重新编译Linux内核镜像的说明。
blktrace源代码模块在中可用external/blktrace。
编译(确保正确设置了构建环境):
	PC $> cd $ANDROID_BUILD_TOP
	PC $> mma blktrace
检查blktrace二进制文件在系统镜像中是否可用:
	PC $> ls out/target/product/<BoardId>/system/bin/blktrace
将二进制文件推送到远程目标文件系统:
	# Remount first the target file system with write access
	PC $> adb root; adb remount
	PC $> adb sync

使用入门

从blktrace开始,跟踪已安装的块设备上的I/O流量(以块设备为例进行说明,该设备 /dev/mmcblk0p6 安装为 /usr/local):
	Board $> mount | grep mmcblk
	/dev/mmcblk0p5 on / type ext4 (rw,relatime,data=ordered)
	/dev/mmcblk0p4 on /boot type ext4 (rw,relatime,data=ordered)
	/dev/mmcblk0p6 on /usr/local type ext4 (rw,relatime,data=ordered)
在后台启动blktrace工具:
	Board $> blktrace -d /dev/mmcblk0p6 &
读取 /usr/local 的内容(它生成对关联块设备的读取访问权限):
	Board $> ls -la /usr/local
将 blktrace 活动放在前台,然后按组合键 Ctrl + C 停止它:
	Board $> fg
	blktrace -d /dev/mmcblk0p6
	Board $> <Ctrl-C>
	^C=== mmcblk0p6 ===
	 CPU  0:                   98 events,        5 KiB data
	 CPU  1:                   79 events,        4 KiB data
	 Total:                   177 events (dropped 0),        9 KiB data
注意:以下信息与 Android 发行版相关,因为文件系统为只读,因此必须使用 ADB。
	PC $> adb root; adb remount
	PC $> adb shell
	Board $> ...
有关blktrace使用的详细指导,请参考手册页[1 ]或帮助信息:
	Board $> blktrace --help
	Usage: blktrace 

	-d <dev>             | --dev=<dev>
	[ -r <debugfs path>  | --relay=<debugfs path> ]
	[ -o <file>          | --output=<file>]
	[ -D <dir>           | --output-dir=<dir>
	[ -w           | --stopwatch=]
	[ -a <action field>  | --act-mask=<action field>]
	[ -A <action mask>   | --set-mask=<action mask>]
	[ -b <size>          | --buffer-size]
	[ -n <number>        | --num-sub-buffers=<number>]
	[ -l                 | --listen]
	[ -h <hostname>      | --host=<hostname>]
	[ -p <port number>   | --port=<port number>]
	[ -s                 | --no-sendfile]
	[ -I <devs file>     | --input-devs=<devs file>]
	[ -v <version>       | --version]
	[ -V <version>       | --version]
		-d Use specified device. May also be given last after options
		-r Path to mounted debugfs, defaults to /sys/kernel/debug
		-o File(s) to send output to
		-D Directory to prepend to output file names
		-w Stop after defined time, in seconds
	 	-a Only trace specified actions. See documentation
		-A Give trace mask as a single value. See documentation
		-b Sub buffer size in KiB (default 512)
		-n Number of sub buffers (default 4)
		-l Run in network listen mode (blktrace server)
		-h Run in network client mode, connecting to the given host
		-p Network port to use (default 8462)
		-s Make the network client NOT use sendfile() to transfer data
		-I Add devices found in <devs file>
		-v Print program version info
		-V Print program version info
要开始使用 blktrace,您还可以参考 Yocto Project Wiki 页面上的 blktrace [3],其中提供了更多详细信息以及示例。

深入学习

blkparse的用法

除了在控制台上为用户显示信息之外,blktrace还创建跟踪文件(每个CPU一个),可以使用blkparse查看该文件。这些文件存储在当前路径目录下。
Board $> blkparse mmcblk0p6
	Input file mmcblk0p6.blktrace.0 added
	Input file mmcblk0p6.blktrace.1 added
	179,6    0        1     0.000000000    99  P   N [jbd2/mmcblk0p5-]
	179,6    0        0     0.000337792     0  m   N cfq99SN insert_request
	179,6    0        0     0.000344292     0  m   N cfq99SN add_to_rr
	179,6    0        0     0.000366250     0  m   N cfq99SN insert_request
	179,6    0        0     0.000374792     0  m   N cfq99SN insert_request
	179,6    0        0     0.000382458     0  m   N cfq99SN insert_request
	179,6    0        0     0.000390167     0  m   N cfq99SN insert_request
	179,6    0        2     0.000396625    99  U   N [jbd2/mmcblk0p5-] 5
	179,6    0        0     0.000452542     0  m   N cfq workload slice:150000000
	179,6    0        0     0.000460750     0  m   N cfq99SN set_active wl_class:0 wl_type:1
	179,6    0        0     0.000469083     0  m   N cfq99SN dispatch_insert
	179,6    0        0     0.000478500     0  m   N cfq99SN dispatched a request
	179,6    0        0     0.000484583     0  m   N cfq99SN activate rq, drv=1
	179,6    0        0     0.000747292     0  m   N cfq99SN dispatch_insert
	179,6    0        0     0.000755042     0  m   N cfq99SN dispatched a request
	179,6    0        0     0.000759708     0  m   N cfq99SN activate rq, drv=2
	179,6    0        0     0.004197583     0  m   N cfq99SN complete rqnoidle 1
	179,6    0        0     0.004206958     0  m   N cfq99SN set_slice=120000000
	179,6    0        0     0.004231917     0  m   N cfq99SN dispatch_insert
	179,6    0        0     0.004239208     0  m   N cfq99SN dispatched a request
	179,6    0        0     0.004243958     0  m   N cfq99SN activate rq, drv=2
	179,6    0        0     0.006287958     0  m   N cfq99SN complete rqnoidle 1
	179,6    0        0     0.006305208     0  m   N cfq99SN dispatch_insert
	179,6    0        0     0.006310542     0  m   N cfq99SN dispatched a request
	179,6    0        0     0.006315417     0  m   N cfq99SN activate rq, drv=2
	179,6    0        0     0.008340833     0  m   N cfq99SN complete rqnoidle 1
	179,6    0        0     0.008359000     0  m   N cfq99SN dispatch_insert
	179,6    0        0     0.008365083     0  m   N cfq99SN dispatched a request
	179,6    0        0     0.008370000     0  m   N cfq99SN activate rq, drv=2
	179,6    0        0     0.011504375     0  m   N cfq99SN complete rqnoidle 1
	179,6    0        0     0.014671667     0  m   N cfq99SN insert_request
	179,6    0        0     0.014727458     0  m   N cfq99SN complete rqnoidle 1
	179,6    0        0     0.014731250     0  m   N cfq schedule dispatch
	179,6    0        0     0.014808000     0  m   N cfq99SN dispatch_insert
	179,6    0        0     0.014813875     0  m   N cfq99SN dispatched a request
	179,6    0        0     0.014819958     0  m   N cfq99SN activate rq, drv=1
	179,6    0        0     0.017068708     0  m   N cfq99SN complete rqnoidle 1
	179,6    0        0     0.017078375     0  m   N cfq schedule dispatch
	179,0    0        3     5.759777419   193  A  WS 1706892 + 2 <- (179,6) 32778
	179,6    0        4     5.759784878   193  Q  WS 1706892 + 2 [jbd2/mmcblk0p6-]
	179,6    0        5     5.759849336   193  G  WS 1706892 + 2 [jbd2/mmcblk0p6-]
	179,6    0        6     5.759854253   193  P   N [jbd2/mmcblk0p6-]
	179,6    1        1     5.759855044    99  P   N [jbd2/mmcblk0p5-]
	179,0    0        7     5.759887628   193  A  WS 1706894 + 2 <- (179,6) 32780
	179,6    0        8     5.759893919   193  Q  WS 1706894 + 2 [jbd2/mmcblk0p6-]
	179,6    0        9     5.759947753   193  G  WS 1706894 + 2 [jbd2/mmcblk0p6-]
	179,6    1        0     5.759975503     0  m   N cfq99SN insert_request
	179,6    1        0     5.759990336     0  m   N cfq99SN insert_request
	179,6    1        2     5.759999253    99  U   N [jbd2/mmcblk0p5-] 2
	179,6    0       10     5.760024669   193  I  WS 1706892 + 2 [jbd2/mmcblk0p6-]
	179,6    0        0     5.760035461     0  m   N cfq193SN insert_request
	179,6    0        0     5.760041711     0  m   N cfq193SN add_to_rr
	179,6    0        0     5.760053169     0  m   N cfq193SN preempt
	179,6    0        0     5.760059253     0  m   N cfq99SN slice expired t=1
	179,6    0        0     5.760066503     0  m   N cfq99SN resid=-5635859836
	179,6    0        0     5.760081503     0  m   N cfq99SN sl_used=120000000 disp=6 charge=120000000 iops=0 sect=12
	179,6    0       11     5.760087294   193  I  WS 1706894 + 2 [jbd2/mmcblk0p6-]
	179,6    0        0     5.760091586     0  m   N cfq193SN insert_request
	179,6    0       12     5.760096294   193  U   N [jbd2/mmcblk0p6-] 2
	179,6    1        0     5.760111211     0  m   N cfq workload slice:300000000
	179,6    1        0     5.760118086     0  m   N cfq193SN set_active wl_class:0 wl_type:1
	179,6    1        0     5.760125669     0  m   N cfq193SN dispatch_insert
	179,6    1        0     5.760133128     0  m   N cfq193SN dispatched a request
	179,6    1        0     5.760137711     0  m   N cfq193SN activate rq, drv=1
	179,6    1        3     5.760145253    80  D  WS 1706892 + 2 [mmcqd/0]
	179,6    1        0     5.760393003     0  m   N cfq193SN dispatch_insert
	179,6    1        0     5.760399961     0  m   N cfq193SN dispatched a request
	179,6    1        0     5.760404128     0  m   N cfq193SN activate rq, drv=2
	179,6    1        4     5.760408211    80  D  WS 1706894 + 2 [mmcqd/0]
	179,6    1        5     5.764367836    80  C  WS 1706892 + 2 [0]
	179,6    1        0     5.764403128     0  m   N cfq193SN complete rqnoidle 1
	179,6    1        0     5.764412461     0  m   N cfq193SN set_slice=120000000
	179,6    1        0     5.764439169     0  m   N cfq193SN slice expired t=0
	179,6    1        0     5.764450253     0  m   N cfq193SN sl_used=33750 disp=2 charge=33750 iops=0 sect=4
	179,6    1        0     5.764456836     0  m   N cfq193SN del_from_rr
	179,6    1        0     5.764464711     0  m   N cfq99SN set_active wl_class:0 wl_type:1
	179,6    1        0     5.764470211     0  m   N cfq99SN dispatch_insert
	179,6    1        0     5.764475669     0  m   N cfq99SN dispatched a request
	179,6    1        0     5.764479378     0  m   N cfq99SN activate rq, drv=2
	179,6    1        6     5.767516794    80  C  WS 1706894 + 2 [0]
	179,6    1        0     5.767546961     0  m   N cfq193SN complete rqnoidle 1
	179,6    1        0     5.767564836     0  m   N cfq99SN dispatch_insert
	179,6    1        0     5.767571086     0  m   N cfq99SN dispatched a request
	179,6    1        0     5.767575628     0  m   N cfq99SN activate rq, drv=2
	179,0    0       13     5.767654378   193  A FWFS 1706896 + 2 <- (179,6) 32782
	179,6    0       14     5.767662669   193  Q  WS 1706896 + 2 [jbd2/mmcblk0p6-]
	179,6    0       15     5.767726461   193  G  WS 1706896 + 2 [jbd2/mmcblk0p6-]
	179,6    0       16     5.767734169   193  I  WS 1706896 + 2 [jbd2/mmcblk0p6-]
	179,6    0        0     5.767744003     0  m   N cfq193SN insert_request
	179,6    0        0     5.767750253     0  m   N cfq193SN add_to_rr
	179,6    0        0     5.767760628     0  m   N cfq193SN preempt
	179,6    0        0     5.767764336     0  m   N cfq99SN slice expired t=1
	179,6    0        0     5.767770044     0  m   N cfq99SN resid=120000000
	179,6    0        0     5.767781378     0  m   N cfq99SN sl_used=10000000 disp=2 charge=10000000 iops=0 sect=4
	179,6    0        0     5.767784378     0  m   N cfq99SN del_from_rr
	179,6    1        0     5.772038836     0  m   N cfq99SN complete rqnoidle 1
	179,6    1        0     5.772064253     0  m   N cfq193SN set_active wl_class:0 wl_type:1
	179,6    1        0     5.772070878     0  m   N cfq193SN dispatch_insert
	179,6    1        0     5.772077044     0  m   N cfq193SN dispatched a request
	179,6    1        0     5.772081878     0  m   N cfq193SN activate rq, drv=2
	179,6    1        7     5.772085086    80  D  WS 1706896 + 2 [mmcqd/0]
	179,6    1        0     5.774473336     0  m   N cfq99SN insert_request
	179,6    1        0     5.774481419     0  m   N cfq99SN add_to_rr
	179,6    1        0     5.774490461     0  m   N cfq99SN preempt
	179,6    1        0     5.774496211     0  m   N cfq193SN slice expired t=1
	179,6    1        0     5.774502586     0  m   N cfq193SN resid=120000000
	179,6    1        0     5.774515044     0  m   N cfq193SN sl_used=10000000 disp=1 charge=10000000 iops=0 sect=2
	179,6    1        0     5.774519128     0  m   N cfq193SN del_from_rr
	179,6    1        0     5.774558711     0  m   N cfq99SN complete rqnoidle 1
	179,6    1        0     5.774577211     0  m   N cfq99SN set_active wl_class:0 wl_type:1
	179,6    1        0     5.774583919     0  m   N cfq99SN dispatch_insert
	179,6    1        0     5.774590253     0  m   N cfq99SN dispatched a request
	179,6    1        0     5.774595086     0  m   N cfq99SN activate rq, drv=2
	179,6    1        8     5.777926544    80  C  WS 1706896 + 2 [0]
	179,6    1        0     5.777956461     0  m   N cfq193SN complete rqnoidle 1
	179,6    1        0     5.782932794     0  m   N cfq99SN complete rqnoidle 1
	179,6    1        0     5.782943419     0  m   N cfq99SN set_slice=120000000
	179,6    1        0     5.782949919     0  m   N cfq schedule dispatch
	CPU0 (mmcblk0p6):
	 Reads Queued:           0,        0KiB	 Writes Queued:           3,        3KiB
	 Read Dispatches:        0,        0KiB	 Write Dispatches:        0,        0KiB
	 Reads Requeued:         0		 Writes Requeued:         0
	 Reads Completed:        0,        0KiB	 Writes Completed:        0,        0KiB
	 Read Merges:            0,        0KiB	 Write Merges:            0,        0KiB
	 Read depth:             0        	 Write depth:             2
	 IO unplugs:             2        	 Timer unplugs:           0
	CPU1 (mmcblk0p6):
	 Reads Queued:           0,        0KiB	 Writes Queued:           0,        0KiB
	 Read Dispatches:        0,        0KiB	 Write Dispatches:        3,        3KiB
	 Reads Requeued:         0		 Writes Requeued:         0
	 Reads Completed:        0,        0KiB	 Writes Completed:        3,        3KiB
	 Read Merges:            0,        0KiB	 Write Merges:            0,        0KiB
	 Read depth:             0        	 Write depth:             2
	 IO unplugs:             1        	 Timer unplugs:           0

	Total (mmcblk0p6):
	 Reads Queued:           0,        0KiB	 Writes Queued:           3,        3KiB
	 Read Dispatches:        0,        0KiB	 Write Dispatches:        3,        3KiB
	 Reads Requeued:         0		 Writes Requeued:         0
	 Reads Completed:        0,        0KiB	 Writes Completed:        3,        3KiB
	 Read Merges:            0,        0KiB	 Write Merges:            0,        0KiB
	 IO unplugs:             3        	 Timer unplugs:           0

	Throughput (R/W): 0KiB/s / 0KiB/s
	Events (mmcblk0p6): 118 entries
	Skips: 0 f
	orward (0 -   0.0%)
注意:以下信息与 Android 发行版相关 blkparse 源代码模块在 external/blktrace 中可用
编译(确保正确设置了构建环境):
	PC $> cd $ANDROID_BUILD_TOP
	PC $> mma blkparse
检查blkparse二进制文件在系统镜像中是否可用:
	PC $> ls out/target/product/<BoardId>/system/bin/blkparse
将二进制文件推送到远程目标文件系统:
	# Remount first the target file system with write access
	PC $> adb root; adb remount
	PC $> adb sync

ftrace用法

一旦Linux内核配置 CONFIG_BLK_DEV_ IO _TRACE 是激活的,块层(BLK)动作可以通过使用被追踪 ftrace:
在这种情况下,只能为 ftrace 配置 blk 跟踪器,如以下命令的结果所示:
	Board $> mount -t tracefs nodev /sys/kernel/tracing
	Board $> cat /sys/kernel/tracing/available_tracers
	blk nop
为了获得更多的 ftrace 跟踪器(例如"function”),必须通过分发程序包激活其他 Linux 内核配置选项,如 ftrace 文章中所述。

通过以 /usr/local 读取内容为例(挂载点为mcblk0p6):

	Board $> echo 1 > /sys/block/mmcblk0/mmcblk0p6/trace/enable
	Board $> echo blk > /sys/kernel/tracing/current_tracer
	Board $> ls -la /usr/local
	Board $> cat /sys/kernel/tracing/trace_pipe
	 jbd2/mmcblk0p5--97    [001] ...1   100.412943: 179,0    A  WS 415902 + 2 <- (179,5) 278652
	 jbd2/mmcblk0p6--196   [000] ...1   100.412943: 179,0    A  WS 1706892 + 2 <- (179,6) 32778
	 jbd2/mmcblk0p5--97    [001] ...1   100.412974: 179,0    Q  WS 415902 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.412987: 179,0    Q  WS 1706892 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.413012: 179,0    G  WS 415902 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.413012: 179,0    G  WS 1706892 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.413018: 179,0    P   N [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.413019: 179,0    P   N [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.413034: 179,0    A  WS 415904 + 2 <- (179,5) 278654
	 jbd2/mmcblk0p6--196   [000] ...1   100.413034: 179,0    A  WS 1706894 + 2 <- (179,6) 32780
	 jbd2/mmcblk0p5--97    [001] ...1   100.413040: 179,0    Q  WS 415904 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.413040: 179,0    Q  WS 1706894 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.413054: 179,0    G  WS 415904 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.413056: 179,0    G  WS 1706894 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...2   100.413071: 179,0    I  WS 1706892 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.413092: 179,0    m   N cfq196SN insert_request
	 jbd2/mmcblk0p6--196   [000] ...2   100.413104: 179,0    I  WS 1706894 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.413111: 179,0    m   N cfq196SN insert_request
	 jbd2/mmcblk0p6--196   [000] ...2   100.413118: 179,0    U   N [jbd2/mmcblk0p6-] 2
	 jbd2/mmcblk0p5--97    [001] ...2   100.413135: 179,0    I  WS 415902 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.413144: 179,0    m   N cfq97SN insert_request
	 jbd2/mmcblk0p5--97    [001] ...1   100.413151: 179,0    m   N cfq97SN add_to_rr
	 jbd2/mmcblk0p5--97    [001] ...1   100.413162: 179,0    m   N cfq97SN preempt
	 jbd2/mmcblk0p5--97    [001] ...1   100.413168: 179,0    m   N cfq196SN slice expired t=1
	 jbd2/mmcblk0p5--97    [001] ...1   100.413176: 179,0    m   N cfq196SN resid=-32494149849
	 jbd2/mmcblk0p5--97    [001] ...1   100.413191: 179,0    m   N cfq196SN sl_used=120000000 disp=1 charge=120000000 iops=0 sect=2
	 jbd2/mmcblk0p5--97    [001] ...2   100.413199: 179,0    I  WS 415904 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.413205: 179,0    m   N cfq97SN insert_request
	 jbd2/mmcblk0p5--97    [001] ...2   100.413211: 179,0    U   N [jbd2/mmcblk0p5-] 2
	         mmcqd/0-80    [000] ...1   100.413224: 179,0    m   N cfq workload slice:200000000
	         mmcqd/0-80    [000] ...1   100.413232: 179,0    m   N cfq97SN set_active wl_class:0 wl_type:1
	         mmcqd/0-80    [000] ...1   100.413241: 179,0    m   N cfq97SN dispatch_insert
	         mmcqd/0-80    [000] ...1   100.413250: 179,0    m   N cfq97SN dispatched a request
	         mmcqd/0-80    [000] ...1   100.413256: 179,0    m   N cfq97SN activate rq, drv=1
	         mmcqd/0-80    [000] ...2   100.413261: 179,0    D  WS 415902 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   100.413515: 179,0    m   N cfq97SN dispatch_insert
	         mmcqd/0-80    [000] ...1   100.413524: 179,0    m   N cfq97SN dispatched a request
	         mmcqd/0-80    [000] ...1   100.413530: 179,0    m   N cfq97SN activate rq, drv=2
	         mmcqd/0-80    [000] ...2   100.413534: 179,0    D  WS 415904 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   100.417441: 179,0    C  WS 415902 + 2 [0]
	         mmcqd/0-80    [000] ...1   100.417482: 179,0    m   N cfq97SN complete rqnoidle 1
	         mmcqd/0-80    [000] ...1   100.417494: 179,0    m   N cfq97SN set_slice=120000000
	         mmcqd/0-80    [000] ...1   100.417526: 179,0    m   N cfq97SN slice expired t=0
	         mmcqd/0-80    [000] ...1   100.417539: 179,0    m   N cfq97SN sl_used=40584 disp=2 charge=40584 iops=0 sect=4
	         mmcqd/0-80    [000] ...1   100.417545: 179,0    m   N cfq97SN del_from_rr
	         mmcqd/0-80    [000] ...1   100.417555: 179,0    m   N cfq196SN set_active wl_class:0 wl_type:1
	         mmcqd/0-80    [000] ...1   100.417561: 179,0    m   N cfq196SN dispatch_insert
	         mmcqd/0-80    [000] ...1   100.417569: 179,0    m   N cfq196SN dispatched a request
	         mmcqd/0-80    [000] ...1   100.417575: 179,0    m   N cfq196SN activate rq, drv=2
	         mmcqd/0-80    [000] ...2   100.417579: 179,0    D  WS 1706892 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   100.419353: 179,0    C  WS 415904 + 2 [0]
	         mmcqd/0-80    [000] ...1   100.419380: 179,0    m   N cfq97SN complete rqnoidle 1
	         mmcqd/0-80    [000] ...1   100.419393: 179,0    m   N cfq196SN dispatch_insert
	         mmcqd/0-80    [000] ...1   100.419400: 179,0    m   N cfq196SN dispatched a request
	         mmcqd/0-80    [000] ...1   100.419405: 179,0    m   N cfq196SN activate rq, drv=2
	         mmcqd/0-80    [000] ...2   100.419409: 179,0    D  WS 1706894 + 2 [mmcqd/0]
	 jbd2/mmcblk0p5--97    [001] ...1   100.419431: 179,0    A FWFS 415906 + 2 <- (179,5) 278656
	 jbd2/mmcblk0p5--97    [001] ...1   100.419440: 179,0    Q  WS 415906 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.419465: 179,0    G  WS 415906 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p5--97    [001] ...2   100.419475: 179,0    I  WS 415906 + 2 [jbd2/mmcblk0p5-]
	 jbd2/mmcblk0p5--97    [001] ...1   100.419484: 179,0    m   N cfq97SN insert_request
	 jbd2/mmcblk0p5--97    [001] ...1   100.419491: 179,0    m   N cfq97SN add_to_rr
	 jbd2/mmcblk0p5--97    [001] ...1   100.419502: 179,0    m   N cfq97SN preempt
	 jbd2/mmcblk0p5--97    [001] ...1   100.419507: 179,0    m   N cfq196SN slice expired t=1
	 jbd2/mmcblk0p5--97    [001] ...1   100.419514: 179,0    m   N cfq196SN resid=120000000
	 jbd2/mmcblk0p5--97    [001] ...1   100.419526: 179,0    m   N cfq196SN sl_used=10000000 disp=2 charge=10000000 iops=0 sect=4
	 jbd2/mmcblk0p5--97    [001] ...1   100.419530: 179,0    m   N cfq196SN del_from_rr
	         mmcqd/0-80    [000] ...1   100.424339: 179,0    C  WS 1706892 + 2 [0]
	         mmcqd/0-80    [000] ...1   100.424367: 179,0    m   N cfq196SN complete rqnoidle 1
	         mmcqd/0-80    [000] ...1   100.424388: 179,0    m   N cfq97SN set_active wl_class:0 wl_type:1
	         mmcqd/0-80    [000] ...1   100.424396: 179,0    m   N cfq97SN dispatch_insert
	         mmcqd/0-80    [000] ...1   100.424404: 179,0    m   N cfq97SN dispatched a request
	         mmcqd/0-80    [000] ...1   100.424409: 179,0    m   N cfq97SN activate rq, drv=2
	         mmcqd/0-80    [000] ...2   100.424413: 179,0    D  WS 415906 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   100.427349: 179,0    C  WS 1706894 + 2 [0]
	         mmcqd/0-80    [000] ...1   100.427382: 179,0    m   N cfq196SN complete rqnoidle 1
	 jbd2/mmcblk0p6--196   [000] ...1   100.427441: 179,0    A FWFS 1706896 + 2 <- (179,6) 32782
	 jbd2/mmcblk0p6--196   [000] ...1   100.427458: 179,0    Q  WS 1706896 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.427482: 179,0    G  WS 1706896 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...2   100.427492: 179,0    I  WS 1706896 + 2 [jbd2/mmcblk0p6-]
	 jbd2/mmcblk0p6--196   [000] ...1   100.427499: 179,0    m   N cfq196SN insert_request
	 jbd2/mmcblk0p6--196   [000] ...1   100.427505: 179,0    m   N cfq196SN add_to_rr
	 jbd2/mmcblk0p6--196   [000] ...1   100.427516: 179,0    m   N cfq196SN preempt
	 jbd2/mmcblk0p6--196   [000] ...1   100.427521: 179,0    m   N cfq97SN slice expired t=1
	 jbd2/mmcblk0p6--196   [000] ...1   100.427528: 179,0    m   N cfq97SN resid=120000000
	 jbd2/mmcblk0p6--196   [000] ...1   100.427545: 179,0    m   N cfq97SN sl_used=10000000 disp=1 charge=10000000 iops=0 sect=2
	 jbd2/mmcblk0p6--196   [000] ...1   100.427550: 179,0    m   N cfq97SN del_from_rr
	         mmcqd/0-80    [000] ...1   100.427598: 179,0    m   N cfq196SN set_active wl_class:0 wl_type:1
	         mmcqd/0-80    [000] ...1   100.427605: 179,0    m   N cfq196SN dispatch_insert
	         mmcqd/0-80    [000] ...1   100.427612: 179,0    m   N cfq196SN dispatched a request
	         mmcqd/0-80    [000] ...1   100.427618: 179,0    m   N cfq196SN activate rq, drv=2
	         mmcqd/0-80    [000] ...2   100.427622: 179,0    D  WS 1706896 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   100.431133: 179,0    C  WS 415906 + 2 [0]
	         mmcqd/0-80    [000] ...1   100.431164: 179,0    m   N cfq97SN complete rqnoidle 1
	         mmcqd/0-80    [000] ...1   100.434921: 179,0    C  WS 1706896 + 2 [0]
	         mmcqd/0-80    [000] ...1   100.434951: 179,0    m   N cfq196SN complete rqnoidle 1
	         mmcqd/0-80    [000] ...1   100.434962: 179,0    m   N cfq196SN set_slice=120000000
	         mmcqd/0-80    [000] ...1   100.434969: 179,0    m   N cfq schedule dispatch
	    kworker/u4:1-65    [001] ...1   101.612916: 179,0    A  WM 137922 + 2 <- (179,5) 672
	    kworker/u4:1-65    [001] ...1   101.612949: 179,0    Q  WM 137922 + 2 [kworker/u4:1]
	    kworker/u4:1-65    [001] ...1   101.613001: 179,0    G  WM 137922 + 2 [kworker/u4:1]
	    kworker/u4:1-65    [001] ...1   101.613012: 179,0    P   N [kworker/u4:1]
	    kworker/u4:1-65    [001] ...1   101.613071: 179,0    A  WM 1674662 + 2 <- (179,6) 548
	    kworker/u4:1-65    [001] ...1   101.613077: 179,0    Q  WM 1674662 + 2 [kworker/u4:1]
	    kworker/u4:1-65    [001] ...1   101.613093: 179,0    G  WM 1674662 + 2 [kworker/u4:1]
	    kworker/u4:1-65    [001] ...2   101.613119: 179,0    I  WM 137922 + 2 [kworker/u4:1]
	    kworker/u4:1-65    [001] ...1   101.613131: 179,0    m   N cfq200A  insert_request
	    kworker/u4:1-65    [001] ...1   101.613139: 179,0    m   N cfq200A  add_to_rr
	    kworker/u4:1-65    [001] ...1   101.613152: 179,0    m   N cfq200A  preempt
	    kworker/u4:1-65    [001] ...1   101.613157: 179,0    m   N cfq196SN slice expired t=1
	    kworker/u4:1-65    [001] ...1   101.613164: 179,0    m   N cfq196SN resid=-1058203000
	    kworker/u4:1-65    [001] ...1   101.613179: 179,0    m   N cfq196SN sl_used=120000000 disp=1 charge=120000000 iops=0 sect=2
	    kworker/u4:1-65    [001] ...1   101.613185: 179,0    m   N cfq196SN del_from_rr
	    kworker/u4:1-65    [001] ...2   101.613198: 179,0    I  WM 1674662 + 2 [kworker/u4:1]
	    kworker/u4:1-65    [001] ...1   101.613206: 179,0    m   N cfq200A  insert_request
	    kworker/u4:1-65    [001] ...2   101.613214: 179,0    U   N [kworker/u4:1] 2
	         mmcqd/0-80    [000] ...1   101.613238: 179,0    m   N cfq workload slice:40000000
	         mmcqd/0-80    [000] ...1   101.613248: 179,0    m   N cfq200A  set_active wl_class:0 wl_type:0
	         mmcqd/0-80    [000] ...1   101.613258: 179,0    m   N cfq200A  dispatch_insert
	         mmcqd/0-80    [000] ...1   101.613267: 179,0    m   N cfq200A  dispatched a request
	         mmcqd/0-80    [000] ...1   101.613274: 179,0    m   N cfq200A  activate rq, drv=1
	         mmcqd/0-80    [000] ...2   101.613280: 179,0    D  WM 1674662 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   101.613511: 179,0    m   N cfq200A  dispatch_insert
	         mmcqd/0-80    [000] ...1   101.613520: 179,0    m   N cfq200A  dispatched a request
	         mmcqd/0-80    [000] ...1   101.613525: 179,0    m   N cfq200A  activate rq, drv=2
	         mmcqd/0-80    [000] ...2   101.613529: 179,0    D  WM 137922 + 2 [mmcqd/0]
	         mmcqd/0-80    [000] ...1   101.618520: 179,0    C  WM 1674662 + 2 [0]
	         mmcqd/0-80    [000] ...1   101.618576: 179,0    m   N cfq200A  complete rqnoidle 0
	         mmcqd/0-80    [000] ...1   101.618586: 179,0    m   N cfq200A  set_slice=40000000
	         mmcqd/0-80    [000] ...1   101.623185: 179,0    C  WM 137922 + 2 [0]
	         mmcqd/0-80    [000] ...1   101.623215: 179,0    m   N cfq200A  complete rqnoidle 0
	         mmcqd/0-80    [000] ...1   101.623221: 179,0    m   N cfq schedule dispatch
注意:以下信息与 Android 发行版相关,因为文件系统为只读,因此必须使用ADB。
	PC $> adb root; adb remount
	PC $> adb shell
	Board $> ...

参考

1. https://linux.die.net/man/8/blktrace
2. https://linux.die.net/man/1/blkparse
3. https://wiki.yoctoproject.org/wiki/Tracing_and_Profiling#blktrace


  • 有用的外部链接
文件链接 文件类型 描述
blktrace 工具源代码,包括用户空间工具 资料来源 blktrace来源git
blktrace 演示 介绍 Alan D. Brunelle的演讲