Search code examples
linuxtimestampperf

What is meaning of timestamp in perf?


I'd like to use 'perf' to measure real execution time of a function. 'perf script' command gives timestamp when the function is called.

Xorg  1523 [001] 25712.423702:    probe:sock_write_iter: (ffffffff95cd8b80)

The timestamp field's format is X.Y. How can I understand this value? Is it X.Y seconds?


Solution

  • X.Y is the timestamp in units of seconds.microseconds.

    How this value is displayed can be looked at here. You can pass the switch --ns to perf script to display the timestamps in seconds.nanoseconds format too.

    To understand this value, you need to understand how the perf module calculates timestamps. You can associate each event with a different clock function to compute the timestamps. By default, perf uses sched_clock function to compute timestamps for an event, more details here.

    event->clock = &local_clock;
    

    But you can use the -k switch along with perf record command to associate an event with various clockids.

    -k, --clockid
               Sets the clock id to use for the various time fields in the
               perf_event_type records. See clock_gettime(). In particular
               CLOCK_MONOTONIC and CLOCK_MONOTONIC_RAW are supported, some
               events might also allow CLOCK_BOOTTIME, CLOCK_REALTIME and
               CLOCK_TAI.
    

    Adding the -k switch to perf record command will enable various clock functions depending on which clockid you use, as can be seen here.

    sched_clock function shall return the number of nanoseconds since the system was started. A particular architecture may or may not provide an implementation of sched_clock() on its own. The system jiffy counter will be used as sched_clock(), if a local implementation is not provided.

    Note that, all of the above code snippets are for Linux kernel 5.6.7.