This is a second version of the post-LPC series. The changes are limited
to the first patch, adding a backward-compatibility kernel parameter.
The v3 cover letter:
I've organised a session on the subject during the tracing minisummit
at LPC 2014 in Dusseldorf. Notes taken from the discussion taken by
Steven Rostedt (thanks Steve!)
http://www.linuxplumbersconf.org/2014/wp-content/uploads/2014/10/LPC2014_Tracing.txt
The following three patches address three main topics. They are pretty
much orthogonal and (subject to small and obvious modifications) could
be applied independently from each other.
An executive summary of both discussion and the patches:
1. User/kernel perf timestamps correlation
Thomas suggested that, instead of jumping through loops of correlation,
perf should simply generate monotonic clock timestamps, instead of
using sched clock. Peter and I pointed out that Ingo didn't like this
idea as monotonic can be slow, but apparently the cases when it is are
irrelevant. Thomas offered to fly to Budapest to physically convince
Ingo - I hope it won't be necessary and he will be able to achieve
this here, on mailing lists :-)
Setting aside potential performance problems, it would be a really
great solution, unifying all trace systems (perf, ftrace and LTTng)
in this respect. I'm more than happy to work on potential improvements
in the are of monotonic clock if it was to help the cause.
If it is a definite no-go, we still have the third patch, allowing post-
capture correlation based on synchronisation events.
2. User event generation
Everyone present agreed that it would be a very-nice-to-have feature.
There was some discussion about implementation details, so I welcome
feedback and comments regarding my take on the matter.
3. Correlation with external timestamps
This is a new issue, which surfaced recently while I was working on
hardware trace infrastructure. It can timestamp trace packets, but is
using yet another, completely different time source to do this.
Thomas suggested solution which gets down to my original proposal for
sched/monotonic clock correlation - an additional sample type so events
can be "double stamped" using different clock sources providing
synchronisation points for later time approximation. I've just extended
the implementation with configuration value to select the clock source.
If the first patch (making perf timestamps monotonic) gets accepted,
there will be no immediate need for this one, but I'd like to gain some
feedback anyway.
That's all for this series. Previous versions:
- RFC: http://www.spinics.net/lists/kernel/msg1824419.html
- v1: http://thread.gmane.org/gmane.linux.kernel/1790231
- v2: http://thread.gmane.org/gmane.linux.kernel/1793272
- v3: http://thread.gmane.org/gmane.linux.kernel.api/5681
Pawel Moll (3):
perf: Use monotonic clock as a source for timestamps
perf: Userspace event
perf: Sample additional clock value
Documentation/kernel-parameters.txt | 9 +++
include/linux/perf_event.h | 6 ++
include/uapi/linux/perf_event.h | 37 +++++++++-
include/uapi/linux/prctl.h | 10 +++
kernel/events/core.c | 138 ++++++++++++++++++++++++++++++++++++
kernel/sys.c | 5 ++
6 files changed, 203 insertions(+), 2 deletions(-)
--
2.1.0
This patch adds an option to sample value of an additional clock with
any perf event, with the the aim of allowing time correlation between
data coming from perf and other sources like hardware trace which is
timestamped with an external clock.
The idea is to generate periodic perf record containing timestamps from
two different sources, sampled as close to each other as possible. This
allows performing simple linear approximation:
other event
-----O--------------+-------------O------> t_other
: | :
: V :
-----O----------------------------O------> t_perf
perf event
User can request such samples for any standard perf event, with the most
obvious examples of cpu-clock (hrtimer) at selected frequency or other
periodic events like sched:sched_switch.
In order to do this, PERF_SAMPLE_CLOCK has to be set in struct
perf_event_attr.sample_type and a type of the clock to be sampled
selected by setting perf_event_attr.clock to a value corresponding to
a POSIX clock clk_id (see "man 2 clock_gettime")
Currently three clocks are implemented: CLOCK_REALITME = 0,
CLOCK_MONOTONIC = 1 and CLOCK_MONOTONIC_RAW = 2. The clock field is
5 bits wide to allow for future extension to custom, non-POSIX clock
sources(MAX_CLOCK for those is 16, see include/uapi/linux/time.h) like
ARM CoreSight (hardware trace) timestamp generator.
Signed-off-by: Pawel Moll <[email protected]>
---
Changes since v3:
- none
include/linux/perf_event.h | 2 ++
include/uapi/linux/perf_event.h | 16 ++++++++++++++--
kernel/events/core.c | 30 ++++++++++++++++++++++++++++++
3 files changed, 46 insertions(+), 2 deletions(-)
diff --git a/include/linux/perf_event.h b/include/linux/perf_event.h
index 680767d..b690a0d 100644
--- a/include/linux/perf_event.h
+++ b/include/linux/perf_event.h
@@ -607,6 +607,8 @@ struct perf_sample_data {
* Transaction flags for abort events:
*/
u64 txn;
+ /* Clock value (additional timestamp for time correlation) */
+ u64 clock;
};
/* default value for data source */
diff --git a/include/uapi/linux/perf_event.h b/include/uapi/linux/perf_event.h
index 9a64eb1..53a7a72 100644
--- a/include/uapi/linux/perf_event.h
+++ b/include/uapi/linux/perf_event.h
@@ -137,8 +137,9 @@ enum perf_event_sample_format {
PERF_SAMPLE_DATA_SRC = 1U << 15,
PERF_SAMPLE_IDENTIFIER = 1U << 16,
PERF_SAMPLE_TRANSACTION = 1U << 17,
+ PERF_SAMPLE_CLOCK = 1U << 18,
- PERF_SAMPLE_MAX = 1U << 18, /* non-ABI */
+ PERF_SAMPLE_MAX = 1U << 19, /* non-ABI */
};
/*
@@ -304,7 +305,16 @@ struct perf_event_attr {
mmap2 : 1, /* include mmap with inode data */
comm_exec : 1, /* flag comm events that are due to an exec */
uevents : 1, /* allow uevents into the buffer */
- __reserved_1 : 38;
+
+ /*
+ * clock: one of the POSIX clock IDs:
+ *
+ * 0 - CLOCK_REALTIME
+ * 1 - CLOCK_MONOTONIC
+ * 4 - CLOCK_MONOTONIC_RAW
+ */
+ clock : 5, /* clock type */
+ __reserved_1 : 33;
union {
__u32 wakeup_events; /* wakeup every n events */
@@ -544,6 +554,7 @@ enum perf_event_type {
* { u64 id; } && PERF_SAMPLE_ID
* { u64 stream_id;} && PERF_SAMPLE_STREAM_ID
* { u32 cpu, res; } && PERF_SAMPLE_CPU
+ * { u64 clock; } && PERF_SAMPLE_CLOCK
* { u64 id; } && PERF_SAMPLE_IDENTIFIER
* } && perf_event_attr::sample_id_all
*
@@ -687,6 +698,7 @@ enum perf_event_type {
* { u64 weight; } && PERF_SAMPLE_WEIGHT
* { u64 data_src; } && PERF_SAMPLE_DATA_SRC
* { u64 transaction; } && PERF_SAMPLE_TRANSACTION
+ * { u64 clock; } && PERF_SAMPLE_CLOCK
* };
*/
PERF_RECORD_SAMPLE = 9,
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 9a2d082..816baa6 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -1264,6 +1264,9 @@ static void perf_event__header_size(struct perf_event *event)
if (sample_type & PERF_SAMPLE_TRANSACTION)
size += sizeof(data->txn);
+ if (sample_type & PERF_SAMPLE_CLOCK)
+ size += sizeof(data->clock);
+
event->header_size = size;
}
@@ -1291,6 +1294,9 @@ static void perf_event__id_header_size(struct perf_event *event)
if (sample_type & PERF_SAMPLE_CPU)
size += sizeof(data->cpu_entry);
+ if (sample_type & PERF_SAMPLE_CLOCK)
+ size += sizeof(data->clock);
+
event->id_header_size = size;
}
@@ -4631,6 +4637,24 @@ static void __perf_event_header__init_id(struct perf_event_header *header,
data->cpu_entry.cpu = raw_smp_processor_id();
data->cpu_entry.reserved = 0;
}
+
+ if (sample_type & PERF_SAMPLE_CLOCK) {
+ switch (event->attr.clock) {
+ case CLOCK_REALTIME:
+ data->clock = ktime_get_real_ns();
+ break;
+ case CLOCK_MONOTONIC:
+ data->clock = ktime_get_mono_fast_ns();
+ break;
+ case CLOCK_MONOTONIC_RAW:
+ data->clock = ktime_get_raw_ns();
+ break;
+ default:
+ data->clock = 0;
+ break;
+ }
+ }
+
}
void perf_event_header__init_id(struct perf_event_header *header,
@@ -4661,6 +4685,9 @@ static void __perf_event__output_id_sample(struct perf_output_handle *handle,
if (sample_type & PERF_SAMPLE_CPU)
perf_output_put(handle, data->cpu_entry);
+ if (sample_type & PERF_SAMPLE_CLOCK)
+ perf_output_put(handle, data->clock);
+
if (sample_type & PERF_SAMPLE_IDENTIFIER)
perf_output_put(handle, data->id);
}
@@ -4889,6 +4916,9 @@ void perf_output_sample(struct perf_output_handle *handle,
if (sample_type & PERF_SAMPLE_TRANSACTION)
perf_output_put(handle, data->txn);
+ if (sample_type & PERF_SAMPLE_CLOCK)
+ perf_output_put(handle, data->clock);
+
if (!event->attr.watermark) {
int wakeup_events = event->attr.wakeup_events;
--
2.1.0
This patch adds a PR_TASK_PERF_UEVENT prctl call which can be used by
any process to inject custom data into perf data stream as a new
PERF_RECORD_UEVENT record, if such process is being observed or if it
is running on a CPU being observed by the perf framework.
The prctl call takes the following arguments:
prctl(PR_TASK_PERF_UEVENT, type, size, data, flags);
- type: a number meaning to describe content of the following data.
Kernel does not pay attention to it and merely passes it further in
the perf data, therefore its use must be agreed between the events
producer (the process being observed) and the consumer (performance
analysis tool). The perf userspace tool will contain a repository of
"well known" types and reference implementation of their decoders.
- size: Length in bytes of the data.
- data: Pointer to the data.
- flags: Reserved for future use. Always pass zero.
Perf context that are supposed to receive events generated with the
prctl above must be opened with perf_event_attr.uevent set to 1. The
PERF_RECORD_UEVENT records consist of a standard perf event header,
32-bit type value, 32-bit data size and the data itself, followed by
padding to align the overall record size to 8 bytes and optional,
standard sample_id field.
Example use cases:
- "perf_printf" like mechanism to add logging messages to perf data;
in the simplest case it can be just
prctl(PR_TASK_PERF_UEVENT, 0, 8, "Message", 0);
- synchronisation of performance data generated in user space with the
perf stream coming from the kernel. For example, the marker can be
inserted by a JIT engine after it generated portion of the code, but
before the code is executed for the first time, allowing the
post-processor to pick the correct debugging information.
Signed-off-by: Pawel Moll <[email protected]>
---
Changes since v3:
- none
include/linux/perf_event.h | 4 +++
include/uapi/linux/perf_event.h | 23 ++++++++++++-
include/uapi/linux/prctl.h | 10 ++++++
kernel/events/core.c | 71 +++++++++++++++++++++++++++++++++++++++++
kernel/sys.c | 5 +++
5 files changed, 112 insertions(+), 1 deletion(-)
diff --git a/include/linux/perf_event.h b/include/linux/perf_event.h
index 893a0d0..680767d 100644
--- a/include/linux/perf_event.h
+++ b/include/linux/perf_event.h
@@ -721,6 +721,8 @@ extern int perf_unregister_guest_info_callbacks(struct perf_guest_info_callbacks
extern void perf_event_exec(void);
extern void perf_event_comm(struct task_struct *tsk, bool exec);
extern void perf_event_fork(struct task_struct *tsk);
+extern int perf_uevent(struct task_struct *tsk, u32 type, u32 size,
+ const char __user *data);
/* Callchains */
DECLARE_PER_CPU(struct perf_callchain_entry, perf_callchain_entry);
@@ -829,6 +831,8 @@ static inline void perf_event_mmap(struct vm_area_struct *vma) { }
static inline void perf_event_exec(void) { }
static inline void perf_event_comm(struct task_struct *tsk, bool exec) { }
static inline void perf_event_fork(struct task_struct *tsk) { }
+static inline int perf_uevent(struct task_struct *tsk, u32 type, u32 size,
+ const char __user *data) { return -1; };
static inline void perf_event_init(void) { }
static inline int perf_swevent_get_recursion_context(void) { return -1; }
static inline void perf_swevent_put_recursion_context(int rctx) { }
diff --git a/include/uapi/linux/perf_event.h b/include/uapi/linux/perf_event.h
index 9d84540..9a64eb1 100644
--- a/include/uapi/linux/perf_event.h
+++ b/include/uapi/linux/perf_event.h
@@ -303,7 +303,8 @@ struct perf_event_attr {
exclude_callchain_user : 1, /* exclude user callchains */
mmap2 : 1, /* include mmap with inode data */
comm_exec : 1, /* flag comm events that are due to an exec */
- __reserved_1 : 39;
+ uevents : 1, /* allow uevents into the buffer */
+ __reserved_1 : 38;
union {
__u32 wakeup_events; /* wakeup every n events */
@@ -712,6 +713,26 @@ enum perf_event_type {
*/
PERF_RECORD_MMAP2 = 10,
+ /*
+ * Data in userspace event record is transparent for the kernel
+ *
+ * Userspace perf tool code maintains a list of known types with
+ * reference implementations of parsers for the data field.
+ *
+ * Overall size of the record (including type and size fields)
+ * is always aligned to 8 bytes by adding padding after the data.
+ *
+ * struct {
+ * struct perf_event_header header;
+ * u32 type;
+ * u32 size;
+ * char data[size];
+ * char __padding[-size & 7];
+ * struct sample_id sample_id;
+ * };
+ */
+ PERF_RECORD_UEVENT = 11,
+
PERF_RECORD_MAX, /* non-ABI */
};
diff --git a/include/uapi/linux/prctl.h b/include/uapi/linux/prctl.h
index 513df75..2a6852f 100644
--- a/include/uapi/linux/prctl.h
+++ b/include/uapi/linux/prctl.h
@@ -179,4 +179,14 @@ struct prctl_mm_map {
#define PR_SET_THP_DISABLE 41
#define PR_GET_THP_DISABLE 42
+/*
+ * Perf userspace event generation
+ *
+ * second argument: event type
+ * third argument: data size
+ * fourth argument: pointer to data
+ * fifth argument: flags (currently unused, pass 0)
+ */
+#define PR_TASK_PERF_UEVENT 43
+
#endif /* _LINUX_PRCTL_H */
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 5d0aa03..9a2d082 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -5597,6 +5597,77 @@ static void perf_log_throttle(struct perf_event *event, int enable)
}
/*
+ * Userspace-generated event
+ */
+
+struct perf_uevent {
+ struct perf_event_header header;
+ u32 type;
+ u32 size;
+ u8 data[0];
+};
+
+static void perf_uevent_output(struct perf_event *event, void *data)
+{
+ struct perf_uevent *uevent = data;
+ struct perf_output_handle handle;
+ struct perf_sample_data sample;
+ int size = uevent->header.size;
+
+ if (!event->attr.uevents)
+ return;
+
+ perf_event_header__init_id(&uevent->header, &sample, event);
+
+ if (perf_output_begin(&handle, event, uevent->header.size) != 0)
+ goto out;
+ perf_output_put(&handle, uevent->header);
+ perf_output_put(&handle, uevent->type);
+ perf_output_put(&handle, uevent->size);
+ __output_copy(&handle, uevent->data, uevent->size);
+
+ /* Padding to align overall data size to 8 bytes */
+ perf_output_skip(&handle, -uevent->size & (sizeof(u64) - 1));
+
+ perf_event__output_id_sample(event, &handle, &sample);
+
+ perf_output_end(&handle);
+out:
+ uevent->header.size = size;
+}
+
+int perf_uevent(struct task_struct *tsk, u32 type, u32 size,
+ const char __user *data)
+{
+ struct perf_uevent *uevent;
+
+ /* Need some reasonable limit */
+ if (size > PAGE_SIZE)
+ return -E2BIG;
+
+ uevent = kmalloc(sizeof(*uevent) + size, GFP_KERNEL);
+ if (!uevent)
+ return -ENOMEM;
+
+ uevent->header.type = PERF_RECORD_UEVENT;
+ uevent->header.size = sizeof(*uevent) + ALIGN(size, sizeof(u64));
+
+ uevent->type = type;
+ uevent->size = size;
+ if (copy_from_user(uevent->data, data, size)) {
+ kfree(uevent);
+ return -EFAULT;
+ }
+
+ perf_event_aux(perf_uevent_output, uevent, NULL);
+
+ kfree(uevent);
+
+ return 0;
+}
+
+
+/*
* Generic event overflow handling, sampling.
*/
diff --git a/kernel/sys.c b/kernel/sys.c
index 1eaa2f0..1c83677 100644
--- a/kernel/sys.c
+++ b/kernel/sys.c
@@ -2121,6 +2121,11 @@ SYSCALL_DEFINE5(prctl, int, option, unsigned long, arg2, unsigned long, arg3,
case PR_TASK_PERF_EVENTS_ENABLE:
error = perf_event_task_enable();
break;
+ case PR_TASK_PERF_UEVENT:
+ if (arg5 != 0)
+ return -EINVAL;
+ error = perf_uevent(me, arg2, arg3, (char __user *)arg4);
+ break;
case PR_GET_TIMERSLACK:
error = current->timer_slack_ns;
break;
--
2.1.0
Until now, perf framework never defined the meaning of the timestamps
captured as PERF_SAMPLE_TIME sample type. The values were obtaining
from local (sched) clock, which is unavailable in userspace. This made
it impossible to correlate perf data with any other events. Other
tracing solutions have the source configurable (ftrace) or just share
a common time domain between kernel and userspace (LTTng).
Follow the trend by using monotonic clock, which is readily available
as POSIX CLOCK_MONOTONIC.
Also add a sysctl "perf_sample_time_clk_id" attribute which can be used
by the user to obtain the clk_id to be used with POSIX clock API (eg.
clock_gettime()) to obtain a time value comparable with perf samples.
Old behaviour can be restored by using "perf_use_local_clock" kernel
parameter.
Signed-off-by: Pawel Moll <[email protected]>
---
Ingo, I remember your comments about this approach in the past, but
during discussions at LPC Thomas was convinced that it's the right
thing to do - see cover letter for the series...
Changes since v3:
- Added "perf_use_lock_clock" parameter...
- ... and creating the sysctl value only when it's not defined (turned
out that negative clk_ids are not invalid - they are used to describe
dynamic clocks)
- Had to keep sysctl_perf_sample_time_clk_id non-const, because struct
ctl_table.data is non-const
Documentation/kernel-parameters.txt | 9 +++++++++
kernel/events/core.c | 37 +++++++++++++++++++++++++++++++++++++
2 files changed, 46 insertions(+)
diff --git a/Documentation/kernel-parameters.txt b/Documentation/kernel-parameters.txt
index 4c81a86..8ead8d8 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -91,6 +91,7 @@ parameter is applicable:
NUMA NUMA support is enabled.
NFS Appropriate NFS support is enabled.
OSS OSS sound support is enabled.
+ PERF Performance events and counters support is enabled.
PV_OPS A paravirtualized kernel is enabled.
PARIDE The ParIDE (parallel port IDE) subsystem is enabled.
PARISC The PA-RISC architecture is enabled.
@@ -2763,6 +2764,14 @@ bytes respectively. Such letter suffixes can also be entirely omitted.
allocator. This parameter is primarily for debugging
and performance comparison.
+ perf_use_local_clock
+ [PERF]
+ Use local_clock() as a source for perf timestamps
+ generation. This was be the default behaviour and
+ this parameter can be used to maintain backward
+ compatibility or on older hardware with expensive
+ monotonic clock source.
+
pf. [PARIDE]
See Documentation/blockdev/paride.txt.
diff --git a/kernel/events/core.c b/kernel/events/core.c
index 2b02c9f..5d0aa03 100644
--- a/kernel/events/core.c
+++ b/kernel/events/core.c
@@ -42,6 +42,7 @@
#include <linux/module.h>
#include <linux/mman.h>
#include <linux/compat.h>
+#include <linux/sysctl.h>
#include "internal.h"
@@ -322,8 +323,41 @@ extern __weak const char *perf_pmu_name(void)
return "pmu";
}
+static bool perf_use_local_clock;
+static int __init perf_use_local_clock_setup(char *__unused)
+{
+ perf_use_local_clock = true;
+ return 1;
+}
+__setup("perf_use_local_clock", perf_use_local_clock_setup);
+
+static int sysctl_perf_sample_time_clk_id = CLOCK_MONOTONIC;
+
+static struct ctl_table perf_sample_time_kern_table[] = {
+ {
+ .procname = "perf_sample_time_clk_id",
+ .data = &sysctl_perf_sample_time_clk_id,
+ .maxlen = sizeof(int),
+ .mode = 0444,
+ .proc_handler = proc_dointvec,
+ },
+ {}
+};
+
+static struct ctl_table perf_sample_time_root_table[] = {
+ {
+ .procname = "kernel",
+ .mode = 0555,
+ .child = perf_sample_time_kern_table,
+ },
+ {}
+};
+
static inline u64 perf_clock(void)
{
+ if (likely(!perf_use_local_clock))
+ return ktime_get_mono_fast_ns();
+
return local_clock();
}
@@ -8230,6 +8264,9 @@ void __init perf_event_init(void)
*/
BUILD_BUG_ON((offsetof(struct perf_event_mmap_page, data_head))
!= 1024);
+
+ if (!perf_use_local_clock)
+ register_sysctl_table(perf_sample_time_root_table);
}
static int __init perf_event_sysfs_init(void)
--
2.1.0
On Thu, 2014-11-06 at 16:51 +0000, Pawel Moll wrote:
> Until now, perf framework never defined the meaning of the timestamps
> captured as PERF_SAMPLE_TIME sample type. The values were obtaining
> from local (sched) clock, which is unavailable in userspace. This made
> it impossible to correlate perf data with any other events. Other
> tracing solutions have the source configurable (ftrace) or just share
> a common time domain between kernel and userspace (LTTng).
>
> Follow the trend by using monotonic clock, which is readily available
> as POSIX CLOCK_MONOTONIC.
>
> Also add a sysctl "perf_sample_time_clk_id" attribute which can be used
> by the user to obtain the clk_id to be used with POSIX clock API (eg.
> clock_gettime()) to obtain a time value comparable with perf samples.
>
> Old behaviour can be restored by using "perf_use_local_clock" kernel
> parameter.
>
> Signed-off-by: Pawel Moll <[email protected]>
It's been 3 weeks without any negative feedback (no feedback at all, but
I take the optimistic view :-)...
How about queuing at least this patch alone for the incoming merge
window? Or at least getting it into -next, with the view at 3.20?
Pawel
On Thu, 2014-11-27 at 15:05 +0000, Pawel Moll wrote:
> On Thu, 2014-11-06 at 16:51 +0000, Pawel Moll wrote:
> > Until now, perf framework never defined the meaning of the timestamps
> > captured as PERF_SAMPLE_TIME sample type. The values were obtaining
> > from local (sched) clock, which is unavailable in userspace. This made
> > it impossible to correlate perf data with any other events. Other
> > tracing solutions have the source configurable (ftrace) or just share
> > a common time domain between kernel and userspace (LTTng).
> >
> > Follow the trend by using monotonic clock, which is readily available
> > as POSIX CLOCK_MONOTONIC.
> >
> > Also add a sysctl "perf_sample_time_clk_id" attribute which can be used
> > by the user to obtain the clk_id to be used with POSIX clock API (eg.
> > clock_gettime()) to obtain a time value comparable with perf samples.
> >
> > Old behaviour can be restored by using "perf_use_local_clock" kernel
> > parameter.
> >
> > Signed-off-by: Pawel Moll <[email protected]>
>
> It's been 3 weeks without any negative feedback (no feedback at all, but
> I take the optimistic view :-)...
>
> How about queuing at least this patch alone for the incoming merge
> window? Or at least getting it into -next, with the view at 3.20?
It's been another two weeks... How about getting it queued for v3.20
then?
Pawel