跳到正文
博客园· SkyOnSky·· 3 小时前AI 评分22

Linux 程序性能分析（二）：用 perf 定位大模型推理程序空载占用 200% CPU 的实例

Linux程序性能分析（二）--- 实例分析1 - SkyOnSky

AI 导读

基于高通参考代码实现的大模型推理程序在无 HTTP 请求时仍占用约 200% CPU，作者用 perf record 按 pid 采样并借助符号文件还原堆栈，定位到 qualla::ThreadPool::loop 中线程反复 lock/unlock std::mutex 的死循环。

正文

PS：要转载请注明出处，本人版权所有。

PS: 这个只是基于《我自己》的理解，

如果和你的原则及想法相冲突，请谅解，勿喷。

环境说明

  无

前言

  在《Linux程序性能分析（一）---perf原理分析》 https://www.cnblogs.com/Iflyinsky/p/22507762 中，我已经简单分析了perf的工作原理，现在以两篇工作中实际遇到的问题来实际分析。

  先来一篇简单的，可以快速上手的。

通过perf分析用户态的程序

  本示例是一个典型的技术架构设计与实际落地工程实践取舍的问题，具体是：我们自己根据高通提供的参考代码，实现了一版自己的大模型推理程序，并通过http接口暴露了openai api。在客户的实际使用过程中，发现在没有任何http请求时，这个推理程序会莫名的占用200%左右的cpu，具体如下图：

rep_img

  根据我们之前的经验，直接抓取所有cpu的perf堆栈采样信息，看看到底哪些函数在跑？这次由于我们知道是哪个程序，因此我们直接传入pid来针对程序进行采集：

echo 0 > /proc/sys/kernel/kptr_restrict
echo -1 > /proc/sys/kernel/perf_event_paranoid
perf record -a -g -F 99 -p target_pid -- sleep 5
perf report --no-children --stdio > perf_data.txt

  然后我得到了原始堆栈结构：

# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 948  of event 'cycles'
# Event count (approx.): 27416695488
#
# Overhead  Command  Shared Object              Symbol                                 
# ........  .......  .........................  .......................................
#
    15.24%  api      libc.so.6                  [.] __aarch64_swp4_rel
            |
            ---__aarch64_swp4_rel
               0x781b82d0f0
               0x78247231fc
               start_thread
               thread_start

    15.20%  api      libc.so.6                  [.] __aarch64_cas4_acq
            |
            ---__aarch64_cas4_acq
               0x781b82d0bc
               0x78247231fc
               start_thread
               thread_start

    11.97%  api      [unknown]                  [k] 0xffffffe3fcaa3604
            |
            ---0xffffffe3fcaa3604
               0xffffffe3fcaa355c
               0xffffffe3fe620620
               0xffffffe3fe620598
               0xffffffe3fca1164c
               |          
               |--8.10%--__GI___lll_lock_wake
               |          0x781b82d0f0
               |          0x78247231fc
               |          start_thread
               |          thread_start
               |          
                --3.87%--__GI___lll_lock_wait
                          pthread_mutex_lock@@GLIBC_2.17
                          0x781b82d0bc
                          0x78247231fc
                          start_thread
                          thread_start

     6.25%  api      libc.so.6                  [.] __aarch64_swp4_acq
            |
            ---__aarch64_swp4_acq
               pthread_mutex_lock@@GLIBC_2.17
               0x781b82d0bc
               0x78247231fc
               start_thread
               thread_start

     6.11%  api      [unknown]                  [k] 0xffffffe3fcc94744
            |
            ---0xffffffe3fcc94744
               0xffffffe3fcc93984
               0xffffffe3fcc9c010
               0xffffffe3fcaa3724
               0xffffffe3fcaa3684
               0xffffffe3fcaa355c
               0xffffffe3fe620620
               0xffffffe3fe620598
               0xffffffe3fca1164c
               __GI___lll_lock_wake
               0x781b82d0f0
               0x78247231fc
               start_thread
               thread_start

     5.63%  api      [unknown]                  [k] 0xffffffe3fcc9470c
            |
            ---0xffffffe3fcc9470c
               0xffffffe3fcc93984
               0xffffffe3fcc9c010
               0xffffffe3fcaa3724
               0xffffffe3fcaa3684
               0xffffffe3fcaa355c
               0xffffffe3fe620620
               0xffffffe3fe620598
               0xffffffe3fca1164c
               __GI___lll_lock_wake
               0x781b82d0f0
               0x78247231fc
               start_thread
               thread_start

  由于原始堆栈结构里面有很多地址是未知的（因为产品化的so，一般都做了符号管制），这个时候，我们需要从下载和so对应的符号文件（这个需要提前准备，也是一个比较好的生产级产品化做法），然后让AI使用内核地址、so地址去解决对应的符号，得到了下面的符号化的堆栈结构：

# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 948  of event 'cycles'
# Event count (approx.): 27416695488
#
# Overhead  Command  Shared Object              Symbol                                 
# ........  .......  .........................  .......................................
#
    15.24%  api      libc.so.6                  [.] __aarch64_swp4_rel
            |
            ---__aarch64_swp4_rel
               qualla::ThreadPool::loop+0x160
               execute_native_thread_routine
               start_thread
               thread_start

    15.20%  api      libc.so.6                  [.] __aarch64_cas4_acq
            |
            ---__aarch64_cas4_acq
               qualla::ThreadPool::loop+0x12c
               execute_native_thread_routine
               start_thread
               thread_start

    11.97%  api      [unknown]                  [k] el0_svc_common
            |
            ---el0_svc_common+0x38
               do_el0_svc+0x28
               el0_svc+0x24
               el0t_64_sync_handler+0x88
               el0t_64_sync+0x1b8
               |          
               |--8.10%--__GI___lll_lock_wake
               |          qualla::ThreadPool::loop+0x160
               |          execute_native_thread_routine
               |          start_thread
               |          thread_start
               |          
                --3.87%--__GI___lll_lock_wait
                          pthread_mutex_lock@@GLIBC_2.17
                          qualla::ThreadPool::loop+0x12c
                          execute_native_thread_routine
                          start_thread
                          thread_start

     6.25%  api      libc.so.6                  [.] __aarch64_swp4_acq
            |
            ---__aarch64_swp4_acq
               pthread_mutex_lock@@GLIBC_2.17
               qualla::ThreadPool::loop+0x12c
               execute_native_thread_routine
               start_thread
               thread_start

     6.11%  api      [unknown]                  [k] futex_wake
            |
            ---futex_wake+0x190
               do_futex+0x1a4
               __arm64_sys_futex+0x234
               invoke_syscall+0x60
               el0_svc_common+0xb8
               do_el0_svc+0x28
               el0_svc+0x24
               el0t_64_sync_handler+0x88
               el0t_64_sync+0x1b8
               __GI___lll_lock_wake
               qualla::ThreadPool::loop+0x160
               execute_native_thread_routine
               start_thread
               thread_start

     5.63%  api      [unknown]                  [k] futex_wake
            |
            ---futex_wake+0x158
               do_futex+0x1a4
               __arm64_sys_futex+0x234
               invoke_syscall+0x60
               el0_svc_common+0xb8
               do_el0_svc+0x28
               el0_svc+0x24
               el0t_64_sync_handler+0x88
               el0t_64_sync+0x1b8
               __GI___lll_lock_wake
               qualla::ThreadPool::loop+0x160
               execute_native_thread_routine
               start_thread
               thread_start

  其实通过上面的堆栈，我们马上就看出来了有线程在死循环，并反复的lock/unlock 这个 std::mutex对象。直接根据符号，查看对应的源码，果然，代码里面，为了kvcache的响应及时性，强行死循环运行，避免了sleep/wait/notify等带来的推理时的开销。其他代码示意如下：

std::mutex mtx;
void ThreadPool::loop()
{
    std::unique_lock<std::mutex> lock(mtx, std::defer_lock);
    while(1){
        lock.lock();

        // do something

        lock.unlock();
    }
}

  最后，根据实际情况，我们没有改变死循环的核心代码，我们采用的方式是，当有推理任务时，通知线程开始死循环运行，既保证了kvcache的实时性，也保证了模型不推理的情况下，资源占用是比较小的。但是在模型推理时，并没有解决死循环带来的cpu空载开销。然后现在我们再看看cpu的占用情况。

rep_img

  发现在系统空载时，成功解决了问题。

后记

  站在这个AI可以帮你自动解决类似问题的时代，手把手实际例子来验证原理是一个有趣的事情，也可以加强对这个的原理理解，使得我更加善于使用AI排查问题。

参考文献

  • 无

打赏、订阅、收藏、丢香蕉、硬币，请关注公众号（攻城狮的搬砖之路）

qrc_img

PS: 请尊重原创，不喜勿喷。

PS: 要转载请注明出处，本人版权所有。

PS: 有问题请留言，看到后我会第一时间回复。

来源：博客园 · cnblogs.com

推理能力部署工程教程实践#教程/实践#推理#部署/工程