如何将perf.data缩小到时间子间隔

I use linux perf (perf_events) to produce a perf.data file with timestamps.

我使用linux perf（perf_events）生成带有时间戳的perf.data文件。

How can I generate a report of all the events in a sub interval of time [i-start, i-end]?

如何在子时间间隔[i-start，i-end]中生成所有事件的报告？

Can I maybe narrow down perf.data to a perf_subinterv.data file with only events in [i-start, i-end]?

我可以将perf.data缩小到只包含[i-start，i-end]中的事件的perf_subinterv.data文件吗？

I need to do this to analyze short intervals (2s - 6s) of poor performance every 5mins or so.

我需要这样做来分析每5分钟左右性能不佳的短间隔（2s - 6s）。

2 个解决方案

#1

I still cannot produce a perf_subinterv.data, but I can narrow down the perf trace in textual representation. Then, for further analysis, I can for instance generate a flame graph.

我仍然无法生成perf_subinterv.data，但我可以缩小文本表示中的perf跟踪。然后，为了进一步分析，我可以例如生成火焰图。

Command to narrow to time interval at 19:29:43 with 3.47s duration:

命令在19:29:43缩小到时间间隔，持续时间为3.47秒：

perf script -i ./perf_2016-03-23_192924.468036489.data | awk -v perfdata=./perf_2016-03-23_192924.468036489.data -v interval_start=19:29:43 -v duration=3.47 -f perf_script_cut_interval.awk > perf_2016-03-23_192924.468036489_INTERV_19:29:43.txt

Generation of flame graph:

生成火焰图：

stackcollapse-perf.pl perf_2016-03-23_192924.468036489_INTERV_19:29:43.txt | flamegraph.pl > perf_2016-03-23_192924.468036489_INTERV_19:29:43.svg

gawk script:

gawk脚本：

#
# Consumes output of 'perf script profile.data' and filters events from a given
# time interval
#
# input variables:
#
# perfdata:
#
#      File with profiling data. Name must be perf_<date>_<time>.data, where
#      <time> has the format <hh><mm><secs>, e.g. perf_2016-03-23_140426.002147215.data
#     
# interval_start:
#
#      Start time of the interval with format <hh><mm><secs>, e.g. 19:29:43.890735
#
# duration:
#
#      length of the interval
#

BEGIN {
  print("processing", perfdata) > "/dev/stderr"
  # parse timestamp of perf rec start
  match(perfdata, /.*perf_.*_(..)(..)(.+)\.data/, ts_perf_rec)
  # parse interval start
  match(interval_start, /(..):(..):(.+)/ , ts_interval)
  hh=1
  mm=2
  ss=3
  printf("ts_perf_rec            = %02d:%02d:%05f\n", ts_perf_rec[hh], ts_perf_rec[mm], ts_perf_rec[ss]) > "/dev/stderr"
  printf("ts_interval            = %02d:%02d:%05f\n", ts_interval[hh], ts_interval[mm], ts_interval[ss]) > "/dev/stderr"
  # current line belongs to header
  in_header = 1
  # current line belongs to selected interval
  in_interval = 0

  # first timestamp in perf.data
  first_ts = -1
  FS="[ :]"
}

# find end of header
/^[^#]/ {
  if (in_header) {
    in_header = 0
  }
}

# find timestamps
# example line: java 15950 515784.682786: cycles: 
/^.+ [0-9]+ [0-9]+\.[0-9]+:/ {
  cur_ts = $3 + 0.0
  if (first_ts == -1) {
    # translate ts_interval to profile data timestamps by identifying the first
    # timestamp with ts_perf_rec
    first_ts = cur_ts

    # delta_recstart_intervalstart is the time difference from the first
    # profiling event to the filter interval
    delta_recstart_intervalstart[ss] = ts_interval[ss] - ts_perf_rec[ss]
    if (delta_recstart_intervalstart[ss] < 0) {
      delta_recstart_intervalstart[ss] += 60
      delta_recstart_intervalstart[mm] = -1
    }
    delta_recstart_intervalstart[mm] += ts_interval[mm] - ts_perf_rec[mm]
    if (delta_recstart_intervalstart[mm] < 0) {
      delta_recstart_intervalstart[mm] += 60
      delta_recstart_intervalstart[hh] = -1
    }
    delta_recstart_intervalstart[hh] += ts_interval[hh] - ts_perf_rec[hh]

    # beginning and end of the interval in profiling timestamps
    interval_begin_s = delta_recstart_intervalstart[hh] * 3600 + delta_recstart_intervalstart[mm] * 60 + delta_recstart_intervalstart[ss] + first_ts
    interval_end_s = interval_begin_s + duration

    printf("ts_perf_rec                  = %02d:%02d:%05f\n", ts_perf_rec[hh], ts_perf_rec[mm], ts_perf_rec[ss]) > "/dev/stderr"
    printf("first_ts                     = %f\n", first_ts) > "/dev/stderr"
    printf("ts_interval                  = %02d:%02d:%05f\n", ts_interval[hh], ts_interval[mm], ts_interval[ss]) > "/dev/stderr"
    printf("delta_recstart_intervalstart = %02d:%02d:%05f\n",
           delta_recstart_intervalstart[hh], delta_recstart_intervalstart[mm], delta_recstart_intervalstart[ss]) > "/dev/stderr"
    printf("duration                     = %f\n", duration) > "/dev/stderr"
    printf("interval_begin_s             = %05f\n", interval_begin_s) > "/dev/stderr"
    printf("interval_end_s               = %05f\n", interval_end_s) > "/dev/stderr"
  }

  in_interval = ((cur_ts >= interval_begin_s) && (cur_ts < interval_end_s))
}

# print every line that belongs to the header or the selected time interval
in_interval || in_header {
  print $0
}

#2

Most perf tools, including perf report, support filtering by time:

大多数perf工具，包括perf报告，支持按时间过滤：

--time::
  Only analyze samples within given time window: <start>,<stop>. Times
  have the format seconds.microseconds. If start is not given (i.e., time
  string is ',x.y') then analysis starts at the beginning of the file. If
  stop time is not given (i.e, time string is 'x.y,') then analysis goes
  to end of file.

For more details see man perf-report.

有关详细信息，请参阅man perf-report。

This is present since version 4.10 (Feb 2017). If you run an older kernel you can try to build the userspace tools part of perf yourself. In more recent versions it is possible to specify time percent and multiple time ranges.

这是自版本4。10（2017年2月）以来的版本。如果您运行较旧的内核，您可以尝试自己构建perf的用户空间工具。在更新的版本中，可以指定时间百分比和多个时间范围。

#1