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