1595 lines
70 KiB
Diff
1595 lines
70 KiB
Diff
From 509f622afa19c0c62834952908db065a237c7e48 Mon Sep 17 00:00:00 2001
|
||
From: LHesperus <2639350497@qq.com>
|
||
Date: Sun, 19 Nov 2023 20:31:31 +0800
|
||
Subject: [PATCH] Modify method of mark invalid data and add summary
|
||
|
||
---
|
||
extra-tools/da-tool/README.md | 166 +++++++++---
|
||
extra-tools/da-tool/analysis/config.cpp | 11 +-
|
||
extra-tools/da-tool/analysis/config.h | 4 +-
|
||
.../da-tool/analysis/function_stack.cpp | 157 ++++++++----
|
||
extra-tools/da-tool/analysis/function_stack.h | 15 +-
|
||
.../da-tool/analysis/sched_analysis.cpp | 100 ++++----
|
||
extra-tools/da-tool/analysis/sched_analysis.h | 7 +-
|
||
extra-tools/da-tool/analysis/time_pair.cpp | 240 ++++++++++--------
|
||
extra-tools/da-tool/analysis/time_pair.h | 32 ++-
|
||
.../da-tool/analysis/trace_resolve.cpp | 5 +-
|
||
extra-tools/da-tool/analysis/trace_resolve.h | 7 -
|
||
extra-tools/da-tool/conf/da-tool.conf | 6 +-
|
||
extra-tools/da-tool/main.cpp | 7 +-
|
||
extra-tools/da-tool/script/da-tool.sh | 2 +-
|
||
extra-tools/da-tool/test/case/case1/case1.cpp | 64 +++++
|
||
.../da-tool/test/case/case2/case2_udp_cli.c | 37 +++
|
||
.../test/case/case2/case2_udp_ser_noblk.c | 53 ++++
|
||
17 files changed, 631 insertions(+), 282 deletions(-)
|
||
create mode 100644 extra-tools/da-tool/test/case/case1/case1.cpp
|
||
create mode 100644 extra-tools/da-tool/test/case/case2/case2_udp_cli.c
|
||
create mode 100644 extra-tools/da-tool/test/case/case2/case2_udp_ser_noblk.c
|
||
|
||
diff --git a/extra-tools/da-tool/README.md b/extra-tools/da-tool/README.md
|
||
index b9a603b..209b43b 100644
|
||
--- a/extra-tools/da-tool/README.md
|
||
+++ b/extra-tools/da-tool/README.md
|
||
@@ -13,9 +13,9 @@
|
||
+ 线程的调度特征
|
||
|
||
## 主要功能
|
||
-+ 分析出内核态函数/用户态函数(C/C++)/sched_switch的时延
|
||
-+ 统计各调用栈时延平均值
|
||
+
|
||
+ 推导调用关系(乱序)
|
||
++ 统计各函数调用栈时延信息
|
||
+ 线程调度特征
|
||
+ 记录系统信息
|
||
|
||
@@ -23,20 +23,21 @@
|
||
+ 不支持递归函数分析
|
||
|
||
## 文件夹说明
|
||
-
|
||
+**工程文件夹**
|
||
+ script : shell脚本
|
||
- + da-tool.sh 利用`uprobe/kprobe` 采集程序trace,同时可生成analysis需要的配置文件
|
||
+ + da-tool.sh 利用`uprobe/kprobe` 采集程序 `trace`,同时可生成analysis需要的配置文件
|
||
+ config 配置文件夹
|
||
+ da-tool.conf 放置`/etc` 目录下
|
||
+ analysis `C++`程序文件
|
||
+ config(.cpp/ch ): 解析外部参数 和 `function_config`
|
||
+ common.h : 通用参数
|
||
- + trace_resolve(.cpp/.h) : 解析trace
|
||
+ + trace_resolve(.cpp/.h) : 解析`trace`
|
||
+ time_pair(.cpp/.h)::获取各函数的起止时间等信息
|
||
+ function_strack(.cpp/.h): 获取各pid 函数调用栈及其时延信息
|
||
+ sched_analysis(.cpp/.h): 计算线程调度信息
|
||
+ main.cpp
|
||
+ CMakeLists.txt
|
||
++ test : 测试程序
|
||
|
||
**本地文件夹**
|
||
|
||
@@ -50,51 +51,131 @@
|
||
+ output : 时延结果信息
|
||
|
||
## 使用方法
|
||
+### 命令格式
|
||
+时延分析工具通过`da-tool.sh`命令采集和分析函数时延,使用格式为
|
||
|
||
-#### 1 配置需要采集的函数
|
||
-配置文件:da-tool.conf
|
||
-+ k 开头为 kernel 符号,u 开头为内核符号, s 开头为调度配置(目前仅支持`sched_switch`)
|
||
-+ k 和 s 只能一行配置完
|
||
-+ u 可以多行配置, 格式:`[u , 程序路径,二进制名称 ,追踪的函数]`
|
||
-+ 函数务必存在,否则uprobe 配置不成功,配置的内核符号应在`/proc/kallsyms`能够查询到,配置的用户态程序符号仅支持`C/C++`,配置的符号应用`objdump`能够查询到
|
||
-+ 每行末尾不要有逗号
|
||
+**da-tool.sh** [-t <*probe time*>]
|
||
|
||
-配置文件举例如下:
|
||
+|参数|是否必选|参数函数|
|
||
+|----|--------|-------|
|
||
+|-t |否| 采集函数 `trace` 的时长,单位秒,最大限制 100,默认10|
|
||
+
|
||
+### 自定义配置函数
|
||
+配置文件:`/etc/da-tool.conf`
|
||
+
|
||
+举例如下:
|
||
```
|
||
-# kernel symbol config
|
||
-k,ksys_write,udp_recvmsg,udp_sendmsg
|
||
+# /etc/da-tool.conf
|
||
+
|
||
+# kernel symbol config (ref: /proc/kallsyms)
|
||
+k,udp_recvmsg,udp_sendmsg,dev_queue_xmit,udp_send_skb,sock_recvmsg,__skb_recv_udp,udp_rcv
|
||
|
||
# sched config
|
||
s,sched_switch
|
||
|
||
-# user symbol config (path ,bin,func1,func2)
|
||
+# user symbol config (format : u,path,bin_name,func1,func2,...,funcN)
|
||
+# u,/path/,bin_name,sendto
|
||
+u,/home/git_repo/nda-tool/nda-tool/test/net_demo2/,server_no_blk,recvfrom
|
||
+u,/home/git_repo/nda-tool/nda-tool/test/net_demo2/,client_to_noblk,sendto
|
||
u,/home/git_repo/nda-tool/nda-tool/test/base_demo/,base_demo_cpp,_Z5func1v,_Z5func2v,_Z5func2i,_Z5func3v,_Z5func4v
|
||
-u,/home/git_repo/nda-tool/nda-tool/test/net_demo1/,client,sendto,recvfrom
|
||
+# end
|
||
```
|
||
-备注,为了支持用户态不同二进制重名函数采集,配置`event`时,命名为`u0_func1``、u1_func1`...,以上面配置为例,`loop_func`为`u2_loop_func`,
|
||
-观测`trace` 结果时不要产生歧义。
|
||
-#### 2 采集trace并分析
|
||
|
||
-```shell
|
||
-da-tool.sh -t 10 # 采集10秒并分析结果
|
||
++ k 开头为 kernel 符号,u 开头为用户态程序符号, s 开头为调度配置(目前仅支持`sched_switch`且必须配置)
|
||
++ k 和 s 只能一行配置完
|
||
++ u 可以多行配置, 格式:`[u,程序路径,二进制名称,追踪的函数]`
|
||
++ 请确保函数存在,否则 `uprobe` 配置不成功,所配置的内核符号应在`/proc/kallsyms`能够查询到,所配置的用户态程序符号仅支持`C/C++`,且通过`objdump`应能够查询到
|
||
++ 每行末尾不要有逗号
|
||
+
|
||
+
|
||
+注意,为了支持用户态不同二进制重名函数采集,配置`event`时,命名为`u0_func1`、`u1_func1`...,以上面配置为例,`_Z5func1v`为`u2__Z5func1v`。
|
||
+### 分析结果说明
|
||
+
|
||
++ 终端输出结果:各函数调用栈的时延信息
|
||
++ 文件夹输出结果 : `/var/da-tool/analysis-output/ouput/`
|
||
+ + func_delay_stack : 函数调用栈时延结果
|
||
+ + process_sched_info :进程的调度信息
|
||
+ + summary_delay.csv : 时延分析总结报告
|
||
+ + summary_sched.csv : 调度分析总结报告
|
||
+
|
||
+#### 终端输出结果介绍
|
||
```
|
||
-采集后会在`/var/da-tool/tmp`文件夹下生成一个`output_时间`格式的文件夹,包含此次采样的结果。
|
||
-分析完成后会在`/var/da-tool/analysis-output/ouput/`下生成分析结果
|
||
+├──pid: 222459{local:(450040, 44.988%), global:(1000346, 100.000%)}
|
||
+│ ├─────sched_switch{local:(13160, 1.316%, 453.793), global:(13160, 1.316%, 453.793), times:29, (int)ret>=0 times:29}
|
||
+│ └─────u0_recvfrom{local:(422312, 42.217%, 10.729), global:(537146, 53.696%, 13.646), times:39362, (int)ret>=0 times:20}
|
||
+│ ├─────sched_switch{local:(2927, 0.293%, 209.071), global:(2927, 0.293%, 209.071), times:14, (int)ret>=0 times:14}
|
||
+│ └─────sock_recvmsg{local:(55313, 5.529%, 1.405), global:(111907, 11.187%, 2.843), times:39362, (int)ret>=0 times:20}
|
||
+│ └─────udp_recvmsg{local:(36357, 3.634%, 0.924), global:(56594, 5.657%, 1.438), times:39362, (int)ret>=0 times:20}
|
||
+│ └─────__skb_recv_udp{local:(20237, 2.023%, 0.514), global:(20237, 2.023%, 0.514), times:39362, (int)ret>=0 times:39342}
|
||
|
||
```
|
||
-├──pid:1473358{(868869,100.000%)}
|
||
-│ │ ├─────u0__Z5func1v{(local: 19, 0.002%, 19.000)(global:150399, 17.310% ,150399.000), times:1, (int)ret>=0 times:1}
|
||
-│ │ │ ├─────sched_switch{(local: 150380, 17.308%, 150380.000)(global:150380, 17.308% ,150380.000), times:1, (int)ret>=0 times:1}
|
||
+以此结果为例,该进程是一个udp非阻塞收包进程。
|
||
++ `u0_recvfrom` 为该进程在运行后执行的用户态函数,`u0_` 前缀表示第一个应用程序的函数,实际函数名为`recvfrom`;`sched_switch` 为调度函数;其余函数为内核函数
|
||
++ `global` 和 `local` 对应的括号内为该函数执行的时延信息,其中 `local` 是剔除掉子函数和调度所执行的时间 , `global` 为该函数实际执行时长
|
||
++ 每个函数的 `global` 和 `local` 的括号内三个信息分别为,时延,该时延所占进程全部时间的百分比,平均时延(时延/执行次数)
|
||
++ 每一级函数的 `global` 时间等于本级函数`local`时间与下一级所有函数的 `global` 时间之和
|
||
++ `times` 是该函数调用栈的次数,
|
||
++ `(int)ret>=0 times`:表示该函数返回值转换为`int`后大于等于0的次数,无返回值函数返回值是无效的值
|
||
++ 以上时间单位为微秒
|
||
+
|
||
+#### 文件夹结果介绍
|
||
+
|
||
+**时延和调用关系信息**:`/var/da-tool/analysis_output/output/func_delay_stack`
|
||
+```
|
||
+# 此部分信息为终端输出结果的文件格式存储
|
||
+pid_222459;sched_switch 13160, localDelaySum ,13160, localAvedelay ,453.793103, localPercentage, 1.316%, globalDelaySum ,13160, globalAvedelay, 453.793103, globalPercentage, 1.316%, times , 29, (int)ret>=0 times ,29
|
||
+pid_222459;u0_recvfrom;sched_switch 2927, localDelaySum ,2927, localAvedelay ,209.071429, localPercentage, 0.293%, globalDelaySum ,2927, globalAvedelay, 209.071429, globalPercentage, 0.293%, times , 14, (int)ret>=0 times ,14
|
||
+pid_222459;u0_recvfrom 422312, localDelaySum ,422312, localAvedelay ,10.728926, localPercentage, 42.217%, globalDelaySum ,537146, globalAvedelay, 13.646309, globalPercentage, 53.696%, times ,39362, (int)ret>=0 times ,20
|
||
+pid_222459;u0_recvfrom;sock_recvmsg 55313, localDelaySum ,55313, localAvedelay ,1.405239, localPercentage, 5.529%, globalDelaySum ,111907, globalAvedelay, 2.843021, globalPercentage, 11.187%, times ,39362, (int)ret>=0 times ,20
|
||
+pid_222459;u0_recvfrom;sock_recvmsg;udp_recvmsg 36357, localDelaySum ,36357, localAvedelay ,0.923657, localPercentage, 3.634%, globalDelaySum ,56594, globalAvedelay, 1.437783, globalPercentage, 5.657%, times ,39362, (int)ret>=0 times ,20
|
||
+pid_222459;u0_recvfrom;sock_recvmsg;udp_recvmsg;__skb_recv_udp 20237, localDelaySum ,20237, localAvedelay ,0.514125, localPercentage, 2.023%, globalDelaySum ,20237, globalAvedelay, 0.514125, globalPercentage, 2.023%, times ,39362, (int)ret>=0 times ,39342
|
||
```
|
||
-以此结果为例,`u0__Z5func1v` 和 `sched_switch` 为 该进程在运行期间执行的函数,`sched_switch`执行周期在 `u0__Z5func1v` 周期内,`(local: 19, 0.002%, 19.000)` 表示该函数剔除子函数和调度所执行的时间,三个参数分别为,总时间、所占整个pid有效时间的百分比,平均时间,`global` 为不剔除子函数所占的时间,`times` 是该函数调用栈的次数,`(int)ret>=0 times`:表示该函数返回值转换为(int)后大于等于0的次数,无返回值函数返回值认为是0.
|
||
-以上时间单位为微秒。
|
||
-## 注意
|
||
-+ 确保trace 中有需要采集的函数的完整调用栈
|
||
-+ 采样时间和函数需要人为评估,某些函数短时间可能采到大量trace,日志过大,解析过慢
|
||
+
|
||
+**调度信息**:`/var/da-tool/analysis_output/output/process_sched_info`
|
||
+```
|
||
+# delaySum : 该pid分析的总时长
|
||
+# schedSwitchDelay : 调度所占的时间
|
||
+# runtime :delaySum - schedSwitchDelay
|
||
+# cpuSwitchTimes : 该pid从一个核切换到另一个核的次数
|
||
+# core 2, run time 704927 : 表示在cpu2 上运行时长为 704927
|
||
+# startTime,67551.691078,endTime,67551.701193,coreIndex,2 :在这个时间段内在cpu2上运行
|
||
+# coreIndex,-1 表示该pid被切走的时长(sched_switch)
|
||
+
|
||
+pid,222459,delaySum ,1000368,schedSwitchDelay ,37201,runtime ,963167,cpuSwitchTimes ,1,
|
||
+ core 2, run time 704927
|
||
+ core 3, run time 258240
|
||
+startTime,67551.691078,endTime,67551.701193,coreIndex,2
|
||
+startTime,67551.701193,endTime,67551.701970,coreIndex,-1
|
||
+startTime,67551.701970,endTime,67551.702503,coreIndex,2
|
||
+startTime,67551.702503,endTime,67551.713700,coreIndex,-1
|
||
+startTime,67551.713700,endTime,67551.723964,coreIndex,2
|
||
+startTime,67551.723964,endTime,67551.724119,coreIndex,-1
|
||
+...
|
||
+
|
||
+```
|
||
+**时延分析总结报告**:`/var/da-tool/analysis_output/output/summary_delay.csv`
|
||
+
|
||
+包含信息如下,其中`(r>=0)`表示函数返回值转成`int`后大于等于0的情况。
|
||
+`ave,sum,min,max,p50,p80,p95,p99`等为时延信息的平均值、总和、极值、各百分位下的数值。
|
||
+```
|
||
+pid,function,call_times,ave,sum,min,max,p50,p80,p95,p99,
|
||
+call_times(r>=0),ave(r>=0),sum(r>=0),min(r>=0),max(r>=0),p50(r>=0),p80(r>=0),p95(r>=0),p99(r>=0),
|
||
+call_times(r<0),ave(r<0),sum(r<0),min(r<0),max(r<0),p50(r<0),p80(r<0),p95(r<0),p99(r<0),
|
||
+```
|
||
+
|
||
+**调度分析总结报告**:`/var/da-tool/analysis_output/output/summary_sched.csv`
|
||
+```
|
||
+pid,delaySum,schedSwitchDelay,schedSwitchPercentage,schedSwitchTimes,cpuSwitchTimes
|
||
+```
|
||
++ delaySum : 总耗时
|
||
++ schedSwitchDelay : 调度总耗时
|
||
++ schedSwitchPercentage : schedSwitchDelay 占 delaySum 的百分比
|
||
++ schedSwitchTimes : 调度次数
|
||
++ cpuSwitchTimes : cpu 切换次数
|
||
|
||
### 扩展功能
|
||
-da-tool 生成的结果信息可调用 火焰图生成工具,可视化分析结果,
|
||
-`./flamegraph.pl` 可在 https://gitee.com/mirrors/FlameGraph 中获取
|
||
+`da-tool` 生成的结果信息可调用 火焰图生成工具,可视化分析结果,
|
||
+`./flamegraph.pl` 可在 `https://gitee.com/mirrors/FlameGraph` 中获取
|
||
```shell
|
||
# 全部信息
|
||
cat /var/da-tool/analysis_output/output/func_delay_stack | grep -o '^[^,]*' | ./flamegraph.pl --countname "delay sum" > allpid.svg
|
||
@@ -118,15 +199,20 @@ Error: event "aaaa" already exists.
|
||
Error: Failed to add events.
|
||
```
|
||
|
||
+采集后会在`/var/da-tool/tmp`文件夹下生成一个`output_时间`格式的文件夹,包含此次采样的结果。
|
||
+采样脚本的采样日志在此路径下:
|
||
+```
|
||
+/var/da-tool/tmp/sample_output_时间/da-tool/sample.log
|
||
+```
|
||
+
|
||
### 注意事项
|
||
+ 配置注意事项
|
||
+ 配置`/etc/da-tool.conf` 时,注意所配置符号一定存在
|
||
- + 内核符号可在`/proc/kallsyms` 中查看,用户态程序符号 可用`objdump -d 二进制 | grep 函数名` 匹配正确的符号
|
||
- + 某些函数名可能存在点(eg:A.B.C),暂**不支持配置此类函数**,例如经过gcc优化选项`-fipa-sra`优化后,函数符号后缀会有`.rsra.num`。
|
||
+ + 某些函数名可能存在点(eg:A.B.C),暂**不支持配置此类函数**,例如经过gcc优化选项`-fipa-sra`优化后,函数符号后缀会有`.rsra.num`。
|
||
+ + 应用程序名也不要有点,建议函数和应用程序**不要包含特殊符号**
|
||
+ 某些函数可能短时间执行大量次数,此时`trace`很大,解析时间会很长,需要认为评估配置的函数运行情况,合理设置采样时间
|
||
+ 由于`trace`可能存在不完整的调用关系,很有可能在`trace`中存在的数据分析时舍弃,如果单次采样没有抓到需要的pid信息,建议多采样几次
|
||
- + 有时`trace`中会有数据丢失,结果可能异常,常见的异常原因为`trace`过大,内核刷新数据时不正常,建议减小采样时间。
|
||
+ + 有时`trace`中会有数据丢失,结果可能异常,常见的异常原因为`trace`过大,内核刷新数据时不正常,比如会出现同一个函数只有返回时间没有进入时间的现象,建议减小采样时间。
|
||
+ 不支持递归函数
|
||
-
|
||
-
|
||
-
|
||
++ 本工具单个CPU所使用的跟踪缓存`RingBuffer`大小为 `40960kb` ,当单核的`trace`大小接近此值时数据可能异常,进而导致分析结果错误。
|
||
++ 确保`trace` 中有需要采集的函数的完整调用栈
|
||
diff --git a/extra-tools/da-tool/analysis/config.cpp b/extra-tools/da-tool/analysis/config.cpp
|
||
index ecbae2d..08420ad 100644
|
||
--- a/extra-tools/da-tool/analysis/config.cpp
|
||
+++ b/extra-tools/da-tool/analysis/config.cpp
|
||
@@ -38,15 +38,16 @@ void Config::pathInit()
|
||
filename[FILE_TYPE_FUNC_CFG] = pathInput + "/analysis_config";
|
||
|
||
// output
|
||
- filename[FILE_TYPE_OUTPUT_DELAY] = pathOutput + "/delay.csv";
|
||
+ filename[FILE_TYPE_OUTPUT_DELAY] = pathOutput + "/summary_delay.csv";
|
||
filename[FILE_TYPE_OUTPUT_FUNC_STACK_DELALY] = pathOutput + "/func_delay_stack";
|
||
filename[FILE_TYPE_OUTPUT_PROCESS_SCHED_INFO] = pathOutput + "/process_sched_info";
|
||
+ filename[FILE_TYPE_OUTPUT_SUMMARY_SCHED_INFO] = pathOutput + "/summary_sched.csv";
|
||
|
||
// debug
|
||
filename[FILE_TYPE_OUTPUT_RUN_LOG] = pathOutputDebug + "/run.log";
|
||
filename[FILE_TYPE_OUTPUT_FUNC_STACK_ALL_INFO] = pathOutput + "/func_stack_all_info";
|
||
- filename[FILE_TYPE_DEBUG_TIME_PAIE] = pathOutputDebug + "/debug_time_pair.csv";
|
||
- filename[FILE_TYPE_DEBUG_TRACE] = pathOutputDebug + "/debug_trace.csv";
|
||
+ filename[FILE_TYPE_DEBUG_TIME_PAIE] = pathOutputDebug + "/debug_time_pair";
|
||
+ filename[FILE_TYPE_DEBUG_TRACE] = pathOutputDebug + "/debug_trace";
|
||
filename[FILE_TYPE_DEBUG_FUNC_STACK_TRACE] = pathOutputDebug + "/debug_funcstk_trace";
|
||
filename[FILE_TYPE_DEBUG_REGEX] = pathOutputDebug + "/debug_resolve_function_trace";
|
||
filename[FILE_TYPE_DEBUG_CONFIG] = pathOutputDebug + "/debug_config_resolve";
|
||
@@ -161,7 +162,7 @@ void Config::configInit(int argc, char *argv[])
|
||
case 'g':
|
||
if (std::stoi(optarg) < DEBUG_LEVEL_MAX) {
|
||
debugLevel = (DEBUG_LEVEL_E)std::stoi(optarg);
|
||
- } else {
|
||
+ } else {
|
||
std::cout << "debugLevel error" << std::endl;
|
||
}
|
||
std::cout << "debugLevel : " << debugLevel << std::endl;
|
||
@@ -172,7 +173,7 @@ void Config::configInit(int argc, char *argv[])
|
||
default:
|
||
std::cout << "Unrecognized option" << std::endl;
|
||
break;
|
||
- }
|
||
+ }
|
||
}
|
||
|
||
for (int i = optind; i < argc; ++i) {
|
||
diff --git a/extra-tools/da-tool/analysis/config.h b/extra-tools/da-tool/analysis/config.h
|
||
index 53b20dd..ccce0f2 100644
|
||
--- a/extra-tools/da-tool/analysis/config.h
|
||
+++ b/extra-tools/da-tool/analysis/config.h
|
||
@@ -28,6 +28,7 @@ typedef enum {
|
||
FILE_TYPE_OUTPUT_FUNC_STACK_DELALY,
|
||
FILE_TYPE_OUTPUT_FUNC_STACK_ALL_INFO,
|
||
FILE_TYPE_OUTPUT_PROCESS_SCHED_INFO,
|
||
+ FILE_TYPE_OUTPUT_SUMMARY_SCHED_INFO,
|
||
|
||
// debug 1
|
||
FILE_TYPE_DEBUG_CONFIG,
|
||
@@ -36,10 +37,11 @@ typedef enum {
|
||
// debug 3
|
||
FILE_TYPE_DEBUG_TRACE,
|
||
FILE_TYPE_DEBUG_REGEX,
|
||
- FILE_TYPE_DEBUG_FUNC_STACK_TRACE,
|
||
FILE_TYPE_DEBUG_TIME_PAIR_ALIGN,
|
||
FILE_TYPE_DEBUG_TIME_PAIE,
|
||
FILE_TYPE_DEBUG_DELAY_FUNC_STACK_TRACE,
|
||
+ // debug 4
|
||
+ FILE_TYPE_DEBUG_FUNC_STACK_TRACE,
|
||
FILE_TYPE_MAX,
|
||
} FILE_TYPE_E;
|
||
|
||
diff --git a/extra-tools/da-tool/analysis/function_stack.cpp b/extra-tools/da-tool/analysis/function_stack.cpp
|
||
index 3841627..fcc2a8d 100644
|
||
--- a/extra-tools/da-tool/analysis/function_stack.cpp
|
||
+++ b/extra-tools/da-tool/analysis/function_stack.cpp
|
||
@@ -89,7 +89,7 @@ void FunctionStack::stackMapInit()
|
||
int maxDelay = 0;
|
||
|
||
for (int i = 0; i < len; i++) {
|
||
- if (funcInfo.second.isInvalid[i] == 1 || delayMap[pid][functionIndex].isStackFinish[i] == true) {
|
||
+ if (funcInfo.second.isInvalid[i] == true || delayMap[pid][functionIndex].isStackFinish[i] == true) {
|
||
if (cfg.getDebugLevel() >= DEBUG_LEVEL_4) {
|
||
debugFile << "pid," << pid << ",functionIndex," << functionIndex << ",invalid" << std::endl;
|
||
}
|
||
@@ -106,7 +106,7 @@ void FunctionStack::stackMapInit()
|
||
}
|
||
|
||
// The time pair has already been calculated, skip next time
|
||
- delayMap[pid][functionIndex].isStackFinish[i] = true;
|
||
+ delayMap[pid][functionIndex].isStackFinish[i] = true;
|
||
|
||
std::string strFunctionStk = funcInfo.second.strFunctionStk[i];
|
||
int fatherFunction = funcInfo.second.fatherFunction[i];
|
||
@@ -170,13 +170,22 @@ void FunctionStack::saveFunctionStackToFile()
|
||
}
|
||
|
||
for (const auto &processInfo : funcStackMap) {
|
||
-
|
||
+ int pid = processInfo.first;
|
||
+ if (cfg.filterCfgMap.size() != 0 && cfg.filterCfgMap.count(pid) == 0) {
|
||
+ continue;
|
||
+ }
|
||
+ if (processDelayMap[pid].delaySum[FS_DELAY_TYPE_GLOBAL] <= 0) {
|
||
+ continue;
|
||
+ }
|
||
+ file << "pid_" + std::to_string(pid);
|
||
+ file << "; " << processDelayMap[pid].delaySum[FS_DELAY_TYPE_LOCAL]; // for flame graph
|
||
+ file << ",localDelaySum," << processDelayMap[pid].delaySum[FS_DELAY_TYPE_LOCAL];
|
||
+ file << ",localPercentage," << std::fixed << std::setprecision(3) << processDelayMap[pid].percentage[FS_DELAY_TYPE_LOCAL] * 100 << "%";
|
||
+ file << ",globalDelaySum," << processDelayMap[pid].delaySum[FS_DELAY_TYPE_GLOBAL];
|
||
+ file << ",globalPercentage," << std::fixed << std::setprecision(3) << processDelayMap[pid].percentage[FS_DELAY_TYPE_GLOBAL] * 100 << "%";
|
||
+ file << std::endl;
|
||
for (const auto &stkInfo : processInfo.second) {
|
||
- int pid = processInfo.first;
|
||
- if (cfg.filterCfgMap.size() != 0 && cfg.filterCfgMap.count(pid) == 0) {
|
||
- continue;
|
||
-
|
||
- }
|
||
+
|
||
file << "pid_" + std::to_string(pid);
|
||
std::stringstream ss(stkInfo.first);
|
||
std::string token;
|
||
@@ -188,14 +197,14 @@ void FunctionStack::saveFunctionStackToFile()
|
||
}
|
||
|
||
file << " " << stkInfo.second.delaySum[FS_DELAY_TYPE_LOCAL]; // for flame graph
|
||
- file << ", localDelaySum ," << stkInfo.second.delaySum[FS_DELAY_TYPE_LOCAL];
|
||
- file << ", localAvedelay ," << std::fixed << std::setprecision(6) << stkInfo.second.aveDelay[FS_DELAY_TYPE_LOCAL];
|
||
- file << ", localPercentage, " << std::fixed << std::setprecision(3) << stkInfo.second.percentage[FS_DELAY_TYPE_LOCAL] * 100 << "%";
|
||
- file << ", globalDelaySum ," << stkInfo.second.delaySum[FS_DELAY_TYPE_GLOBAL];
|
||
- file << ", globalAvedelay, " << std::fixed << std::setprecision(6) << stkInfo.second.aveDelay[FS_DELAY_TYPE_GLOBAL];
|
||
- file << ", globalPercentage, " << std::fixed << std::setprecision(3) << stkInfo.second.percentage[FS_DELAY_TYPE_GLOBAL] * 100 << "%";
|
||
- file << ", times ," << std::setw(5) << std::setfill(' ') << stkInfo.second.num;
|
||
- file << ", (int)ret>=0 times ," << stkInfo.second.num - stkInfo.second.retValLessZeroTimes;
|
||
+ file << ",localDelaySum," << stkInfo.second.delaySum[FS_DELAY_TYPE_LOCAL];
|
||
+ file << ",localAvedelay," << std::fixed << std::setprecision(6) << stkInfo.second.aveDelay[FS_DELAY_TYPE_LOCAL];
|
||
+ file << ",localPercentage," << std::fixed << std::setprecision(3) << stkInfo.second.percentage[FS_DELAY_TYPE_LOCAL] * 100 << "%";
|
||
+ file << ",globalDelaySum," << stkInfo.second.delaySum[FS_DELAY_TYPE_GLOBAL];
|
||
+ file << ",globalAvedelay," << std::fixed << std::setprecision(6) << stkInfo.second.aveDelay[FS_DELAY_TYPE_GLOBAL];
|
||
+ file << ",globalPercentage," << std::fixed << std::setprecision(3) << stkInfo.second.percentage[FS_DELAY_TYPE_GLOBAL] * 100 << "%";
|
||
+ file << ",times ," << std::setw(5) << std::setfill(' ') << stkInfo.second.num;
|
||
+ file << ",(int)ret>=0 times," << stkInfo.second.num - stkInfo.second.retValLessZeroTimes;
|
||
|
||
file << std::endl;
|
||
}
|
||
@@ -209,11 +218,7 @@ std::string getFatherFuncStk(const std::string &strFunctionStk)
|
||
{
|
||
size_t lastDotPos = strFunctionStk.find_last_of('.');
|
||
if (lastDotPos != std::string::npos) {
|
||
- if (lastDotPos == 0) {
|
||
- return ".0";
|
||
- } else {
|
||
- return strFunctionStk.substr(0, lastDotPos);
|
||
- }
|
||
+ return strFunctionStk.substr(0, lastDotPos);
|
||
} else {
|
||
return "";
|
||
}
|
||
@@ -221,7 +226,6 @@ std::string getFatherFuncStk(const std::string &strFunctionStk)
|
||
|
||
void FunctionStack::stackNodeMapInit()
|
||
{
|
||
-
|
||
for (const auto &processInfo : funcStackMap) {
|
||
int pid = processInfo.first;
|
||
if (stackNodeMap.count(pid) == 0) {
|
||
@@ -230,11 +234,7 @@ void FunctionStack::stackNodeMapInit()
|
||
}
|
||
|
||
for (const auto &stkInfo : processInfo.second) {
|
||
- std::string strFunctionStk = stkInfo.first;
|
||
- if (stackNodeMap[pid].count(strFunctionStk) != 0) {
|
||
- StackNode node_tmp;
|
||
- stackNodeMap[pid].emplace(strFunctionStk, node_tmp);
|
||
- }
|
||
+ std::string strFunctionStk = ".0" + stkInfo.first;
|
||
int func_index_tmp = 0;
|
||
std::stringstream ss(strFunctionStk);
|
||
std::string token;
|
||
@@ -243,67 +243,111 @@ void FunctionStack::stackNodeMapInit()
|
||
func_index_tmp = std::stoi(token);
|
||
}
|
||
}
|
||
- stackNodeMap[pid][strFunctionStk].functionIndex = func_index_tmp;
|
||
+
|
||
std::string fatherFuncStk = getFatherFuncStk(strFunctionStk);
|
||
+ StackNode node_tmp;
|
||
+ if (stackNodeMap[pid].count(strFunctionStk) == 0) {
|
||
+ stackNodeMap[pid].emplace(strFunctionStk, node_tmp);
|
||
+ }
|
||
+ if (stackNodeMap[pid].count(fatherFuncStk) == 0) {
|
||
+ stackNodeMap[pid].emplace(fatherFuncStk, node_tmp);
|
||
+ }
|
||
+ stackNodeMap[pid][strFunctionStk].functionIndex = func_index_tmp;
|
||
stackNodeMap[pid][fatherFuncStk].nextStack.emplace_back(strFunctionStk);
|
||
}
|
||
}
|
||
}
|
||
|
||
+std::string removeRootStk(std::string strFunctionStk)
|
||
+{
|
||
+ return strFunctionStk.substr(2); // remove ".0"
|
||
+}
|
||
|
||
-void FunctionStack::stackNodeMapDfs(int pid, int functionIndex, std::string strFunctionStk, int space_len)
|
||
+void FunctionStack::stackNodeMapDfs(int pid, bool endFlag, std::string strFunctionStk, std::string headStr)
|
||
{
|
||
+ std::string headStrTmp = headStr;
|
||
Config &cfg = Config::getInstance();
|
||
- TimePair &tpInst = TimePair::getInstance();
|
||
if (strFunctionStk == ".0") {
|
||
- std::cout << "├──pid:" << pid;
|
||
- int pidDelay = tpInst.getProcessValidTime(pid);
|
||
- if (pidDelay > 0) {
|
||
- std::cout << "{(" << tpInst.getProcessValidTime(pid) << ",100.000%)}";
|
||
+ std::cout << "├──pid: " << pid;
|
||
+ if (processDelayMap[pid].delaySum[FS_DELAY_TYPE_GLOBAL] > 0) {
|
||
+ std::cout << "{";
|
||
+ std::cout << "local:(" << processDelayMap[pid].delaySum[FS_DELAY_TYPE_LOCAL] << ", ";
|
||
+ std::cout << std::fixed << std::setprecision(3) << processDelayMap[pid].percentage[FS_DELAY_TYPE_LOCAL] * 100 << "%)";
|
||
+ std::cout << ", global:(" << processDelayMap[pid].delaySum[FS_DELAY_TYPE_GLOBAL] << ", ";
|
||
+ std::cout << std::fixed << std::setprecision(3) << processDelayMap[pid].percentage[FS_DELAY_TYPE_GLOBAL] * 100 << "%)";
|
||
+ std::cout << "}";
|
||
} else {
|
||
std::cout << " data invalid!!!";
|
||
}
|
||
-
|
||
std::cout << std::endl;
|
||
} else {
|
||
-
|
||
- for (int i = 0; i < space_len; i++) {
|
||
- if (i % SPLIT_SPACE_LEN == 0)
|
||
-
|
||
-
|
||
- {
|
||
- std::cout << "│";
|
||
- }
|
||
+ std::cout << "│";
|
||
+ if (endFlag == false) {
|
||
+ headStrTmp += "│";
|
||
+ }
|
||
+ for (int i = 1; i < SPLIT_SPACE_LEN; i++) {
|
||
std::cout << " ";
|
||
+ headStrTmp += " ";
|
||
+ }
|
||
+ std::cout << headStr;
|
||
+ if (endFlag == false) {
|
||
+ std::cout << "├─────";
|
||
+ } else {
|
||
+ std::cout << "└─────";
|
||
}
|
||
- std::cout << "├─────" << cfg.IndexToFunction[stackNodeMap[pid][strFunctionStk].functionIndex];
|
||
+
|
||
+ std::cout << cfg.IndexToFunction[stackNodeMap[pid][strFunctionStk].functionIndex];
|
||
std::cout << "{";
|
||
- std::cout << "(local: " << funcStackMap[pid][strFunctionStk].delaySum[FS_DELAY_TYPE_LOCAL] << ", " << std::fixed << std::setprecision(3) << funcStackMap[pid][strFunctionStk].percentage[FS_DELAY_TYPE_LOCAL] * 100 << "%, " << funcStackMap[pid][strFunctionStk].aveDelay[FS_DELAY_TYPE_LOCAL] << ")";
|
||
- std::cout << "(global:" << funcStackMap[pid][strFunctionStk].delaySum[FS_DELAY_TYPE_GLOBAL] << ", " << std::fixed << std::setprecision(3) << funcStackMap[pid][strFunctionStk].percentage[FS_DELAY_TYPE_GLOBAL] * 100 << "% ," << funcStackMap[pid][strFunctionStk].aveDelay[FS_DELAY_TYPE_GLOBAL] << ")";
|
||
- std::cout << ", times:" << funcStackMap[pid][strFunctionStk].num;
|
||
- std::cout << ", (int)ret>=0 times:" << funcStackMap[pid][strFunctionStk].num - funcStackMap[pid][strFunctionStk].retValLessZeroTimes;
|
||
+ std::string noRootStk = removeRootStk(strFunctionStk);
|
||
+ std::cout << "local:(" << funcStackMap[pid][noRootStk].delaySum[FS_DELAY_TYPE_LOCAL] << ", ";
|
||
+ std::cout << std::fixed << std::setprecision(3) << funcStackMap[pid][noRootStk].percentage[FS_DELAY_TYPE_LOCAL] * 100 << "%, ";
|
||
+ std::cout << funcStackMap[pid][noRootStk].aveDelay[FS_DELAY_TYPE_LOCAL] << ")";
|
||
+ std::cout << ", global:(" << funcStackMap[pid][noRootStk].delaySum[FS_DELAY_TYPE_GLOBAL] << ", ";
|
||
+ std::cout << std::fixed << std::setprecision(3) << funcStackMap[pid][noRootStk].percentage[FS_DELAY_TYPE_GLOBAL] * 100 << "%, ";
|
||
+ std::cout << funcStackMap[pid][noRootStk].aveDelay[FS_DELAY_TYPE_GLOBAL] << ")";
|
||
+ std::cout << ", times:" << funcStackMap[pid][noRootStk].num;
|
||
+ std::cout << ", (int)ret>=0 times:" << funcStackMap[pid][noRootStk].num - funcStackMap[pid][noRootStk].retValLessZeroTimes;
|
||
std::cout << "}" << std::endl;
|
||
}
|
||
|
||
- for (const auto &nextStack : stackNodeMap[pid][strFunctionStk].nextStack) {
|
||
- stackNodeMapDfs(pid, stackNodeMap[pid][strFunctionStk].functionIndex, nextStack, space_len + SPLIT_SPACE_LEN);
|
||
+ int len = stackNodeMap[pid][strFunctionStk].nextStack.size();
|
||
+ for (int i = 0; i < len; i++) {
|
||
+ stackNodeMapDfs(pid, i == (len - 1), stackNodeMap[pid][strFunctionStk].nextStack[i], headStrTmp);
|
||
}
|
||
+}
|
||
|
||
+void FunctionStack::processDelayAnalysis()
|
||
+{
|
||
+ TimePair &tpInst = TimePair::getInstance();
|
||
+ for (const auto &processInfo : stackNodeMap) {
|
||
+ int pid = processInfo.first;
|
||
+ if (processDelayMap.count(pid) == 0) {
|
||
+ ProcessDelay delaytmp;
|
||
+ processDelayMap.emplace(pid, delaytmp);
|
||
+ }
|
||
+ processDelayMap[pid].delaySum[FS_DELAY_TYPE_LOCAL] = tpInst.getProcessValidTime(pid);
|
||
+ processDelayMap[pid].delaySum[FS_DELAY_TYPE_GLOBAL] = tpInst.getProcessValidTime(pid);
|
||
+ for (const auto &firstStack : stackNodeMap[pid][".0"].nextStack) {
|
||
+ std::string noRootStk = removeRootStk(firstStack);
|
||
+ processDelayMap[pid].delaySum[FS_DELAY_TYPE_LOCAL] -= funcStackMap[pid][noRootStk].delaySum[FS_DELAY_TYPE_GLOBAL];
|
||
+
|
||
+ }
|
||
+ processDelayMap[pid].percentage[FS_DELAY_TYPE_LOCAL] = \
|
||
+ processDelayMap[pid].delaySum[FS_DELAY_TYPE_LOCAL] * 1.0 / processDelayMap[pid].delaySum[FS_DELAY_TYPE_GLOBAL];
|
||
+ processDelayMap[pid].percentage[FS_DELAY_TYPE_GLOBAL] = 1.0;
|
||
+ }
|
||
}
|
||
|
||
void FunctionStack::stackNodeMapDisplay()
|
||
{
|
||
Config &cfg = Config::getInstance();
|
||
std::cout << "Display the function delay of each pid " << std::endl;
|
||
- // std::cout << "format:function symbol{( delay sum (microsecond) ,percentage(occupy the entire pid runtime) ),average delay | num in trace}" << std::endl;
|
||
for (const auto &processInfo : stackNodeMap) {
|
||
int pid = processInfo.first;
|
||
if (cfg.filterCfgMap.size() == 0 || cfg.filterCfgMap.count(pid) != 0) {
|
||
- std::cout << "───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────" << std::endl;
|
||
- stackNodeMapDfs(processInfo.first, 0, ".0", SPLIT_SPACE_LEN);
|
||
- std::cout << "───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────" << std::endl;
|
||
+ std::cout << "│" << std::endl;
|
||
+ stackNodeMapDfs(processInfo.first, 0, ".0", "");
|
||
}
|
||
-
|
||
}
|
||
std::cout << std::endl;
|
||
}
|
||
@@ -313,8 +357,9 @@ void FunctionStack::function_stack_proc()
|
||
delayMapInit();
|
||
stackMapInit();
|
||
stackMapAnalysis();
|
||
- saveFunctionStackToFile();
|
||
|
||
stackNodeMapInit();
|
||
+ processDelayAnalysis();
|
||
stackNodeMapDisplay();
|
||
+ saveFunctionStackToFile();
|
||
}
|
||
\ No newline at end of file
|
||
diff --git a/extra-tools/da-tool/analysis/function_stack.h b/extra-tools/da-tool/analysis/function_stack.h
|
||
index 34781c3..9f6e2d7 100644
|
||
--- a/extra-tools/da-tool/analysis/function_stack.h
|
||
+++ b/extra-tools/da-tool/analysis/function_stack.h
|
||
@@ -52,8 +52,15 @@ public:
|
||
std::vector<int> delay;
|
||
};
|
||
|
||
+class ProcessDelay {
|
||
+public:
|
||
+ int delaySum[FS_DELAY_TYPE_MAX];
|
||
+ double percentage[FS_DELAY_TYPE_MAX];
|
||
+};
|
||
+
|
||
class StackNode {
|
||
public:
|
||
+ // if stk .0.1.2.3 , then .0.1's nextStack is .0.1.2 , functionIndex is 1
|
||
int functionIndex;
|
||
std::vector<std::string> nextStack;
|
||
};
|
||
@@ -70,24 +77,24 @@ public:
|
||
~FunctionStack() {}
|
||
|
||
private:
|
||
+ std::unordered_map<int, ProcessDelay> processDelayMap;
|
||
std::unordered_map<int, std::unordered_map<std::string, StackInfo>>
|
||
funcStackMap; // [pid][strFunctionStk]
|
||
std::unordered_map<int, std::unordered_map<int, FsDelayInfo>>
|
||
delayMap; // [pid][functionIndex] , copy from trace_reslove
|
||
void delayMapInit();
|
||
void stackMapInit();
|
||
+ void processDelayAnalysis();
|
||
|
||
void stackMapAnalysis();
|
||
void saveFunctionStackToFile();
|
||
|
||
private: // stack node
|
||
std::unordered_map<int, std::unordered_map<std::string, StackNode>>
|
||
- stackNodeMap; // [pid][strFunctionStk]
|
||
+ stackNodeMap; // [pid][".0" + strFunctionStk]
|
||
void stackNodeMapInit();
|
||
void stackNodeMapDisplay();
|
||
- void stackNodeMapDfs(int pid, int functionIndex, std::string strFunctionStk,
|
||
- int space_len);
|
||
-
|
||
+ void stackNodeMapDfs(int pid, bool endFlag, std::string strFunctionStk, std::string headStr);
|
||
public:
|
||
void function_stack_proc();
|
||
};
|
||
diff --git a/extra-tools/da-tool/analysis/sched_analysis.cpp b/extra-tools/da-tool/analysis/sched_analysis.cpp
|
||
index ba8c49f..aea3d25 100644
|
||
--- a/extra-tools/da-tool/analysis/sched_analysis.cpp
|
||
+++ b/extra-tools/da-tool/analysis/sched_analysis.cpp
|
||
@@ -24,47 +24,21 @@ SchedAnalysis::SchedAnalysis()
|
||
|
||
}
|
||
|
||
-void SchedAnalysis::processSchedAnalysisLoop(const int &pid, const int ×tamp, const int &coreIndex, LINE_TYPE_E lineType)
|
||
+void SchedAnalysis::processSchedAnalysisLoop(const int &pid, const int ×tamp, const int &coreIndex)
|
||
{
|
||
if (processSchedMap.count(pid) != 0) {
|
||
ProcessSchedInfo tmp;
|
||
processSchedMap.emplace(pid, tmp);
|
||
}
|
||
int size = processSchedMap[pid].coreTrace.size();
|
||
- if (lineType == LINE_TYPE_FUNC) {
|
||
- if (size == 0) {
|
||
- ProcessCoreTrace pct;
|
||
- pct.startTime = timestamp;
|
||
- pct.endTime = 0;
|
||
- pct.coreIndex = coreIndex;
|
||
- processSchedMap[pid].coreTrace.emplace_back(pct);
|
||
- } else {
|
||
- processSchedMap[pid].coreTrace[size - 1].endTime = timestamp;
|
||
- }
|
||
-
|
||
- } else if (lineType == LINE_TYPE_SCHED_SWITCH) // pid1 - > pidn
|
||
- {
|
||
- if (size != 0) {
|
||
- processSchedMap[pid].coreTrace[size - 1].endTime = timestamp;
|
||
- }
|
||
- ProcessCoreTrace pct;
|
||
- pct.startTime = timestamp;
|
||
- pct.endTime = timestamp;
|
||
- pct.coreIndex = -1;
|
||
- processSchedMap[pid].coreTrace.emplace_back(pct);
|
||
-
|
||
- } else if (lineType == LINE_TYPE_SCHED_SWITCH_RET) // pidm - > pid1
|
||
- {
|
||
- if (size != 0) {
|
||
- processSchedMap[pid].coreTrace[size - 1].endTime = timestamp;
|
||
- }
|
||
- ProcessCoreTrace pct;
|
||
- pct.startTime = timestamp;
|
||
- pct.endTime = timestamp;
|
||
- pct.coreIndex = coreIndex;
|
||
- processSchedMap[pid].coreTrace.emplace_back(pct);
|
||
+ ProcessCoreTrace pct;
|
||
+ pct.startTime = timestamp;
|
||
+ pct.endTime = timestamp;
|
||
+ pct.coreIndex = coreIndex;
|
||
+ if (size != 0) {
|
||
+ processSchedMap[pid].coreTrace[size - 1].endTime = timestamp;
|
||
}
|
||
-
|
||
+ processSchedMap[pid].coreTrace.emplace_back(pct);
|
||
}
|
||
|
||
void SchedAnalysis::schedInfoProc()
|
||
@@ -82,19 +56,17 @@ void SchedAnalysis::schedInfoProc()
|
||
for (const auto &line_info_tmp : slv.getTraceLine()) {
|
||
std::string functionName = line_info_tmp.functionName;
|
||
int pid = line_info_tmp.pid;
|
||
- if (cfg.funcCfgMap.count(functionName) == 0 || pid == 0) {
|
||
+ if (cfg.funcCfgMap.count(functionName) == 0) {
|
||
continue;
|
||
}
|
||
int timestamp = line_info_tmp.timestamp;
|
||
int coreIndex = line_info_tmp.core;
|
||
int functionIndex = cfg.funcCfgMap[functionName].functionIndex;
|
||
|
||
- if (functionIndex != sched_switch_funcidx) {
|
||
- processSchedAnalysisLoop(pid, timestamp, coreIndex, LINE_TYPE_FUNC);
|
||
- } else {
|
||
+ if (functionIndex == sched_switch_funcidx) {
|
||
int nextPid = line_info_tmp.schedSwitchLine.nextPid;
|
||
- processSchedAnalysisLoop(pid, timestamp, coreIndex, LINE_TYPE_SCHED_SWITCH);
|
||
- processSchedAnalysisLoop(nextPid, timestamp, coreIndex, LINE_TYPE_SCHED_SWITCH_RET);
|
||
+ processSchedAnalysisLoop(pid, timestamp, -1); // pid1 - > pidn
|
||
+ processSchedAnalysisLoop(nextPid, timestamp, coreIndex); // pidm - > pid1
|
||
}
|
||
}
|
||
}
|
||
@@ -105,13 +77,15 @@ void SchedAnalysis::schedInfoAnalysis()
|
||
int lastCoreIndex = -1;
|
||
int delaySum = 0;
|
||
int delaySched = 0;
|
||
- int cpuSwichTimes = 0;
|
||
+ int schedSwitchTimes = 0;
|
||
+ int cpuSwitchTimes = 0;
|
||
for (auto &coreTrace : sched_tmp.second.coreTrace) {
|
||
int delay = coreTrace.endTime - coreTrace.startTime;
|
||
int coreIndex = coreTrace.coreIndex;
|
||
delaySum += delay;
|
||
if (coreIndex == -1) {
|
||
delaySched += delay;
|
||
+ schedSwitchTimes++;
|
||
} else {
|
||
sched_tmp.second.runTimeOfCore[coreIndex] += delay;
|
||
}
|
||
@@ -121,13 +95,14 @@ void SchedAnalysis::schedInfoAnalysis()
|
||
}
|
||
|
||
if (lastCoreIndex != coreIndex && coreIndex != -1) {
|
||
- cpuSwichTimes++;
|
||
+ cpuSwitchTimes++;
|
||
lastCoreIndex = coreTrace.coreIndex;
|
||
}
|
||
-
|
||
}
|
||
sched_tmp.second.schedSwitchDelay = delaySched;
|
||
- sched_tmp.second.cpuSwichTimes = cpuSwichTimes;
|
||
+ sched_tmp.second.schedSwitchTimes = schedSwitchTimes;
|
||
+ sched_tmp.second.percentageSchedSwitch = delaySum == 0? 0.0 : delaySched * 1.0 / delaySum;
|
||
+ sched_tmp.second.cpuSwitchTimes = cpuSwitchTimes;
|
||
sched_tmp.second.delaySum = delaySum;
|
||
}
|
||
}
|
||
@@ -147,10 +122,10 @@ void SchedAnalysis::saveSchedInfoToFile()
|
||
continue;
|
||
}
|
||
file << "pid," << pid << ",";
|
||
- file << "delaySum ," << sched_tmp.second.delaySum << ",";
|
||
- file << "schedSwitchDelay ," << sched_tmp.second.schedSwitchDelay << ",";
|
||
- file << "runtime ," << sched_tmp.second.delaySum - sched_tmp.second.schedSwitchDelay << ",";
|
||
- file << "cpuSwichTimes ," << sched_tmp.second.cpuSwichTimes << ",";
|
||
+ file << "delaySum," << sched_tmp.second.delaySum << ",";
|
||
+ file << "schedSwitchDelay," << sched_tmp.second.schedSwitchDelay << ",";
|
||
+ file << "runtime," << sched_tmp.second.delaySum - sched_tmp.second.schedSwitchDelay << ",";
|
||
+ file << "cpuSwitchTimes," << sched_tmp.second.cpuSwitchTimes << ",";
|
||
file << std::endl;
|
||
for (int coreIndex = 0; coreIndex < sched_tmp.second.runTimeOfCore.size(); coreIndex++) {
|
||
int run_time = sched_tmp.second.runTimeOfCore[coreIndex];
|
||
@@ -171,9 +146,38 @@ void SchedAnalysis::saveSchedInfoToFile()
|
||
file.close();
|
||
}
|
||
|
||
+void SchedAnalysis::saveSchedInfoSummaryToFile()
|
||
+{
|
||
+ Config &cfg = Config::getInstance();
|
||
+ std::ofstream file(cfg.filename[FILE_TYPE_OUTPUT_SUMMARY_SCHED_INFO], std::ios::out | std::ios::trunc);
|
||
+ if (!file) {
|
||
+ std::cout << "file open failed:" << cfg.filename[FILE_TYPE_OUTPUT_SUMMARY_SCHED_INFO] << std::endl;
|
||
+ return;
|
||
+ }
|
||
+ file << "pid,delaySum,schedSwitchDelay,schedSwitchPercentage,schedSwitchTimes,cpuSwitchTimes";
|
||
+ file << std::endl;
|
||
+ TraceResolve &slv = TraceResolve::getInstance();
|
||
+ for (const auto &sched_tmp : processSchedMap) {
|
||
+ int pid = sched_tmp.first;
|
||
+ if (pid == 0) {
|
||
+ continue;
|
||
+ }
|
||
+ file << pid << ",";
|
||
+ file << sched_tmp.second.delaySum << ",";
|
||
+ file << sched_tmp.second.schedSwitchDelay << ",";
|
||
+ file << std::fixed << std::setprecision(3) << sched_tmp.second.percentageSchedSwitch * 100 << "%,";
|
||
+ file << sched_tmp.second.schedSwitchTimes << ",";
|
||
+ file << sched_tmp.second.cpuSwitchTimes << ",";
|
||
+ file << std::endl;
|
||
+ }
|
||
+
|
||
+ file.close();
|
||
+}
|
||
+
|
||
void SchedAnalysis::schedAnalysisProc()
|
||
{
|
||
schedInfoProc();
|
||
schedInfoAnalysis();
|
||
saveSchedInfoToFile();
|
||
+ saveSchedInfoSummaryToFile();
|
||
}
|
||
diff --git a/extra-tools/da-tool/analysis/sched_analysis.h b/extra-tools/da-tool/analysis/sched_analysis.h
|
||
index dd35764..85036ce 100644
|
||
--- a/extra-tools/da-tool/analysis/sched_analysis.h
|
||
+++ b/extra-tools/da-tool/analysis/sched_analysis.h
|
||
@@ -34,7 +34,9 @@ public:
|
||
std::vector<ProcessCoreTrace>
|
||
coreTrace; // CPU information of pid in each time period
|
||
int schedSwitchDelay;
|
||
- int cpuSwichTimes;
|
||
+ int schedSwitchTimes;
|
||
+ double percentageSchedSwitch;
|
||
+ int cpuSwitchTimes;
|
||
int delaySum;
|
||
};
|
||
|
||
@@ -68,10 +70,11 @@ private: // process sched info
|
||
std::unordered_map<int, ProcessSchedInfo> processSchedMap; // [pid]
|
||
// std::vector <std::vector<CpuSchedInfo>> allCpuSchedInfo; // [coreIndex]
|
||
void processSchedAnalysisLoop(const int &pid, const int ×tamp,
|
||
- const int &coreIndex, LINE_TYPE_E line_type);
|
||
+ const int &coreIndex);
|
||
void schedInfoProc();
|
||
void schedInfoAnalysis();
|
||
void saveSchedInfoToFile();
|
||
+ void saveSchedInfoSummaryToFile();
|
||
|
||
public:
|
||
void schedAnalysisProc();
|
||
diff --git a/extra-tools/da-tool/analysis/time_pair.cpp b/extra-tools/da-tool/analysis/time_pair.cpp
|
||
index b9e16a6..037bce1 100644
|
||
--- a/extra-tools/da-tool/analysis/time_pair.cpp
|
||
+++ b/extra-tools/da-tool/analysis/time_pair.cpp
|
||
@@ -48,6 +48,16 @@ typedef enum {
|
||
TRACE_INFO_SHCEMAX,
|
||
} TRACE_INFO_SCHED_SWITCH_E;
|
||
|
||
+typedef enum {
|
||
+ DEBUG_POS_0,
|
||
+ DEBUG_POS_1,
|
||
+ DEBUG_POS_2,
|
||
+ DEBUG_POS_3,
|
||
+ DEBUG_POS_4,
|
||
+ DEBUG_POS_5,
|
||
+ DEBUG_POS_MAX,
|
||
+} DEBUG_POS_E;
|
||
+
|
||
TimePair::TimePair()
|
||
{
|
||
}
|
||
@@ -91,38 +101,35 @@ void TimePair::saveFuncStkDebugToFile(std::ofstream &file, const int &pid, const
|
||
}
|
||
int TimePair::getFatherFunctionIdLoop(const int &pid, const int &functionIndex, const int &isRet, int &debugPos)
|
||
{
|
||
- debugPos = 0;
|
||
+ debugPos = DEBUG_POS_0;
|
||
|
||
- if (funcStkMap.count(pid) == 0)
|
||
- {
|
||
+ if (funcStkMap.count(pid) == 0) {
|
||
std::vector<int> tmp;
|
||
funcStkMap.emplace(pid, tmp);
|
||
}
|
||
|
||
- if (funcStkMap[pid].size() == 0)
|
||
- {
|
||
+ if (funcStkMap[pid].size() == 0) {
|
||
if (isRet) // stk empty
|
||
{
|
||
- debugPos = 1;
|
||
+ debugPos = DEBUG_POS_1;
|
||
return 0;
|
||
} else {
|
||
funcStkMap[pid].emplace_back(functionIndex);
|
||
- debugPos = 2;
|
||
+ debugPos = DEBUG_POS_2;
|
||
}
|
||
} else {
|
||
- if (funcStkMap[pid][funcStkMap[pid].size() - 1] == functionIndex) // stk not empty
|
||
- {
|
||
+ if (funcStkMap[pid][funcStkMap[pid].size() - 1] == functionIndex) { // stk not empty
|
||
funcStkMap[pid].pop_back(); // match ,pop
|
||
if (funcStkMap[pid].size() > 0) {
|
||
- debugPos = 3;
|
||
+ debugPos = DEBUG_POS_3;
|
||
return funcStkMap[pid][funcStkMap[pid].size() - 1];
|
||
} else {
|
||
- debugPos = 4;
|
||
+ debugPos = DEBUG_POS_4;
|
||
return 0; // can't find father function
|
||
}
|
||
} else { // function unmath , push
|
||
funcStkMap[pid].emplace_back(functionIndex);
|
||
- debugPos = 5;
|
||
+ debugPos = DEBUG_POS_5;
|
||
return funcStkMap[pid][funcStkMap[pid].size() - 2];
|
||
}
|
||
}
|
||
@@ -140,18 +147,20 @@ void TimePair::timePairUpdateLoop(const int &pid, const int &functionIndex, cons
|
||
|
||
if (timePairMap[pid].count(functionIndex) == 0) {
|
||
TimePairInfo infoTmp;
|
||
+ infoTmp.maxStartTimeInvaild = 0;
|
||
+ infoTmp.minEndTimeInvalid = INT_MAX;
|
||
timePairMap[pid].emplace(functionIndex, infoTmp);
|
||
}
|
||
|
||
if (isRet) {
|
||
- if (timePairMap[pid][functionIndex].startTime.size() == 0) // fist is endtime ,startime=endtime
|
||
- {
|
||
+ if (timePairMap[pid][functionIndex].startTime.size() == 0) { // fist is endtime ,startime=endtime
|
||
timePairMap[pid][functionIndex].startTime.emplace_back(timestamp);
|
||
timePairMap[pid][functionIndex].childFuncTimes.emplace_back(0);
|
||
timePairMap[pid][functionIndex].strFunctionStk.emplace_back('.' + std::to_string(functionIndex));
|
||
timePairMap[pid][functionIndex].fatherFunction.emplace_back(0);
|
||
timePairMap[pid][functionIndex].fatherFuncPos.emplace_back(-1);
|
||
- timePairMap[pid][functionIndex].isInvalid.emplace_back(1); // only have retval , invalid
|
||
+ timePairMap[pid][functionIndex].isInvalid.emplace_back(true); // only have retval , invalid
|
||
+ timePairMap[pid][functionIndex].maxStartTimeInvaild = timestamp;
|
||
} // Be careful when adding else branches. Only when there is no exit at the entrance, you will not be able to enter else
|
||
timePairMap[pid][functionIndex].endTime.emplace_back(timestamp);
|
||
if (line_info_tmp.args.size() != 0) {
|
||
@@ -162,13 +171,10 @@ void TimePair::timePairUpdateLoop(const int &pid, const int &functionIndex, cons
|
||
} else {
|
||
timePairMap[pid][functionIndex].startTime.emplace_back(timestamp);
|
||
timePairMap[pid][functionIndex].childFuncTimes.emplace_back(0);
|
||
-
|
||
std::string father_func_stk = fatherFunction != 0 ? \
|
||
timePairMap[pid][fatherFunction].strFunctionStk[timePairMap[pid][fatherFunction].strFunctionStk.size() - 1] : "";
|
||
-
|
||
std::string strFunctionStk = father_func_stk + '.' + std::to_string(functionIndex);
|
||
timePairMap[pid][functionIndex].strFunctionStk.emplace_back(strFunctionStk);
|
||
-
|
||
timePairMap[pid][functionIndex].fatherFunction.emplace_back(fatherFunction);
|
||
int fatherFuncPos = 0;
|
||
if (fatherFunction == 0) {
|
||
@@ -178,8 +184,7 @@ void TimePair::timePairUpdateLoop(const int &pid, const int &functionIndex, cons
|
||
timePairMap[pid][fatherFunction].childFuncTimes[fatherFuncPos]++;
|
||
}
|
||
timePairMap[pid][functionIndex].fatherFuncPos.emplace_back(fatherFuncPos);
|
||
-
|
||
- timePairMap[pid][functionIndex].isInvalid.emplace_back(0);
|
||
+ timePairMap[pid][functionIndex].isInvalid.emplace_back(false);
|
||
}
|
||
}
|
||
|
||
@@ -199,6 +204,7 @@ void TimePair::timePairAlignment()
|
||
for (auto &processInfo : timePairMap) {
|
||
for (auto &funcInfo : processInfo.second) {
|
||
int diffLen = funcInfo.second.startTime.size() - funcInfo.second.endTime.size();
|
||
+ bool updateEndTimeInvalid = false;
|
||
if (diffLen == 0) {
|
||
if (isOutputDebugFile) {
|
||
file << diffLen << "," << processInfo.first << " ," << funcInfo.first << " ," << \
|
||
@@ -215,8 +221,7 @@ void TimePair::timePairAlignment()
|
||
}
|
||
} else {
|
||
if (isOutputDebugFile) {
|
||
- if (diffLen > 1)
|
||
- {
|
||
+ if (diffLen > 1) {
|
||
// A normal trace usually does not have a startTime greater than endtime dimension greater than 1,
|
||
// indicating that a function has not returned and has been pushed back onto the stack.
|
||
file << "run error(diffLen>1)!!!,";
|
||
@@ -225,7 +230,12 @@ void TimePair::timePairAlignment()
|
||
funcInfo.second.startTime.size() << " ," << funcInfo.second.endTime.size() << std::endl;
|
||
}
|
||
for (int i = 0; i < diffLen; i++) {
|
||
- funcInfo.second.endTime.emplace_back(funcInfo.second.startTime[funcInfo.second.startTime.size() - diffLen + i]);
|
||
+ int endTime = funcInfo.second.startTime[funcInfo.second.startTime.size() - diffLen + i];
|
||
+ funcInfo.second.endTime.emplace_back(endTime);
|
||
+ if (updateEndTimeInvalid == false) {
|
||
+ funcInfo.second.minEndTimeInvalid = endTime;
|
||
+ updateEndTimeInvalid = true;
|
||
+ }
|
||
}
|
||
}
|
||
}
|
||
@@ -236,52 +246,50 @@ void TimePair::timePairAlignment()
|
||
|
||
void TimePair::timePairMarkInvalidData()
|
||
{
|
||
- // Find each function from front to back, find the first time pair that is not equal as the starting time point of the function,
|
||
- // and then compare the maximum of each function as the global starting time point of the pid
|
||
- // Find each function from the back to the front, find the first time pair that is not equal as the end time point of the function,
|
||
- // and then compare the smallest of each function as the global end point of the pid
|
||
for (auto &processInfo : timePairMap) {
|
||
int pid = processInfo.first;
|
||
VaildRange vr_tmp;
|
||
validTimeOfPid.emplace(pid, vr_tmp);
|
||
- int validStartTime = 0;
|
||
- int validEndTime = INT_MAX;
|
||
+ int validStartTime = INT_MAX;
|
||
+ int validEndTime = 0;
|
||
+ int maxInvalidStartTime = 0;
|
||
+ int minInvalidEndTime = INT_MAX;
|
||
|
||
+ // maxInvalidStartTime choose max value of every func
|
||
+ for (const auto &funcInfo : processInfo.second) {
|
||
+ if (funcInfo.second.maxStartTimeInvaild > maxInvalidStartTime) {
|
||
+ maxInvalidStartTime = funcInfo.second.maxStartTimeInvaild;
|
||
+ }
|
||
+ if (funcInfo.second.minEndTimeInvalid < minInvalidEndTime) {
|
||
+ minInvalidEndTime = funcInfo.second.minEndTimeInvalid;
|
||
+ }
|
||
+ }
|
||
+ // [start, maxInvalidStartTime] and [minInvalidEndTime, end] data invalid
|
||
for (auto &funcInfo : processInfo.second) {
|
||
for (int i = 0; i < funcInfo.second.startTime.size(); i++) {
|
||
- if (funcInfo.second.endTime[i] - funcInfo.second.startTime[i] > 0) {
|
||
- if (funcInfo.second.startTime[i] > validStartTime) {
|
||
- validStartTime = funcInfo.second.startTime[i];
|
||
- }
|
||
- break;
|
||
+ if (funcInfo.second.startTime[i] <= maxInvalidStartTime) {
|
||
+ funcInfo.second.isInvalid[i] = true;
|
||
+ }
|
||
+ if (funcInfo.second.endTime[i] >= minInvalidEndTime) {
|
||
+ funcInfo.second.isInvalid[i] = true;
|
||
}
|
||
}
|
||
+ }
|
||
|
||
- for (int i = funcInfo.second.startTime.size() - 1; i >= 0; i--) {
|
||
- if (funcInfo.second.endTime[i] - funcInfo.second.startTime[i] > 0) {
|
||
- if (funcInfo.second.endTime[i] < validEndTime) {
|
||
+ for (const auto &funcInfo : processInfo.second) {
|
||
+ for (int i = 0; i < funcInfo.second.startTime.size(); i++) {
|
||
+ if (funcInfo.second.isInvalid[i] != true) {
|
||
+ if (funcInfo.second.startTime[i] <= validStartTime) {
|
||
+ validStartTime = funcInfo.second.startTime[i];
|
||
+ }
|
||
+ if (funcInfo.second.endTime[i] >= validEndTime) {
|
||
validEndTime = funcInfo.second.endTime[i];
|
||
}
|
||
- break;
|
||
}
|
||
}
|
||
}
|
||
-
|
||
-
|
||
validTimeOfPid[pid].validStartTime = validStartTime;
|
||
validTimeOfPid[pid].validEndTime = validEndTime;
|
||
-
|
||
- // [validStartTime,validEndTime] out range invalid
|
||
- for (auto &funcInfo : processInfo.second) {
|
||
- for (int i = 0; i < funcInfo.second.startTime.size(); i++) {
|
||
- if (funcInfo.second.startTime[i] < validStartTime) {
|
||
- funcInfo.second.isInvalid[i] = 1;
|
||
- }
|
||
- if (funcInfo.second.endTime[i] > validEndTime) {
|
||
- funcInfo.second.isInvalid[i] = 1;
|
||
- }
|
||
- }
|
||
- }
|
||
}
|
||
|
||
Config &cfg = Config::getInstance();
|
||
@@ -340,49 +348,69 @@ void TimePair::timePairMatching()
|
||
file.close();
|
||
}
|
||
|
||
+void TimePair::functionDelayUpdate()
|
||
+{
|
||
+ for (auto &processInfo : timePairMap) {
|
||
+ for (auto &funcInfo : processInfo.second) {
|
||
+ for (int i = 0; i < funcInfo.second.startTime.size(); i++) {
|
||
+ funcInfo.second.delay.emplace_back(funcInfo.second.endTime[i] - funcInfo.second.startTime[i]);
|
||
+ }
|
||
+ }
|
||
+ }
|
||
+}
|
||
+
|
||
void TimePair::functionStatisticsAnalysis()
|
||
{
|
||
for (auto &processInfo : timePairMap) {
|
||
for (auto &funcInfo : processInfo.second) {
|
||
- int maxDelay = 0;
|
||
- int minDelay = INT_MAX;
|
||
- int delaySum = 0;
|
||
- int maxDelayPos = 0;
|
||
- int minDelayPos = 0;
|
||
- int len = funcInfo.second.startTime.size();
|
||
- int valid_len = 0;
|
||
+ std::vector<int> delayTmp[DELAY_INFO_MAX];
|
||
+ int len = funcInfo.second.delay.size();
|
||
+ int delaySum[DELAY_INFO_MAX] = { 0 };
|
||
for (int i = 0; i < len; i++) {
|
||
-
|
||
- int delay = funcInfo.second.endTime[i] - funcInfo.second.startTime[i];
|
||
- funcInfo.second.delay.emplace_back(delay);
|
||
- int isInvalid = funcInfo.second.isInvalid[i];
|
||
- if (isInvalid) {
|
||
+ if (funcInfo.second.isInvalid[i]) {
|
||
continue;
|
||
}
|
||
-
|
||
- if (maxDelay < delay) {
|
||
- maxDelay = delay;
|
||
- maxDelayPos = i;
|
||
+ int delay = funcInfo.second.delay[i];
|
||
+ delayTmp[DELAY_INFO_ALL].emplace_back(delay);
|
||
+ delaySum[DELAY_INFO_ALL] += delay;
|
||
+ if ((int)funcInfo.second.retVal[i] < 0) {
|
||
+ delayTmp[DELAY_INFO_RETVAL_LESS_ZERO].emplace_back(delay);
|
||
+ delaySum[DELAY_INFO_RETVAL_LESS_ZERO] += delay;
|
||
+ } else {
|
||
+ delayTmp[DELAY_INFO_RETVAL_GEOREQ_ZERO].emplace_back(delay);
|
||
+ delaySum[DELAY_INFO_RETVAL_GEOREQ_ZERO] += delay;
|
||
}
|
||
- if (minDelay > delay) {
|
||
- minDelay = delay;
|
||
- minDelayPos = i;
|
||
+ }
|
||
+ for (int i = 0; i < DELAY_INFO_MAX; i++) {
|
||
+ DELAY_INFO_E type = (DELAY_INFO_E)i;
|
||
+ sort(delayTmp[type].begin(), delayTmp[type].end());
|
||
+ int valid_len = delayTmp[type].size();
|
||
+ if (valid_len > 0) {
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_SUM] = delaySum[type];
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_MIN] = delayTmp[type][0];
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_MAX] = delayTmp[type][valid_len - 1];
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P50] = delayTmp[type][ceil(0.50 * valid_len) - 1];
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P80] = delayTmp[type][ceil(0.80 * valid_len) - 1];
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P95] = delayTmp[type][ceil(0.95 * valid_len) - 1];
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P99] = delayTmp[type][ceil(0.99 * valid_len) - 1];
|
||
+ funcInfo.second.summary.callTimes[type] = valid_len;
|
||
+ funcInfo.second.summary.aveDelay[type] = delaySum[type] * 1.0 / valid_len;
|
||
+ } else {
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_SUM] = 0;
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_MIN] = 0;
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_MAX] = 0;
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P50] = 0;
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P80] = 0;
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P95] = 0;
|
||
+ funcInfo.second.summary.delay[type][DELAY_SUMMARY_P99] = 0;
|
||
+ funcInfo.second.summary.callTimes[type] = 0;
|
||
+ funcInfo.second.summary.aveDelay[type] = 0;
|
||
}
|
||
-
|
||
- delaySum += delay;
|
||
- valid_len++;
|
||
}
|
||
-
|
||
- funcInfo.second.aveDelay = valid_len == 0 ? 0.0 : delaySum * 1.0 / valid_len;
|
||
- funcInfo.second.minDelay = minDelay;
|
||
- funcInfo.second.maxDelay = maxDelay;
|
||
- funcInfo.second.maxDelayPos = maxDelayPos;
|
||
- funcInfo.second.minDelayPos = minDelayPos;
|
||
- funcInfo.second.delaySum = delaySum;
|
||
- funcInfo.second.callTimes = valid_len;
|
||
}
|
||
}
|
||
}
|
||
+
|
||
void TimePair::saveTimePairToFile()
|
||
{
|
||
Config &cfg = Config::getInstance();
|
||
@@ -454,38 +482,39 @@ void TimePair::saveTimePairToFile()
|
||
void TimePair::saveDelayInfoToFile()
|
||
{
|
||
Config &cfg = Config::getInstance();
|
||
- if (cfg.getDebugLevel() < DEBUG_LEVEL_1) {
|
||
- return;
|
||
- }
|
||
std::ofstream file(cfg.filename[FILE_TYPE_OUTPUT_DELAY], std::ios::out | std::ios::trunc);
|
||
if (!file) {
|
||
std::cout << "file open failed:" << cfg.filename[FILE_TYPE_OUTPUT_DELAY] << std::endl;
|
||
return;
|
||
}
|
||
|
||
- bool is_filter = true;
|
||
- if (cfg.getDebugLevel() < DEBUG_LEVEL_3) {
|
||
- is_filter = false;
|
||
- }
|
||
TraceResolve &trace_resolve_inst = TraceResolve::getInstance();
|
||
+ file << "note : (r>=0) => (int)return value >=0; ave => average delay,";
|
||
+ file << "pid,function,";
|
||
+ file << "call_times,ave,sum,min,max,p50,p80,p95,p99,";
|
||
+ file << "call_times(r>=0),ave(r>=0),sum(r>=0),min(r>=0),max(r>=0),p50(r>=0),p80(r>=0),p95(r>=0),p99(r>=0),";
|
||
+ file << "call_times(r<0),ave(r<0),sum(r<0),min(r<0),max(r<0),p50(r<0),p80(r<0),p95(r<0),p99(r<0),";
|
||
+ file << std::endl;
|
||
for (const auto &processInfo : timePairMap) {
|
||
for (const auto &funcInfo : processInfo.second) {
|
||
- if (!is_filter || (cfg.filterCfgMap.size() != 0 && cfg.filterCfgMap.count(processInfo.first) == 0)) {
|
||
+ if (cfg.filterCfgMap.size() != 0 && cfg.filterCfgMap.count(processInfo.first) == 0) {
|
||
continue;
|
||
}
|
||
- file << "pid:" << processInfo.first << "," << std::endl;
|
||
- file << "functionIndex:" << funcInfo.first << "," << cfg.IndexToFunction[funcInfo.first] << std::endl;
|
||
-
|
||
- file << "aveDelay:" << funcInfo.second.aveDelay << std::endl;
|
||
- file << "maxDelay:" << funcInfo.second.maxDelay << std::endl;
|
||
- file << "minDelay:" << funcInfo.second.minDelay << std::endl;
|
||
- file << "delaySum:" << funcInfo.second.delaySum << std::endl;
|
||
-
|
||
- file << "call times:" << funcInfo.second.callTimes << std::endl;
|
||
- file << "max_delay_at:" << std::fixed << std::setprecision(6) << \
|
||
- trace_resolve_inst.convertTimeIntToDouble(funcInfo.second.startTime[funcInfo.second.maxDelayPos]) << std::endl;
|
||
- file << "min_delay_at:" << std::fixed << std::setprecision(6) << \
|
||
- trace_resolve_inst.convertTimeIntToDouble(funcInfo.second.startTime[funcInfo.second.minDelayPos]) << std::endl;
|
||
+ if (funcInfo.second.summary.callTimes[DELAY_INFO_ALL] <= 0) {
|
||
+ continue;
|
||
+ }
|
||
+ file << "," << processInfo.first << ",";
|
||
+ file << cfg.IndexToFunction[funcInfo.first] << ",";
|
||
+
|
||
+ for (int i = 0; i < DELAY_INFO_MAX; i++) {
|
||
+ DELAY_INFO_E infoType = (DELAY_INFO_E)i;
|
||
+ file << funcInfo.second.summary.callTimes[infoType] << ",";
|
||
+ file << std::fixed << std::setprecision(3) << funcInfo.second.summary.aveDelay[infoType] << ",";
|
||
+ for (int j = 0; j < DELAY_SUMMARY_ENUM_MAX; j++) {
|
||
+ DELAY_SUMMARY_E summaryType = (DELAY_SUMMARY_E)j;
|
||
+ file << funcInfo.second.summary.delay[infoType][summaryType] << ",";
|
||
+ }
|
||
+ }
|
||
file << std::endl;
|
||
}
|
||
}
|
||
@@ -493,6 +522,7 @@ void TimePair::saveDelayInfoToFile()
|
||
file.close();
|
||
}
|
||
|
||
+
|
||
int TimePair::getProcessValidTime(const int &pid)
|
||
{
|
||
if (validTimeOfPid.count(pid) != 0) {
|
||
@@ -502,6 +532,7 @@ int TimePair::getProcessValidTime(const int &pid)
|
||
}
|
||
|
||
}
|
||
+
|
||
void TimePair::timePairAnalysis()
|
||
{
|
||
// step 1 : convert trace to time pair
|
||
@@ -511,10 +542,9 @@ void TimePair::timePairAnalysis()
|
||
// step 3 : mark date whether invalid
|
||
timePairMarkInvalidData();
|
||
// step 4: compute statistics rst
|
||
+ functionDelayUpdate();
|
||
functionStatisticsAnalysis();
|
||
-
|
||
// step 5: save rst
|
||
saveTimePairToFile();
|
||
saveDelayInfoToFile();
|
||
-
|
||
}
|
||
\ No newline at end of file
|
||
diff --git a/extra-tools/da-tool/analysis/time_pair.h b/extra-tools/da-tool/analysis/time_pair.h
|
||
index 70dee67..9d3e757 100644
|
||
--- a/extra-tools/da-tool/analysis/time_pair.h
|
||
+++ b/extra-tools/da-tool/analysis/time_pair.h
|
||
@@ -27,6 +27,31 @@ public:
|
||
int validEndTime;
|
||
};
|
||
|
||
+typedef enum {
|
||
+ DELAY_SUMMARY_SUM,
|
||
+ DELAY_SUMMARY_MIN,
|
||
+ DELAY_SUMMARY_MAX,
|
||
+ DELAY_SUMMARY_P50,
|
||
+ DELAY_SUMMARY_P80,
|
||
+ DELAY_SUMMARY_P95,
|
||
+ DELAY_SUMMARY_P99,
|
||
+ DELAY_SUMMARY_ENUM_MAX,
|
||
+} DELAY_SUMMARY_E;
|
||
+
|
||
+typedef enum {
|
||
+ DELAY_INFO_ALL,
|
||
+ DELAY_INFO_RETVAL_GEOREQ_ZERO, // ret>=0
|
||
+ DELAY_INFO_RETVAL_LESS_ZERO, // ret<0
|
||
+ DELAY_INFO_MAX,
|
||
+} DELAY_INFO_E;
|
||
+
|
||
+class TimePairSummary {
|
||
+public:
|
||
+ double aveDelay[DELAY_INFO_MAX];
|
||
+ int callTimes[DELAY_INFO_MAX];
|
||
+ int delay[DELAY_INFO_MAX][DELAY_SUMMARY_ENUM_MAX];
|
||
+};
|
||
+
|
||
class TimePairInfo {
|
||
public:
|
||
// The time relative to the integer time of the first trace , Unit:
|
||
@@ -42,11 +67,15 @@ public:
|
||
std::vector<int> fatherFuncPos;
|
||
std::vector<int> childFuncTimes; // Number of calls to other functions.
|
||
std::vector<uintptr_t> retVal; // return value
|
||
- std::vector<int> isInvalid; // isInvalid=true indicates that there is no
|
||
+ std::vector<bool> isInvalid; // isInvalid=true indicates that there is no
|
||
// complete call stack data
|
||
std::vector<std::string> strFunctionStk;
|
||
|
||
+ int maxStartTimeInvaild;
|
||
+ int minEndTimeInvalid;
|
||
+
|
||
// analysis result
|
||
+ TimePairSummary summary;
|
||
double aveDelay;
|
||
int maxDelay;
|
||
int minDelay;
|
||
@@ -86,6 +115,7 @@ private:
|
||
const int &functionIndex, const int &isRet,
|
||
const int ×tamp, const int &fatherFunction,
|
||
const int &debugPos);
|
||
+ void functionDelayUpdate();
|
||
void functionStatisticsAnalysis();
|
||
|
||
void timePairMatching();
|
||
diff --git a/extra-tools/da-tool/analysis/trace_resolve.cpp b/extra-tools/da-tool/analysis/trace_resolve.cpp
|
||
index 8224346..8424464 100644
|
||
--- a/extra-tools/da-tool/analysis/trace_resolve.cpp
|
||
+++ b/extra-tools/da-tool/analysis/trace_resolve.cpp
|
||
@@ -95,7 +95,7 @@ void TraceResolve::resolveTrace()
|
||
while (getline(file, line)) {
|
||
line_num++;
|
||
if (line_num % 10000 == 0) {
|
||
- std::cout << "resolve:" << line_num << " lines," << regex_num << " lines match " << std::endl;
|
||
+ std::cout << regex_num << "/" << line_num << " (matched/lines)" << std::endl;
|
||
}
|
||
if (line_num < cfg.readTraceBegin) {
|
||
continue;
|
||
@@ -141,8 +141,7 @@ void TraceResolve::resolveTrace()
|
||
}
|
||
|
||
if (isMatch) {
|
||
- if (isFirstMatch)
|
||
- {
|
||
+ if (isFirstMatch) {
|
||
startTimeIntPart = std::stoi(match[TRACE_INFO_TIMESTAMP_INT].str());
|
||
isFirstMatch = false;
|
||
}
|
||
diff --git a/extra-tools/da-tool/analysis/trace_resolve.h b/extra-tools/da-tool/analysis/trace_resolve.h
|
||
index feec87f..df330d5 100644
|
||
--- a/extra-tools/da-tool/analysis/trace_resolve.h
|
||
+++ b/extra-tools/da-tool/analysis/trace_resolve.h
|
||
@@ -38,13 +38,6 @@ typedef enum
|
||
PROCESS_STATE_MAX,
|
||
} PROCESS_STATE_E;
|
||
|
||
-typedef enum {
|
||
- LINE_TYPE_FUNC,
|
||
- LINE_TYPE_SCHED_SWITCH,
|
||
- LINE_TYPE_SCHED_SWITCH_RET,
|
||
- LINE_TYPE_MAX,
|
||
-} LINE_TYPE_E;
|
||
-
|
||
class SchedSwitchLine {
|
||
public:
|
||
int prevPid;
|
||
diff --git a/extra-tools/da-tool/conf/da-tool.conf b/extra-tools/da-tool/conf/da-tool.conf
|
||
index df1560a..4c823bc 100644
|
||
--- a/extra-tools/da-tool/conf/da-tool.conf
|
||
+++ b/extra-tools/da-tool/conf/da-tool.conf
|
||
@@ -1,12 +1,12 @@
|
||
# /etc/da-tool.conf
|
||
|
||
-# kernel symbol config
|
||
-k,ksys_write,udp_recvmsg,udp_sendmsg,dev_queue_xmit,udp_send_skb,sock_recvmsg,__skb_recv_udp,udp_rcv
|
||
+# kernel symbol config (ref: /proc/kallsyms)
|
||
+k,udp_recvmsg,udp_sendmsg,dev_queue_xmit,udp_send_skb,sock_recvmsg,__skb_recv_udp,udp_rcv
|
||
|
||
# sched config
|
||
s,sched_switch
|
||
|
||
# user symbol config (format : u,path,bin_name,func1,func2,...,funcN)
|
||
-#u,/path/,bin_name,sendto
|
||
+# u,/path/,bin_name,sendto
|
||
|
||
# end
|
||
diff --git a/extra-tools/da-tool/main.cpp b/extra-tools/da-tool/main.cpp
|
||
index 365b1f3..b6ec46d 100644
|
||
--- a/extra-tools/da-tool/main.cpp
|
||
+++ b/extra-tools/da-tool/main.cpp
|
||
@@ -24,23 +24,18 @@ int main(int argc, char *argv[])
|
||
cout << "analysis start..." << endl;
|
||
Config &cfg = Config::getInstance();
|
||
cfg.configInit(argc, argv);
|
||
- cout << "analysis Config completed" << endl;
|
||
-
|
||
+ cout << "analysis resolve..." << endl;
|
||
TraceResolve &trace_resolve_inst = TraceResolve::getInstance();
|
||
trace_resolve_inst.trace_resolve_proc();
|
||
- cout << "analysis resolve completed" << endl;
|
||
|
||
TimePair &tpInst = TimePair::getInstance();
|
||
tpInst.timePairAnalysis();
|
||
- cout << "analysis time pair completed" << endl;
|
||
|
||
SchedAnalysis &schedAnalysisInst = SchedAnalysis::getInstance();
|
||
schedAnalysisInst.schedAnalysisProc();
|
||
- cout << "analysis sched completed" << endl;
|
||
|
||
FunctionStack &fstk = FunctionStack::getInstance();
|
||
fstk.function_stack_proc();
|
||
- cout << "analysis FunctionStack completed" << endl;
|
||
cout << "analysis finish" << endl;
|
||
return 0;
|
||
}
|
||
\ No newline at end of file
|
||
diff --git a/extra-tools/da-tool/script/da-tool.sh b/extra-tools/da-tool/script/da-tool.sh
|
||
index 8329a15..ccc3443 100644
|
||
--- a/extra-tools/da-tool/script/da-tool.sh
|
||
+++ b/extra-tools/da-tool/script/da-tool.sh
|
||
@@ -252,7 +252,7 @@ function clear_env() {
|
||
function sample_init() {
|
||
echo 0 >/sys/kernel/debug/tracing/tracing_on
|
||
echo >/sys/kernel/debug/tracing/trace
|
||
- echo 4096 >/sys/kernel/debug/tracing/buffer_size_kb
|
||
+ echo 40960 >/sys/kernel/debug/tracing/buffer_size_kb
|
||
|
||
echo >/sys/kernel/debug/tracing/uprobe_events
|
||
echo >/sys/kernel/debug/tracing/kprobe_events
|
||
diff --git a/extra-tools/da-tool/test/case/case1/case1.cpp b/extra-tools/da-tool/test/case/case1/case1.cpp
|
||
new file mode 100644
|
||
index 0000000..1e16f7c
|
||
--- /dev/null
|
||
+++ b/extra-tools/da-tool/test/case/case1/case1.cpp
|
||
@@ -0,0 +1,64 @@
|
||
+#include <iostream>
|
||
+#include <unistd.h>
|
||
+
|
||
+using namespace std;
|
||
+
|
||
+void delay_1us()
|
||
+{
|
||
+ usleep(1);
|
||
+}
|
||
+
|
||
+void delay_10us()
|
||
+{
|
||
+ usleep(10);
|
||
+}
|
||
+
|
||
+void delay_1ms()
|
||
+{
|
||
+ usleep(1000);
|
||
+}
|
||
+
|
||
+void delay_10ms()
|
||
+{
|
||
+ usleep(10000);
|
||
+}
|
||
+
|
||
+void funcC()
|
||
+{
|
||
+ for (int i = 0; i < 1000; i++) {
|
||
+ }
|
||
+}
|
||
+void funcB()
|
||
+{
|
||
+ for (int i = 0; i < 100; i++) {
|
||
+ for (int j = 0; j < 1000; j++) {
|
||
+ }
|
||
+ funcC();
|
||
+ }
|
||
+}
|
||
+void funcA()
|
||
+{
|
||
+ for (int i = 0; i < 100; i++) {
|
||
+ funcB();
|
||
+ }
|
||
+}
|
||
+
|
||
+int main()
|
||
+{
|
||
+ int loopnum = 0;
|
||
+ while (1) {
|
||
+ cout << "loopnum:" << loopnum << endl;
|
||
+ loopnum++;
|
||
+ delay_10us();
|
||
+ delay_1us();
|
||
+ delay_1ms();
|
||
+ delay_10ms();
|
||
+ funcA();
|
||
+ funcB();
|
||
+ funcC();
|
||
+ }
|
||
+ return 0;
|
||
+}
|
||
+
|
||
+// g++ case1.cpp -o case1
|
||
+// _Z9delay_1usv,_Z10delay_10usv,_Z9delay_1msv,_Z10delay_10msv,_Z5funcCv,_Z5funcBv,_Z5funcAv
|
||
\ No newline at end of file
|
||
diff --git a/extra-tools/da-tool/test/case/case2/case2_udp_cli.c b/extra-tools/da-tool/test/case/case2/case2_udp_cli.c
|
||
new file mode 100644
|
||
index 0000000..80f9dd7
|
||
--- /dev/null
|
||
+++ b/extra-tools/da-tool/test/case/case2/case2_udp_cli.c
|
||
@@ -0,0 +1,37 @@
|
||
+#include <stdio.h>
|
||
+#include <stdlib.h>
|
||
+#include <string.h>
|
||
+#include <unistd.h>
|
||
+#include <sys/socket.h>
|
||
+#include <netinet/in.h>
|
||
+#include <arpa/inet.h>
|
||
+
|
||
+#define SERVER_IP "127.0.0.1"
|
||
+#define SERVER_PORT 12345
|
||
+
|
||
+int main() {
|
||
+ int sockfd;
|
||
+ struct sockaddr_in server_addr;
|
||
+ char buffer[1024];
|
||
+
|
||
+ sockfd = socket(AF_INET, SOCK_DGRAM, 0);
|
||
+ if (sockfd < 0) {
|
||
+ perror("socket creation failed");
|
||
+ exit(EXIT_FAILURE);
|
||
+ }
|
||
+
|
||
+ memset(&server_addr, 0, sizeof(server_addr));
|
||
+ server_addr.sin_family = AF_INET;
|
||
+ server_addr.sin_addr.s_addr = inet_addr(SERVER_IP);
|
||
+ server_addr.sin_port = htons(SERVER_PORT);
|
||
+
|
||
+ int loop_num =0;
|
||
+ while (1) {
|
||
+ usleep(50000);
|
||
+ sprintf(buffer, "loop num : %d", loop_num++);
|
||
+ sendto(sockfd, buffer, strlen(buffer), 0, (const struct sockaddr *)&server_addr, sizeof(server_addr));
|
||
+ }
|
||
+
|
||
+ close(sockfd);
|
||
+ return 0;
|
||
+}
|
||
diff --git a/extra-tools/da-tool/test/case/case2/case2_udp_ser_noblk.c b/extra-tools/da-tool/test/case/case2/case2_udp_ser_noblk.c
|
||
new file mode 100644
|
||
index 0000000..a24841d
|
||
--- /dev/null
|
||
+++ b/extra-tools/da-tool/test/case/case2/case2_udp_ser_noblk.c
|
||
@@ -0,0 +1,53 @@
|
||
+#include <stdio.h>
|
||
+#include <stdlib.h>
|
||
+#include <string.h>
|
||
+#include <unistd.h>
|
||
+#include <fcntl.h>
|
||
+#include <sys/socket.h>
|
||
+#include <netinet/in.h>
|
||
+#include <arpa/inet.h>
|
||
+
|
||
+#define SERVER_PORT 12345
|
||
+
|
||
+int main() {
|
||
+ int sockfd;
|
||
+ struct sockaddr_in server_addr, client_addr;
|
||
+ socklen_t client_len;
|
||
+ char buffer[1024];
|
||
+
|
||
+ sockfd = socket(AF_INET, SOCK_DGRAM, 0);
|
||
+ if (sockfd < 0) {
|
||
+ perror("socket creation failed");
|
||
+ exit(EXIT_FAILURE);
|
||
+ }
|
||
+
|
||
+ // no blk
|
||
+ int flags = fcntl(sockfd, F_GETFL, 0);
|
||
+ fcntl(sockfd, F_SETFL, flags | O_NONBLOCK);
|
||
+
|
||
+ memset(&server_addr, 0, sizeof(server_addr));
|
||
+ server_addr.sin_family = AF_INET;
|
||
+ server_addr.sin_addr.s_addr = INADDR_ANY;
|
||
+ server_addr.sin_port = htons(SERVER_PORT);
|
||
+
|
||
+ if (bind(sockfd, (const struct sockaddr *)&server_addr, sizeof(server_addr)) < 0) {
|
||
+ perror("bind failed");
|
||
+ exit(EXIT_FAILURE);
|
||
+ }
|
||
+
|
||
+ while (1) {
|
||
+ memset(buffer, 0, sizeof(buffer));
|
||
+ client_len = sizeof(client_addr);
|
||
+ ssize_t recv_len = recvfrom(sockfd, buffer, sizeof(buffer) - 1, MSG_DONTWAIT, (struct sockaddr *)&client_addr, &client_len);
|
||
+
|
||
+ if (recv_len > 0) {
|
||
+ buffer[recv_len] = '\0';
|
||
+ printf("recv from %s:%d data: %s recv_len=%d\n", inet_ntoa(client_addr.sin_addr), ntohs(client_addr.sin_port), buffer, recv_len);
|
||
+ } else {
|
||
+ printf("recv_len=%d\n", recv_len);
|
||
+ }
|
||
+ }
|
||
+
|
||
+ close(sockfd);
|
||
+ return 0;
|
||
+}
|
||
--
|
||
2.33.0
|
||
|