trace-cmd-report - 云端在线

程序：

您的姓名

trace-cmd-report - 以 ASCII 显示由 trace-cmd 记录创建的跟踪

概要

跟踪命令 报告 [配置[输入文件]

商品描述

这个 跟踪命令(1) report 命令将输出一个人类可读的跟踪报告
trace-cmd 记录。

配置

-i 输入文件
默认情况下，trace-cmd 报告会读取文件 跟踪文件。 但 -i 选项打开
给定的 输入文件 反而。 注意，输入文件也可以指定为最后一个
命令行中的项目。

-e
这将输出文件的字节序。 trace-cmd 报告足够智能，能够
在小端机器上读取大端文件，反之亦然。

-f
这将输出已记录在文件中的函数列表。

-P
这将输出“trace_printk()”数据列表。 原始跟踪数据指向静态
内核中的指针。 这必须存储在 trace.dat 文件中。

-E
这列出了文件中可能的事件（但这个列表不一定是列表
文件中的事件）。

--事件
这将列出存储在 trace.dat 文件中的事件格式。

- 事件 正则表达式
这将打印与给定正则表达式匹配的事件。 如果指定了冒号，则
冒号前的字符将用于匹配系统和后的字符
冒号将匹配事件。

trace-cmd 报告 --event sys:read

以上只会匹配系统名称包含“sys”的事件
并且事件名称包含“读取”。

trace-cmd 报告 --event 读取

以上将匹配名称中包含“read”的所有事件。 还有它
也可以列出包含“读取”的系统的所有事件。

--检查事件
这将解析存储在 trace.dat 文件中的事件格式字符串并
返回是否可以正确解析格式。 它会加载插件，除非 -N is
指定的。

-t
打印完整的时间戳。 数据文件中的时间戳通常记录到
纳秒。 但是时间戳的默认显示只有到微秒。 到
查看完整的时间戳，添加 -t 选项。

-F 过滤
添加过滤器以限制显示的事件。 过滤器的格式为：

':'
=系统'/'事件| 系统 | 活动 | ','
= EVENT_FIELD | '&&' |
'||' | '(' ')' | '！
= '==' | '!=' | '>=' | '<=' | '>' | '<' | '&' | '|' | '^' |
'+' | '-' | '*' | '/' | '%'
= NUM​​ | 字符串 | EVENT_FIELD

SYSTEM 是要过滤的系统的名称。 如果 EVENT 被排除在外，
那么它适用于系统下的所有事件。 如果只使用一个字符串
没有 '/' 来分隔 SYSTEM 和 EVENT，那么过滤器
将应用于与给定字符串匹配的所有系统和事件。

空白被忽略，这样 "sched:next_pid==123" 等价于
“调度：next_pid == 123”。

STRING 用单引号或双引号定义（单引号必须以
单引号，双引号）。 引号内的空格不是
忽略了。

SYSTEM 或 EVENT 的表示也可以是正则表达式
由 ' 定义正则表达式（3）”。

EVENT_FIELD 是正在执行的事件字段的名称
过滤。 如果事件不包含 EVENT_FIELD，那部分
等式将被视为错误。

-F 'sched : 假 == 1 || common_pid == 2'

“bogus == 1”将始终评估为 FALSE，因为没有事件具有
名为“bogus”的字段，但仍会评估“common_pid == 2”
因为所有事件都有字段“common_pid”。 任何“sched”事件
将显示由 PID 为 2 的进程跟踪。

注意，EVENT_FIELD 是字段名称，如事件格式所示
（如 *--events* 所示），而不是在输出中找到的内容。
如果输出显示“ID:foo”但“foo”所属的字段是
在事件格式中称为“name”，则过滤器中必须使用“name”。
价值观也是如此。 如果显示的值被转换
by 到一个字符串符号，过滤器检查原始值而不是
值显示。 例如，要过滤在
上下文切换时的运行状态：

-F 'sched/sched_switch : prev_state==0'

尽管输出显示 'R'，但具有 'prev_stat=="R"' 将不起作用。

注意：您还可以将“COMM”指定为 EVENT_FIELD。 这将使用
要比较的记录的任务名称（或通信）。 例如，过滤掉
所有“trace-cmd”任务：

-F '.*:COMM != "trace-cmd"'

-v
这会导致以下过滤器 -F 过滤掉匹配的事件。

-v -F 'sched/sched_switch : prev_state == 0'

不会显示 prev_state 为 0 的任何 sched_switch 事件。
删除 *-v* 只会打印出这些事件。

-T
测试 -F 的过滤器。 处理过滤器字符串后，生成的过滤器将是
为每个事件显示。 这对于将过滤器用于多个事件很有用
其中一个字段可能并非在所有事件中都存在。 它也可以用来确保有
没有拼写错误的事件字段名称，因为它们将被简单地忽略。 -T 被忽略如果 -F
未指定。

-V
显示加载的插件。

-L
这不会加载系统范围的插件。 它加载“仅限本地”。 这就是它发现的
，在 ~/.trace-cmd/插件 目录。

-N
这不会加载任何插件。

-n 事件重新
这将导致与该选项匹配的所有事件忽略任何已注册的处理程序（通过
插件）打印事件。 将改为打印正常事件。 这
事件重新 是由定义的正则表达式 正则表达式(3).

- 轮廓
随着 - 轮廓 选项，“trace-cmd report”将首先处理所有事件，并且
然后输出一个格式，显示任务在内核中花费的时间，以及
它们被阻塞最多的地方，以及唤醒延迟的地方。

参见 跟踪命令配置文件(1) 有关更多详细信息和示例。

-H 事件挂钩
添加自定义事件匹配以将任意两个事件连接在一起。

参见 跟踪命令配置文件(1) 格式。

-R
这将以“原始”格式显示事件。 也就是说，它将忽略事件的打印
格式化并打印每个字段的内容。

-r 事件重新
这将导致与选项匹配的所有事件打印其原始字段。 这 事件重新
是由定义的正则表达式 正则表达式(3).

-l
这增加了“延迟输出”格式。 有关中断被禁用的信息，软
irq 被禁用，“need_resched”标志被设置，抢占计数和大内核
每个事件都会记录锁定。 但是默认显示不显示
此信息。 此选项将设置以 6 个字符显示此信息。
当其中一个字段为零或 N/A 时，会显示 '.\'。

-0 0d.h1。 106467.859747：函数：ktime_get <--tick_check_idle

0d.h1。 表示此信息。 第一个字符永远不是'.'
并表示跟踪记录在哪个 CPU 上（CPU 0）。 'd' 表示
中断被禁用。 'h' 表示这是在内部调用的
一个中断处理程序。 “1”是禁用抢占（preempt_count）
被设置为一。 两个“.”是“need_resched”标志和内核锁
柜台。 如果设置了“need_resched”标志，则该字符将是
'N'。

-w
如果两者都 调度开关 和 计划唤醒 事件已启用，则此选项将
报告任务第一次被唤醒的时间和它被唤醒的时间之间的延迟
预定在。

-q
安静的非严重警告。

-O
将选项传递给加载的 trace-cmd 插件。

-O 插件：var=value

'plugin:' 和 '=value' 是可选的。 选项的值可能会被忽略
那是布尔值。 如果 'plugin:' 被关闭，那么任何匹配的变量
在所有插件中将被设置。

示例：-O fgraph:tailprint

--统计
如果 trace.dat 文件记录了最终统计数据（在记录末尾输出）
--统计 选项可用于检索它们。

--uname
如果 trace.dat 文件在运行期间记录了 uname，这将检索到
信息。

示例

使用通过以下方式创建的 trace.dat 文件：

# trace-cmd 记录 -p 函数 -e all sleep 5

默认报告显示：

# trace-cmd 报告
trace-cmd-16129 [002] 158126.498411：函数：__mutex_unlock_slowpath <-- mutex_unlock
trace-cmd-16131 [000] 158126.498411: kmem_cache_alloc: call_site=811223c5 ptr=0xffff88003ecf2b40 bytes_req=272 bytes_alloc=320 gfp_flags=GFP_ZKEEROEL|GFP
trace-cmd-16130 [003] 158126.498411：函数：do_splice_to <-- sys_splice
sleep-16133 [001] 158126.498412：函数：inotify_inode_queue_event <-- vfs_write
trace-cmd-16129 [002] 158126.498420: lock_release: 0xffff88003f1fa4f8 &sb->s_type->i_mutex_key
trace-cmd-16131 [000] 158126.498421：函数：security_file_alloc <-- get_empty_filp
sleep-16133 [001] 158126.498422：函数：__fsnotify_parent <-- vfs_write
trace-cmd-16130 [003] 158126.498422：函数：rw_verify_area <-- do_splice_to
trace-cmd-16131 [000] 158126.498424：函数：cap_file_alloc_security <-- security_file_alloc
trace-cmd-16129 [002] 158126.498425：函数：syscall_trace_leave <-- int_check_syscall_exit_work
sleep-16133 [001] 158126.498426：函数：inotify_dentry_parent_queue_event <-- vfs_write
trace-cmd-16130 [003] 158126.498426：函数：security_file_permission <-- rw_verify_area
trace-cmd-16129 [002] 158126.498428：函数：audit_syscall_exit <--syscall_trace_leave
[...]

要查看除函数跟踪之外的所有内容：

# trace-cmd 报告 -v -F 'function'
trace-cmd-16131 [000] 158126.498411: kmem_cache_alloc: call_site=811223c5 ptr=0xffff88003ecf2b40 bytes_req=272 bytes_alloc=320 gfp_flags=GFP_ZKEEROEL|GFP
trace-cmd-16129 [002] 158126.498420: lock_release: 0xffff88003f1fa4f8 &sb->s_type->i_mutex_key
trace-cmd-16130 [003] 158126.498436：lock_acquire：0xffffffff8166bf78 读取 all_cpu_access_lock
trace-cmd-16131 [000] 158126.498438：lock_acquire：0xffff88003df5b520 读取 &fs->lock
跟踪-cmd-16129 [002] 158126.498446: kfree: call_site=810a7abb ptr=0x0
trace-cmd-16130 [003] 158126.498448: lock_acquire: 0xffff880002250a80 &per_cpu(cpu_access_lock, cpu)
跟踪 cmd-16129 [002] 158126.498450：sys_exit_splice：0xfffffff5
trace-cmd-16131 [000] 158126.498454: lock_release: 0xffff88003df5b520 &fs->lock
sleep-16133 [001] 158126.498456：kfree：call_site = 810a7abb ptr = 0x0
sleep-16133 [001] 158126.498460：sys_exit_write：0x1
trace-cmd-16130 [003] 158126.498462：kmalloc：call_site=810bf95b ptr=0xffff88003dedc040 bytes_req=24 bytes_alloc=32 gfp_flags=GFP_KERNEL|GFP_ZERO

仅查看大于 1000 字节的 kmalloc 调用：

#trace-cmd 报告 -F 'kmalloc: bytes_req > 1000'
-0 [000] 158128.126641: kmalloc: call_site=81330635 ptr=0xffff88003c2fd000 bytes_req=2096 bytes_alloc=4096 gfp_flags=GFP_ATOMIC

要查看使上一个任务处于运行状态的唤醒和调度开关：

# trace-cmd 报告 -F 'sched: prev_state == 0 || (成功 == 1)'
trace-cmd-16132 [002] 158126.499951: sched_wakeup: comm=trace-cmd pid=16129 prio=120 成功=1 target_cpu=002
trace-cmd-16132 [002] 158126.500401: sched_switch: prev_comm=trace-cmd prev_pid=16132 prev_prio=120 prev_state=R ==> next_comm=trace-cmd next_pid=16129 next_prio=120
-0 [003] 158126.500585: sched_wakeup: comm=trace-cmd pid=16130 prio=120 success=1 target_cpu=003
-0 [003] 158126.501241: sched_switch: prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=trace-cmd next_pid=16130 next_prio=120
trace-cmd-16132 [000] 158126.502475: sched_wakeup: comm=trace-cmd pid=16131 prio=120 成功=1 target_cpu=000
trace-cmd-16131 [002] 158126.506516: sched_wakeup: comm=trace-cmd pid=16129 prio=120 成功=1 target_cpu=002
-0 [003] 158126.550110: sched_switch: prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=trace-cmd next_pid=16130 next_prio=120
trace-cmd-16131 [003] 158126.570243: sched_wakeup: comm=trace-cmd pid=16129 prio=120 成功=1 target_cpu=003
trace-cmd-16130 [002] 158126.618202: sched_switch: prev_comm=trace-cmd prev_pid=16130 prev_prio=120 prev_state=R ==> next_comm=yum-updatesd next_pid=3088 next_prio=1
trace-cmd-16129 [003] 158126.622379: sched_wakeup: comm=trace-cmd pid=16131 prio=120 成功=1 target_cpu=003
trace-cmd-16129 [000] 158126.649287: sched_wakeup: comm=trace-cmd pid=16131 prio=120 成功=1 target_cpu=000

以上需要稍微解释一下。 过滤器指定了“sched”子系统，它
包括 sched_switch 和 sched_wakeup 事件。 任何没有
格式字段“prev_state”或“success”，会将这些表达式评估为 FALSE，并将
不产生匹配。 使用“||” 将进行“prev_state”测试
“sched_switch”事件和“sched_wakeup”事件的“成功”测试发生。

# trace-cmd report -w -F 'sched_switch, sched_wakeup.*'
[...]
trace-cmd-16130 [003] 158131.580616: sched_wakeup: comm=trace-cmd pid=16131 prio=120 成功=1 target_cpu=003
trace-cmd-16129 [000] 158131.581502: sched_switch: prev_comm=trace-cmd prev_pid=16129 prev_prio=120 prev_state=S ==> next_comm=trace-cmd next_pid=16131 next_prio.tc=120 next_prio.885.901
trace-cmd-16131 [000] 158131.582414: sched_wakeup: comm=trace-cmd pid=16129 prio=120 成功=1 target_cpu=000
trace-cmd-16132 [001] 158131.583219: sched_switch: prev_comm=trace-cmd prev_pid=16132 prev_prio=120 prev_state=S ==> next_comm=trace-cmd next_pid=16129 next_prio.tc=120 next_prio.804.809
sleep-16133 [002] 158131.584121：sched_wakeup：comm=trace-cmd pid=16120 prio=120 success=1 target_cpu=002
trace-cmd-16129 [001] 158131.584128: sched_wakeup: comm=trace-cmd pid=16132 prio=120 成功=1 target_cpu=001
sleep-16133 [002] 158131.584275: sched_switch: prev_comm=sleep prev_pid=16133 prev_prio=120 prev_state=R ==> next_comm=trace-cmd next_pid=16120 next_prio=120 use Lats.
trace-cmd-16130 [003] 158131.585284: sched_switch: prev_comm=trace-cmd prev_pid=16130 prev_prio=120 prev_state=S ==> next_comm=trace-cmd next_pid=16132 next_prio.tc=120 next_prio.1155.677

平均唤醒延迟：26626.656 微秒

上面的跟踪产生了任务的唤醒延迟。 “sched_switch”事件
在写入事件信息后报告每个单独的延迟。 在结束时
报告，报告平均唤醒延迟。

# trace-cmd 报告 -w -F 'sched_switch, sched_wakeup.*: prio < 100 || next_prio < 100'
-0 [003] 158131.516753: sched_wakeup: comm=ksoftirqd/3 pid=13 prio=49 success=1 target_cpu=003
-0 [003] 158131.516855：sched_switch：prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=ksoftirqd/3 next_pid=13 next_prio=49 延迟：101.244
-0 [003] 158131.533781: sched_wakeup: comm=ksoftirqd/3 pid=13 prio=49 success=1 target_cpu=003
-0 [003] 158131.533897：sched_switch：prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=ksoftirqd/3 next_pid=13 next_prio=49 延迟：115.608
-0 [003] 158131.569730: sched_wakeup: comm=ksoftirqd/3 pid=13 prio=49 success=1 target_cpu=003
-0 [003] 158131.569851：sched_switch：prev_comm=swapper prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=ksoftirqd/3 next_pid=13 next_prio=49 延迟：121.024

平均唤醒延迟：110.021 微秒

上面的版本只会显示实时任务的唤醒和上下文切换。 这
PRIO 在内核中使用从 0 开始以获得最高优先级。 那是 PRIO 0 是等价的
到用户空间实时优先级99，优先级98相当于用户空间实时
优先级 1. 小于 100 的 Prios 代表实时任务。

配置文件示例：

# trace-cmd 记录 --profile sleep 1
# trace-cmd 报告 --profile --comm 睡眠
任务：sleep-21611
事件：sched_switch:R (1) 总数：99442 平均值：99442 最大值：99442 最小值：99442
1 总数：99442 最小值：99442 最大值：99442 平均值=99442
=> ftrace_raw_event_sched_switch (0xffffffff8105f812)
=> __schedule (0xffffffff8150810a)
=> preempt_schedule (0xffffffff8150842e)
=> ___preempt_schedule (0xffffffff81273354)
=> cpu_stop_queue_work (0xffffffff810b03c5)
=> stop_one_cpu (0xffffffff810b063b)
=> sched_exec (0xffffffff8106136d)
=> do_execve_common.isra.27 (0xffffffff81148c89)
=> do_execve (0xffffffff811490b0)
=> SyS_execve (0xffffffff811492c4)
=> return_to_handler (0xffffffff8150e3c8)
=> stub_execve (0xffffffff8150c699)
事件：sched_switch:S (1) 总数：1000506680 平均值：1000506680 最大值：1000506680 最小值：1000506680
1 总数：1000506680 最小值：1000506680 最大值：1000506680 平均值=1000506680
=> ftrace_raw_event_sched_switch (0xffffffff8105f812)
=> __schedule (0xffffffff8150810a)
=> 时间表（0xffffffff815084b8）
=> do_nanosleep (0xffffffff8150b22c)
=> hrtimer_nanosleep (0xffffffff8108d647)
=> SyS_nanosleep (0xffffffff8108d72c)
=> return_to_handler (0xffffffff8150e3c8)
=> tracesys_phase2 (0xffffffff8150c304)
事件：sched_wakeup:21611 (1) 总数：30326 平均值：30326 最大值：30326 最小值：30326
1 总数：30326 最小值：30326 最大值：30326 平均值=30326
=> ftrace_raw_event_sched_wakeup_template (0xffffffff8105f653)
=> ttwu_do_wakeup (0xffffffff810606eb)
=> ttwu_do_activate.constprop.124 (0xffffffff810607c8)
=> try_to_wake_up (0xffffffff8106340a)

使用 onworks.net 服务在线使用 trace-cmd-report