zoukankan      html  css  js  c++  java
  • 一个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=0
                 cat-165   [000] ...1    53.738804: task_rename: pid=165 oldcomm=sh newcomm=cat oom_score_adj=0
                  sh-153   [000] ....    84.638270: task_newtask: pid=166 comm=sh clone_flags=1200011 oom_score_adj=0
       xchip_runtime-166   [000] ...1    84.645910: task_rename: pid=166 oldcomm=sh newcomm=xchip_runtime oom_score_adj=0
       xchip_runtime-166   [000] ....    85.098260: task_newtask: pid=167 comm=xchip_runtime clone_flags=3d0f00 oom_score_adj=0
       Log2Hostflush-167   [000] ...1    85.099145: task_rename: pid=167 oldcomm=xchip_runtime newcomm=Log2Hostflush oom_score_adj=0
       xchip_runtime-166   [000] ....    85.133881: task_newtask: pid=168 comm=xchip_runtime clone_flags=3d0f00 oom_score_adj=0
     usb_server_list-168   [000] ...1    85.134077: task_rename: pid=168 oldcomm=xchip_runtime newcomm=usb_server_list oom_score_adj=0
     usb_server_list-168   [000] ....   116.497292: task_newtask: pid=169 comm=usb_server_list clone_flags=3d0f00 oom_score_adj=0
            coreComm-169   [000] ...1   116.501998: task_rename: pid=169 oldcomm=usb_server_list newcomm=coreComm oom_score_adj=0
     usb_server_list-168   [000] ....   116.514232: task_newtask: pid=170 comm=usb_server_list clone_flags=3d0f00 oom_score_adj=0

    1.2 脚本分析生成线程树形结构

    在jupyter-notebook中读取trace.txt文件,然后从中提取关键信息,pid、comm、父pid、子pid列表。

    以pid为字典键值,分析过程如下。

    import re
    
    process_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):
            continue
        proc = 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=0
        task_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=0
        task_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']+':'+key
            for child1 in item['child']:
                print "    |-2-"+process_tree[child1]['comm']+':'+child1
                for child2 in process_tree[child1]['child']:
                    print "        |-3-"+process_tree[child2]['comm']+':'+child2
                    for child3 in process_tree[child2]['child']:
                        print "            |-4-"+process_tree[child3]['comm']+':'+child3
                        for child4 in process_tree[child3]['child']:
                            print "                |-5-"+process_tree[child4]['comm']+':'+child4
                            for child5 in process_tree[child4]['child']:
                                print "                    |-6-"+process_tree[child5]['comm']+':'+child5
                                for child6 in process_tree[child5]['child']:
                                    print "                        |-7-"+process_tree[child6]['comm']+':'+child6
                                    for 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 40000
    
    void 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.
    ", 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
    ", 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 40000
    
    void 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.
    ", 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
    ", 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),对两种方式进行测试结果如下。

      loop pthread_4simu 分析
    5ms 两者总的CPU占用率相差20%,
    10ms 两者总的CPU占用率相差18%
    25ms 两者总的CPU占用率相差8%
    40ms 两者总的CPU占用率相差1%
    100ms 两者总的CPU占用率基本持平

    说明起线程执行任务,开销还是存在的;在新建线程数量较小情况下,对CPU占用率影响较低。但是随着新建线程数量增加,对CPU占用率的影响会越来越明显,严重时系统调度能力会下降。

    3. 解决方法

    针对线程名混乱的情况,在有了线程树形结构之后,结合代码比较容易找到入口点,修改线程名称prctl()/pthread_setname_np()。

    修改usb_server_list:179的处理方式,改成单线程处理任务。一是降低系统线程创建销毁的开销,二是让top统计CPU占用率更加准确。

    有了这两者,就可以明确线程占用率和功能对应关系,进入具体线程进行分析。

  • 相关阅读:
    Knockout应用开发指南 第八章:简单应用举例(2)
    微软ASP.NET站点部署指南(7):生产环境部署
    Knockout应用开发指南 第七章:Mapping插件
    《Microsoft Sql server 2008 Internals》读书笔记第九章Plan Caching and Recompilation(6)
    《Microsoft Sql server 2008 Internals》读书笔记第九章Plan Caching and Recompilation(5)
    《Microsoft Sql server 2008 Internals》读书笔记第九章Plan Caching and Recompilation(3)
    《Microsoft Sql server 2008 Internals》读书笔记第九章Plan Caching and Recompilation(9)
    《Microsoft Sql server 2008 Internals》读书笔记第九章Plan Caching and Recompilation(8)
    Microsoft Visual Studio .NET 2003 引导程序插件下载地址(非官方)
    Vs2010在没有安装SQL Server 2005/2008 Express时如何连接MDF数据文件?
  • 原文地址:https://www.cnblogs.com/arnoldlu/p/12112225.html
Copyright © 2011-2022 走看看