Analyzing execution times with perf script

Question

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.

Answer 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