criticalstat

@amitmund September 11, 2026

Linux criticalstat — Complete Learning Notes & Output Guide

criticalstat is an eBPF/BCC performance-tracing tool designed to measure the duration of kernel critical sections where preemption is disabled (preempt_disable()) or interrupts are disabled (local_irq_disable()). By logging critical sections that exceed a specified time threshold, it identifies kernel routines, lock contentions, and device drivers responsible for system latency spikes, scheduling jitter, and real-time execution delays.


1. What is criticalstat?

In the Linux kernel, critical sections protect shared internal data structures using spinlocks, raw spinlocks, or explicit disablement calls:

  • Preemption Disabled (preempt_disable): Prevents the Linux CPU scheduler from context-switching the current task off the core, even if a higher-priority task (or real-time thread) becomes runnable.
  • Interrupts Disabled (local_irq_disable): Prevents the CPU core from responding to hardware interrupts (IRQs) and timer ticks.

When a driver or kernel subsystem keeps preemption or hardware interrupts disabled for too long, the system experiences scheduling jitter, network packet drops, and audio/video buffer underruns.

criticalstat instruments these sections without requiring full kernel re-compilations with heavy debug instrumentation.

It answers critical low-latency and systems engineering questions:

  • Which kernel functions or drivers are disabling hardware interrupts or preemption for excessive durations?
  • Why is a high-priority real-time thread (SCHED_FIFO / SCHED_RR) experiencing scheduling delays?
  • Which spinlock or kernel code path is the source of recurring microsecond-level latency spikes?
  • Are interrupts being masked during storage writes, network packet processing, or memory allocation?

2. Installation & Prerequisites

criticalstat is part of the BCC (BPF Compiler Collection) toolkit and requires root privileges (sudo) and a kernel with eBPF and kprobes enabled.

Debian / Ubuntu

sudo apt update
sudo apt install bpfcc-tools linux-headers-$(uname -r)

(On Debian/Ubuntu, BCC tools reside in /usr/sbin/ with a -bpfcc suffix: criticalstat-bpfcc).

RHEL / Rocky / AlmaLinux / CentOS

sudo dnf install bcc-tools kernel-devel-$(uname -r)

(Executables reside in /usr/share/bcc/tools/criticalstat).

Arch Linux

sudo pacman -S bcc-tools

Verify:

sudo criticalstat -h 2>/dev/null || sudo criticalstat-bpfcc -h


3. Basic Syntax & Primary Options

sudo criticalstat [options]

Essential Command Flags

Flag Purpose Practical Example
**-i, --irq** Trace sections where hardware interrupts (IRQs) are disabled. sudo criticalstat -i
**-p, --preempt** Trace sections where kernel preemption is disabled. sudo criticalstat -p
**-d <us>, --duration <us>** Set the minimum latency threshold in microseconds (only log sections exceeding this value). sudo criticalstat -i -d 100
**-s, --stack** Print the kernel call stack trace that entered the critical section. sudo criticalstat -p -s

4. Anatomy of criticalstat Output

Running criticalstat targeting interrupt-disabled sections exceeding $50\,\mu\text{s}$:

sudo criticalstat -i -d 50

Raw Output Example

Tracing critical sections with IRQs disabled longer than 50 us... Hit Ctrl-C to end.
TIME(s)     CPU  COMM             PID    LAT(us)  CALLER
07:42:01    2    swapper/2        0           85  default_idle
07:42:05    0    kworker/u8:1     120         64  _raw_spin_lock_irqsave
07:42:12    3    postgres         5410        72  finish_task_switch
07:42:18    1    systemd-journal  1120        95  zap_pte_range

Raw Output Example with Kernel Stacks (-s)

sudo criticalstat -p -d 100 -s

TIME(s)     CPU  COMM             PID    LAT(us)  CALLER
07:45:10    4    python3          8912       142  _raw_spin_lock
    _raw_spin_lock+0x5/0x30
    futex_wait_queue_me+0x80/0x120
    do_futex+0x140/0x8a0
    __x64_sys_futex+0x85/0x180
    do_syscall_64+0x38/0xc0


5. Breakdown of Every Output Heading & Field

+----------+-----+-----------------+------+---------+------------------------+
| TIME(s)  | CPU | COMM            | PID  | LAT(us) | CALLER                 |
+----------+-----+-----------------+------+---------+------------------------+
| 07:42:05 |  0  | kworker/u8:1    | 120  |      64 | _raw_spin_lock_irqsave |
+----------+-----+-----------------+------+---------+------------------------+

5.1 TIME(s)

  • Format: HH:MM:SS or relative seconds since tool start.
  • Meaning: The timestamp when the critical section exited (re-enabled interrupts or preemption).

5.2 CPU

  • Format: Integer (e.g., 0, 2).
  • Meaning: The logical CPU core on which the critical section was executed.
  • Troubleshooting Significance: Identifies whether critical section stalls are concentrated on a specific socket, core complex, or IRQ-handling core.

5.3 COMM

  • Format: String (first 16 characters of task_struct->comm).
  • Meaning: The executable command name of the task running when the critical section began. If the CPU was in an idle power-saving state, it appears as swapper/N.

5.4 PID

  • Format: Integer.
  • Meaning: The Process ID of the active task.

5.5 LAT(us)

  • Format: Integer microseconds ($\mu\text{s}$).
  • Meaning: The total duration for which preemption or interrupts remained disabled on that CPU core:

$$\text{Duration} = \text{Timestamp}_{\text{enable}} - \text{Timestamp}_{\text{disable}}$$

  • Diagnostic Thresholds:
  • For standard enterprise servers: Critical sections $>100\,\mu\text{s}$ are notable.
  • For low-latency / real-time trading / audio systems: Any critical section $>20\,\mu\text{s}$ is considered problematic.

5.6 CALLER

  • Format: Kernel function symbol name (e.g., _raw_spin_lock_irqsave, zap_pte_range, finish_task_switch).
  • Meaning: The specific kernel function responsible for disabling preemption/interrupts or acquiring the critical lock.

6. How criticalstat Works Internally

criticalstat tracks state transitions across kernel lock primitives:

+-------------------------------------------------------------------------+
|                              KERNEL SPACE                               |
|                                                                         |
|   1. Critical Section Entry:                                            |
|      - When tracing IRQs (-i): Hooks tracepoint/kprobe on               |
|        local_irq_disable() or trace_irq_disable()                       |
|      - When tracing Preemption (-p): Hooks preempt_disable() or         |
|        trace_preempt_disable()                                          |
|      - Records: Key = CPU ID                                            |
|                 Value = { start_ns: bpf_ktime_get_ns(), caller_ip }     |
|                 in BPF Per-CPU Array/Hash Map                           |
|                                                                         |
|   2. Critical Section Exit:                                             |
|      - Hooks local_irq_enable() or preempt_enable()                     |
|      - Calculates: delta_us = (bpf_ktime_get_ns() - start_ns) / 1000   |
|      - Evaluates: If delta_us >= threshold:                             |
|          - Emits event record via BPF Ring Buffer to user space         |
|      - Clears CPU entry in BPF map                                      |
+-------------------------------------------------------------------------+
                                    |
                                    v (BPF Ring Buffer)
+-------------------------------------------------------------------------+
|                              USER SPACE                                 |
|   Python CLI: Resolves kernel caller IP addresses into human-readable   |
|               symbols (/proc/kallsyms) and prints formatted output.     |
+-------------------------------------------------------------------------+


7. Preemption Disabled vs. Interrupts Disabled

+-----------------------------------+-----------------------------------+
|     Preemption Disabled (-p)      |      Interrupts Disabled (-i)     |
+-----------------------------------+-----------------------------------+
| * The CPU CAN service hardware    | * The CPU CANNOT service hardware |
|   interrupts (network, disk).     |   interrupts or timer ticks.      |
| * The scheduler CANNOT switch     | * The scheduler CANNOT run.       |
|   to another user or RT thread.   | * Complete core blindness to      |
| * Caused by: standard spinlocks,  |   incoming physical events.       |
|   rcu_read_lock(), preempt_disable| * Caused by: spin_lock_irqsave(), |
|                                   |   hardware ISRs, local_irq_disable|
+-----------------------------------+-----------------------------------+

The Real-Time Latency Cascade

When a driver runs with interrupts disabled for $200\,\mu\text{s}$:

  1. Incoming network packets hitting the NIC cannot trigger the hardware interrupt handler.
  2. The NIC's onboard FIFO and host ring buffer risk overflowing, causing packet drops.
  3. High-priority RT threads waiting on timer events miss their deadlines because timer interrupts are held pending.

8. Real-World Troubleshooting Scenarios

Scenario A: Investigating Scheduling Jitter in Low-Latency Workloads

A high-frequency trading application or real-time control system pinned to dedicated cores experiences recurring $100\,\mu\text{s}$ latency spikes.

Trace preemption-disabled sections exceeding $50\,\mu\text{s}$:

sudo criticalstat -p -d 50 -s

Diagnosis: The output logs zap_pte_range or unmap_page_range with durations over $80\,\mu\text{s}$. Root Cause: Another process on the system is freeing massive memory allocations or tearing down virtual memory areas. The kernel traverses large page tables while holding memory locks with preemption disabled, stalling tasks on that core.


Scenario B: Isolating a Misbehaving Hardware Device Driver

A physical server experiences sporadic TCP packet drops on a 10GbE adapter during disk-heavy backups, despite low overall CPU utilization.

Trace interrupt-disabled sections exceeding $100\,\mu\text{s}$:

sudo criticalstat -i -d 100

Output:

TIME(s)     CPU  COMM             PID    LAT(us)  CALLER
11:02:14    0    kworker/0:2      45     185      megasas_build_and_issue_cmd

Diagnosis: The storage RAID controller driver (megaraid_sas) holds interrupts disabled for $185\,\mu\text{s}$ inside megasas_build_and_issue_cmd to serialize access to hardware command registers. During this window, the NIC on CPU 0 cannot service incoming frame interrupts, leading to ring buffer drops.


9. Important Interview Questions & Answers

Q: What is the difference between criticalstat and the kernel's built-in ftrace latency tracers (irqsoff and preemptoff)?

Answer: Both target the same phenomenon (sections where IRQs or preemption are disabled), but their mechanisms and operational footprints differ:

  • ftrace (irqsoff/preemptoff): Relies on the kernel compilation flags CONFIG_IRQSOFF_TRACER and CONFIG_PREEMPT_TRACER. When active, it instruments every function entry via compiler profiling (-pg / mcount), introducing measurable overhead across the entire kernel.
  • criticalstat: Uses in-kernel eBPF. It attaches dynamically to tracepoints or kprobes at the entry and exit points of lock primitives or disablement calls. It introduces lower system overhead and can be loaded, filtered by threshold, and unloaded dynamically without reconfiguring debug filesystems.

Q: Why is disabling interrupts more disruptive to real-time latency than disabling preemption?

Answer: Disabling preemption prevents user-space threads (including real-time threads) from preempting the running task, but the CPU core can still respond to hardware interrupts, clock timers, and device notifications. Disabling interrupts (local_irq_disable) blocks the CPU core from acknowledging all external physical events and timer ticks. As a result, interrupt handling is deferred, hardware buffers on peripherals risk filling and dropping data, and timer-driven scheduling decisions are delayed until interrupts are explicitly re-enabled.


0 Likes
2 Views
0 Comments

Filters

No filters available for this view.

Reset All