3每个 Yocto 跟踪工具的基本用法（附示例）
目录
本章介绍了每个跟踪工具的基本使用示例。
3.1 PERF
“perf”工具是与 Linux 内核捆绑在一起的分析和跟踪工具。
不要让它是内核的一部分这一事实使您误以为它仅用于跟踪和分析内核 - 您确实可以使用它来跟踪和分析内核，但您也可以使用它来单独分析特定的应用程序（有或没有内核上下文），您还可以使用它同时跟踪和分析系统上的内核和所有应用程序，以获得系统范围内正在发生的事情的视图。
在许多方面，perf 旨在成为当今 Linux 中可用的所有跟踪和分析工具的超集，包括本 HOWTO 中涵盖的所有其他工具。在过去的几年里，perf 包含了许多其他工具的功能，同时，这些其他工具删除了大部分以前的功能，并用对现在由 perf 实现的等效功能的调用取而代之子系统。推断表明，在某些时候，其他工具将变得完全多余并消失；在那之前，我们将在这些页面中介绍那些其他工具，并在许多情况下展示如何在 perf 和其他工具中完成相同的事情，当这样做似乎有用时。
下面的内容详细介绍了您可能希望应用该工具的一些最常见方式；可以在工具本身或perf(1)的手册页中找到完整的文档 。
3.1.1性能设置
在本节中，我们假设您已经执行了“常规设置”部分中概述的基本设置。
特别是，如果您在local.conf文件中分析使用以下内容构建的图像，您将从 perf 中获得最大收益：
INHIBIT_PACKAGE_STRIP = "1"
perf 大部分运行在目标系统上。您可以存档配置文件数据并将其复制到主机进行分析，但对于本文档的其余部分，我们假设您已通过 ssh 连接到主机并将在目标上运行 perf 命令。
3.1.2基本性能使用
perf 工具几乎是自我记录的。要提醒自己可用的命令，只需键入“perf”，它将显示基本用法以及可用的 perf 子命令：
root@crownbay:~# perf
usage: perf [--version] [--help] COMMAND [ARGS]
The most commonly used perf commands are:
annotate Read perf.data (created by perf record) and display annotated code
archive Create archive with object files with build-ids found in perf.data file
bench General framework for benchmark suites
buildid-cache Manage build-id cache.
buildid-list List the buildids in a perf.data file
diff Read two perf.data files and display the differential profile
evlist List the event names in a perf.data file
inject Filter to augment the events stream with additional information
kmem Tool to trace/measure kernel memory(slab) properties
kvm Tool to trace/measure kvm guest os
list List all symbolic event types
lock Analyze lock events
probe Define new dynamic tracepoints
record Run a command and record its profile into perf.data
report Read perf.data (created by perf record) and display the profile
sched Tool to trace/measure scheduler properties (latencies)
script Read perf.data (created by perf record) and display trace output
stat Run a command and gather performance counter statistics
test Runs sanity tests.
timechart Tool to visualize total system behavior during a workload
top System profiling tool.
See 'perf help COMMAND' for more information on a specific command.
3.1.2.1使用 perf 进行基本分析
作为一个简单的测试案例，我们将分析一个相当大的文件的“wget”，这是一个最有趣的案例，因为它同时具有文件和网络 I/O 方面，至少在标准 Yocto 图像的情况下，它是作为 BusyBox 的一部分实现，因此我们用来分析它的方法可以以与 Yocto 中支持的整个 BusyBox 小程序非常相似的方式使用。
root@crownbay:~# rm linux-2.6.19.2.tar.bz2; \
wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
获取有关特定工作负载正在发生的事情的一些基本整体数据的最快和最简单的方法是使用“性能统计”对其进行分析。'perf stat' 基本上使用一些默认计数器进行分析，并在运行结束时显示总计数：
root@crownbay:~# perf stat wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
Connecting to downloads.yoctoproject.org (140.211.169.59:80)
linux-2.6.19.2.tar.b 100% |***************************************************| 41727k 0:00:00 ETA
Performance counter stats for 'wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2':
4597.223902 task-clock # 0.077 CPUs utilized
23568 context-switches # 0.005 M/sec
68 CPU-migrations # 0.015 K/sec
241 page-faults # 0.052 K/sec
3045817293 cycles # 0.663 GHz
<not supported> stalled-cycles-frontend
<not supported> stalled-cycles-backend
858909167 instructions # 0.28 insns per cycle
165441165 branches # 35.987 M/sec
19550329 branch-misses # 11.82% of all branches
59.836627620 seconds time elapsed
很多时候，这样一个头脑简单的测试不会产生太大的兴趣，但有时它会产生（请参阅真实世界的 Yocto 错误（慢循环安装写入速度））。
另外，请注意，'perf stat' 不限于一组固定的计数器 - 基本上，'perf list' 输出中列出的任何事件都可以通过 'perf stat' 进行统计。例如，假设我们想查看与内核内存分配/释放以及缓存命中和未命中相关的所有事件的摘要：
root@crownbay:~# perf stat -e kmem:* -e cache-references -e cache-misses wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
Connecting to downloads.yoctoproject.org (140.211.169.59:80)
linux-2.6.19.2.tar.b 100% |***************************************************| 41727k 0:00:00 ETA
Performance counter stats for 'wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2':
5566 kmem:kmalloc
125517 kmem:kmem_cache_alloc
0 kmem:kmalloc_node
0 kmem:kmem_cache_alloc_node
34401 kmem:kfree
69920 kmem:kmem_cache_free
133 kmem:mm_page_free
41 kmem:mm_page_free_batched
11502 kmem:mm_page_alloc
11375 kmem:mm_page_alloc_zone_locked
0 kmem:mm_page_pcpu_drain
0 kmem:mm_page_alloc_extfrag
66848602 cache-references
2917740 cache-misses # 4.365 % of all cache refs
44.831023415 seconds time elapsed
因此，'perf stat' 为我们提供了一种很好的简单方法来快速了解一组事件可能发生的情况，但通常我们需要更多细节才能以我们可以的方式了解正在发生的事情以有用的方式采取行动。
为了深入研究下一个细节，我们可以使用“perf record”/“perf report”，它会收集分析数据并使用基于文本的交互式 UI（或者如果我们指定 –stdio 则简单地作为文本） '性能报告'）。
作为我们第一次尝试分析此工作负载时，我们将简单地运行“perf record”，将我们想要分析的工作负载交给它（在“perf record”之后的所有内容以及我们提供给它的任何 perf 选项 - 这里没有 - 将在一个新外壳）。perf 收集样本直到进程退出并将它们记录在当前工作目录中名为“perf.data”的文件中。
root@crownbay:~# perf record wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
Connecting to downloads.yoctoproject.org (140.211.169.59:80)
linux-2.6.19.2.tar.b 100% |************************************************| 41727k 0:00:00 ETA
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.176 MB perf.data (~7700 samples) ]
要在“基于文本的 UI” (tui) 中查看结果，只需运行“perf report”，它将读取当前工作目录中的 perf.data 文件并在交互式 UI 中显示结果：
root@crownbay:~# perf report
上面的屏幕截图显示了一个“平面”配置文件，每个“存储桶”对应于在分析运行期间分析的功能的一个条目，从最流行到最不常用（perf 也有按各种顺序和键排序的选项）作为仅高于特定阈值的显示条目等 - 有关详细信息，请参阅 perf 文档）。请注意，这包括用户空间函数（包含 [.] 的条目）和进程的内核函数（包含 [k] 的条目）。（perf 具有命令行修饰符，可用于将分析限制为内核或用户空间等）。
还请注意，上面的报告显示了“busybox”的条目，它是在 Yocto 中实现“wget”的可执行文件，但该条目中不是有用的函数名称，而是显示一个不太友好的十六进制值。以下步骤将展示如何解决该问题。
然而，在我们这样做之前，让我们尝试运行一个不同的配置文件，它显示一些更有趣的东西。新配置文件和前一个配置文件之间的唯一区别是我们将添加 -g 选项，它不仅会记录采样函数的地址，还会记录采样函数的整个调用链：
root@crownbay:~# perf record -g wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
Connecting to downloads.yoctoproject.org (140.211.169.59:80)
linux-2.6.19.2.tar.b 100% |************************************************| 41727k 0:00:00 ETA
[ perf record: Woken up 3 times to write data ]
[ perf record: Captured and wrote 0.652 MB perf.data (~28476 samples) ]
root@crownbay:~# perf report
使用调用图视图，我们实际上不仅可以看到哪些函数花费了最多的时间，而且我们还可以看到这些函数如何被调用的摘要，并了解程序如何在进程中与内核交互。
请注意，上面屏幕截图中的每个条目现在都在左侧包含一个“+”。这意味着我们可以扩展条目并深入到进入该条目的调用链。在其中任何一个上按 'enter' 将展开调用链（您也可以按 'E' 同时展开它们或按 'C' 将它们全部折叠）。
在上面的屏幕截图中，我们一直__copy_to_user_ll()向下切换条目和几个子节点。这让我们可以看到哪些调用链对分析__copy_to_user_ll()函数做出了贡献，该函数占总分析的 1.77%。
作为对这些调用链的一些背景解释，请考虑在运行 wget 以在网络上获取文件时在高层会发生什么。基本上发生的事情是数据通过网络连接（套接字）进入内核并传递给用户空间程序“wget”（它实际上是 BusyBox 的一部分，但现在这并不重要），它使用缓冲区内核传递给它并将其写入磁盘文件以保存它。
我们在上面的调用堆栈中看到的这个过程的部分是内核将从套接字读取的数据向下传递到 wget 的部分，即复制到用户的部分。
还要注意，这里还有一种情况，十六进制值显示在调用堆栈中，这里是展开的sys_clock_gettime() 函数中。稍后我们将看到它解析为 busybox 中的用户空间函数调用。
上面的屏幕截图显示了数据旅程的另一半 - 从 wget 程序的用户空间缓冲区到磁盘。为了将缓冲区写入磁盘，wget 程序发出 a write(2)，它对copy-from-user内核执行 a ，然后通过一些迂回路径（可能也存在于配置文件数据中的某处）进行处理，以将其安全地发送到磁盘。
现在我们已经看到了配置文件数据的基本布局以及如何从中提取有用信息的基础知识，让我们回到手头的任务，看看我们是否可以对时间花在哪些地方有一些基本的了解我们正在分析的程序，wget。请记住，wget 实际上是作为 BusyBox 中的小程序实现的，因此虽然进程名称是“wget”，但我们真正感兴趣的可执行文件是 BusyBox。因此，让我们展开包含 BusyBox 的第一个条目：
同样，在我们展开之前，我们看到函数被标记为十六进制值，而不是像大多数内核条目一样的符号。扩展 BusyBox 条目并没有让它变得更好。
问题是 perf 找不到 busybox 二进制文件的符号信息，这实际上是被 Yocto 构建系统剥离的。
一种解决方法是在local.conf构建映像时将以下内容放入文件中：
INHIBIT_PACKAGE_STRIP = "1"
但是，我们已经有一个二进制文件被剥离的图像，那么我们可以做些什么来获得 perf 来解析符号呢？基本上我们需要为 BusyBox 包安装调试信息。
要生成图像中的包的调试信息，我们可以添加 dbg-pkgs到EXTRA_IMAGE_FEATURES中local.conf。例如：
EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile dbg-pkgs"
此外，为了生成 perf 理解的 debuginfo 类型，我们还需要 在文件中设置 PACKAGE_DEBUG_SPLIT_STYLElocal.conf：
PACKAGE_DEBUG_SPLIT_STYLE = 'debug-file-directory'
完成后，我们可以为 BusyBox 安装调试信息。构建后的调试包可以 build/tmp/deploy/rpm/*在主机系统中找到。找到busybox-dbg-...rpm 文件并将其复制到目标。例如：
[trz@empanada core2]$ scp /home/trz/yocto/crownbay-tracing-dbg/build/tmp/deploy/rpm/core2_32/busybox-dbg-1.20.2-r2.core2_32.rpm root@192.168.1.31:
busybox-dbg-1.20.2-r2.core2_32.rpm 100% 1826KB 1.8MB/s 00:01
现在在目标上安装调试 rpm：
root@crownbay:~# rpm -i busybox-dbg-1.20.2-r2.core2_32.rpm
现在安装了 debuginfo，我们看到 BusyBox 条目现在象征性地显示它们的功能：
如果我们展开其中一个条目并在叶节点上按“回车”，我们会看到一个操作菜单，我们可以采取这些操作来获取与该条目相关的更多信息：
这些操作之一允许我们显示一个视图，该视图显示分析函数的以 busybox 为中心的视图（在这种情况下，我们还使用“E”键扩展了所有节点）：
最后，我们可以看到，现在安装了 BusyBox debuginfo，前面sys_clock_gettime()提到的条目中以前未解析的符号现在已解析，并且显示 sys_clock_gettime 系统调用是 6.75% 的复制到用户开销的来源由handle_input()BusyBox 函数发起：
在最低级别的细节上，我们可以深入到汇编级别，看看哪些指令导致函数中的开销最大。在“udhcpc_main”函数上按“enter”，我们再次看到一个菜单：
选择“Annotate udhcpc_main”，我们可以通过 udhcpc_main 函数的指令获得详细的百分比列表。从显示中，我们可以看到在此函数中花费的时间超过 50% 被几个测试和常量 (1) 移动到寄存器占用：
作为跟踪的继续，让我们尝试使用不同计数器的另一个配置文件，而不是默认的“周期”。
Linux 中的跟踪和分析基础设施已经变得统一，允许我们使用具有完全不同的计数器集的相同工具，而不仅仅是传统工具必须限制自己使用的标准硬件计数器（当然传统工具也可以利用他们现在可用的扩展可能性，并且在某些情况下，如前所述）。
我们可以通过“perf list”获取可用于分析工作负载的可用事件列表：
root@crownbay:~# perf list
List of pre-defined events (to be used in -e):
cpu-cycles OR cycles [Hardware event]
stalled-cycles-frontend OR idle-cycles-frontend [Hardware event]
stalled-cycles-backend OR idle-cycles-backend [Hardware event]
instructions [Hardware event]
cache-references [Hardware event]
cache-misses [Hardware event]
branch-instructions OR branches [Hardware event]
branch-misses [Hardware event]
bus-cycles [Hardware event]
ref-cycles [Hardware event]
cpu-clock [Software event]
task-clock [Software event]
page-faults OR faults [Software event]
minor-faults [Software event]
major-faults [Software event]
context-switches OR cs [Software event]
cpu-migrations OR migrations [Software event]
alignment-faults [Software event]
emulation-faults [Software event]
L1-dcache-loads [Hardware cache event]
L1-dcache-load-misses [Hardware cache event]
L1-dcache-prefetch-misses [Hardware cache event]
L1-icache-loads [Hardware cache event]
L1-icache-load-misses [Hardware cache event]
.
.
.
rNNN [Raw hardware event descriptor]
cpu/t1=v1[,t2=v2,t3 ...]/modifier [Raw hardware event descriptor]
(see 'perf list --help' on how to encode it)
mem:<addr>[:access] [Hardware breakpoint]
sunrpc:rpc_call_status [Tracepoint event]
sunrpc:rpc_bind_status [Tracepoint event]
sunrpc:rpc_connect_status [Tracepoint event]
sunrpc:rpc_task_begin [Tracepoint event]
skb:kfree_skb [Tracepoint event]
skb:consume_skb [Tracepoint event]
skb:skb_copy_datagram_iovec [Tracepoint event]
net:net_dev_xmit [Tracepoint event]
net:net_dev_queue [Tracepoint event]
net:netif_receive_skb [Tracepoint event]
net:netif_rx [Tracepoint event]
napi:napi_poll [Tracepoint event]
sock:sock_rcvqueue_full [Tracepoint event]
sock:sock_exceed_buf_limit [Tracepoint event]
udp:udp_fail_queue_rcv_skb [Tracepoint event]
hda:hda_send_cmd [Tracepoint event]
hda:hda_get_response [Tracepoint event]
hda:hda_bus_reset [Tracepoint event]
scsi:scsi_dispatch_cmd_start [Tracepoint event]
scsi:scsi_dispatch_cmd_error [Tracepoint event]
scsi:scsi_eh_wakeup [Tracepoint event]
drm:drm_vblank_event [Tracepoint event]
drm:drm_vblank_event_queued [Tracepoint event]
drm:drm_vblank_event_delivered [Tracepoint event]
random:mix_pool_bytes [Tracepoint event]
random:mix_pool_bytes_nolock [Tracepoint event]
random:credit_entropy_bits [Tracepoint event]
gpio:gpio_direction [Tracepoint event]
gpio:gpio_value [Tracepoint event]
block:block_rq_abort [Tracepoint event]
block:block_rq_requeue [Tracepoint event]
block:block_rq_issue [Tracepoint event]
block:block_bio_bounce [Tracepoint event]
block:block_bio_complete [Tracepoint event]
block:block_bio_backmerge [Tracepoint event]
.
.
writeback:writeback_wake_thread [Tracepoint event]
writeback:writeback_wake_forker_thread [Tracepoint event]
writeback:writeback_bdi_register [Tracepoint event]
.
.
writeback:writeback_single_inode_requeue [Tracepoint event]
writeback:writeback_single_inode [Tracepoint event]
kmem:kmalloc [Tracepoint event]
kmem:kmem_cache_alloc [Tracepoint event]
kmem:mm_page_alloc [Tracepoint event]
kmem:mm_page_alloc_zone_locked [Tracepoint event]
kmem:mm_page_pcpu_drain [Tracepoint event]
kmem:mm_page_alloc_extfrag [Tracepoint event]
vmscan:mm_vmscan_kswapd_sleep [Tracepoint event]
vmscan:mm_vmscan_kswapd_wake [Tracepoint event]
vmscan:mm_vmscan_wakeup_kswapd [Tracepoint event]
vmscan:mm_vmscan_direct_reclaim_begin [Tracepoint event]
.
.
module:module_get [Tracepoint event]
module:module_put [Tracepoint event]
module:module_request [Tracepoint event]
sched:sched_kthread_stop [Tracepoint event]
sched:sched_wakeup [Tracepoint event]
sched:sched_wakeup_new [Tracepoint event]
sched:sched_process_fork [Tracepoint event]
sched:sched_process_exec [Tracepoint event]
sched:sched_stat_runtime [Tracepoint event]
rcu:rcu_utilization [Tracepoint event]
workqueue:workqueue_queue_work [Tracepoint event]
workqueue:workqueue_execute_end [Tracepoint event]
signal:signal_generate [Tracepoint event]
signal:signal_deliver [Tracepoint event]
timer:timer_init [Tracepoint event]
timer:timer_start [Tracepoint event]
timer:hrtimer_cancel [Tracepoint event]
timer:itimer_state [Tracepoint event]
timer:itimer_expire [Tracepoint event]
irq:irq_handler_entry [Tracepoint event]
irq:irq_handler_exit [Tracepoint event]
irq:softirq_entry [Tracepoint event]
irq:softirq_exit [Tracepoint event]
irq:softirq_raise [Tracepoint event]
printk:console [Tracepoint event]
task:task_newtask [Tracepoint event]
task:task_rename [Tracepoint event]
syscalls:sys_enter_socketcall [Tracepoint event]
syscalls:sys_exit_socketcall [Tracepoint event]
.
.
.
syscalls:sys_enter_unshare [Tracepoint event]
syscalls:sys_exit_unshare [Tracepoint event]
raw_syscalls:sys_enter [Tracepoint event]
raw_syscalls:sys_exit [Tracepoint event]
捆绑在一起
这些与跟踪事件子系统定义的事件集完全相同，由 ftrace/tracecmd/kernelshark 作为 /sys/kernel/debug/tracing/events 中的文件公开，由 SystemTap 作为 kernel.trace(“tracepoint_name”) 和（部分) 由 LTTng 访问。
在查看此工作负载时，我们只会对其中的一个子集感兴趣，因此让我们选择最有可能的子系统（由 Tracepoint 事件中冒号前的字符串标识）并仅使用那些通配符子系统执行“perf stat”运行：
root@crownbay:~# perf stat -e skb:* -e net:* -e napi:* -e sched:* -e workqueue:* -e irq:* -e syscalls:* wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
Performance counter stats for 'wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2':
23323 skb:kfree_skb
0 skb:consume_skb
49897 skb:skb_copy_datagram_iovec
6217 net:net_dev_xmit
6217 net:net_dev_queue
7962 net:netif_receive_skb
2 net:netif_rx
8340 napi:napi_poll
0 sched:sched_kthread_stop
0 sched:sched_kthread_stop_ret
3749 sched:sched_wakeup
0 sched:sched_wakeup_new
0 sched:sched_switch
29 sched:sched_migrate_task
0 sched:sched_process_free
1 sched:sched_process_exit
0 sched:sched_wait_task
0 sched:sched_process_wait
0 sched:sched_process_fork
1 sched:sched_process_exec
0 sched:sched_stat_wait
2106519415641 sched:sched_stat_sleep
0 sched:sched_stat_iowait
147453613 sched:sched_stat_blocked
12903026955 sched:sched_stat_runtime
0 sched:sched_pi_setprio
3574 workqueue:workqueue_queue_work
3574 workqueue:workqueue_activate_work
0 workqueue:workqueue_execute_start
0 workqueue:workqueue_execute_end
16631 irq:irq_handler_entry
16631 irq:irq_handler_exit
28521 irq:softirq_entry
28521 irq:softirq_exit
28728 irq:softirq_raise
1 syscalls:sys_enter_sendmmsg
1 syscalls:sys_exit_sendmmsg
0 syscalls:sys_enter_recvmmsg
0 syscalls:sys_exit_recvmmsg
14 syscalls:sys_enter_socketcall
14 syscalls:sys_exit_socketcall
.
.
.
16965 syscalls:sys_enter_read
16965 syscalls:sys_exit_read
12854 syscalls:sys_enter_write
12854 syscalls:sys_exit_write
.
.
.
58.029710972 seconds time elapsed
让我们选择这些跟踪点之一并告诉 perf 使用它作为采样事件做一个配置文件：
root@crownbay:~# perf record -g -e sched:sched_wakeup wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
上面的截图显示了使用 sched:sched_switch tracepoint 运行配置文件的结果，它显示了到 sched_wakeup 的各种路径的相对成本（注意 sched_wakeup 是跟踪点的名称——它实际上是在 ttwu_do_wakeup() 中定义的，它说明了配置文件中实际显示的函数名称：
/*
* Mark the task runnable and perform wakeup-preemption.
*/
static void
ttwu_do_wakeup(struct rq *rq, struct task_struct *p, int wake_flags)
{
trace_sched_wakeup(p, true);
.
.
.
}
上面展开并显示了几个更有趣的调用链，基本上是一些网络接收路径，当网络数据准备好时，它们可能最终会唤醒 wget（busybox）。
请注意，因为跟踪点通常用于跟踪，所以跟踪点的默认采样周期为 1，即对于跟踪点 perf 将在每次事件发生时进行采样（这可以使用 -c 选项进行更改）。这与硬件计数器形成对比，例如用于正常分析的默认“周期”硬件计数器，其中采样周期要高得多（以千计），因为分析应该具有尽可能低的开销，并且每个周期的采样将贵得令人望而却步。
3.1.2.2使用 perf 进行基本跟踪
分析是一个很好的工具，可用于解决许多问题或获取工作负载或整个系统中正在发生的事情的高级视图。然而，根据定义，它是一个近似值，正如与之相关的最突出的词“采样”所暗示的那样。一方面，它允许廉价地拍摄系统中正在发生的事情的代表性图片，但另一方面，当数据表明需要更深入地“深入研究”以发现真正的东西时，这种廉价性限制了其效用继续。在这种情况下，查看真实情况的唯一方法是能够查看（或更智能地总结）进入由粗粒度分析数据公开的更高级别行为的各个步骤。
作为一个具体的例子，我们可以跟踪我们认为可能适用于我们的工作负载的所有事件：
root@crownbay:~# perf record -g -e skb:* -e net:* -e napi:* -e sched:sched_switch -e sched:sched_wakeup -e irq:*
-e syscalls:sys_enter_read -e syscalls:sys_exit_read -e syscalls:sys_enter_write -e syscalls:sys_exit_write
wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2
我们可以使用不带参数的“perf script”查看原始跟踪输出：
root@crownbay:~# perf script
perf 1262 [000] 11624.857082: sys_exit_read: 0x0
perf 1262 [000] 11624.857193: sched_wakeup: comm=migration/0 pid=6 prio=0 success=1 target_cpu=000
wget 1262 [001] 11624.858021: softirq_raise: vec=1 [action=TIMER]
wget 1262 [001] 11624.858074: softirq_entry: vec=1 [action=TIMER]
wget 1262 [001] 11624.858081: softirq_exit: vec=1 [action=TIMER]
wget 1262 [001] 11624.858166: sys_enter_read: fd: 0x0003, buf: 0xbf82c940, count: 0x0200
wget 1262 [001] 11624.858177: sys_exit_read: 0x200
wget 1262 [001] 11624.858878: kfree_skb: skbaddr=0xeb248d80 protocol=0 location=0xc15a5308
wget 1262 [001] 11624.858945: kfree_skb: skbaddr=0xeb248000 protocol=0 location=0xc15a5308
wget 1262 [001] 11624.859020: softirq_raise: vec=1 [action=TIMER]
wget 1262 [001] 11624.859076: softirq_entry: vec=1 [action=TIMER]
wget 1262 [001] 11624.859083: softirq_exit: vec=1 [action=TIMER]
wget 1262 [001] 11624.859167: sys_enter_read: fd: 0x0003, buf: 0xb7720000, count: 0x0400
wget 1262 [001] 11624.859192: sys_exit_read: 0x1d7
wget 1262 [001] 11624.859228: sys_enter_read: fd: 0x0003, buf: 0xb7720000, count: 0x0400
wget 1262 [001] 11624.859233: sys_exit_read: 0x0
wget 1262 [001] 11624.859573: sys_enter_read: fd: 0x0003, buf: 0xbf82c580, count: 0x0200
wget 1262 [001] 11624.859584: sys_exit_read: 0x200
wget 1262 [001] 11624.859864: sys_enter_read: fd: 0x0003, buf: 0xb7720000, count: 0x0400
wget 1262 [001] 11624.859888: sys_exit_read: 0x400
wget 1262 [001] 11624.859935: sys_enter_read: fd: 0x0003, buf: 0xb7720000, count: 0x0400
wget 1262 [001] 11624.859944: sys_exit_read: 0x400
这为我们提供了在工作负载中发生的与这些事件相关的带时间戳的详细事件序列。
在许多方面，分析可以被视为跟踪的一个子集——理论上，如果您有一组足以捕获工作负载的所有重要方面的跟踪事件，您可以得出分析运行可以得到的任何结果或视图.
传统分析的另一个方面是，虽然在很多方面都很强大，但它受到底层数据粒度的限制。分析工具提供了各种对样本数据进行排序和呈现的方式，这使得它更有用，更适合用户实验，但最终它不能以开放式方式用于提取不存在的数据由于从概念上讲，其中大部分已被丢弃。
然而，完整的详细跟踪数据确实提供了以无限多种方式操作和呈现在跟踪运行期间收集的信息的机会。
另一种看待它的方式是，“原始”计数器可以单独使用以生成有趣的输出的方式只有这么多；要获得比简单计数更复杂的东西，需要一些额外的逻辑，这些逻辑通常非常针对手头的问题。例如，如果我们想使用一个“计数器”来映射进程在处理器上计划运行的时间和它实际运行的时间之间的时间差值，我们不会期望这样的计数器单独存在，但我们可以派生出一个叫做“wakeup_latency”的方法，并使用它从跟踪数据中提取该指标的有用视图。同样，我们真的无法从标准分析工具中计算出系统上每个进程读取和写入的数据量，以及这些读取和写入中完全失败的次数。
幸运的是，有一种通用方法可以处理此类需求，称为“编程语言”。在给定数据的特定格式的情况下，使编程语言易于应用于此类问题被称为该数据和语言的“编程语言绑定”。Perf 支持两种编程语言绑定，一种用于 Python，一种用于 Perl。
捆绑在一起
用于操作和聚合跟踪数据的语言绑定当然不是一个新想法。第一个这样做的项目是 IBM 的 DProbes dpcc 编译器，这是一个 ANSI C 编译器，它针对在目标系统上的内核解释器上运行的低级汇编语言。这与 Sun 的 DTrace 所做的完全类似，只是 DTrace 为此目的发明了自己的语言。Systemtap 深受 DTrace 的启发，也创建了自己的一次性语言，但不是在内核解释器上运行该产品，而是创建了一个精心设计的基于编译器的机制，将其语言翻译成用 C 编写的内核模块。
现在我们在 perf.data 中有跟踪数据，我们可以使用 'perf script -g' 生成一个骨架脚本，其中包含我们记录的读/写进入/退出事件的处理程序：
root@crownbay:~# perf script -g python
generated Python script: perf-script.py
骨架脚本只是为 perf.data 文件中的每个事件类型创建一个 python 函数。每个函数的主体只是打印事件名称及其参数。例如：
def net__netif_rx(event_name, context, common_cpu,
common_secs, common_nsecs, common_pid, common_comm,
skbaddr, len, name):
print_header(event_name, common_cpu, common_secs, common_nsecs,
common_pid, common_comm)
print "skbaddr=%u, len=%u, name=%s\n" % (skbaddr, len, name),
我们可以直接运行该脚本来打印 perf.data 文件中包含的所有事件：
root@crownbay:~# perf script -s perf-script.py
in trace_begin
syscalls__sys_exit_read 0 11624.857082795 1262 perf nr=3, ret=0
sched__sched_wakeup 0 11624.857193498 1262 perf comm=migration/0, pid=6, prio=0, success=1, target_cpu=0
irq__softirq_raise 1 11624.858021635 1262 wget vec=TIMER
irq__softirq_entry 1 11624.858074075 1262 wget vec=TIMER
irq__softirq_exit 1 11624.858081389 1262 wget vec=TIMER
syscalls__sys_enter_read 1 11624.858166434 1262 wget nr=3, fd=3, buf=3213019456, count=512
syscalls__sys_exit_read 1 11624.858177924 1262 wget nr=3, ret=512
skb__kfree_skb 1 11624.858878188 1262 wget skbaddr=3945041280, location=3243922184, protocol=0
skb__kfree_skb 1 11624.858945608 1262 wget skbaddr=3945037824, location=3243922184, protocol=0
irq__softirq_raise 1 11624.859020942 1262 wget vec=TIMER
irq__softirq_entry 1 11624.859076935 1262 wget vec=TIMER
irq__softirq_exit 1 11624.859083469 1262 wget vec=TIMER
syscalls__sys_enter_read 1 11624.859167565 1262 wget nr=3, fd=3, buf=3077701632, count=1024
syscalls__sys_exit_read 1 11624.859192533 1262 wget nr=3, ret=471
syscalls__sys_enter_read 1 11624.859228072 1262 wget nr=3, fd=3, buf=3077701632, count=1024
syscalls__sys_exit_read 1 11624.859233707 1262 wget nr=3, ret
最低0.47元/天 解锁文章
5702
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
