首页 » ORACLE 9i-23ai, 系统相关 » 如何在 Linux 上诊断高 %Sys CPU

如何在 Linux 上诊断高 %Sys CPU

Linux中CPU负载高必须引起关注,通常需要先查看CPU使用类型,CPU使用分为us(用户进程)还是sy(内核调用), sys通常不应该超过user , 数据库专用主机主要来自用户级的 CPU 时间(无论是“user”还是“nice”)。因此,当 CPU 时间的大部分时间花在内核(sys)中时,这表明出现了问题, %sys一般也不超过10%, 但是%sys超高这样的问题遇到好多次,原因有:NFS4 bug、 swap IO、安装了linux杀毒如卡巴斯基、3rd party modules、NUMA、内存碎片、cpu 中断、内核参数配置错误等,查看方法如TOP

top - 15:06:12 up 100 days, 19:37, 28 users,  load average: 142.57, 143.03, 126.
Tasks: 10637 total, 106 running, 10531 sleeping,   0 stopped,   0 zombie
%Cpu(s): 17.7 us, 39.4 sy,  0.0 ni, 40.9 id,  1.0 wa,  0.0 hi,  1.0 si,  0.0 st
 
KiB Mem : 10561102+total, 18588532 free, 69364883+used, 34387289+buff/cache
KiB Swap: 16777212 total, 16715004 free,    62208 used. 32979763+avail Mem
 
   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
  5294 oracle    20   0  518.5g  62236  43484 R 100.0  0.0   0:22.10 oracle_52+
119947 oracle    20   0  518.5g  57024  41288 R 100.0  0.0  30:52.57 oracle_11+
128631 oracle    20   0  518.5g  44424  31992 R 100.0  0.0   0:07.68 oracle_12+
 45650 oracle    20   0  518.5g  65336  48492 R  99.3  0.0   2:50.30 oracle_45+
 79648 oracle    20   0  518.5g  68044  49720 R  99.3  0.0  11:01.96 oracle_79+
117514 oracle    20   0  518.8g 149480  87108 S  99.3  0.0   1182:26 ora_scmn_+
117566 oracle    20   0  518.8g 150252  88152 S  99.3  0.0   1173:29 ora_scmn_+
117618 oracle    20   0  518.8g 152764  88040 S  99.3  0.0   1191:01 ora_scmn_+

其它还有vmstat,pidstat、dstat、mpstat,SAR等

什么是SYS CPU 时间?

这个“sys”CPU 时间是多少?它指的是 CPU 在内核模式下运行的时间——通常是这个系统调用列表中列出的函数之一。

如何诊断原因

使用strace和gdb排查程序消耗sys的原因

我们想找出特定进程导致系统 CPU 时间异常高的原因。最上面的工具将说明哪个进程正在使用大部分 CPU——但是您可能需要选择一个单独的线程来挖掘。要在 Linux 上列出进程中的线程,请使用以下命令:

ps -AL |grep进程名

strace工具对于确定特定调用是否过多非常有用。该工具对调试很有用,因为它记录了进程正在进行的系统调用。计数选项 ( -c ) 提供有关进程的一些性能信息,以查看哪个调用占用了多少系统 CPU 时间:

anbob.com# strace -c -p xxx
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 69.16    0.764598           4    214801           getrusage
 25.20    0.278548         142      1959           poll
  3.67    0.040564          13      3101           write

另一种技术是转储异常进程中所有线程的运行堆栈:

anbob.com# for i in `ps -AL |grep process_name |cut -c 7-12`; do \
    echo === $i ===; \
    gdb --q --n --ex bt --batch --pid $i; \
  done 2>&1 |tee /tmp/stacks.txt

通过perf分析

anbob.com# perf record -agT -- sleep 10
anbob.com# perf archive
anbob.com# perf report --sort=comm --stdio
anbob.com# perf top

通过crash分析

如果系统crash并且dump出了vmcore(vmcore是通过kdump这样的工具dump出内存),可以参考crash来排查vmcore

内存碎片

有时当sys cpu%高时,perf 可以看到_reset_isolation_suitable 占用非常高时可能是OS的内存碎片原因,Linux内核提供了 pagetypeinfo,slabinfo,buddyinfo 等方面提供分析,查看buddyinfo分析系统内存碎片

# cat /proc/buddyinfo | awk -v ps="`getconf PAGESIZE`" -v date="`date`" -v host="`hostname`" \
'BEGIN{printf("\nFragmentation Report\nLow is Order 1-4, High is order 5-9, Normal is order 10-11\n%s\t%s\n\n",host,date)} {\
L= ps * ( ($5 * 1) + ($6 * 2) + ($7 * 4) + ($8 * 8) ); \
H= ps * ( ($9 * 16) + ($10 * 32) + ($11 * 64) + ($12 * 128) + ($13 * 256)  ); \
N= ps * ( ($14 * 512) + ($15 * 1024) ); \
T=L+H+N; \
printf("%s\tTotal: %8dM\tLow: %02.2f%%\tHigh: %02.2f%%\tNormal: %02.2f%%\n",\
$1" "$2" "$3" "$4,T/1024/1024,(L/T)*100,(H/T)*100,(N/T)*100);}'

NORMAL: 正常使用的物理内存区域,大部分申请的内存都使用的是该区域
LOW:低水位,代表内存已经开始吃紧,需要启动回收页内核线性kswapped去回收内存
HIGH:高水位,代表内存还是足够的

与碎片相关的内核调优参数:

vm.extfrag_threshold = 500
vm.min_free_kbytes = 45056
vm.watermark_scale_factor = 10

与ORACLE性能相关的案例

案例1

因为启用NUMA 分配了过多的共享内存段, 而session的创建与退出需要操作共享内存段,因为共享内存段数目过多,退出时间变长, 如果再遇到logon storm 大量的短连接,就可能会出现这样的%sys 内核调用。可以使用strace -c或truss -d去记录调用时间。

案例2

因为配置了不合理的kernel.sem 信号量,配置过大,而导致SCMN后台线程使用sys 增加, perf  发现semtimedop调用较多如下:

      start_thread                                                                                                                                              
     skgp_thread_async_main                                                                                                                                    
     ssthrdmain                                                                                                                                                
     opirip                                                                                                                                                    
     ksbdispatch                                                                                                                                               
     ksvrdp_cbk                                                                                                                                                
     ksvrdp_int                                                                                                                                                
   - kjblcrspslmain                                                                                                                                            
      - 6.79% kjblcrslmain                                                                                                                                     
         - 6.77% kslwaitctx                                                                                                                                    
            - 6.77% ksliwat                                                                                                                                    
               - 6.76% skgpwwait                                                                                                                               
                  - 6.75% semtimedop                                                                                                                           
                     - 6.74% system_call_fastpath                                                                                                              
                        - 6.74% sys_semtimedop                                                                                                                 
                           - 6.74% SYSC_semtimedop                                                                                                             
                              - 6.72% _raw_qspin_lock                                                                                                          
                                 - 6.72% queued_spin_lock_slowpath                                                                                             
                                      6.58% native_queued_spin_lock_slowpath                                                                                   
+    6.79%     0.00%  ora_cr00_scsbgj  oracle                   [.] skgp_thread_async_main   

在High SYS CPU Usage ON LMS Thread (SCMN/CR00/RS01) During High Workload (Doc ID 2707048.1) 和 http://www.minniebaby.tech/2022/06/10/%e6%a1%88%e4%be%8b%ef%bc%9atroubleshooting-high-sys-cpu-usage-on-19c-rac/ 记录了这个问题。

打赏

对不起,这篇文章暂时关闭评论。