写在前面博文内容涉及工具来自《BPF Performance Tools》 一书,CPU性能指标涉及:系统短期创建的线程进程跟踪进程线程的CPU运行时长,脱离时长统计线程的运行队列长度,等待延时时间,有多少线程在等待,多核队列是否均衡跟踪线程运行调用栈和脱离调用栈跟踪线程 软硬中断 CPU时间,LLC 三级缓存命中率分析内核态系统调用跟踪分析这里感谢译本的作者,抱着英文版的瞅了好久...,有条件小伙伴可以支持下理解不足小伙伴帮忙指正 :),生活加油
喜欢文字的人,大多敏感且心软,忽然不快乐忽然被回忆揪住心脏忽然沉默到泪流。或许是内心孤独的缘故,轻易便可从他人的故事里看到自己的影子所以,悲伤总要比别人多一半。
实验环境,大部分是在 Rocky 上完成,Demo 需要 root 如果你用普通用户执行,会报错
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$hostnamectl Static hostname: vms99.liruilongs.github.io Icon name: computer-vm Chassis: vm Machine ID: ea70bf6266cb413c84266d4153276342 Boot ID: 0d01838b0095494c82d1befb174a317d Virtualization: vmware Operating System: Rocky Linux 8.9 (Green Obsidian) CPE OS Name: cpe:/o:rocky:rocky:8:GA Kernel: Linux 4.18.0-513.9.1.el8_9.x86_64 Architecture: x86-64┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
传统的性能工具提供了对 CPU 各种用量的测量,比如CPU 的使用率(mpstat),平均负载(uptime),上下文切换(perf),软硬中断(proc/*)的CPU使用率,运行队列长度(mpstat)等,
BPF 跟踪工具可以提供更多细节信息,包括内核态和用户态的埋点跟踪,利用PMC来获取定时采样的CPU数据和CPU 内部数据
在使用 BPF 工具的时候需要考虑工具所带来的消耗问题,最糟糕的情况下,针对调度器的跟踪可能会消耗 10% 的系统性能。
通过 BPF 工具可以回答以下这些问题:
系统短期创建了哪些新进程(线程)?execsnoopexecsnoop(8) 可以列出新进程运行信息,是一个CPU调度监控工具,用于跟踪全系统中的新进程执行信息。利用这个工具可以找到 消耗大量CPU的短期进程,并且可以用来分析软件执行过程,包括启动脚本等。
execsnoop(8)直接跟踪 execve(2)系统调用(是最常用的exec(2)变体),可以直接打印 execve(2)的调用参数和返回值。
代码语言:javascript代码运行次数:0运行复制┌──[root@liruilongs.github.io]-[/usr/share/bcc/tools]└─$./execsnoopPCOMM PID PPID RET ARGSsshd 50066 1076 0 /usr/sbin/sshd -D -Runix_chkpwd 50068 50066 0 rootunix_chkpwd 50069 50066 0 rootbash 50071 50070 0 /bin/bashid 50072 50071 0 /usr/bin/id -unhostnamectl 50074 50073 0 /usr/bin/hostnamectl --transient8 50075 1 0 /proc/self/fd/8 --deserialize 76 --log-level info --log-target journal-or-kmsgsystemd-hostnam 50075 1 0 /usr/lib/systemd/systemd-hostnamedgrepconf.sh 50077 50071 0 /usr/libexec/grepconf.sh -cgrep 50078 50077 0 /usr/bin/grep -qsi ^COLOR.*none /etc/GREP_COLORS.................................
一般情况下 execsnoop(8)用来寻找高频出现、消耗资源的短期进程,比如那种频繁创建销毁的,或者是那种一直新建连接的。
列表解释:
PCOMM:进程名称PID:进程IDPPID:父进程IDRET:系统调用返回值,0表示成功ARGS:系统调用的参数这里看一个特殊情况,用 py 的 multiprocessing 模块创建多个进程
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$cat jc.pyimport multiprocessingimport timedef short_task(duration): print(f"Task started, will run for {duration} seconds.") time.sleep(duration) print(f"Task finished.")if __name__ == "__main__": processes = [] num_tasks = 5 task_duration = 2 # Duration of each task in seconds for _ in range(num_tasks): p = multiprocessing.Process(target=short_task, args=(task_duration,)) processes.append(p) p.start() for p in processes: p.join() print("All tasks completed.")┌──[root@vms99.liruilongs.github.io]-[~]└─$
运行命令测试
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$python jc.pyTask started, will run for 2 seconds.Task started, will run for 2 seconds.Task started, will run for 2 seconds.Task started, will run for 2 seconds.Task started, will run for 2 seconds.Task finished.Task finished.Task finished.Task finished.Task finished.All tasks completed.
通过 execsnoop 来跟踪新的进程
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./execsnoopPCOMM PID PPID RET ARGSpython3 37950 2082 0 /usr/bin/python3 jc.py
会发现只有一个,这是为什么?这是因为默认情况下,multiprocessing 使用 os.fork() 来创建子进程,而没有执行 os.exec*() ,所以 execsnoop 无法捕捉到这些子进程的创建,前面我们有讲, execsnoop 主要跟踪 exec 以及对应的变体。
在执行的时候打印一下方法栈
代码语言:javascript代码运行次数:0运行复制........... File "/root/jc.py", line 20, in <module> p.start() File "/usr/lib/python3.10/multiprocessing/process.py", line 121, in start self._popen = self._Popen(self) File "/usr/lib/python3.10/multiprocessing/context.py", line 224, in _Popen return _default_context.get_context().Process._Popen(process_obj) File "/usr/lib/python3.10/multiprocessing/context.py", line 281, in _Popen return Popen(process_obj) File "/usr/lib/python3.10/multiprocessing/popen_fork.py", line 19, in __init__ self._launch(process_obj) File "/usr/lib/python3.10/multiprocessing/popen_fork.py", line 71, in _launch code = process_obj._bootstrap(parent_sentinel=child_r) File "/usr/lib/python3.10/multiprocessing/process.py", line 314, in _bootstrap self.run() File "/usr/lib/python3.10/multiprocessing/process.py", line 108, in run self._target(*self._args, **self._kwargs) File "/root/jc.py", line 8, in short_task traceback.print_stack()
我们可以在源码的这个位置看到
代码语言:javascript代码运行次数:0运行复制┌──[root@liruilongs.github.io]-[~] └─$vim +71 /usr/lib/python3.10/multiprocessing/popen_fork.py.......... 62 def _launch(self, process_obj): 63 code = 1 64 parent_r, child_w = os.pipe() 65 child_r, parent_w = os.pipe() 66 self.pid = os.fork() 67 if self.pid == 0: 68 try: 69 os.close(parent_r) 70 os.close(parent_w) 71 code = process_obj._bootstrap(parent_sentinel=child_r) 72 finally: 73 os._exit(code).......
在运维脚本中我们经常会用到 subprocess 模块来执行 命令行操作,也会遇到这种情况,默认情况下,subprocess 使用 os.fork() 和 os.exec*() 组合的方式来创建子进程,如果类似 multiprocessing ,只使用了 os.fork 但是没有使用 exec*(),就会无法被跟踪。
代码语言:javascript代码运行次数:0运行复制import subprocess# 使用 subprocess.PIPE 会导致 execsnoop 无法捕获子进程process = subprocess.Popen(['python', 'script.py'], stdout=subprocess.PIPE)# 使用 subprocess.DEVNULL 可以让 execsnoop 捕获子进程process = subprocess.Popen(['python', 'script.py'], stdout=subprocess.DEVNULL)
在编码中一般以线程为单位进行编码,线程也是 CPU 上下文切换的基本单位,那么线程的创建如何被跟踪?
thrcadsnoopthrcadsnoop(8),可以用来跟踪线程的创建,通过跟踪 pthread_create() 库调⽤来跟踪线程的创建
这里在看一个 Demo,通过 py 的 threading 模块创建多个线程
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$cat xc.pyimport threadingimport timedef worker(): """线程执行的任务""" time.sleep(3) print(f"Thread {threading.current_thread().name} is running")# 创建并启动多个线程threads = []for i in range(5): t = threading.Thread(target=worker, name=f"Thread-{i}") threads.append(t) t.start()# 等待所有线程完成for t in threads: t.join()print("All threads have finished.")┌──[root@vms99.liruilongs.github.io]-[~]└─$
运行 Demo
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$python xc.pyThread Thread-0 is runningThread Thread-1 is runningThread Thread-3 is runningThread Thread-2 is runningThread Thread-4 is runningAll threads have finished.
通过输出可以看到线程的创建速度,以及创建线程的父ID,和线程的函数入口。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$threadsnoopTIME(ms) PID COMM FUNC0 12177 b'python3' b'[unknown]'0 12177 b'python3' b'[unknown]'0 12177 b'python3' b'[unknown]'0 12177 b'python3' b'[unknown]'0 12177 b'python3' b'[unknown]'
可以看大函数状态均为 unknown,通常意味着 threadsnoop 无法获取当前线程正在执行的具体函数名。可能是由于缺乏调试信息或其他原因。
可以通过源码简单了解下
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$cat /usr/share/bcc/tools/threadsnoop#!/usr/libexec/platform-python# @lint-avoid-python-3-compatibility-imports## threadsnoop List new thread creation.# For Linux, uses BCC, eBPF. Embedded C.## Copyright (c) 2019 Brendan Gregg.# Licensed under the Apache License, Version 2.0 (the "License").# This was originally created for the BPF Performance Tools book# published by Addison Wesley. ISBN-13: 9780136554820# When copying or porting, include this comment.## 02-Jul-2019 Brendan Gregg Ported from bpftrace to BCC.from __future__ import print_functionfrom bcc import BPF# load BPF programb = BPF(text="""#include <linux/sched.h>struct data_t { u64 ts; u32 pid; u64 start; char comm[TASK_COMM_LEN];};BPF_PERF_OUTPUT(events);void do_entry(struct pt_regs *ctx) { struct data_t data = {}; data.ts = bpf_ktime_get_ns(); data.pid = bpf_get_current_pid_tgid() >> 32; data.start = PT_REGS_PARM3(ctx); bpf_get_current_comm(&data.comm, sizeof(data.comm)); events.perf_submit(ctx, &data, sizeof(data));};""")# Since version 2.34, pthread features are integrated in libctry: b.attach_uprobe(name="pthread", sym="pthread_create", fn_name="do_entry")except Exception: b.attach_uprobe(name="c", sym="pthread_create", fn_name="do_entry")print("%-10s %-7s %-16s %s" % ("TIME(ms)", "PID", "COMM", "FUNC"))start_ts = 0# process eventdef print_event(cpu, data, size): global start_ts event = b["events"].event(data) if start_ts == 0: start_ts = event.ts func = b.sym(event.start, event.pid) if (func == "[unknown]"): func = hex(event.start) print("%-10d %-7d %-16s %s" % ((event.ts - start_ts) / 1000000, event.pid, event.comm, func))b["events"].open_perf_buffer(print_event)while 1: try: b.perf_buffer_poll() except KeyboardInterrupt: exit()┌──[root@vms99.liruilongs.github.io]-[~]└─$
BPF 程序无法确定线程创建时调用的具体函数名
系统进程运行时长是多长?为什么退出了?exitsnoopexitsnoop(8)'是一个BCC 工具,用于跟踪进程的退出事件,打印出进程的总运行时长和退出原因。运行时长是指进程从创建到终止的时长,包括CPU运行时间和非运行时间(就绪和等待)。
使用的是sched:sched_process_exit内核跟踪点和它的参数信息,同时利用 bpf_get_current_task()以便从task 结构体中读取起始信息(这并不是一个稳定接口)。
这里我们使用上面的创建进程的 py 脚本来观察 exitsnoop
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$python jc.pyTask started, will run for 2 seconds.Task started, will run for 2 seconds.Task started, will run for 2 seconds.Task started, will run for 2 seconds.Task started, will run for 2 seconds.Task finished.Task finished.Task finished.Task finished.Task finished.All tasks completed.
通过下面的输出可以看到,exitsnoop 和 execsnoop 虽然都可以用来调试短期进程,但是是的有区别的,exitsnoop 可以跟踪那些 没有调用 exec以及变体创建进程的进程,他同时会输出父进程和子进程的数据。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./exitsnoopPCOMM PID PPID TID AGE(s) EXIT_CODEpython3 37904 37903 37904 2.00 0python3 37908 37903 37908 2.00 0python3 37907 37903 37907 2.00 0python3 37906 37903 37906 2.00 0python3 37905 37903 37905 2.01 0python3 37903 2082 37903 2.04 0
输出信息中可以看到,最长时间的进程为父进程,上面的进程都为子进程。同时展示了线程ID,EXIT_CODE 列可以看到线程的退出状态码
线程每次唤醒时在CPU上花费多长时间?cpudist通过 cpudist 可以展示每次线程唤醒之后在CPU上执行的时长分布的直方图。
需要说明 cpudist 在内部跟踪 CPU 调度器的上下文切换事件,在生产环境中如果频繁的上下文切换,那么这个工具的额外开销就很严重。
可以看到在 10 秒中 8192 -> 16383 us 为最多的时间区间,即线程在CPU上执行的时间相对较长,没有发生频繁的上下文切换。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$cpudist 10 1Tracing on-CPU time... Hit Ctrl-C to end. usecs : count distribution 0 -> 1 : 0 | | 2 -> 3 : 16 | | 4 -> 7 : 250 |*** | 8 -> 15 : 232 |*** | 16 -> 31 : 471 |******* | 32 -> 63 : 158 |** | 64 -> 127 : 70 |* | 128 -> 255 : 34 | | 256 -> 511 : 5 | | 512 -> 1023 : 0 | | 1024 -> 2047 : 12 | | 2048 -> 4095 : 45 | | 4096 -> 8191 : 160 |** | 8192 -> 16383 : 2621 |****************************************| 16384 -> 32767 : 602 |********* | 32768 -> 65535 : 288 |**** | 65536 -> 131071 : 27 | | 131072 -> 262143 : 2 | |┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
使用 -m 参数可以按照毫秒数输出,这时可以看到 CPU 上线文切换非常快,每个线程运行时间为 0-1 毫秒,也就是 0-1000 微秒。实际上这是在一个空闲的机器的执行的。如果在一个生产系统,频繁的上线文切换,而且CPU 唤醒之后执行时间很少,就可能存在性能问题
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$cpudist -mTracing on-CPU time... Hit Ctrl-C to end.^C msecs : count distribution 0 -> 1 : 1019 |****************************************| 2 -> 3 : 0 | | 4 -> 7 : 0 | | 8 -> 15 : 1 | |┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$cpu
profile 是一个定时采样调用栈信息并汇报调用栈出现频率信息的一个工具,该工具的消耗基本可以忽略不计,而且采样频率可以随时调整。
默认情况下,该工具会以 49Hz 的频率同时采样所有的 CPU 内核态和用户态的调用栈信息。但是用户态的栈信息往往会获取不到
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$profileSampling at 49 Hertz of all threads by user + kernel stack... Hit Ctrl-C to end.^C _raw_spin_unlock_irqrestore _raw_spin_unlock_irqrestore prepare_to_swait_event rcu_gp_kthread kthread ret_from_fork - rcu_sched (14) 1 kmem_cache_alloc_node kmem_cache_alloc_node __alloc_skb __ip_append_data.isra.50 ip_append_data.part.51 ip_send_unicast_reply tcp_v4_send_reset tcp_v4_rcv ip_protocol_deliver_rcu ip_local_deliver_finish ip_local_deliver ip_rcv __netif_receive_skb_core process_backlog __napi_poll net_rx_action __softirqentry_text_start do_softirq_own_stack do_softirq.part.16 __local_bh_enable_ip ip_finish_output2 ip_output __ip_queue_xmit __tcp_transmit_skb tcp_connect tcp_v4_connect __inet_stream_connect inet_stream_connect __sys_connect __x64_sys_connect do_syscall_64 entry_SYSCALL_64_after_hwframe [unknown] - haproxy (1203) 1 show_vma_header_prefix show_vma_header_prefix show_map_vma show_map seq_read vfs_read ksys_read do_syscall_64 entry_SYSCALL_64_after_hwframe [unknown] [unknown] - awk (39726) 1............. ┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
通过输出我们可以看到,第一个采集的线程为 rcu_sched,PID 为 14, 采集可一次。与内核的 RCU 机制有关。
第二个调用栈数据为 haproxy 进程,pid 为 1203,通过内核态函数的调用可以看到主要进网络数据包的处理,以及TCP 连接的建立。
kmem_cache_alloc_node 表示分配内存。__ip_append_data 和 ip_send_unicast_reply 表示处理 IP 数据。tcp_v4_send_reset 和 tcp_v4_rcv 表示 TCP 协议的处理。__sys_connect 和 __x64_sys_connect 表示进行系统调用以建立连接。实际中生产环境, 上面的输出会很多,所以一般情况会通过火焰图快速理解 prefile 的命令的输出。
火焰图通过 -f 折叠输出,通过 -a 来标记 内核态和用户态函数。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$profile -af 20 > profilelrl.log
需要使用 FlameGraph 项目来输出,所以这里我们克隆项目
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$git clone https://github.com/brendangregg/FlameGraph.git正克隆到 'FlameGraph'...remote: Enumerating objects: 1285, done.remote: Counting objects: 100% (707/707), done.remote: Compressing objects: 100% (146/146), done.remote: Total 1285 (delta 584), reused 575 (delta 561), pack-reused 578接收对象中: 100% (1285/1285), 1.92 MiB | 174.00 KiB/s, 完成.处理 delta 中: 100% (761/761), 完成.┌──[root@vms99.liruilongs.github.io]-[~]└─$cd FlameGraph/
然后通过下面的命令生成对应的 火焰图 矢量图
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~/FlameGraph]└─$./flamegraph.pl --hash --bgcolors=grey < ../out.txt > out.svgCan't locate open.pm in @INC (you may need to install the open module) (@INC contains: /usr/local/lib64/perl5 /usr/local/share/perl5 /usr/lib64/perl5/vendor_perl /usr/share/perl5/vendor_perl /usr/lib64/perl5 /usr/share/perl5) at ./flamegraph.pl line 97.BEGIN failed--compilation aborted at ./flamegraph.pl line 97.
可以看到报错了,这个错误消息表明在运行 ./flamegraph.pl 脚本时,Perl 解释器无法找到所需的 open.pm 模块。该模块可能没有正确安装或没有包含在 Perl 解释器的模块搜索路径中。
要解决这个问题,你可以尝试以下几个步骤:
检查模块安装:确保 open.pm 模块已经正确安装。你可以使用 CPAN 或其他 Perl 模块管理工具来安装该模块。
安装模块管理器
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~/FlameGraph]└─$yum install perl-CPAN -y
安装模块
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~/FlameGraph]└─$cpan openLoading internal null logger. Install Log::Log4perl for logging messagesCPAN.pm requires configuration, but most of it can be done automatically.If you answer 'no' below, you will enter an interactive dialog for eachconfiguration option instead.Would you like to configure as much as possible automatically? [yes] yesCPAN: HTTP::Tiny loaded ok (v0.074)...............http://www.cpan.org/modules/03modlist.data.gzReading '/root/.cpan/sources/modules/03modlist.data.gz'DONEWriting /root/.cpan/MetadataRunning install for module 'open'The most recent version "1.13" of the module "open"is part of the perl-5.38.2 distribution. To install that, you need to run force install open --or-- install P/PE/PEVANS/perl-5.38.2.tar.gz
安装完之后提示我们需要安装对应的 perl 版本
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~/FlameGraph]└─$perl -vThis is perl 5, version 26, subversion 3 (v5.26.3) built for x86_64-linux-thread-multi(with 58 registered patches, see perl -V for more detail)Copyright 1987-2018, Larry WallPerl may be copied only under the terms of either the Artistic License or theGNU General Public License, which may be found in the Perl 5 source kit.Complete documentation for Perl, including FAQ lists, should be found onthis system using "man perl" or "perldoc perl". If you have access to theInternet, point your browser at http://www.perl.org/, the Perl Home Page.┌──[root@vms99.liruilongs.github.io]-[~/FlameGraph]└─$yum -y install perl -y
升级 perl 版本之后,火焰图可以正常生成,通过帮助文档可以简单了解命令的使用
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$./FlameGraph/flamegraph.pl --helpUSAGE: ./FlameGraph/flamegraph.pl [options] infile > outfile.svg --title TEXT # change title text --subtitle TEXT # second level title (optional) --width NUM # width of image (default 1200) --height NUM # height of each frame (default 16) --minwidth NUM # omit smaller functions. In pixels or use "%" for # percentage of time (default 0.1 pixels) --fonttype FONT # font type (default "Verdana") --fontsize NUM # font size (default 12) --countname TEXT # count type label (default "samples") --nametype TEXT # name type label (default "Function:") --colors PALETTE # set color palette. choices are: hot (default), mem, # io, wakeup, chain, java, js, perl, red, green, blue, # aqua, yellow, purple, orange --bgcolors COLOR # set background colors. gradient choices are yellow # (default), blue, green, grey; flat colors use "#rrggbb" --hash # colors are keyed by function name hash --random # colors are randomly generated --cp # use consistent palette (palette.map) --reverse # generate stack-reversed flame graph --inverted # icicle graph --flamechart # produce a flame chart (sort by time, do not merge stacks) --negate # switch differential hues (blue<->red) --notes TEXT # add notes comment in SVG (for debugging) --help # this message eg, ./FlameGraph/flamegraph.pl --title="Flame Graph: malloc()" trace.txt > graph.svg
输出我们上面的采集数据,启动一个 http 服务访问
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$./FlameGraph/flamegraph.pl < profilelrl.log > profilelrl.svg┌──[root@vms99.liruilongs.github.io]-[~] └─$python -m http.serverServing HTTP on 0.0.0.0 port 8000 (http://0.0.0.0:8000/) ...192.168.26.1 - - [18/Oct/2024 05:15:37] "GET / HTTP/1.1" 200 -192.168.26.1 - - [18/Oct/2024 05:15:37] code 404, message File not found192.168.26.1 - - [18/Oct/2024 05:15:37] "GET /favicon.ico HTTP/1.1" 404 -192.168.26.1 - - [18/Oct/2024 05:15:52] "GET /profilelrl.svg HTTP/1.1" 200 -
可以看到采集的应用程序调用栈很少,当前系统是一个空闲的系统,我们使用 stress 来做 CPU 负载模拟,所以看到的基本上是 stress 的调用栈
实际上生产场景的火焰图相对复杂
CPU 调度的最小单位为线程,线程的运行队列长度可以反应CPU 是否处于饱和状态, runqlat 是基于 BCC 和 bpftrace 的 CPU 调度器延迟分析工具,CPU 调度器延迟通常被称为运行队列延迟,实际上不是简单的队列, runqlat 统计的是每个线程等待CPU的耗时。
这里我们通过 stress 来模拟CPU 的饱和状态。启动 100 个线程
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$stress --cpu 100 --timeout 100sstress: info: [38244] dispatching hogs: 100 cpu, 0 io, 0 vm, 0 hddstress: info: [38244] successful run completed in 100s┌──[root@vms99.liruilongs.github.io]-[~]└─$
下面的命令使用 runqlat 每隔 10 秒输出一次, 就输出一次的的直方图数据,
usecs:表示延迟的时间区间(以微秒为单位)。count:表示在该时间区间内发生的事件数量。distribution:通过星号 (*) 表示的分布图,用于可视化延迟的分布。代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./runqlat 10 1Tracing run queue latency... Hit Ctrl-C to end. usecs : count distribution 0 -> 1 : 13 | | 2 -> 3 : 119 |** | 4 -> 7 : 355 |****** | 8 -> 15 : 183 |*** | 16 -> 31 : 144 |** | 32 -> 63 : 219 |*** | 64 -> 127 : 72 |* | 128 -> 255 : 21 | | 256 -> 511 : 22 | | 512 -> 1023 : 74 |* | 1024 -> 2047 : 143 |** | 2048 -> 4095 : 214 |*** | 4096 -> 8191 : 326 |***** | 8192 -> 16383 : 247 |**** | 16384 -> 32767 : 200 |*** | 32768 -> 65535 : 331 |***** | 65536 -> 131071 : 586 |********** | 131072 -> 262143 : 2295 |****************************************| 262144 -> 524287 : 1589 |*************************** | 524288 -> 1048575 : 554 |********* | 1048576 -> 2097151 : 31 | | 2097152 -> 4194303 : 1 | |┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
可以看到,离群点为较高的延迟 131072 微秒及以上 占整个延迟区间的大部分,通过分布图也可以直观的感受。大部分线程处于等待状态,并且等待时间较长,可以确定当前CPU 呈现饱和状态。
runqlat(8)利用对 CPU 调度器的线程唤醒事件和线程上线文切换事件的跟踪来计算线程从唤醒到运行之前的时间间隔。
在比较繁忙的系统中,这类事件的发生频率可能很好,每秒超过10000次,所以在使用这个命令的时候需要多加注意。
也可以通过 sar(1) 来同时展示 CPU 利用率(-u) 和 运行队列性能指标(-q)。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$sar -uq 1Linux 4.18.0-513.9.1.el8_9.x86_64 (vms99.liruilongs.github.io) 2024年10月09日 _x86_64_ (6 CPU)11时27分08秒 CPU %user %nice %system %iowait %steal %idle11时27分09秒 all 96.13 0.00 3.87 0.00 0.00 0.0011时27分08秒 runq-sz plist-sz ldavg-1 ldavg-5 ldavg-15 blocked11时27分09秒 100 592 15.81 14.33 11.57 011时27分09秒 CPU %user %nice %system %iowait %steal %idle11时27分10秒 all 95.51 0.00 4.49 0.00 0.00 0.0011时27分09秒 runq-sz plist-sz ldavg-1 ldavg-5 ldavg-15 blocked11时27分10秒 101 592 15.81 14.33 11.57 0
可以看到 用户态CPU 利用率为 趋于饱和,空闲时间为0,同时平均运行队列长度为 100左右,包括正在运行 + 等待的线程(与vmstat的r列相同), 1,5,15 分钟的负载为 15 左右,但是通过下面的输出可以看到当前我们只有6个逻辑核。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$lscpu | grep CPU:CPU: 6
一般情况下,平均负载ldavg-1 ldavg-5 ldavg-15远远超过 CPU 逻辑核数的的时候,认为系统负载非常高,CPU 趋于饱和状态 ,通过 runq-sz > CUP数量 我们可以推断出 平局负载高的原因之一是因为 存在大量的线程在等待CPU调度,堆积在运行队列
实际上对于运行队列的长度我们也可以通过专门的 BPF 工具来采集
运行队列最长的时候有多少线程在等待执行?runqlenrunqlen 是一个基于 BCC 和 bpftrace 的工具,用于采样 CPU运行队列的长度信息,统计有多少线程正在等待运行,同样可以以直方图的形式展现。
下面的输出为一台空闲的机器的 运行队列长度采集输出。可以看到,大部分时间的运行队列的长度都为0,即线程不需要等待可以立即执行。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./runqlen 10 1Sampling run queue length... Hit Ctrl-C to end. runqlen : count distribution 0 : 5123 |****************************************|
通过 stress 来模拟 CPU 饱和
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[~]└─$stress --cpu 100 --timeout 100sstress: info: [38556] dispatching hogs: 100 cpu, 0 io, 0 vm, 0 hdd
同样的命令再次执行,可以很明显的看到变化,队列长度集中在 10 到 25 之间,即大部分的CPU任务存在积压,线程需要等待才能执行。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./runqlen 10 1Sampling run queue length... Hit Ctrl-C to end. runqlen : count distribution 0 : 367 |******************************* | 1 : 73 |****** | 2 : 39 |*** | 3 : 53 |**** | 4 : 57 |**** | 5 : 45 |*** | 6 : 83 |******* | 7 : 90 |******* | 8 : 97 |******** | 9 : 84 |******* | 10 : 118 |********** | 11 : 135 |*********** | 12 : 189 |**************** | 13 : 110 |********* | 14 : 166 |************** | 15 : 170 |************** | 16 : 318 |*************************** | 17 : 297 |************************* | 18 : 459 |****************************************| 19 : 232 |******************** | 20 : 308 |************************** | 21 : 358 |******************************* | 22 : 213 |****************** | 23 : 137 |*********** | 24 : 141 |************ | 25 : 143 |************ | 26 : 93 |******** | 27 : 42 |*** | 28 : 63 |***** | 29 : 58 |***** | 30 : 33 |** | 31 : 29 |** | 32 : 8 | | 33 : 33 |** | 34 : 10 | | 35 : 13 |* | 36 : 0 | | 37 : 0 | | 38 : 3 | |┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
原书作者把运行队列被定义为二级指标,而且运行时间延迟被定义为一级指标,因为运行队列延迟会直接的按比例影响系统性能,而运行队列长度则不一样。
runqlen 可以进一步定性 runqlat 发现的问题,同时,runqlen 的采样频率为 99HZ,而 runqlat 需要跟踪 CPU 调度器,后者比前者有更多的性能消耗,一般情况下,会通过 runqlen 来发现问题,通过runqlat 的量化延迟,确定问题。
当进程进行单CPU亲和性配置的时候,一个进程的多个线程始终中一个CPU运行,这个时候,如果队列长度为3,即可确定该进程,有一个线程中运行,3线程位于队列中。
runqlat 和 runqlen 可以分析当前系统CPU使用异常是否存在由CPU调度延迟影响的,那么如果确定之后,如何定位到具体的线程,或者说应用程序?
runqslowerrunqslower 可以列出运行队列中等待延迟超过阈值的线程名字,同时输出受延迟影响的进程名字和对应的延迟时长
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./runqslowerTracing run queue latency higher than 10000 usTIME COMM TID LAT(us)12:11:12 b'stress' 39402 1308912:11:12 b'stress' 39401 1467912:11:12 b'stress' 39397 2366012:11:12 b'stress' 39395 1785212:11:12 b'kworker/u256:28' 573 2285412:11:12 b'stress' 39398 3453212:11:12 b'stress' 39399 5274912:11:12 b'stress' 39400 10772512:11:12 b'runqslower' 39303 7634612:11:12 b'kworker/u256:28' 573 1179712:11:12 b'stress' 39408 1077912:11:12 b'stress' 39405 13447012:11:12 b'runqslower' 39303 1006312:11:12 b'stress' 39410 1996312:11:12 b'stress' 39407 15064012:11:12 b'runqslower' 39303 1141812:11:12 b'stress' 39370 1329112:11:12 b'stress' 39403 13288612:11:12 b'runqslower' 39303 3316912:11:12 b'stress' 39390 121633
上面的输出为超过默认阈值 10000 us 毫秒的的运行队列发生的次数,可以看到大多为上面的测试工具 stress 的线程。LAT(us)为线程在运行队列中的等待延迟,单位是微秒。
不同 CPU之间的运行队列是否均衡?runqlen当其他运行队列中有需要运行的程序时,我们希望知道哪些CPU仍然处于空闲状态? 即对于每个进程,每个 CPU 的权重是否一致,是否存在不均衡的情况。通过 runqlen 的 -C 选项可以为每个CPU输出一个直方图。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$./runqlen -CSampling run queue length... Hit Ctrl-C to end.^Ccpu = 1 runqlen : count distribution 0 : 0 | | 1 : 0 | | 2 : 0 | | 3 : 0 | | 4 : 0 | | 5 : 0 | | 6 : 0 | | 7 : 92 |*********************** | 8 : 0 | | 9 : 65 |**************** | 10 : 0 | | 11 : 77 |******************* | 12 : 0 | | 13 : 0 | | 14 : 157 |****************************************|cpu = 0 runqlen : count distribution 0 : 0 | | 1 : 0 | | 2 : 0 | | 3 : 0 | | 4 : 0 | | 5 : 0 | | 6 : 0 | | 7 : 0 | | 8 : 0 | | 9 : 0 | | 10 : 0 | | 11 : 0 | | 12 : 0 | | 13 : 0 | | 14 : 0 | | 15 : 0 | | 16 : 0 | | 17 : 0 | | 18 : 0 | | 19 : 333 |****************************************| 20 : 0 | | 21 : 0 | | 22 : 0 | | 23 : 0 | | 24 : 132 |*************** |┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
可以很直观的看的 每个 CPU 上的线程队列长度,CPU 0 和 CPU 1 的运行队列长度分布存在明显的差异,这表明两个 CPU 的运行队列并不均衡,CPU0 的负载要高于 CPU1.可能是CPU 亲和性配置,或者编码中绑定了CPU
cpuunclaimedcpu_unclaimed 工具用于采样 CPU 运行队列的长度,并关注在某个 CPU 上有排队线程的情况下有多少其他 CPU 处于空闲状态。这个工具可以帮助识别 CPU 资源分配的不均衡问题,
这个命令在我的实验环境中会报错,时间关系我也没有研究,感兴趣小伙伴可以留言讨论,
下面为一个Demo数据,表示在 12:34:56 时,CPU 0 上有 10 个线程排队,而有 3 个 CPU 处于空闲状态。
代码语言:javascript代码运行次数:0运行复制TIME CPU QUEUE_LENGTH IDLE_CPUS12:34:56 0 10 312:34:57 1 5 212:34:58 2 0 4...
offcputime(8) 用于统计线程阻塞和脱离CPU 运行的时间,同时会输出调用栈信息,
输出顺序依次为 内核态函数,用户态件函数,之后是进程名字,ID 以及调用栈出现的全部时间,也就是脱离时间。
代码语言:javascript代码运行次数:0运行复制┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$offcputime 1Tracing off-CPU time (us) of all threads by user + kernel stack for 1 secs. 。。。。。。。。。。。。。。。。。。。。。。。。。。 finish_task_switch __sched_text_start schedule schedule_hrtimeout_range_clock do_select core_sys_select kern_select __x64_sys_select do_syscall_64 entry_SYSCALL_64_after_hwframe __select - httpd (38029) 921073 finish_task_switch __sched_text_start schedule schedule_hrtimeout_range_clock do_select core_sys_select kern_select __x64_sys_select do_syscall_64 entry_SYSCALL_64_after_hwframe __select - tuned (1713) 947681。。。。。。。。┌──[root@vms99.liruilongs.github.io]-[/usr/share/bcc/tools]└─$
以上就是Linux性能调优之使用BPF工具观测CPU性能指标的详细内容,更多请关注php中文网其它相关文章!
Copyright 2014-2025 https://www.php.cn/ All Rights Reserved | php.cn | 湘ICP备2023035733号