Linux perf 在 Linux 4.10 中获得了一个新的 CPU 调度程序分析视图：perf sched timehist。由于我之前没有讨论过性能调度，我将在这里总结它的功能。如果您赶时间，浏览以下屏幕截图可能会有所帮助，以便您了解可用的内容。（我已将此内容添加到我的性能示例页面。
Perf Sched 使用转储和后处理方法来分析调度程序事件，这可能是一个问题，因为这些事件可能非常频繁（每秒数百万个），需要花费 CPU、内存和磁盘开销来记录。我最近一直在使用 eBPF/bcc（包括 runqlat）编写调度程序分析工具，这让我通过使用内核内摘要大大减少了开销。但在某些情况下，您可能希望改用性能调度来捕获每个事件，尽管开销更高。想象一下，在自动终止之前，有五分钟的时间分析一个坏的云实例，并且您希望捕获所有内容以供以后分析。
我将首先记录一秒钟的事件：
perf script --header
captured on: Sun Feb 26 19:40:00 2017
os release : 4.10-virtual
arch : x86_64
nrcpus avail : 8
cpuid : GenuineIntel,6,62,4
cmdline : /usr/bin/perf sched record -- sleep 1
event : name = sched:sched_stat_wait, , id = { 2760, 2761, 2762, 2763, 2764, 2765, 2766, 2...
event : name = sched:sched_stat_iowait, , id = { 2776, 2777, 2778, 2779, 2780, 2781, 2782,...
event : name = sched:sched_process_fork, , id = { 2792, 2793, 2794, 2795, 2796, 2797, 2798...
event : name = sched:sched_wakeup_new, , id = { 2808, 2809, 2810, 2811, 2812, 2813, 2814, ...
HEADER_CPU_TOPOLOGY info available, use -I to display
pmu mappings: breakpoint = 5, power = 7, software = 1, tracepoint = 2, msr = 6
missing features: HEADER_BRANCH_STACK HEADER_GROUP_DESC HEADER_AUXTRACE HEADER_STAT
perf 16984 [005] 991962.879966: sched:sched_wakeup: comm=perf pid=16999 prio=120 target_cpu=005
[...]
可以通过多种方式报告捕获的跟踪文件，并通过帮助消息进行汇总：
39;t complain, do it
-i, --input input file name
-v, --verbose be more verbose (show symbol address, etc)
性能计划延迟将按任务汇总计划程序延迟，包括平均和最大延迟：
perf sched map
*A0 991962.879971 secs A0 => perf:16999
A0 *B0 991962.880070 secs B0 => cc1:16863
*C0 A0 B0 991962.880070 secs C0 => :17023:17023
*D0 C0 A0 B0 991962.880078 secs D0 => ksoftirqd/0:6
D0 C0 *E0 A0 B0 991962.880081 secs E0 => ksoftirqd/3:28
D0 C0 *F0 A0 B0 991962.880093 secs F0 => :17022:17022
*G0 C0 F0 A0 B0 991962.880108 secs G0 => :17016:17016
G0 C0 F0 *H0 B0 991962.880256 secs H0 => migration/5:39
G0 C0 F0 *I0 B0 991962.880276 secs I0 => perf:16984
G0 C0 F0 *J0 B0 991962.880687 secs J0 => cc1:16996
G0 C0 *K0 J0 B0 991962.881839 secs K0 => cc1:16945
G0 C0 K0 J0 *L0 B0 991962.881841 secs L0 => :17020:17020
G0 C0 K0 J0 *M0 B0 991962.882289 secs M0 => make:16637
G0 C0 K0 J0 *N0 B0 991962.883102 secs N0 => make:16545
G0 *O0 K0 J0 N0 B0 991962.883880 secs O0 => cc1:16819
G0 *A0 O0 K0 J0 N0 B0 991962.884069 secs
G0 A0 O0 K0 *P0 J0 N0 B0 991962.884076 secs P0 => rcu_sched:7
G0 A0 O0 K0 *Q0 J0 N0 B0 991962.884084 secs Q0 => cc1:16831
G0 A0 O0 K0 Q0 J0 *R0 B0 991962.884843 secs R0 => cc1:16825
G0 *S0 O0 K0 Q0 J0 R0 B0 991962.885636 secs S0 => cc1:16900
G0 S0 O0 *T0 Q0 J0 R0 B0 991962.886893 secs T0 => :17014:17014
G0 S0 O0 *K0 Q0 J0 R0 B0 991962.886917 secs
[...]
这是一个 8 个 CPU 的系统，您可以从左侧开始看到每个 CPU 的 8 列。某些 CPU 列以空白开头，因为我们尚未在配置文件开始时跟踪该 CPU 上的事件。他们很快就被覆盖了。
您看到的两个字符代码（“A0”、“C0”）是任务的标识符，它们映射在右侧（“=>”）。这比使用进程（任务）ID 更紧凑。“*”显示哪个 CPU 具有上下文切换事件，以及正在运行的新事件。例如，最后一行显示，在 991962.886917（秒）处，CPU 4 上下文切换到 K0（“cc1”进程，PID 16945）。
该示例来自繁忙的系统。下面是一个空闲系统：
perf sched timehist
Samples do not have callchains.
time cpu task name wait time sch delay run time
[tid/pid] (msec) (msec) (msec)
--------------- ------ ------------------------------ --------- --------- ---------
991962.879971 [0005] perf[16984] 0.000 0.000 0.000
991962.880070 [0007] :17008[17008] 0.000 0.000 0.000
991962.880070 [0002] cc1[16880] 0.000 0.000 0.000
991962.880078 [0000] cc1[16881] 0.000 0.000 0.000
991962.880081 [0003] cc1[16945] 0.000 0.000 0.000
991962.880093 [0003] ksoftirqd/3[28] 0.000 0.007 0.012
991962.880108 [0000] ksoftirqd/0[6] 0.000 0.007 0.030
991962.880256 [0005] perf[16999] 0.000 0.005 0.285
991962.880276 [0005] migration/5[39] 0.000 0.007 0.019
991962.880687 [0005] perf[16984] 0.304 0.000 0.411
991962.881839 [0003] cat[17022] 0.000 0.000 1.746
991962.881841 [0006] cc1[16825] 0.000 0.000 0.000
[...]
991963.885740 [0001] :17008[17008] 25.613 0.000 0.057
991963.886009 [0001] sleep[16999] 1000.104 0.006 0.269
991963.886018 [0005] cc1[17083] 19.998 0.000 9.948
此输出包括 sleep 命令运行，用于将 perf 本身的持续时间设置为 1 秒。请注意，睡眠的等待时间为 1000.104 毫秒，因为我运行了“睡眠 1”：这是它等待计时器唤醒事件进入睡眠状态的时间。它的调度程序延迟仅为 0.006 毫秒，在 CPU 上的时间为 0.269 毫秒。
timehist 有许多选项，包括 -V 用于添加 CPU 可视化列，-M 用于添加迁移事件，-w 用于唤醒事件。例如：
perf sched script
perf 16984 [005] 991962.879960: sched:sched_stat_runtime: comm=perf pid=16984 runtime=3901506 [ns] vruntime=165...
perf 16984 [005] 991962.879966: sched:sched_wakeup: comm=perf pid=16999 prio=120 target_cpu=005
perf 16984 [005] 991962.879971: sched:sched_switch: prev_comm=perf prev_pid=16984 prev_prio=120 prev_stat...
perf 16999 [005] 991962.880058: sched:sched_stat_runtime: comm=perf pid=16999 runtime=98309 [ns] vruntime=16405...
cc1 16881 [000] 991962.880058: sched:sched_stat_runtime: comm=cc1 pid=16881 runtime=3999231 [ns] vruntime=7897...
:17024 17024 [004] 991962.880058: sched:sched_stat_runtime: comm=cc1 pid=17024 runtime=3866637 [ns] vruntime=7810...
cc1 16900 [001] 991962.880058: sched:sched_stat_runtime: comm=cc1 pid=16900 runtime=3006028 [ns] vruntime=7772...
cc1 16825 [006] 991962.880058: sched:sched_stat_runtime: comm=cc1 pid=16825 runtime=3999423 [ns] vruntime=7876...
这些事件中的每一个（“sched：sched_stat_runtime”等）都是可以使用 perf 记录直接检测的跟踪点。如前所述，此原始输出可用于比摘要命令更深入的挖掘。
