searchusermenu
  • 发布文章
  • 消息中心
点赞
收藏
评论
分享
原创

性能分析工具之strace

2023-06-29 05:44:38
88
0

工具介绍

用户在liunx下使用对象存储的SDK做对象上传时,可能会遇到上传慢的场景,但是慢在哪儿,是读磁盘慢?还是网络发送慢?还是业务侧的调度慢?不能很快的定位到原因,在这种情况下,我们可以使用strace帮助我们分析。

strace有两种运行形态

  • 跟踪二进制:可以跟踪程序的加载、执行过程。
    strace ./a.out
  • 跟踪进程:可以跟踪进程或者线程的运行过程
    strace -p pid

常用参数介绍

strace -tt -T -v -f -e trace=all -o ./strace.log -s 1024 -p 2117

-tt 显示微秒级别的时间
-T 显示每次系统调用所花费的时间
-v 对于某些相关调用,把完整的环境变量,文件stat结构等打出来。
-f 跟踪目标进程,以及目标进程创建的所有子进程
-e 指定要跟踪的系统调用,all表示跟踪所有的系统调用
-o 将跟踪采集结果输出到指定文件
-s 当系统调用的某个参数是字符串时,最多输出指定长度的内容,默认是32个字节
-p 指定要跟踪的进程pid

输出日志介绍

3186  18:37:03.361424 open("./10MB", O_RDONLY) = 3 <0.000028>
3186  18:37:03.361510 fstat(3, {st_dev=makedev(253, 0), st_ino=52490120, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=19536, st_size=10000000, st_atime=1687948549 /* 2023-06-28T18:35:49.400895519+0800
 */, st_atime_nsec=400895519, st_mtime=1686042779 /* 2023-06-06T17:12:59.782763698+0800 */, st_mtime_nsec=782763698, st_ctime=1686042779 /* 2023-06-06T17:12:59.782763698+0800 */, st_ctime_nsec=782763698}) = 0 <0.000016>
3186  18:37:03.361622 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbc2b4df000 <0.000022>
3186  18:37:03.361695 fstat(3, {st_dev=makedev(253, 0), st_ino=52490120, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=19536, st_size=10000000, st_atime=1687948549 /* 2023-06-28T18:35:49.400895519+0800

日志的每一行代表的是一个系统调用,包含该系统调用的调用时间、系统调用名称、参数、该调用的耗时。

示例分析

某个业务运行着一个并发上传服务,该服务会定期的将本地磁盘上的大文件,上传到对象存储,对于相同大小的文件,有的上传慢,有的上传快。
我们通过strace工具,抓取了上传服务其中一个线程5分钟的调用过程,并分析了两个相同文件大小,不同耗时(一个8s,一个3s)的上传过程,通过对所有的系统调用进行分析,得到如下信息:

耗时8s上传的系统调用统计

系统调用名称 调用次数 总耗时(s)
read 12210 4.2
sendto 12001 0.31
poll 12001 1.17
others 112 0.51

耗时3s上传的系统调用统计

系统调用名称 调用次数 总耗时(s)
read 12210 0.21
sendto 12001 0.26
poll 12001 0.87
others 112 0.53

通过以上分析,我们看到网络上的耗时差不多,但是读文件的耗时差距较大,我们对两个文件的所有read调用再做一次分析,得到如下信息:总耗时8s上传过程中的12210次read调用,单次超过100ms的,一共59次,总耗时为4.09s;耗时3s上传过程中的read调用,没有一次超时1ms。

通过以上分析,我们能看出,用户在网络发送上的时延是接近的,但是在读磁盘文件的耗时上差距巨大,再配合磁盘的监控数据,我们可以判断上传服务和其他服务在磁盘的使用上产生了竞争,需要进行针对性优化。

其他场景

在linux操作系统下,用户态的程序要想访问计算机的硬件设备,就需要通过系统调用,所以和硬件设备有关的问题,我们都可以借助strace工具进行分析,为此strace工具借助-e选项也为系统调用做了分类,方便用户去根据某类具体的问题进行分析。

-e trace=file             和文件访问相关的调用
-e trace=desc          和文件描述符相关
-e trace=network    和网络通信相关的调用
-e trace=process     和进程管理相关的调用
-e trace=ipc            和进程通讯相关
-e trace=signal       和信号发送和处理相关

 

 

0条评论
0 / 1000
z****m
2文章数
0粉丝数
z****m
2 文章 | 0 粉丝
z****m
2文章数
0粉丝数
z****m
2 文章 | 0 粉丝
原创

性能分析工具之strace

2023-06-29 05:44:38
88
0

工具介绍

用户在liunx下使用对象存储的SDK做对象上传时,可能会遇到上传慢的场景,但是慢在哪儿,是读磁盘慢?还是网络发送慢?还是业务侧的调度慢?不能很快的定位到原因,在这种情况下,我们可以使用strace帮助我们分析。

strace有两种运行形态

  • 跟踪二进制:可以跟踪程序的加载、执行过程。
    strace ./a.out
  • 跟踪进程:可以跟踪进程或者线程的运行过程
    strace -p pid

常用参数介绍

strace -tt -T -v -f -e trace=all -o ./strace.log -s 1024 -p 2117

-tt 显示微秒级别的时间
-T 显示每次系统调用所花费的时间
-v 对于某些相关调用,把完整的环境变量,文件stat结构等打出来。
-f 跟踪目标进程,以及目标进程创建的所有子进程
-e 指定要跟踪的系统调用,all表示跟踪所有的系统调用
-o 将跟踪采集结果输出到指定文件
-s 当系统调用的某个参数是字符串时,最多输出指定长度的内容,默认是32个字节
-p 指定要跟踪的进程pid

输出日志介绍

3186  18:37:03.361424 open("./10MB", O_RDONLY) = 3 <0.000028>
3186  18:37:03.361510 fstat(3, {st_dev=makedev(253, 0), st_ino=52490120, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=19536, st_size=10000000, st_atime=1687948549 /* 2023-06-28T18:35:49.400895519+0800
 */, st_atime_nsec=400895519, st_mtime=1686042779 /* 2023-06-06T17:12:59.782763698+0800 */, st_mtime_nsec=782763698, st_ctime=1686042779 /* 2023-06-06T17:12:59.782763698+0800 */, st_ctime_nsec=782763698}) = 0 <0.000016>
3186  18:37:03.361622 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fbc2b4df000 <0.000022>
3186  18:37:03.361695 fstat(3, {st_dev=makedev(253, 0), st_ino=52490120, st_mode=S_IFREG|0644, st_nlink=1, st_uid=0, st_gid=0, st_blksize=4096, st_blocks=19536, st_size=10000000, st_atime=1687948549 /* 2023-06-28T18:35:49.400895519+0800

日志的每一行代表的是一个系统调用,包含该系统调用的调用时间、系统调用名称、参数、该调用的耗时。

示例分析

某个业务运行着一个并发上传服务,该服务会定期的将本地磁盘上的大文件,上传到对象存储,对于相同大小的文件,有的上传慢,有的上传快。
我们通过strace工具,抓取了上传服务其中一个线程5分钟的调用过程,并分析了两个相同文件大小,不同耗时(一个8s,一个3s)的上传过程,通过对所有的系统调用进行分析,得到如下信息:

耗时8s上传的系统调用统计

系统调用名称 调用次数 总耗时(s)
read 12210 4.2
sendto 12001 0.31
poll 12001 1.17
others 112 0.51

耗时3s上传的系统调用统计

系统调用名称 调用次数 总耗时(s)
read 12210 0.21
sendto 12001 0.26
poll 12001 0.87
others 112 0.53

通过以上分析,我们看到网络上的耗时差不多,但是读文件的耗时差距较大,我们对两个文件的所有read调用再做一次分析,得到如下信息:总耗时8s上传过程中的12210次read调用,单次超过100ms的,一共59次,总耗时为4.09s;耗时3s上传过程中的read调用,没有一次超时1ms。

通过以上分析,我们能看出,用户在网络发送上的时延是接近的,但是在读磁盘文件的耗时上差距巨大,再配合磁盘的监控数据,我们可以判断上传服务和其他服务在磁盘的使用上产生了竞争,需要进行针对性优化。

其他场景

在linux操作系统下,用户态的程序要想访问计算机的硬件设备,就需要通过系统调用,所以和硬件设备有关的问题,我们都可以借助strace工具进行分析,为此strace工具借助-e选项也为系统调用做了分类,方便用户去根据某类具体的问题进行分析。

-e trace=file             和文件访问相关的调用
-e trace=desc          和文件描述符相关
-e trace=network    和网络通信相关的调用
-e trace=process     和进程管理相关的调用
-e trace=ipc            和进程通讯相关
-e trace=signal       和信号发送和处理相关

 

 

文章来自个人专栏
文章 | 订阅
0条评论
0 / 1000
请输入你的评论
0
0