记录 ZFS VOP 时间的脚本

如果您正在运行某个应用程序,并且您很想知道 zfs 将时间花在了哪些地方。这里有一些脚本可以帮您计算出每个 VOP 用掉了多少时间。

这个脚本 (zfs_get_vop_times.d) 可以显示每个 VOP 被调用的次数、VOP 的平均用时以及每个 VOP 花掉的总时间。这适用于系统上的全部 ZFS 文件系统。它生成如下输出:

# ./zvop_times.d 
dtrace: script './zvop_times.d' matched 66 probes
\^C
CPU     ID                    FUNCTION:NAME
 17      2                             :END 
ZFS COUNT


  zfs_fsync                                                        61
  zfs_write                                                       494
  zfs_read                                                        520

ZFS AVG TIME

  zfs_read                                                    2737251
  zfs_write                                                   6992704
  zfs_fsync                                                  73401109


ZFS SUM TIME

  zfs_read                                                 1423370640
  zfs_write                                                3454396080
  zfs_fsync                                                4477467680

这个脚本 (zvop_times_fsid.d) 与上一个的操作相同,但是只针对一个文件系统——也就是您通过 FSID ints 指定的系统。

最后这个脚本 (zvop_times_fsid_large.d) 的操作同上(按每个 FSID 追踪),不同的是它可以在 zfs 的 VOP 调用时间超过 X 时(这里的 X 是传入脚本的值)显示堆栈和量化信息。这使我们可以轻松查看是否存在一些运行非常缓慢的调用。 它生成如下输出(此处略过与上例相同的输出):

# ./zvop_times_fsid_large.d 0x7929404d 0xb3d52b08 50000000
dtrace: script './zvop_times_fsid_large.d' matched 123 probes
CPU     ID                    FUNCTION:NAME
 14  35984                  zfs_read:return 
              genunix`fop_read+0x20
              genunix`read+0x29c
              unix`syscall_trap32+0x1e8

 16  35994               zfs_putpage:return 
              genunix`fop_putpage+0x1c
              nfssrv`rfs3_commit+0x110
              nfssrv`common_dispatch+0x588
              rpcmod`svc_getreq+0x1ec
              rpcmod`svc_run+0x1e8
              nfs`nfssys+0x1b8
              unix`syscall_trap32+0x1e8

 18  35994               zfs_putpage:return 
              genunix`fop_putpage+0x1c
              nfssrv`rfs3_commit+0x110
              nfssrv`common_dispatch+0x588
              rpcmod`svc_getreq+0x1ec
              rpcmod`svc_run+0x1e8
              nfs`nfssys+0x1b8
              unix`syscall_trap32+0x1e8

 12  35972                 zfs_fsync:return 
              genunix`fop_fsync+0x14
              nfssrv`rfs4_createfile+0x500
              nfssrv`rfs4_do_opennull+0x44
              nfssrv`rfs4_op_open+0x380
              nfssrv`rfs4_compound+0x208
              nfssrv`rfs4_dispatch+0x11c
              nfssrv`common_dispatch+0x154
              rpcmod`svc_getreq+0x1ec
              rpcmod`svc_run+0x1e8
              nfs`nfssys+0x1b8
              unix`syscall_trap32+0x1e8

\^C


  zfs_fsync                                         
           value  ------------- Distribution ------------- count    
        33554432 |                                         0        
        67108864 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
       134217728 |                                         0        

  zfs_putpage                                       
           value  ------------- Distribution ------------- count    
        33554432 |                                         0        
        67108864 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2        
       134217728 |                                         0        

  zfs_read                                          
           value  ------------- Distribution ------------- count    
        67108864 |                                         0        
       134217728 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
       268435456 |                                         0     

您可以随意使用这些脚本,亦可以随意增减内容。

Comments:

Post a Comment:
Comments are closed for this entry.
About

erickustarz

Search

Categories
Archives
« April 2014
SunMonTueWedThuFriSat
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
Today