使用Ftrace追踪和分析实时系统延迟源

需积分: 13 169 浏览量更新于2024-09-02 1 收藏 191KB PDF 举报

"ftrace_latency.pdf" 本文介绍了一个名为"Ftrace"的内核工具，它在Linux实时系统分析中扮演着关键角色，特别适用于定位和分析导致意外延迟的源头。Ftrace起源于-rt补丁中的延迟跟踪器，具有强大的功能，能够帮助开发者追踪和诊断各种类型的延迟问题。 1. 概述 Ftrace是一个内核调试和性能分析工具，它能够帮助开发者深入了解系统中延迟的来源。主要关注的问题是延迟是否由应用程序引起，还是由内核造成，或者是由于中断禁用、预emption禁用，或者这两者的组合所导致。通过对这些情况的精确追踪，Ftrace可以为实时系统的优化提供关键信息。 2. 唤醒延迟追踪 Ftrace能够捕获最高优先级任务的最大唤醒延迟。这不仅限于监控所有任务，还可以被配置为仅追踪实时进程的唤醒延迟。这种能力对于实时系统的性能评估至关重要，因为它能确保关键任务在预期时间内得到响应。 3. 中断和预emption禁用的延迟 Ftrace还包含一个专门的延迟追踪器，用于测量中断和/或预emption禁用的时间长度。通过记录这段时间内的最大延迟，开发者可以查看到在此期间调用的函数，这有助于识别出导致延迟的具体代码路径。 4. 丰富的追踪特性 Ftrace提供了丰富的追踪功能，这些特性可以帮助区分延迟是由内核引起还是应用程序的副作用。通过细致的事件记录和分析，开发者可以更准确地定位问题所在，从而进行针对性的优化。 5. 引言 Ftrace的控制结构允许用户自定义追踪事件，这使得它成为一个非常灵活的工具，能够适应各种复杂的系统分析需求。通过Ftrace，开发者可以深入到内核的底层，对系统行为有更深入的理解。 6. 应用场景在实时系统中，任何微小的延迟都可能影响整个系统的性能和稳定性。Ftrace的这些功能对于调试、性能优化以及问题排查都非常有用，特别是在需要确保系统满足严格的实时性要求的场景下。总结，Ftrace是Linux内核中一个强大的分析工具，它能够帮助开发者定位和解决与延迟相关的复杂问题，无论是应用程序还是内核层面。通过Ftrace，可以有效地提升实时系统的性能，并确保其满足严苛的服务质量标准。

that this could cause a very large overhead, but if

the kernel is also conﬁgured with dynamic function

tracing (CONFIG_DYNAMIC_FTRACE) then these calls,

when not in use, are converted at run time to nops.

This allows the function tracer to have zero overhead

when not in use. If you do not understand this part,

don’t worry, you do not need to understand the im-

plementation to use it. Just realize that enabling the

dynamic function tracer gives you great power with

no overhead.

4.2 The Heisenberg Principle

Any computer scientist (or any scientist for that mat-

ter) should be aware of the Heisenberg Principle

[3]. Basically this means that the act of measuring

something can and will modify the result. This is es-

pecially true with the interrupt tracer and even more

so when the function tracer is enabled. The idea is to

trace the time interrupts are disabled, but by adding

a tracer to these core functions, it adds a little over-

head. By running with the function tracer, it adds

even more overhead to the time interrupts are dis-

abled, because we are tracing every function that is

called within the critical section.

You do not need to unconﬁgure the function

tracer to keep it from running while tracing inter-

rupt latency. There exists a proc ﬁle that lets you

disable the function tracer from running at run time.

# echo 0 > /proc/sys/kernel/ftrace_enabled

This will allow you to ﬁnd something a bit closer

to the actual latency

. Listing 5 shows the result of

a latency trace with the function tracer disabled.

To get a good idea of the overhead, the bench-

mark test hackbench [4] can show the results well.

Running hackbench with the function tracer enabled

yields a test run time of 47.686 seconds and a max

latency of 171 microseconds (way above the max

that we allow for the real-time kernel). Running

hackbench with the function tracing disabled, yields

a test run of 34.361 seconds and a max latency of 30

microseconds

. Note: running hackbench with both

tracers disabled only took a running time of 9.774

seconds. I do not know the latency because it was

not being traced.

Note: when enabling or disabling the function

tracing for the latency tracers, it is best to reset the

tracer or it may take eﬀect. That is, echo in nop into

the current_tracer ﬁle and irqsoff again.

5 Reading the Trace

Before we continue to the other tracers, a descrip-

tion of how to read the output is in order. The lines

in the Listings of 1, 2, 3 and 4 are numbered. We

will go through some of the lines and explain their

meanings.

Lines 001 through 018 is the latency tracer

header, and is annotated with a ’#’ at the begin-

ning of the line. Line 001 states the name of the

current plugin tracer. Line 003 has the kernel ver-

sion that is executing (ignore the trace version, that

has not changed in a long time). Line 005 has a bit

of information. Here we see that the latency trace

recorded a 70 microsecond time that interrupts were

disabled. This may be diﬀerent than the last trace

entry, but not by much, due to the tracer writing

entries after it took the ﬁnishing time stamp. The

#170/170 means that there was 170 entries printed

out of 170 that were recorded. Since the latency

trace ftrace plugins are usually small

the two num-

bers should always match. But for other tracers, it is

quite possible to have the ﬁrst number smaller than

the second due to the trace ring buﬀer overwriting

older data.

The CPU#0 shows that this latency happened

on CPU 0. Inside the parenthesis, the VP, KP,

SP and HP will always be zero since they are not

yet implemented. The M element shows what type

of preemption the kernel was conﬁgured at. Here

it is “preempt” but really should be “preempt-rt”.

Since the latency tracer has been replaced with the

upstream ftrace, this ﬁeld has not been updated.

The other selections of preempt type are “desk-

top” for CONFIG

PREEMPT VOLUNTARY (ker-

nel preempts only at preemption points) or “server”

for CONFIG PREEMPT NONE (no preemption in-

side the kernel). The #P:2 shows that there were 2

online CPUS active.

Line 007 shows information about the task

that was executing when the latency was recorded.

The task here was “sirqtimer/0” with process id

5. The policy shows that it was running un-

der SCHED FIFO (1) where as 0 would be a

non real-time running the SCHED NORMAL policy.

SCHED RR is represented with 2, SCHED BATCH

is 3, and SCHED IDLE is 5. Because this is run-

ning under a real-time policy, the nice value can be

ignored. The rt_prio ﬁeld is the real-time prio as

Note: you must have a space between the 0 and the > otherwise the shell will interpret it as a redirection of standard I/O.

hackbench did not even get on the radar in this run

170 is small compared to thousands that the function tracer can do.

剩余13页未读，继续阅读

mounter625

粉丝: 1099
资源: 85

使用Ftrace追踪和分析实时系统延迟源

开源项目-evilsocket-ftrace.zip

Linux内核中断trace机制log解析工具

ftrace使用简介

ftrace_caller 和ftrace_regs_caller

ftrace_trace_function

kernel.ftrace_dump_on_oops = 0

struct ftrace_ops的结构定义（代码）

kernel.ftrace_enabled = 1

最新资源