Information regarding the perf tool

Information regarding the perf tool

[Harald Servat]

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

Re: Information regarding the perf tool

[Andi Kleen]

Harald Servat <harald.servat@bsc.es> writes:

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

perf report -D reports everything, including time stamps.

-Andi

-- 
ak@linux.intel.com -- Speaking for myself only

Re: Information regarding the perf tool

[Harald Servat]

On 23/10/13 14:47, Andi Kleen wrote:
> Harald Servat <harald.servat@bsc.es> writes:
>
>> Dear list,
>>
>>     I'm wondering whether it be possible to extend the "perf mem"
>> (tool) to emit the TSC of the sampling event?
>
> perf report -D reports everything, including time stamps.
>
> -Andi
>

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

Re: Information regarding the perf tool

[Harald Servat]

On 23/10/13 14:47, Andi Kleen wrote:
> Harald Servat <harald.servat@bsc.es> writes:
>
>> Dear list,
>>
>>     I'm wondering whether it be possible to extend the "perf mem"
>> (tool) to emit the TSC of the sampling event?
>
> perf report -D reports everything, including time stamps.
>
> -Andi
>

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

Re: Information regarding the perf tool

[David Ahern]

On 10/31/13, 9:45 AM, Harald Servat wrote:
> Can anyone point me where and how is the timestamp calculated for every
> sample reported by perf?


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

David

Re: Information regarding the perf tool

[Harald Servat]

On 31/10/13 17:39, David Ahern wrote:
> On 10/31/13, 9:45 AM, Harald Servat wrote:
>> Can anyone point me where and how is the timestamp calculated for every
>> sample reported by perf?
>
>
> 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

Re: Information regarding the perf tool

[David Ahern]

[-- Attachment #1: Type: text/plain, Size: 590 bytes --]

On 10/31/13, 11:23 AM, Harald Servat wrote:
> 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?

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

[-- Attachment #2: 0001-perf-POSIX-CLOCK_PERF-to-report-current-time-value.patch --]
[-- Type: text/plain, Size: 2609 bytes --]

From 5e2d4c81b9e4a82090ec44a24e84223e00a4c5fd Mon Sep 17 00:00:00 2001
From: David Ahern <dsahern@gmail.com>
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);

Signed-off-by: Pawel Moll <pawel.moll@arm.com>
Signed-off-by: David Ahern <dsahern@gmail.com>
---
 include/uapi/linux/time.h |  1 +
 kernel/events/core.c      | 20 ++++++++++++++++++++
 2 files changed, 21 insertions(+)

diff --git a/include/uapi/linux/time.h b/include/uapi/linux/time.h
index e75e1b6ff27f..9066bf02c867 100644
--- a/include/uapi/linux/time.h
+++ b/include/uapi/linux/time.h
@@ -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)
diff --git a/kernel/events/core.c b/kernel/events/core.c
index b073975af05a..98c26fb1d9fd 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -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)


[-- Attachment #3: perf-Add-ioctl-to-return-perf_clock.patch --]
[-- Type: text/plain, Size: 1649 bytes --]

From 3601ad205e74a0af22de4421f12a5f0ee0559057 Mon Sep 17 00:00:00 2001
From: Pawel Moll <pawel.moll@arm.com>
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.

Signed-off-by: Pawel Moll <pawel.moll@arm.com>
---
 include/uapi/linux/perf_event.h |    1 +
 kernel/events/core.c            |    8 ++++++++
 2 files changed, 9 insertions(+)

diff --git a/include/uapi/linux/perf_event.h b/include/uapi/linux/perf_event.h
index 0b1df41..41cb39e 100644
--- a/include/uapi/linux/perf_event.h
+++ b/include/uapi/linux/perf_event.h
@@ -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,
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 1833bc5..62a44d9 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -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

Re: Information regarding the perf tool

[Harald Servat]

[-- Attachment #1: Type: text/plain, Size: 2091 bytes --]

On 31/10/13 19:22, David Ahern wrote:
> On 10/31/13, 11:23 AM, Harald Servat wrote:
>> 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?
>
> 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

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

[-- Attachment #2: perf-clock.tar.bz2 --]
[-- Type: application/x-bzip, Size: 842 bytes --]

Re: Information regarding the perf tool

[David Ahern]

[added Pawel, author of the patches]

On 11/4/13, 10:26 AM, Harald Servat wrote:
> On 31/10/13 19:22, David Ahern wrote:
>> On 10/31/13, 11:23 AM, Harald Servat wrote:
>>> 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?
>>
>> 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
>
> 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.

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

>    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?

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

>
>    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.

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

David

Re: Information regarding the perf tool

[Pawel Moll]

On Mon, 2013-11-04 at 17:53 +0000, David Ahern wrote:
> that's why we would like to get a perf_clock/trace_clock time source 
> exported by the kernel.

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ł

Re: Information regarding the perf tool

[David Ahern]

On 11/4/13, 10:26 AM, Harald Servat wrote:
> On 31/10/13 19:22, David Ahern wrote:
>> On 10/31/13, 11:23 AM, Harald Servat wrote:
>>> 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?
>>
>> 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.
>>

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

Re: Information regarding the perf tool

[Harald Servat]

On 12/12/13 01:56, David Ahern wrote:
> On 11/4/13, 10:26 AM, Harald Servat wrote:
>> On 31/10/13 19:22, David Ahern wrote:
>>> On 10/31/13, 11:23 AM, Harald Servat wrote:
>>>> 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?
>>>
>>> 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.
>>>
>
> 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.
>

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

Re: Information regarding the perf tool

[Harald Servat]

On 12/12/13 09:47, Harald Servat wrote:
> On 12/12/13 01:56, David Ahern wrote:
>> On 11/4/13, 10:26 AM, Harald Servat wrote:
>>> On 31/10/13 19:22, David Ahern wrote:
>>>> On 10/31/13, 11:23 AM, Harald Servat wrote:
>>>>> 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?
>>>>
>>>> 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.
>>>>
>>
>> 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.
>>
>
> Thank you very much David. Using a module instead of recompiling would
> be a very nice alternative. I'll give it a try.
>

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!


> --
> To unsubscribe from this list: send the line "unsubscribe
> linux-perf-users" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html


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

Re: Information regarding the perf tool

[Andi Kleen]

>   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.

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

Re: Information regarding the perf tool

[Harald Servat]

On 31/10/13 17:48, Andi Kleen wrote:
>>    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.
>
> 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.
>


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