如何在ftrace/trace-cmd中获取}后函数名及编写超10ms函数统计脚本

Great to hear you're already leveraging ftrace and trace-cmd for function graph tracing! Extracting functions that exceed a specific latency threshold is a super useful workflow, and we can build a straightforward script to automate this.

Step 1: Capture Your Trace (With a Custom Output File) #

First, it's good practice to save your trace to a named file instead of using the default trace.dat (to avoid overwriting):

trace-cmd record -p function_graph -F <your-bash-command> -o my_trace.dat

Step 2: Script to Filter Functions Taking >10ms #

Here's a bash script that parses the trace-cmd report output, converts units (if needed), and filters out functions that take longer than 10ms:

#!/bin/bash

# Use provided trace file or default to trace.dat
TRACE_FILE="${1:-trace.dat}"

# Check if trace file exists
if [ ! -f "$TRACE_FILE" ]; then
    echo "Error: Trace file $TRACE_FILE not found!"
    exit 1
fi

# Parse trace report and filter slow functions
trace-cmd report -i "$TRACE_FILE" | awk '
# Target lines marking function completion (containing "}" )
/}/ {
    # Extract duration value and unit using regex
    if (match($0, /([0-9]+\.[0-9]+) (ms|us)/, duration_match)) {
        duration = duration_match[1]
        unit = duration_match[2]

        # Convert microseconds to milliseconds if needed
        if (unit == "us") {
            duration = duration / 1000
        }

        # Check if duration exceeds 10ms
        if (duration >= 10) {
            # Extract function name from the line
            if (match($0, /} ([^()]+)\(\);/, func_match)) {
                func_name = func_match[1]
                printf "%.3f ms | %s\n", duration, func_name
            }
        }
    }
}'

How to Use the Script #

1. Save the script as filter_slow_funcs.sh
2. Make it executable:

   chmod +x filter_slow_funcs.sh
   

3. Run it with your trace file (or omit the file to use trace.dat):

   ./filter_slow_funcs.sh my_trace.dat
   

Bonus Enhancements #

• Deduplicate Results: To see unique slow functions, pipe the output to sort and uniq:

  ./filter_slow_funcs.sh my_trace.dat | sort -k2 | uniq
  

• Calculate Aggregate Stats: To get max/average duration per function, extend the script with awk's associative arrays:

  # Replace the printf in the awk block with:
  func_durations[func_name] = func_durations[func_name] " " duration
  
  # Add this END block at the end of the awk script:
  END {
      for (func in func_durations) {
          split(func_durations[func], durations)
          count = length(durations)
          sum = 0
          max = 0
          for (d in durations) {
              sum += durations[d]
              if (durations[d] > max) max = durations[d]
          }
          avg = sum / count
          printf "Function: %s | Max: %.3f ms | Avg: %.3f ms | Calls: %d\n", func, max, avg, count
      }
  }
  

Notes #

• The regex patterns assume standard trace-cmd report output. If your version uses slightly different formatting, adjust the regex matches to fit your trace lines.
• For very large trace files, use trace-cmd report with filtering options (like -P to target specific processes) first to reduce the data the script processes.

内容的提问来源于stack exchange，提问作者kokkalla kalyan