Information regarding the perf tool

Dear list,

I'm wondering whether it be possible to extend the "perf mem" (tool)
to emit the TSC of the sampling event?

I started looking at the code, and I'd like to understand how does
the perf tool work to extend that tool providing such functionality. However, I'm clueless on how the perf tool works. I have a machine with kernel 3.11.0 and its source code and within the source code in tools/perf/builtin-mem.c I observe that the application is somehow executed through "cmd_record ()" but I don't see the implementation of cmd_record() around. Would anyone on the list giving me some hints on how this is done?

Additionally, it seems that perf.data is a file that mostly contains
perf_event that represent the data gathered. It seems to be defined in include/linux/perf_event.h, but it doesn't seem to me a simple container for performance data. Is that the struct I'm looking for?

Thank you very much.

WARNING / LEGAL TEXT: This message is intended only for the use of the
individual or entity to which it is addressed and may contain
information which is privileged, confidential, proprietary, or exempt
from disclosure under applicable law. If you are not the intended
recipient or the person responsible for delivering the message to the
intended recipient, you are strictly prohibited from disclosing,
distributing, copying, or in any way using this message. If you have
received this communication in error, please notify the sender and
destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

perf report -D reports everything, including time stamps.

-Andi

[email protected] -- Speaking for myself only

Thank you very much for the pointer Andi. I see, the first data shown refers to the timestamp, but as returned by clock_gettime(). I was looking for the processor TSC, but I guess that this will work for now.

WARNING / LEGAL TEXT: This message is intended only for the use of the
individual or entity to which it is addressed and may contain
information which is privileged, confidential, proprietary, or exempt
from disclosure under applicable law. If you are not the intended
recipient or the person responsible for delivering the message to the
intended recipient, you are strictly prohibited from disclosing,
distributing, copying, or in any way using this message. If you have
received this communication in error, please notify the sender and
destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

Hello,

returning to this topic, I'd like to mention that the time-stamps
associated with the data samples seems to be a bit delayed from the actual computation.

I tried to look at how are timestamps set in the perf samples and I
took a look at

arch/x86/kernel/cpu/perf_event_intel_ds.c

and also at Intel Architectures Software Developer Manual [1].

The first thing I notice is that pebs_record_core structure seems to
be the same as the record of PEBS as indicated in Figure 17-10 of [1] (page 105), while pebs_record_nhm seems to be the record as indicated in Table 18-12 of [1] (page 147), but neither Table 18-12 nor Figure 17-10 provide the time when the record was generated, so the timestamp in the perf sample is generated elsewhere.

In fact, I expected that for each entry into the PEBS a handler would
be executed, but Intel documentations points that to use PEBS the tool (here perf) needs to allocate space for multiple PEBS entries, so the when the handler is invoked there may be multiple entries in the buffer, which makes things a little more obscure.

Can anyone point me where and how is the timestamp calculated for
every sample reported by perf?

Thank you very much.

[1] http://download.intel.com/products/processor/manual/253669.pdf

WARNING / LEGAL TEXT: This message is intended only for the use of the
individual or entity to which it is addressed and may contain
information which is privileged, confidential, proprietary, or exempt
from disclosure under applicable law. If you are not the intended
recipient or the person responsible for delivering the message to the
intended recipient, you are strictly prohibited from disclosing,
distributing, copying, or in any way using this message. If you have
received this communication in error, please notify the sender and
destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

See perf_clock() in kernel/events/core.c

David

Just another question.

Which is the relation between perf_clock() (or local_clock()) and clock_gettime (CLOCK_MONOTONIC, ). Are they the same? If not, is there a way to correlate them? Or alternatively, is it possible to call local_clock() from the userland?

Thank you in advance.

WARNING / LEGAL TEXT: This message is intended only for the use of the
individual or entity to which it is addressed and may contain
information which is privileged, confidential, proprietary, or exempt
from disclosure under applicable law. If you are not the intended
recipient or the person responsible for delivering the message to the
intended recipient, you are strictly prohibited from disclosing,
distributing, copying, or in any way using this message. If you have
received this communication in error, please notify the sender and
destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

We still do not have a means of correlating perf_clock to time-of-day, monotonic or any other clock source. Still trying.

Pawell Moll has a couple of patches posted -- one uses an ioctl to get perf_clock timestamps the other makes perf_clock accessible through clock_gettime. See attached.

David

From 5e2d4c81b9e4a82090ec44a24e84223e00a4c5fd Mon Sep 17 00:00:00 2001
From: David Ahern <[email protected]>
Date: Wed, 23 Oct 2013 16:53:05 +0100
Subject: [PATCH] perf: POSIX CLOCK_PERF to report current time value

To co-relate user space events with the perf events stream a current (as in: "what time(stamp) is it now?") time value must be made available.

This patch adds a POSIX clock returning the perf_clock() value and accesible from userspace:

    #include <time.h>

    struct timespec ts;

    clock_gettime(CLOCK_PERF, &ts);

---
 include/uapi/linux/time.h |  1 +
 kernel/events/core.c      | 20 ++++++++++++++++++++
 2 files changed, 21 insertions(+)

index e75e1b6ff27f..9066bf02c867 100644
@@ -56,6 +56,7 @@ struct itimerval {
 #define CLOCK_BOOTTIME_ALARM		9
 #define CLOCK_SGI_CYCLE			10	/* Hardware specific */
 #define CLOCK_TAI			11
+#define CLOCK_PERF			12
 
 #define MAX_CLOCKS			16
 #define CLOCKS_MASK			(CLOCK_REALTIME | CLOCK_MONOTONIC)

index b073975af05a..98c26fb1d9fd 100644
@@ -39,6 +39,7 @@
 #include <linux/hw_breakpoint.h>
 #include <linux/mm_types.h>
 #include <linux/cgroup.h>
+#include <linux/posix-timers.h>
 
 #include "internal.h"
 

@@ -303,6 +304,19 @@ static inline u64 perf_clock(void)
 }
 #endif
 
+static int perf_posix_clock_getres(const clockid_t which_clock,
+		struct timespec *tp)
+{
+	*tp = ns_to_timespec(TICK_NSEC);
+	return 0;
+}
+
+static int perf_posix_clock_get(clockid_t which_clock, struct timespec *tp)
+{
+	*tp = ns_to_timespec(perf_clock());
+	return 0;
+}
+
 static inline struct perf_cpu_context *
 __get_cpu_context(struct perf_event_context *ctx)
 {

@@ -7878,6 +7892,10 @@ perf_cpu_notify(struct notifier_block *self, unsigned long action, void *hcpu)
 
 void __init perf_event_init(void)
 {
+	struct k_clock perf_posix_clock = {
+		.clock_getres = perf_posix_clock_getres,
+		.clock_get = perf_posix_clock_get,
+	};
 	int ret;
 
 	idr_init(&pmu_idr);

@@ -7894,6 +7912,8 @@ void __init perf_event_init(void)
 	ret = init_hw_breakpoint();
 	WARN(ret, "hw_breakpoint initialization failed with: %d", ret);
 
+	posix_timers_register_clock(CLOCK_PERF, &perf_posix_clock);
+
 	/* do not patch jump label more than once per second */
 	jump_label_rate_limit(&perf_sched_events, HZ);
 

1.8.3.4 (Apple Git-47)

From 3601ad205e74a0af22de4421f12a5f0ee0559057 Mon Sep 17 00:00:00 2001
From: Pawel Moll <[email protected]>
Date: Fri, 1 Feb 2013 14:03:56 +0000
Subject: [PATCH 16/45] perf: Add ioctl to return current time value

To co-relate user space events with the perf events stream a current (as in: "what time(stamp) is it now?") time value must be made available.

This patch adds a perf ioctl that makes this possible.

---
 include/uapi/linux/perf_event.h |    1 +
 kernel/events/core.c            |    8 ++++++++
 2 files changed, 9 insertions(+)

index 0b1df41..41cb39e 100644
@@ -321,6 +321,7 @@ struct perf_event_attr {
 #define PERF_EVENT_IOC_PERIOD		_IOW('$', 4, __u64)
 #define PERF_EVENT_IOC_SET_OUTPUT	_IO ('$', 5)
 #define PERF_EVENT_IOC_SET_FILTER	_IOW('$', 6, char *)
+#define PERF_EVENT_IOC_GET_TIME		_IOR('$', 7, __u64)
 
 enum perf_event_ioc_flags {
 	PERF_IOC_FLAG_GROUP		= 1U << 0,

index 1833bc5..62a44d9 100644
@@ -3543,6 +3543,14 @@ static long perf_ioctl(struct file *file, unsigned int cmd, unsigned long arg)
 	case PERF_EVENT_IOC_SET_FILTER:
 		return perf_event_set_filter(event, (void __user *)arg);
 
+	case PERF_EVENT_IOC_GET_TIME:
+	{
+		u64 time = perf_clock();
+		if (copy_to_user((void __user *)arg, &time, sizeof(time)))
+			return -EFAULT;
+		return 0;
+	}
+
 	default:
 		return -ENOTTY;
 	}

1.7.10.1

Hello,

thank you David! Those patches are great! I decided to access perf
clock through clock_gettime because I'm more used to this call since I used it before.

I understand that the patches are a bit hardcoded, right? I tried to
#include "/usr/include/linux/time.h" after #include <time.h> but they seem to conflict. If I just extract the interesting bits (#define CLOCK_PERF) it seems to work. Is there a cleaner way to use this right now?

JFTR, I have written a very small app that demonstrate the usage of
this clock_gettime + perf (attached). It is very interesting to see that the difference between the monotonic and the perf clock is rather similar. However, as time goes by, at least in my machine, perf clock seems to advance at a faster pace than the monotonic clock.

Best regards.

WARNING / LEGAL TEXT: This message is intended only for the use of the
individual or entity to which it is addressed and may contain
information which is privileged, confidential, proprietary, or exempt
from disclosure under applicable law. If you are not the intended
recipient or the person responsible for delivering the message to the
intended recipient, you are strictly prohibited from disclosing,
distributing, copying, or in any way using this message. If you have
received this communication in error, please notify the sender and
destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

[added Pawel, author of the patches]

My long term preference as well with a hook into vdso page.

They should just work. I seem to have misplaced my test case; I don't recall having problems with it.

that's why we would like to get a perf_clock/trace_clock time source exported by the kernel.

David

By all means. One of the issues right now is that perf and trace clocks can be (and are at least on ARM) different. Once the LLTng people get around providing One Source To Rule Them All, we'll be in much better position to convince John Stultz to provide a posix clock for it (which should make it VDSO-able as well).

Paweł

Coming back to this....

Here is a module version of the posix clock approach:
https://github.com/dsahern/linux/blob/perf-full-monty/README.ahern

As far as I can tell it works for 2.6.38 and forward and there should not be a conflict with the CLOCK_PERF id of 12. No need to patch and build your kernel, just build the module, load and go.

That branch also has time-of-day hooks for record, report, script and sched.

David

Thank you very much David. Using a module instead of recompiling would be a very nice alternative. I'll give it a try.

WARNING / LEGAL TEXT: This message is intended only for the use of the individual or entity to which it is addressed and may contain information which is privileged, confidential, proprietary, or exempt from disclosure under applicable law. If you are not the intended recipient or the person responsible for delivering the message to the intended recipient, you are strictly prohibited from disclosing, distributing, copying, or in any way using this message. If you have received this communication in error, please notify the sender and destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

Hello,

just a mail to tell you that I tried this module and it works fine!
Not having to build a kernel is a nice improvement here!

Thank you very much!

WARNING / LEGAL TEXT: This message is intended only for the use of the individual or entity to which it is addressed and may contain information which is privileged, confidential, proprietary, or exempt from disclosure under applicable law. If you are not the intended recipient or the person responsible for delivering the message to the intended recipient, you are strictly prohibited from disclosing, distributing, copying, or in any way using this message. If you have received this communication in error, please notify the sender and destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer

perf always uses threshold 1 for the PEBS buffer.

But yes there is some delay until the handler executes, and the time stamp is only computed in the handler.

-Andi

David, Andi,

thank you for your valuable comments, they're really helpful.

David, wrt to the clock, which actually calls local_clock() I'm a bit
worried about the comment in sched/clock.c

* Similar to cpu_clock() for the current cpu. Time will only be observed
* to be monotonic if care is taken to only compare timestampt taken on the
* same CPU.

I'll rerun my experiments making sure that I pin the processes to a
single CPU.

Again, thank you!

WARNING / LEGAL TEXT: This message is intended only for the use of the
individual or entity to which it is addressed and may contain
information which is privileged, confidential, proprietary, or exempt
from disclosure under applicable law. If you are not the intended
recipient or the person responsible for delivering the message to the
intended recipient, you are strictly prohibited from disclosing,
distributing, copying, or in any way using this message. If you have
received this communication in error, please notify the sender and
destroy and delete any copies you may have received.

http://www.bsc.es/disclaimer