使用blktrace统计磁盘块I/O访问频率

    如果我们想知道，在一段时间内，那一个磁盘块被读写的频率最高，怎么办？
    我问这个问题是看到taobao kernel wiki上面有这么一段话，看了我十分心痒：

1. 通过对blktrace的输出结果进行分析，我们可以对特定时间段内发生的读、写操作的磁盘块进行I/O频次统计。结合通过将磁盘块I/O频度统计和page cache命中率统计相结合，就可以比较有效的判断服务器节点的cache使用效率。通过这套工具，CDN系统修正了一个固态硬盘上cache管理的缺陷，显著提高了I/O性能（详细信息）

    淘宝大神给了一个shell脚本解决这个问题，但是我守着代码，不知道怎么用。就研究了下blktrace和大神的代码。
    常常听淘宝的霸爷，提起blktrace。 iostat，iotop这些的工具也是统计磁盘IO的，也非常有用，但是和blktrace比，信息过于summarized，而blktrace跟踪了发生在块设备层的很多事件，简直就是整个块设备层事件的回放。
    blktrace能够trace那些事件呢？

    上面这个胶片来自HP的介绍blktrace的胶片，介绍的非常好，是参考文献中一篇。
    这些事件都会被blktrace 捕捉到。由于这些事件要和kernel代码中block device的work flow一一对应，目前我的功力尚不足，所以我就不一一介绍这些事件了。
    blktrace输出的东西，不是文本，是一些特殊的格式，要想可读，需要blkparse解析blktrace的输出。
    我们看下blktrace和blkparse合作方式  

1. blktrace -d /dev/sda -o - |blkparse -i - -o blkparse.out

    这是一个比较典型的使用：
   blktrace -d表示monitor哪个设备，-o -表示讲输出吐出到标准输出。
   blkparse -i -  表示从标准输入获取信息，-o 表示讲解析的内容记录在blkparse.out
    我们看下输出长的什么样子：
    
    这个胶片非常好的介绍了各个字段的含义。主次设备号，CPU ID，sequence num，time stamp PID ，起始扇区号，进程名字比较好理解，比较难理解的是$6,$7
    $6中的GPQMDC，一堆字母，代表什么含义？$7的WR 又代表什么含义呢？
    一个一个来，对于$6,表示的是event，官方手册给了事件对应表：
    
    那么$7是干嘛的呢  ？   
    基本上是R和W，也会出现B和S. R表示是read操作，W表示write操作，B是barrier operation，S是synchronous operation。
    看到这个blkparse的输出，我们发现这些更像是raw data，需要我们挖掘背后的信息。btt这个工具就是一个分析输出得到更高层信息的tool，他不是我们本文的重点，我们不提他。
    回到开篇的问题，如何知道which磁盘扇区被读写的次数最多？有了blkparse的输出，我们完全可以做到这个统计：淘宝的Coly大神的shell脚本已经帮我们作了这个事情。   

1. root@manu-hacks:~/code/shell/blkstrace_calculator# cat cal.sh
   
2. #!/bin/bash
   
3. 
   
4. TMP_DIR=".blktrace_cal"
   
5. 
   
6. # extend the blktrace log to "blockid R/W"
   
7. extend()
   
8. {
   
9.     awk -v max=$2 -v mod=$3 '{
   
10.         if ( NR%max==mod && $6 == "D" && (index($7, "R") || index($7, "W")) ) {
    
11.             for(i=0; i<$10; i++) {
    
12.                 print $8+i" "substr($7, 1, 1);
    
13.             }
    
14.         }
    
15.     }' $1 | sort -k1 -nr > $TMP_DIR/.tmp.$1.$3
    
16.     touch $TMP_DIR/$3.ok
    
17. }
    
18. 
    
19. usage()
    
20. {
    
21.     echo "Usage: $1 input_log [parallel_num]"
    
22.     exit
    
23. }
    
24. 
    
25. rm -rf $TMP_DIR
    
26. mkdir $TMP_DIR
    
27. 
    
28. if [ "$1" == "" ]; then
    
29.     usage $0
    
30. fi
    
31. 
    
32. # does input_log exists?
    
33. if [ ! -f $1 ]; then
    
34.     echo "($1) not exists"
    
35.     exit
    
36. fi
    
37. 
    
38. parallel=$2
    
39. 
    
40. if [ "$2" == "" ]; then
    
41.     parallel=4
    
42. fi
    
43. 
    
44. echo "[input: $1]"
    
45. 
    
46. max=`expr $parallel - 1`
    
47. files=""
    
48. filename=`basename $1`
    
49. 
    
50. echo "[run $parallel process]"
    
51. 
    
52. for i in `seq 0 $max`
    
53. do
    
54.     extend $filename $parallel $i &
    
55.     files=$files" $TMP_DIR/.tmp.$filename.$i"
    
56. done
    
57. echo "processing...."
    
58. 
    
59. nr=0
    
60. # awk will finish if all *.ok created.
    
61. while [ $nr -ne "$parallel" ]
    
62. do
    
63.     nr=`find $TMP_DIR -maxdepth 1 -name "*.ok"|wc -l`
    
64.     echo -n "."
    
65.     sleep 1
    
66. done
    
67. 
    
68. echo ""
    
69. echo "merge sort"
    
70. sort -m -k1 -nr $files | uniq -c | sort -k1 -nr > tmp
    
71. total=`awk '{sum+=$1} END{print sum}' tmp`
    
72. awk -v sum=$total '{
    
73.     print $0"\t"$1*1000/sum;
    
74. }' tmp > result
    
75. 
    
76. echo "sort finish."
    
77. 
    
78. rm -rf $TMP_DIR

    这段代码是Coly大神的代码，我无意抄袭前辈，只是晚辈拿来欣赏学习，光荣属于淘宝的Coly前辈。
    先说parallel，这个是为了充分利用CPU资源，让多个CPU一起来执行extend。NR%max==mod 将一个文件按照行分开，由多个进程分别处理之。不多讲。
    extend的含义也比较简单：

1.   8,0 0 909 19.618798623 6475 Q W 20397704 + 8 [evince-thumbnai]
   
2.   8,0 0 910 19.618803866 6475 G W 20397704 + 8 [evince-thumbnai]

    20397704是起始扇区，+ 8表示的连续8个扇区都在本次事件之内，也就是说20397704/20397705/20397706.. 都是本次事件涉及的扇区。
    OK，我们看下cal.sh的使用及输出：

1. ../blkstrace_calculator/cal.sh blkparse.out 4

    当前目录下生成了tmp和result文件：

1. root@manu-hacks:~/code/shell/blktrace# head result
   
2.      39 454375583 W    0.228744
   
3.      39 454375582 W    0.228744
   
4.      39 454375581 W    0.228744
   
5.      39 454375580 W    0.228744
   
6.      39 454375579 W    0.228744
   
7.      39 454375578 W    0.228744
   
8.      39 454375577 W    0.228744
   
9.      39 454375576 W    0.228744
   
10.      27 264753359 W    0.158361
    
11.      27 264753358 W    0.158361

    我们可以看到，扇区号为454375583被访问的次数为39次，占总访问的千分之0.228744。
  那这个扇区属于拿个文件呢？debugfs就可以来帮忙了.我们以访问27次的264753359扇区为例。扇区是512字节，我的文件系统ext4的块大小是4K，所以根据扇区可以定位的块号，debugfs根据块号，可以定位到inode，再根据inode，就可定位到filename。

1. root@manu-hacks:~/code/shell/blktrace# echo 264753359/8 |bc
   
2. 33094169
   
3.   
   
4. root@manu-hacks:~/code/shell/blktrace# debugfs -R "icheck 33094169" /dev/sda1
   
5. debugfs 1.42 (29-Nov-2011)
   
6. Block    Inode number
   
7. 33094169    14290766
   
8. 
   
9. root@manu-hacks:~/code/shell/blktrace# debugfs -R "ncheck 14290766" /dev/sda1
   
10. debugfs 1.42 (29-Nov-2011)
    
11. Inode    Pathname
    
12. 14290766    /home/manu/.pki/nssdb/key4.db

    我们发现，这个文件被读写的次数最多。谁干的？ lsof来帮忙？  

1. root@manu-hacks:~/code/shell/blktrace# lsof /home/manu/.pki/nssdb/key4.db
   lsof: WARNING: can't stat() fuse.gvfs-fuse-daemon file system /home/manu/.gvfs
   Output information may be incomplete.
   COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
   chromium- 5717 manu 57u REG 8,1 11264 14290766 /home/manu/.pki/nssdb/key4.db
   chromium- 5902 manu 7u REG 8,1 11264 14290766 /home/manu/.pki/nssdb/key4.db
   chromium- 5906 manu 7u REG 8,1 11264 14290766 /home/manu/.pki/nssdb/key4.db
   

    我们用Coly大神的脚本和blktrace/blkparse就解决了磁盘块IO访问频率的统计。如果有个别的block被频繁的读取，表示cache的替换效率不高。
    
参考文献
1 通过blktrace, debugfs分析磁盘IO
2  Documents/kernel team successful stories
3 Block I/O Layer Tracing: blktrace   Alan D. Brunelle