diff --git a/0004-Modify-method-of-mark-invalid-data-and-add-summary.patch b/0004-Modify-method-of-mark-invalid-data-and-add-summary.patch new file mode 100644 index 0000000..cdada06 --- /dev/null +++ b/0004-Modify-method-of-mark-invalid-data-and-add-summary.patch @@ -0,0 +1,1594 @@ +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 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 nextStack; + }; +@@ -70,24 +77,24 @@ public: + ~FunctionStack() {} + + private: ++ std::unordered_map processDelayMap; + std::unordered_map> + funcStackMap; // [pid][strFunctionStk] + std::unordered_map> + delayMap; // [pid][functionIndex] , copy from trace_reslove + void delayMapInit(); + void stackMapInit(); ++ void processDelayAnalysis(); + + void stackMapAnalysis(); + void saveFunctionStackToFile(); + + private: // stack node + std::unordered_map> +- 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 + 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 processSchedMap; // [pid] + // std::vector > 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 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 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 fatherFuncPos; + std::vector childFuncTimes; // Number of calls to other functions. + std::vector retVal; // return value +- std::vector isInvalid; // isInvalid=true indicates that there is no ++ std::vector isInvalid; // isInvalid=true indicates that there is no + // complete call stack data + std::vector 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 ++#include ++ ++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 ++#include ++#include ++#include ++#include ++#include ++#include ++ ++#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 ++#include ++#include ++#include ++#include ++#include ++#include ++#include ++ ++#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 + diff --git a/aops-ceres.spec b/aops-ceres.spec index 16e1a90..2264d9e 100644 --- a/aops-ceres.spec +++ b/aops-ceres.spec @@ -2,7 +2,7 @@ Name: aops-ceres Version: v1.3.4 -Release: 6 +Release: 7 Summary: An agent which needs to be adopted in client, it managers some plugins, such as gala-gopher(kpi collection), fluentd(log collection) and so on. License: MulanPSL2 URL: https://gitee.com/openeuler/%{name} @@ -10,6 +10,7 @@ Source0: %{name}-%{version}.tar.gz Patch0001: 0001-support-kabi-check.patch Patch0002: 0002-modify-re-of-kernel-filter.patch Patch0003: 0003-fix-bug-in-test_hotpatch.py.patch +Patch0004: 0004-Modify-method-of-mark-invalid-data-and-add-summary.patch BuildRequires: python3-setuptools Requires: python3-requests python3-jsonschema python3-libconf @@ -89,6 +90,12 @@ install -b -m755 ./extra-tools/da-tool/script/da-tool.sh ${RPM_BUILD_ROOT} %attr(755, root, root) %{_bindir}/da-tool-analysis %changelog +* Mon Nov 20 2023 liuchanggeng - v1.3.4-7 +- new patch for da-tool +- add summary report of schedswitch and delay +- modify method of mark invalid data and expanding valid data range +- adjusted the format of the output data + * Wed Nov 15 2023 wangguangge - v1.3.4-6 - fix bug in test_hotpatch.py