本文主要是介绍一个100%CPU占用率,但是线程名混乱和top不准问题定位过程,希望对大家解决编程问题提供一定的参考价值,需要的开发者们随着小编来一起学习吧!
关键词:task_newtask
、task_rename
、process tree
、top
等。
有一个场景CPU
占用率100%
,同时进程下创建了一大堆线程,很多线程同样的名称。
而且存在一个情况,top
查看所有进程占用率要远小于100%
。
这里有两个问题,
一是线程同名问题,由于程序设计之初没有考虑线程名问题,导致无法根据把线程名和业务联系起来;而且通过top/pstree
能看到的这是进程和线程的父子关系。
二是,这些丢失的CPU
占用率究竟哪里去了?
1. 获取进程下所有线程的树形结构
这一步很关键,因为很多系统中线程的创建非常频繁,而且处理完任务,快速退出。
常用的工具top
和pstree
等,对线程之间的父子关系是没有显示的,只明确了进程和线程的父子关系。
这里借助/sys/kernel/debug/tracing/events/task/
下的task_newtask
和task_rename
,这两者分别创建线程,然后对线程改名。
有了这两个trace events
,就可以记录新创建的线程,新创建的线程和父线程同名,然后通过task_rename
进行名称修改,常用的是prctl()
。
1.1 抓取task_newtask
和task_rename
数据
通过trace event
抓取到的数据如下,task_newtask
详细记录了线程由谁创建(父线程)、创建了谁(子线程)、名称是什么(子线程名),然后task_rename
详细记录了哪个线程由什么旧名称改成了什么新名称
sh-153 [000] .... 53.734695: task_newtask: pid=165 comm=sh clone_flags=1200011 oom_score_adj=0cat-165 [000] ...1 53.738804: task_rename: pid=165 oldcomm=sh newcomm=cat oom_score_adj=0sh-153 [000] .... 84.638270: task_newtask: pid=166 comm=sh clone_flags=1200011 oom_score_adj=0xchip_runtime-166 [000] ...1 84.645910: task_rename: pid=166 oldcomm=sh newcomm=xchip_runtime oom_score_adj=0xchip_runtime-166 [000] .... 85.098260: task_newtask: pid=167 comm=xchip_runtime clone_flags=3d0f00 oom_score_adj=0Log2Hostflush-167 [000] ...1 85.099145: task_rename: pid=167 oldcomm=xchip_runtime newcomm=Log2Hostflush oom_score_adj=0xchip_runtime-166 [000] .... 85.133881: task_newtask: pid=168 comm=xchip_runtime clone_flags=3d0f00 oom_score_adj=0usb_server_list-168 [000] ...1 85.134077: task_rename: pid=168 oldcomm=xchip_runtime newcomm=usb_server_list oom_score_adj=0usb_server_list-168 [000] .... 116.497292: task_newtask: pid=169 comm=usb_server_list clone_flags=3d0f00 oom_score_adj=0coreComm-169 [000] ...1 116.501998: task_rename: pid=169 oldcomm=usb_server_list newcomm=coreComm oom_score_adj=0usb_server_list-168 [000] .... 116.514232: task_newtask: pid=170 comm=usb_server_list clone_flags=3d0f00 oom_score_adj=0
请问下怎么通过trace event
抓取到/sys/kernel/debug/tracing/events/task/task_newtask
的数据
echo 1 > /sys/kernel/debug/tracing/events/enable
/sys/kernel/debug/tracing/events/task/task_newtask enble
echo 1 > /sys/kernel/debug/tracing/tracing_on
cat /sys/kernel/debug/tracing/trace > /sdcard/trace.txt
cat /sys/kernel/debug/tracing/trace|grep -E 'task_rename|task_newtask'
1.2 脚本分析生成线程树形结构
在jupyter-notebook
中读取trace.txt
文件,然后从中提取关键信息,pid
、comm
、父pid
、子pid
列表。
以pid
为字典键值,分析过程如下。
import reprocess_tree = {}
ap_trace_file = open('/home/al/trace.txt', 'rb')
for line in ap_trace_file:ftrace_line_fmt = \' *(?P<proc>.*)-(?P<pid>[0-9]*) *\[(?P<cpu>[0-9]*)\] *'+\'(?P<flags>.{4}) *(?P<ktime>[0-9\.]*): *'+\'(?P<msg>.*)'m = re.match(ftrace_line_fmt, line)if(not m):continueproc = m.group('proc')pid = m.group('pid')msg = m.group('msg')if (not process_tree.has_key(pid)):process_tree[pid] = {'comm':proc, 'child':[], 'father':0}#Analyze task_newtask.#task_newtask: pid=165 comm=sh clone_flags=1200011 oom_score_adj=0task_newtask_fmt = 'task_newtask: pid=(?P<cpid>[0-9]*) comm=(?P<comm>.*) clone_flags.*'m = re.match(task_newtask_fmt, msg)if(m):cpid = m.group('cpid')comm = m.group('comm')#print pid, cpid, comm#process_tree.update({cpid:{'child':[], 'comm':comm}})process_tree[pid]['child'].append(cpid)if(not process_tree.has_key(cpid)):process_tree[cpid] = {'comm':comm, 'child':[], 'father':pid}#Analyze task_rename.#task_rename: pid=170 oldcomm=usb_server_list newcomm=adapter oom_score_adj=0task_rename_fmt = 'task_rename: pid=(?P<cpid>[0-9]*) oldcomm=(?P<oldcomm>.*) newcomm=(?P<newcomm>.*) oom_score_adj.*'m = re.match(task_rename_fmt, msg)if(m):cpid = m.group('cpid')oldcomm = m.group('oldcomm')newcomm = m.group('newcomm')process_tree[cpid]['comm'] = newcomm#print cpid, oldcomm, newcomm
ap_trace_file.close()
然后根据process_tree
解析结果,显示成树形结构:
for key, item in process_tree.items():if ( item['father'] == 0 ):print item['comm']+':'+keyfor child1 in item['child']:print " |-2-"+process_tree[child1]['comm']+':'+child1for child2 in process_tree[child1]['child']:print " |-3-"+process_tree[child2]['comm']+':'+child2for child3 in process_tree[child2]['child']:print " |-4-"+process_tree[child3]['comm']+':'+child3for child4 in process_tree[child3]['child']:print " |-5-"+process_tree[child4]['comm']+':'+child4for child5 in process_tree[child4]['child']:print " |-6-"+process_tree[child5]['comm']+':'+child5for child6 in process_tree[child5]['child']:print " |-7-"+process_tree[child6]['comm']+':'+child6for child7 in process_tree[child6]['child']:print " |-8-"+process_tree[child7]['comm']+':'+child7
最终输出结果如下。
这里可以看出xchip_runtime
下所有线程的创建轨迹,以及其父子关系。
sh:153|-2-cat:165|-2-xchip_runtime:166|-3-Log2Hostflush:167|-3-usb_server_list:168|-4-coreComm:169|-4-adapter:170|-4-usb_server_list:171|-4-sh:172|-5-fp_download_tes:173|-6-sh:174|-7-find:175|-7-awk:176|-6-sh:177|-7-rm:178|-4-usb_server_list:179|-5-usb_server_list:202|-5-usb_server_list:203
...|-5-usb_server_list:2851|-5-usb_server_list:2852|-4-usb_server_list:180|-4-p2p_rx_task:181|-4-IFMS_Init:182|-4-omx_main:183|-5-omx_g1_output:218|-4-src:src:184|-5-omxdec:src:219|-4-iccsrc_rx:185|-4-usb_server_list:186|-4-p2p_rx_task:187|-4-omx_main:188|-5-omx_g1_output:192|-4-src:src:189|-5-omxdec:src:193|-4-iccsrc_rx:190|-4-usb_server_list:191|-4-p2p_rx_task:194|-4-omx_main:195|-5-omx_g1_output:199|-4-src:src:196|-5-omxdec:src:200|-4-iccsrc_rx:197|-4-usb_server_list:198|-4-p2p_rx_task:201|-4-omx_main:228|-5-omx_g1_output:240|-4-src:src:229|-5-omxdec:src:241|-4-iccsrc_rx:230|-4-usb_server_list:235|-2-top:646|-2-pidof:1873|-2-top:1907|-2-cat:2830
2. 单线程or
多线程执行
根据usb_server_list:179
线程的创建线程数量和频率,结合功能就可以判定其对应关系。
线程占用率低于100%
的原因,可能是由于usb_server_list
创建的子线程频繁创建并快速退出。
在top
采样周期内并不能完成的存在,这些线程所占用的CPU
资源,在总和中得到了统计,但是在top
显示具体进程/线程的时候无法统计到。
为了验证构造两个不同的应用,启动一个周期性timer
,频率可调整。
然后一个应用顺序执行四个任务,另一个应用分别启动四个线程执行四个任务。
通过top
查看其CPU
占用率。
2.1 测试程序
创建四个线程分别执行任务:
#include <pthread.h>
#include <unistd.h>
#include <thread>
#include <stdio.h>
#include <time.h>
#include <stdlib.h>
#include <signal.h>
#include <string.h>unsigned int count = 0;
#define LOOP_COUNT 40000void thread_fn(void)
{unsigned int i, a;for(i = 0; i < LOOP_COUNT; i++) {a++;}
}void timer_thread(union sigval v)
{std::thread thread1, thread2, thread3, thread4;//printf("pthread count=%d.\n", count++);thread1 = std::thread(thread_fn);thread2 = std::thread(thread_fn);thread3 = std::thread(thread_fn);thread4 = std::thread(thread_fn);thread1.join();thread2.join();thread3.join();thread4.join();
}int main(int argc, char** argv)
{timer_t timerid = 0;struct itimerspec it;struct sigevent evp;memset(&evp, 0, sizeof(struct sigevent));evp.sigev_value.sival_int = 111;evp.sigev_notify = SIGEV_THREAD;evp.sigev_notify_function = timer_thread;if (timer_create(CLOCK_REALTIME, &evp, &timerid) == -1) { perror("fail to timer_create"); return -1;; } printf("timer_create timerid = %d\n", timerid);it.it_interval.tv_sec = 0;it.it_interval.tv_nsec = atoi(argv[1]); it.it_value.tv_sec = 1;it.it_value.tv_nsec = 0; if (timer_settime(&timerid, 0, &it, NULL) == -1) { perror("fail to timer_settime"); return -1;} while(1) {sleep(1);}return 0;
}
编译如下:
csky-abiv2-linux-g++ pthread_4simu.cc -o pthread_4simu -lpthread --std=c++11 -lrt
创建顺序执行四个任务:
#include <pthread.h>
#include <unistd.h>
#include <thread>
#include <stdio.h>
#include <time.h>
#include <stdlib.h>
#include <signal.h>
#include <string.h>unsigned int count = 0;
#define LOOP_COUNT 40000void thread_fn(void)
{unsigned int i, a;for(i = 0; i < LOOP_COUNT; i++) {a++;}
}void timer_thread(union sigval v)
{//printf("loop count=%d.\n", count++);thread_fn();thread_fn();thread_fn();thread_fn();
}int main(int argc, char** argv)
{timer_t timerid = 0;struct itimerspec it;struct sigevent evp;memset(&evp, 0, sizeof(struct sigevent));evp.sigev_value.sival_int = 111;evp.sigev_notify = SIGEV_THREAD;evp.sigev_notify_function = timer_thread;if (timer_create(CLOCK_REALTIME, &evp, &timerid) == -1) { perror("fail to timer_create"); return -1;; } printf("timer_create timerid = %d\n", timerid);it.it_interval.tv_sec = 0;it.it_interval.tv_nsec = atoi(argv[1]); it.it_value.tv_sec = 1;it.it_value.tv_nsec = 0; if (timer_settime(&timerid, 0, &it, NULL) == -1) { perror("fail to timer_settime"); return -1;} while(1) {sleep(1);}return 0;
}
编译如下:
csky-abiv2-linux-g++ loop.cc -o loop -lrt
2.2 测试结果
分别采用不同周期(5ms
、10ms
、25ms
、40ms
、100ms
),对两种方式进行测试结果如下
https://www.cnblogs.com/arnoldlu/p/12112225.html
说明起线程执行任务,开销还是存在的;在新建线程数量较小情况下,对CPU
占用率影响较低。但是随着新建线程数量增加,对CPU
占用率的影响会越来越明显,严重时系统调度能力会下降。
3. 解决方法
针对线程名混乱的情况,在有了线程树形结构之后,结合代码比较容易找到入口点,修改线程名称prctl()/pthread_setname_np()。
修改usb_server_list:179
的处理方式,改成单线程处理任务。一是降低系统线程创建销毁的开销,二是让top
统计CPU
占用率更加准确。
有了这两者,就可以明确线程占用率和功能对应关系,进入具体线程进行分析。
这篇关于一个100%CPU占用率,但是线程名混乱和top不准问题定位过程的文章就介绍到这儿,希望我们推荐的文章对编程师们有所帮助!