0

I'm trying to measure exact execution time/cycles for specific functions with oerf tool. I added events for entering and returning from each function by using perf probe. I can see the functions with perf script like so:

  perf script --header -F comm,pid,tid,cpu,time,event

This is what I get:

  kpktgend_1 33688/33688 [001] 151433.505544: probe:pktgen_alloc_skb:
  kpktgend_1 33688/33688 [001] 151433.505545: probe:pktgen_alloc_skb_1:
  kpktgend_1 33688/33688 [001] 151433.505546: probe:mlx5e_xmit:
  kpktgend_1 33688/33688 [001] 151433.505546: probe:mlx5e_xmit_1:
  kpktgend_1 33688/33688 [001] 151433.505547: probe:pktgen_alloc_skb:
  kpktgend_1 33688/33688 [001] 151433.505547: probe:pktgen_alloc_skb_1:
  kpktgend_1 33688/33688 [001] 151433.505548: probe:mlx5e_xmit:
  kpktgend_1 33688/33688 [001] 151433.505549: probe:mlx5e_xmit_1:

Each "event" is entry point to the function and "event"_1 is the return point from the function. This is pretty close to what I want, as you can see I get the timing of the calls.

Three questions:

  1. What is the format of the time? Is it seconds? This might seem so as I expect mlx5e_xmit to take less than a microsecond.
  2. Can I get a better resolution? I need the exact time and as you can see above some functions start and end on the same timestamp.
  3. Can I get number of cycles instead of time? This would give me the best resolution.
Tgilgul
  • 1,614
  • 1
  • 20
  • 35

1 Answers1

1

Running perf script with --ns flag solves the issue.

perf script -F time --ns
76970.575503465:
76970.575506464:
76970.575507479:

Without:

$perf script -F time
76970.575503:
76970.575506:
76970.575507:

From documentation:

perf script -h
--ns              Use 9 decimal places when displaying time
Tgilgul
  • 1,614
  • 1
  • 20
  • 35
  • 1
    Note there is also `-k, --clockid` for `perf record` where you can select a different clock. The default should be fine however. – Zulan Sep 27 '17 at 10:46
  • I can't find this option on perf record, do you know which version it was introduced at? I use: perf version 3.10.0-514.el7.x86_64.debug. In any case, the issue was in the presentation of perf script, not in the record itself which is parsed in nano-second resolution either way. – Tgilgul Sep 28 '17 at 06:19
  • 2
    It was introduced in 4.1, which was released 2 years ago. – Zulan Sep 28 '17 at 07:42