Furkan İkkan Türkçe
Back to posts
Post

· Network & System Administrator

Profiling kernel function calls with Perfetto at microsecond resolution

Use Perfetto and tracepoint events to pinpoint latency sources in sched/switch and irq/handler at function level.

SistemPerfettoftracelatency analysiskernel tracing

When latency spikes appear in production Linux systems, guessing which kernel function is responsible wastes time. I’ve seen teams stare at top output or generic perf reports, only to miss the real culprit buried in interrupt handling or scheduler delays. Perfetto changes that by letting you trace kernel functions with microsecond resolution and correlate them to tracepoints like sched/switch or irq/handler. In this post, I’ll walk through how I use it to drill down from high-level latency symptoms to the exact function causing the delay.

Setting up Perfetto for kernel function tracing

First, ensure you have a recent kernel with function tracing enabled (CONFIG_FUNCTION_TRACER=y) and Perfetto installed. I typically use the official binary from perfetto.dev because distro packages often lag. Grab the latest release, extract it, and add the perfetto binary to your PATH.

To trace function calls alongside scheduler and irq events, I use a config like this:

# perfetto_config.pbtxt
buffers: {
  size_kb: 10240
  fill_policy: RING_BUFFER
}

data_sources: {
  config {
    name: "linux.ftrace"
    linux_ftrace_config {
      ftrace_events: "sched/switch"
      ftrace_events: "irq/handler*
      enable_function_tracing: true
      function_filter: "schedule\|do_softirq\|handle_irq"
    }
  }
}

This captures every sched/switch and irq/handler event while enabling function tracing for a focused set of functions. You can widen the filter later, but starting narrow avoids overwhelming the buffer.

Capturing the trace during a latency spike

I trigger the trace manually when I observe high latency—say, via a monitoring alert on 99th percentile response time. In one terminal, I start Perfetto:

perfetto -c perfetto_config.pbtxt -o latency_trace.pb

Let it run for 10–30 seconds during the spike, then stop with Ctrl+C. The output is a protobuf file you can load into the Perfetto UI (ui.perfetto.dev).

Analyzing function-level latency in the UI

Open the trace in the Perfetto web UI. First, look at the sched/switch trace to see when tasks are delayed. Zoom in on a gap where a task stays out of RUNNING longer than expected. Then, switch to the function trace track.

Here’s what I look for:

  • A long stretch of kernel function execution between two sched/switch events
  • Repeated calls to a specific function (e.g., do_softirq taking 200µs each time)
  • Irq/handler events stacking up before a task finally runs

In one case, I saw __do_softirq consuming 800µs per invocation during network spikes. The function filter had caught it, and the UI showed it was called from ixgbe_poll. That pointed directly to the NIC driver’s NAPI loop under heavy load.

Going deeper with custom function filters

Sometimes the default filter isn’t enough. If you suspect a subsystem but don’t know the exact function, enable broader tracing briefly:

# Temporarily enable all function tracing (use with caution)
echo function > /sys/kernel/debug/tracing/current_tracer
echo 1 > /sys/kernel/debug/tracing/tracing_on
# ... reproduce issue ...
echo 0 > /sys/kernel/debug/tracing/tracing_on

Then extract the trace with perfetto’s ftrace parser or compare it to a baseline. I keep a baseline trace from idle periods and use the diff view in Perfetto to see what changed.

Correlating with user-space impact

Kernel function delays only matter if they affect user tasks. In the Perfetto UI, enable the "sched" track to see task states. When a long irq/handler or function trace coincides with a task stuck in INTERRUPTIBLE_SLEEP or UNINTERRUPTIBLE_SLEEP, you’ve found the blocking path.

enable_function_tracing: true
function_filter: "schedule\|do_softirq\|handle_irq\|mysqld"

This helps isolate whether the delay is in kernel work done on behalf of a specific task.

Limitations and gotchas

Function tracing adds overhead—typically 2–5% CPU on modern kernels, but it can rise if you trace too many functions. I avoid enabling it globally on busy production boxes without testing first. Also, not all functions are traced due to compiler optimizations or dynamic tracing limits; if a function isn’t showing up, check if it’s marked notrace or static.

Another pitfall: buffer overruns. If you see "dropped events" in the trace stats, increase the buffer size or shorten the capture window. I’ve found 10MB buffers sufficient for 30-second spikes on most systems.

When to reach for Perfetto over perf or eBPF

I still use perf record -g for CPU flamegraphs when I need user-kernel mixed stacks. But for latency hunting where timing and tracepoint correlation matter—especially around scheduling and interrupts—Perfetto gives me a clearer, synchronized view. It’s also easier to share traces with teammates than perf.data files.

As I mentioned before in my post about Auditd and SIEM integration, having traceable, queryable data beats guessing. Perfetto turns kernel latency from a black box into a traceable signal.

If you’re dealing with mysterious jitter in networking, storage, or real-time workloads, start with sched/switch and irq/handler traces, add function filtering, and let the data show you where time is really going.

Cover image: USDAgov · PDM (Openverse / kamu malı) · https://www.flickr.com/photos/41284017@N08/7644752188