perf: Block perf calls for system call tracepoints
Subsystems (6)
Jiri Olsa
reviewerRFC 1/8 perf: Block perf calls for system call tracepoints
hi,
Steven asked for possibility to block traced process in case the tracer can't keep up and we would loose events.
This (RFC) patchset tries to implement this by adding 'block' bool in struct perf_event_attr to be set only for syscalls tracepoints and adding code to block the traced process, if there's no space in event's ring buffer.
The blocking code will poll/periodically check for the space and continue if the event was successfully written.
Available also here:
git://git.kernel.org/pub/scm/linux/kernel/git/jolsa/perf.git
perf/block
Thoughts?
thanks,
jirka
---
Jiri Olsa (8):
perf: Allow to block process in syscall tracepoints perf tools: Sync uapi perf_event.h
perf record: Add --block option
perf trace: Add --block option
perf tools: Add block term support for tracepoints perf tools: Add ordered_events__flush_time interface perf trace: Move event delivery to deliver_event function perf trace: Add ordered processing for --block option
arch/x86/entry/common.c | 36 ++++++++++++++++++++++++++++++++++-- include/linux/perf_event.h | 2 ++ include/linux/sched.h | 2 ++ include/linux/syscalls.h | 2 ++ include/uapi/linux/perf_event.h | 3 ++- kernel/events/core.c | 40 ++++++++++++++++++++++++++++++++++++++-- kernel/events/ring_buffer.c | 4 +++- kernel/trace/trace_event_perf.c | 4 ++++ kernel/trace/trace_syscalls.c | 28 ++++++++++++++++++++++++---- tools/include/uapi/linux/perf_event.h | 3 ++- tools/perf/builtin-record.c | 9 +++++++++ tools/perf/builtin-trace.c | 97 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++--------- tools/perf/perf.h | 1 + tools/perf/util/evsel.c | 7 +++++++ tools/perf/util/evsel.h | 2 ++ tools/perf/util/ordered-events.c | 34 ++++++++++++++++++++++++++++++---- tools/perf/util/ordered-events.h | 3 +++ tools/perf/util/parse-events.c | 8 ++++++++ tools/perf/util/parse-events.h | 1 + tools/perf/util/parse-events.l | 1 + 20 files changed, 263 insertions(+), 24 deletions(-)
Jiri Olsa
reviewerPATCH 1/8 perf: Allow to block process in syscall tracepoints
Adding support to specify 'block' bool in struct perf_event_attr for syscalls tracepoints, allowing the event to block the process, if there's no space in the ring buffer.
The blocking code will poll/periodically check for the space and continue if the event was successfully written.
It's allowed only for syscall tracepoint events attached to process. Following syscall events are supported:
raw_syscalls:sys_enter
raw_syscalls:sys_exit
syscalls:sys_enter_accept
syscalls:sys_enter_accept4
syscalls:sys_enter_access
syscalls:sys_enter_acct
syscalls:sys_enter_add_key
...
--- arch/x86/entry/common.c | 36 +++++++++++++++++++++++++++-- include/linux/perf_event.h | 2 ++ include/linux/sched.h | 2 ++ include/linux/syscalls.h | 2 ++ include/uapi/linux/perf_event.h | 3 ++- kernel/events/core.c | 40 +++++++++++++++++++++++++++++++-- kernel/events/ring_buffer.c | 4 +++- kernel/trace/trace_event_perf.c | 4 ++++ kernel/trace/trace_syscalls.c | 28 +++++++++++++++++++---- 9 files changed, 111 insertions(+), 10 deletions(-)
arch/x86/entry/common.c +34 -2
@@ -60,6 +60,32 @@ static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) } } +static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + +do { +schedule_timeout (100 *HZ ); + current->perf_blocked_cnt =0 ; + +if (enter) { +/* perf syscalls:* enter */ +perf_trace_syscall_enter (regs); + +/* perf raw_syscalls:* enter */ +perf_trace_sys_enter (&event_sys_enter, regs, regs->orig_ax); + }else { +/* perf syscalls:* enter */ +perf_trace_syscall_exit (regs); + +/* perf raw_syscalls:* enter */ +perf_trace_sys_exit (&event_sys_exit, regs, regs->ax); + } + }while (current->perf_blocked_cnt); + + current->perf_blocked = false; +} +/* * Returns the syscall nr to run (which should match regs->orig_ax) or -1 * to skip the syscall.
@@ -123,8 +149,11 @@ static long syscall_trace_enter(struct pt_regs *regs) }#endif -if (unlikely (test_thread_flag (TIF_SYSCALL_TRACEPOINT ))) +if (unlikely (test_thread_flag (TIF_SYSCALL_TRACEPOINT ))) {trace_sys_enter (regs, regs->orig_ax); +if (current->perf_blocked_cnt) +trace_block_syscall (regs, true); + }do_audit_syscall_entry (regs, arch);
@@ -224,8 +253,11 @@ static void syscall_slow_exit_work(struct pt_regs *regs, u32 cached_flags)audit_syscall_exit (regs); -if (cached_flags & _TIF_SYSCALL_TRACEPOINT) +if (cached_flags & _TIF_SYSCALL_TRACEPOINT) {trace_sys_exit (regs, regs->ax); +if (current->perf_blocked_cnt) +trace_block_syscall (regs, false); + }/* * If TIF_SYSCALL_EMU is set, we only get here because of
include/linux/perf_event.h +2 -0
@@ -695,6 +695,8 @@ struct perf_event {#endif struct list_head sb_list; + +bool blocked;#endif /* CONFIG_PERF_EVENTS */ };
include/linux/sched.h +2 -0
@@ -1009,6 +1009,8 @@ struct task_struct {struct perf_event_context *perf_event_ctxp[perf_nr_task_contexts];struct mutex perf_event_mutex;struct list_head perf_event_list; +bool perf_blocked; +unsigned int perf_blocked_cnt;#endif #ifdef CONFIG_DEBUG_PREEMPT unsigned long preempt_disable_ip;
include/linux/syscalls.h +2 -0
@@ -1296,4 +1296,6 @@ static inline unsigned int ksys_personality(unsigned int personality) return old; } +void perf_trace_syscall_enter (struct pt_regs *regs); +void perf_trace_syscall_exit (struct pt_regs *regs);#endif
include/uapi/linux/perf_event.h +2 -1
@@ -372,7 +372,8 @@ struct perf_event_attr { context_switch : 1, /* context switch data */ write_backward : 1, /* Write ring buffer from end to beginning */ namespaces : 1, /* include namespaces data */ - __reserved_1 : 35; + block : 1, /* block process if there's no space in RB (syscall tracepoints only) */ + __reserved_1 : 34;union {__u32 wakeup_events;/* wakeup every n events */
kernel/events/core.c +38 -2
@@ -6489,6 +6489,23 @@ void perf_prepare_sample(struct perf_event_header *header, data->phys_addr =perf_virt_to_phys (data->addr); } +static bool perf_event_is_blocked (struct perf_event *event) +{ +bool blocked = event->attr.block && event->blocked; + +if (blocked) + event->blocked = false; +return blocked; +} + +static void perf_event_set_blocked (struct perf_event *event) +{ +if (event->attr.block) { + current->perf_blocked_cnt++; + event->blocked = true; + } +} + static __always_inline void __perf_event_output(struct perf_event *event, struct perf_sample_data *data,
@@ -6505,8 +6522,10 @@ __perf_event_output(struct perf_event *event,perf_prepare_sample (&header, data, event, regs); -if (output_begin (&handle, event, header.size)) +if (output_begin (&handle, event, header.size)) { +perf_event_set_blocked (event); goto exit; + }perf_output_sample (&handle, &header, data, event);
@@ -8264,7 +8283,7 @@ void perf_trace_run_bpf_submit(void *raw_data, int size, int rctx, struct pt_regs *regs, struct hlist_head *head, struct task_struct *task) { - if (bpf_prog_array_valid(call)) { + if (!current->perf_blocked && bpf_prog_array_valid(call)) { *(struct pt_regs **)raw_data = regs;if (!trace_call_bpf (call, raw_data) ||hlist_empty (head)) {perf_swevent_put_recursion_context (rctx);
@@ -8296,6 +8315,8 @@ void perf_tp_event(u16 event_type, u64 count, void *record, int entry_size,perf_trace_buf_update (record, event_type);hlist_for_each_entry_rcu (event, head, hlist_entry) { +if (current->perf_blocked && !perf_event_is_blocked (event)) +continue ;if (perf_tp_event_match (event, &data, regs))perf_swevent_event (event, count, &data, regs); }
@@ -8314,6 +8335,8 @@ void perf_tp_event(u16 event_type, u64 count, void *record, int entry_size, goto unlock;list_for_each_entry_rcu (event, &ctx->event_list, event_entry) { +if (current->perf_blocked && !perf_event_is_blocked (event)) +continue ;if (event->cpu !=smp_processor_id ())continue ;if (event->attr.type !=PERF_TYPE_TRACEPOINT )
@@ -10461,6 +10484,19 @@ SYSCALL_DEFINE5(perf_event_open,return -EINVAL ; } +if (attr.block) { +/* +* Allow only syscall tracepoints, check for syscall class +* is made in the tracepoint event_init callback. +*/ +if (attr.type !=PERF_TYPE_TRACEPOINT ) +return -EINVAL ; + +/* Allow to block only if we attach to a process. */ +if (pid ==-1 ) +return -EINVAL ; + } +/* Only privileged users can get physical addresses */ if ((attr.sample_type &PERF_SAMPLE_PHYS_ADDR ) &&perf_paranoid_kernel () && !capable (CAP_SYS_ADMIN ))
kernel/events/ring_buffer.c +3 -1
@@ -223,7 +223,9 @@ __perf_output_begin(struct perf_output_handle *handle,return 0 ; fail: -local_inc (&rb->lost); +/* Do not count lost if we are going to block and try again. */ +if (!event->attr.block) +local_inc (&rb->lost);perf_output_put_handle (handle); out:rcu_read_unlock ();
kernel/trace/trace_event_perf.c +4 -0
@@ -8,6 +8,7 @@#include <linux/module.h> #include <linux/kprobes.h> +#include <linux/syscalls.h> #include "trace.h" #include "trace_probe.h"
@@ -85,6 +86,9 @@ static int perf_trace_event_perm(struct trace_event_call *tp_event,if (perf_paranoid_tracepoint_raw () && !capable (CAP_SYS_ADMIN ))return -EPERM ; +if (p_event->attr.block && !is_syscall_trace_event (tp_event)) +return -EINVAL ; +return 0 ; }
kernel/trace/trace_syscalls.c +24 -4
@@ -578,7 +578,7 @@ static int perf_call_bpf_enter(struct trace_event_call *call, struct pt_regs *rereturn trace_call_bpf (call, ¶m); } -static void perf_syscall_enter (void *ignore,struct pt_regs *regs,long id) +static void __perf_syscall_enter (struct pt_regs *regs,long id) {struct syscall_metadata *sys_data;struct syscall_trace_enter *rec;
@@ -616,7 +616,7 @@ static void perf_syscall_enter(void *ignore, struct pt_regs *regs, long id)syscall_get_arguments (current, regs,0 , sys_data->nb_args, (unsigned long *)&rec->args); -if ((valid_prog_array && +if ((!current->perf_blocked && valid_prog_array && !perf_call_bpf_enter (sys_data->enter_event, regs, sys_data, rec)) ||hlist_empty (head)) {perf_swevent_put_recursion_context (rctx);
@@ -628,6 +628,16 @@ static void perf_syscall_enter(void *ignore, struct pt_regs *regs, long id) head, NULL); } +static void perf_syscall_enter (void *ignore,struct pt_regs *regs,long id) +{ +__perf_syscall_enter (regs, id); +} + +void perf_trace_syscall_enter (struct pt_regs *regs) +{ +__perf_syscall_enter (regs, regs->orig_ax); +} +static int perf_sysenter_enable (struct trace_event_call *call) {int ret =0 ;
@@ -677,7 +687,7 @@ static int perf_call_bpf_exit(struct trace_event_call *call, struct pt_regs *regreturn trace_call_bpf (call, ¶m); } -static void perf_syscall_exit (void *ignore,struct pt_regs *regs,long ret) +static void __perf_syscall_exit (struct pt_regs *regs,long ret) {struct syscall_metadata *sys_data;struct syscall_trace_exit *rec;
@@ -713,7 +723,7 @@ static void perf_syscall_exit(void *ignore, struct pt_regs *regs, long ret) rec->nr = syscall_nr; rec->ret =syscall_get_return_value (current, regs); -if ((valid_prog_array && +if ((!current->perf_blocked && valid_prog_array && !perf_call_bpf_exit (sys_data->exit_event, regs, rec)) ||hlist_empty (head)) {perf_swevent_put_recursion_context (rctx);
@@ -724,6 +734,16 @@ static void perf_syscall_exit(void *ignore, struct pt_regs *regs, long ret) 1, regs, head, NULL); } +static void perf_syscall_exit (void *ignore,struct pt_regs *regs,long ret) +{ +__perf_syscall_exit (regs, ret); +} + +void perf_trace_syscall_exit (struct pt_regs *regs) +{ +__perf_syscall_exit (regs, regs->ax); +} +static int perf_sysexit_enable (struct trace_event_call *call) {int ret =0 ;
Signature · 1 line
2.17.2
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 20 lines · On Wed, 5 Dec 2018 17:05:02 +0100 Jiri Olsa <[email protected]> wrote:
arch/x86/entry/common.c +12
-0@@ -60,6 +60,32 @@ static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) } } +static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); +
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 84
Quoted 10 lines
arch/x86/entry/common.c +10
-0+/* perf raw_syscalls:* enter */ +perf_trace_sys_enter (&event_sys_enter, regs, regs->orig_ax); + }else { +/* perf syscalls:* enter */ +perf_trace_syscall_exit (regs); + +/* perf raw_syscalls:* enter */ +perf_trace_sys_exit (&event_sys_exit, regs, regs->ax); + } + }while (current->perf_blocked_cnt);
I was thinking, if the process reading the perf buffer dies, how do we tell this task to continue on?
-- Steve
Quoted 4 lines
arch/x86/entry/common.c +4
-0+ + current->perf_blocked = false; +} +
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 28 lines · Steven Rostedt
Quoted 25 lines · On Wed, 5 Dec 2018 17:05:02 +0100 Jiri Olsa <[email protected]> wrote:
arch/x86/entry/common.c +17
-0@@ -60,6 +60,32 @@ static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) } } +static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_enter(&event_sys_enter, regs, regs->orig_ax); + } else { + /* perf syscalls:* enter */ + perf_trace_syscall_exit(regs);
Quoted 8 lines
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 84
Quoted 5 lines
arch/x86/entry/common.c +5
-0+ +/* perf raw_syscalls:* enter */ +perf_trace_sys_exit (&event_sys_exit, regs, regs->ax); + } + }while (current->perf_blocked_cnt);I was thinking, if the process reading the perf buffer dies, how do we tell this task to continue on?
when the tracer process dies, its event will get uninstalled from the trace_event_call::perf_events list, so the next iteration of above loop won't get any blocked event and it will leave (assuming there's just single event)
jirka
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Jiri OlsaQuoted 1 line · Jiri Olsa
Adding support to specify 'block' bool in struct
perf_event_attr
NAK for having _Bool in structures.
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 4 lines · Peter Zijlstra
Quoted 1 line · Jiri Olsa
Adding support to specify 'block' bool in struct
perf_event_attrNAK for having
_Boolin structures.
oops, will change.. if there's ever another version ;-)
jirka
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Jiri OlsaQuoted 15 lines · Jiri Olsa
arch/x86/entry/common.c +15
-0+static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_enter(&event_sys_enter, regs, regs->orig_ax); + } else {
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 87
Quoted 10 lines
arch/x86/entry/common.c +10
-0+/* perf syscalls:* enter */ +perf_trace_syscall_exit (regs); + +/* perf raw_syscalls:* enter */ +perf_trace_sys_exit (&event_sys_exit, regs, regs->ax); + } + }while (current->perf_blocked_cnt); + + current->perf_blocked = false; +}
I don't understand this.. why are we using schedule_timeout() and all that?
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 21 lines · Peter Zijlstra
Quoted 20 lines · Jiri Olsa
arch/x86/entry/common.c +20
-0+static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_enter(&event_sys_enter, regs, regs->orig_ax); + } else { + /* perf syscalls:* enter */ + perf_trace_syscall_exit(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_exit(&event_sys_exit, regs, regs->ax);
Quoted 8 lines
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 87
Quoted 5 lines
arch/x86/entry/common.c +5
-0+ } + }while (current->perf_blocked_cnt); + + current->perf_blocked = false; +}I don't understand this.. why are we using
schedule_timeout()and all that?
the idea is to block the process and try to deliver the event later
the ring buffer space is freed by user space process moving the tail pointer, so I can't see doing this other way than polling
jirka
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 31 lines · Jiri Olsa
Quoted 21 lines · Peter Zijlstra
Quoted 20 lines · Jiri Olsa
arch/x86/entry/common.c +20
-0+static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_enter(&event_sys_enter, regs, regs->orig_ax); + } else { + /* perf syscalls:* enter */ + perf_trace_syscall_exit(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_exit(&event_sys_exit, regs, regs->ax);Quoted 8 lines
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 87
Quoted 5 lines
arch/x86/entry/common.c +5
-0+ } + }while (current->perf_blocked_cnt); + + current->perf_blocked = false; +}I don't understand this.. why are we using
schedule_timeout()and all that?
Quoted 4 lines
the idea is to block the process and try to deliver the event later
the ring buffer space is freed by user space process moving the tail pointer, so I can't see doing this other way than polling
Right, figured that out.
I really really hate this stuff. poll-waiting fundamentally stinks, but also perf is designed to not/minimally interfere with the observed tasks, as is ftrace.
And bolting, as it really doesn't fit in the fundamental design, this fugly thing on top for this special case.. urgh.
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Peter ZijlstraQuoted 21 lines · Peter Zijlstra
Quoted 20 lines · Jiri Olsa
arch/x86/entry/common.c +20
-0+static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_enter(&event_sys_enter, regs, regs->orig_ax); + } else { + /* perf syscalls:* enter */ + perf_trace_syscall_exit(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_exit(&event_sys_exit, regs, regs->ax);
Quoted 8 lines
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 87
Quoted 5 lines
arch/x86/entry/common.c +5
-0+ } + }while (current->perf_blocked_cnt); + + current->perf_blocked = false; +}I don't understand this.. why are we using
schedule_timeout()and all that?
Urgh.. in fact, the more I look at this the more I hate it.
We want to block in __perf_output_begin(), but we cannot because both tracepoints and perf will have preemptability disabled down there.
So what we do is fail the event, fake the lost count and go all the way up that callstack, detect the failure and then poll-wait and retry.
And only do this for a few special events... *yuck*
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 31 lines · Peter Zijlstra
Quoted 21 lines · Peter Zijlstra
Quoted 20 lines · Jiri Olsa
arch/x86/entry/common.c +20
-0+static void trace_block_syscall (struct pt_regs *regs,bool enter) +{ + current->perf_blocked = true; + + do { + schedule_timeout(100 * HZ); + current->perf_blocked_cnt = 0; + + if (enter) { + /* perf syscalls:* enter */ + perf_trace_syscall_enter(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_enter(&event_sys_enter, regs, regs->orig_ax); + } else { + /* perf syscalls:* enter */ + perf_trace_syscall_exit(regs); + + /* perf raw_syscalls:* enter */ + perf_trace_sys_exit(&event_sys_exit, regs, regs->ax);Quoted 8 lines
arch/x86/entry/common.c static void do_audit_syscall_entry(struct pt_regs *regs, u32 arch) · line 87
Quoted 5 lines
arch/x86/entry/common.c +5
-0+ } + }while (current->perf_blocked_cnt); + + current->perf_blocked = false; +}I don't understand this.. why are we using
schedule_timeout()and all that?
Quoted 7 lines
Urgh.. in fact, the more I look at this the more I hate it.
We want to block in
__perf_output_begin(), but we cannot because both tracepoints and perf will have preemptability disabled down there.So what we do is fail the event, fake the lost count and go all the way up that callstack, detect the failure and then poll-wait and retry.
right
Quoted 2 lines
And only do this for a few special events... *yuck*
yes ;-)
jirka
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Peter ZijlstraQuoted 6 lines · On Thu, 6 Dec 2018 09:34:00 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 3 lines
I don't understand this.. why are we using
schedule_timeout()and all that?Urgh.. in fact, the more I look at this the more I hate it.
Quoted 7 lines
We want to block in
__perf_output_begin(), but we cannot because both tracepoints and perf will have preemptability disabled down there.So what we do is fail the event, fake the lost count and go all the way up that callstack, detect the failure and then poll-wait and retry.
And only do this for a few special events... *yuck*
Since this is a special case, we should add a new option to the perf system call that, 1 states that it wants the traced process to block (and must have PTRACE permission to do so) and 2, after it reads from the buffer, it needs to check a bit that says "this process is blocked, please wake it up" and then do another perf call to kick the process to continue.
I really dislike the polling too. But because this is not a default case, and is a new feature, we can add more infrastructure to make it work properly, instead of trying to hack the current method into something that does something poorly.
-- Steve
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 15 lines · Steven Rostedt
Quoted 12 lines · On Thu, 6 Dec 2018 09:34:00 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 3 lines
I don't understand this.. why are we using
schedule_timeout()and all that?Urgh.. in fact, the more I look at this the more I hate it.
We want to block in
__perf_output_begin(), but we cannot because both tracepoints and perf will have preemptability disabled down there.So what we do is fail the event, fake the lost count and go all the way up that callstack, detect the failure and then poll-wait and retry.
Quoted 8 lines
Quoted 1 line
And only do this for a few special events... *yuck*
Since this is a special case, we should add a new option to the perf system call that, 1 states that it wants the traced process to block (and must have PTRACE permission to do so) and 2, after it reads from the buffer, it needs to check a bit that says "this process is blocked, please wake it up" and then do another perf call to kick the process to continue.
so instead of polling the traced process would properly wait for tracer to kick him again after it reads/frees the buffer
I guess we could use the control mmap page (struct perf_event_mmap_page) to communicate the 'we are block-ed' message to the tracer and have new ioctl to wake the waiting process
jirka
Quoted 7 lines
I really dislike the polling too. But because this is not a default case, and is a new feature, we can add more infrastructure to make it work properly, instead of trying to hack the current method into something that does something poorly.
-- Steve
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Steven RostedtQuoted 24 lines · Steven Rostedt
Quoted 6 lines · On Thu, 6 Dec 2018 09:34:00 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 3 lines
I don't understand this.. why are we using
schedule_timeout()and all that?Urgh.. in fact, the more I look at this the more I hate it.
Quoted 7 lines
We want to block in
__perf_output_begin(), but we cannot because both tracepoints and perf will have preemptability disabled down there.So what we do is fail the event, fake the lost count and go all the way up that callstack, detect the failure and then poll-wait and retry.
And only do this for a few special events... *yuck*
Since this is a special case, we should add a new option to the perf system call that, 1 states that it wants the traced process to block (and must have PTRACE permission to do so) and 2, after it reads from the buffer, it needs to check a bit that says "this process is blocked, please wake it up" and then do another perf call to kick the process to continue.
Quoted 4 lines
I really dislike the polling too. But because this is not a default case, and is a new feature, we can add more infrastructure to make it work properly, instead of trying to hack the current method into something that does something poorly.
So why are we doing this? What makes the syscall tracepoints so much more special than many of the others that we need to overhaul our fundamental design principles for them?
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
IOW, what problem are we solving ?
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 5 lines · On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <[email protected]> wrote:
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
IOW, what problem are we solving ?
I guess the cover letter should have had a link (or copy) of this:
http://lkml.kernel.org/r/[email protected]
-- Steve
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 7 lines · Steven Rostedt
Quoted 4 lines · On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <[email protected]> wrote:
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
Quoted 5 lines
Quoted 1 line
IOW, what problem are we solving ?
I guess the cover letter should have had a link (or copy) of this:
That doesn't even begin to explain. Who cares about strace and why? And why is it such a bad thing to loose the occasional record etc..
Arnaldo Carvalho de Melo
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Em Fri, Dec 07, 2018 at 04:11:05PM +0100, Peter Zijlstra escreveu:
Quoted 7 lines · Steven Rostedt
Quoted 5 lines · On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 4 lines
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
Quoted 8 lines
Quoted 5 lines
Quoted 1 line
IOW, what problem are we solving ?
I guess the cover letter should have had a link (or copy) of this:
That doesn't even begin to explain. Who cares about strace and why? And why is it such a bad thing to loose the occasional record etc..
The following almost addresses all the details for doing such a perf based strace tool (modulo signals), was started by Thomas a long time ago [1] and is in the tree for a long time, with BPF attached to the raw_syscalls:sys_{enter,exit} (that -e augmented_raw_syscalls.c thing that lives in tools/perf/examples/bpf now but would be put in place transparently and pre-compiled as augmented_raw_syscalls.o) to collect pointer contents without using ptrace:
[root@seventh bpf]# perf trace --no-inherit -e augmented_raw_syscalls.c sleep 1
0.019 ( 0.001 ms): brk( ) = 0x559ca9dd7000
0.031 ( 0.004 ms): access(filename: , mode: R ) = -1 ENOENT No such file or directory
0.039 ( 0.003 ms): openat(dfd: CWD, filename: /etc/ld.so.cache, flags: CLOEXEC ) = 3
0.043 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7ffdfa50e940 ) = 0
0.045 ( 0.003 ms): mmap(len: 103484, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7fa76b2ce000
0.049 ( 0.001 ms): close(fd: 3 ) = 0
0.056 ( 0.003 ms): openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 3
0.060 ( 0.002 ms): read(fd: 3, buf: 0x7ffdfa50eb08, count: 832 ) = 832
0.063 ( 0.001 ms): fstat(fd: 3, statbuf: 0x7ffdfa50e9a0 ) = 0
0.065 ( 0.002 ms): mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS ) = 0x7fa76b2cc000
0.070 ( 0.003 ms): mmap(len: 3889792, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 3 ) = 0x7fa76ad0e000
0.075 ( 0.005 ms): mprotect(start: 0x7fa76aebb000, len: 2093056 ) = 0
0.081 ( 0.005 ms): mmap(addr: 0x7fa76b0ba000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 1753088) = 0x7fa76b0ba000
0.089 ( 0.002 ms): mmap(addr: 0x7fa76b0c0000, len: 14976, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7fa76b0c0000
0.095 ( 0.001 ms): close(fd: 3 ) = 0
0.105 ( 0.001 ms): arch_prctl(option: 4098, arg2: 140357034366208 ) = 0
0.144 ( 0.004 ms): mprotect(start: 0x7fa76b0ba000, len: 16384, prot: READ ) = 0
0.159 ( 0.002 ms): mprotect(start: 0x559ca81aa000, len: 4096, prot: READ ) = 0
0.163 ( 0.002 ms): mprotect(start: 0x7fa76b2e8000, len: 4096, prot: READ ) = 0
0.167 ( 0.008 ms): munmap(addr: 0x7fa76b2ce000, len: 103484 ) = 0
0.218 ( 0.001 ms): brk( ) = 0x559ca9dd7000
0.220 ( 0.002 ms): brk(brk: 0x559ca9df8000 ) = 0x559ca9df8000
0.224 ( 0.001 ms): brk( ) = 0x559ca9df8000
0.228 ( 0.004 ms): open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC ) = 3
0.233 ( 0.001 ms): fstat(fd: 3, statbuf: 0x7fa76b0bfaa0 ) = 0
0.235 ( 0.003 ms): mmap(len: 113045344, prot: READ, flags: PRIVATE, fd: 3 ) = 0x7fa76413f000
0.241 ( 0.001 ms): close(fd: 3 ) = 0
0.264 (1000.163 ms): nanosleep(rqtp: 0x7ffdfa50f680 ) = 0
1000.440 ( 0.002 ms): close(fd: 1 ) = 0
1000.443 ( 0.001 ms): close(fd: 2 ) = 0
1000.449 ( ): exit_group( )[root@seventh bpf]#
doing just:
# perf trace --filter-pids pid-of-your-local-xterm,gnome-shell-pid-for-your-term
For system wide stracing elliminating the feedback loop of your GUI components will most of the time work with the default ring buffer size and when it doesn't, you'll get things like that "LOST events!" message, and for such extreme cases, just use '-m' to bump the rb size some more.
# trace --filter-pids 2279,1643 <SNIP> 8793.387 ( 0.003 ms): cc1/19097 openat(dfd: CWD, filename: 0x3df9940, flags: NOCTTY ) = 21 8793.390 ( 0.001 ms): cc1/19097 fstat(fd: 21, statbuf: 0x3df9648 ) = 0 8793.394 ( 0.003 ms): cc1/19097 read(fd: 21, buf: 0x3d6e0f0, count: 5804 ) = 5804 8793.398 ( 0.001 ms): cc1/19097 close(fd: 21 ) = 0 8793.403 ( 0.002 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70, flags: NOCTTY ) = -1 ENOENT No such file or directory 8793.406 ( 0.001 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70, flags: NOCTTY ) = -1 ENOENT No such file or directory 8793.409 ( 0.002 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70, flags: NOCTTY ) = 21 8793.412 ( 0.001 ms): cc1/19097 fstat(fd: 21, statbuf: 0x3df9738 ) = 0 8793.414 ( 0.022 ms): cc1/19097 read(fd: 21, buf: 0x3eb6d90, count: 25315 ) = 25315 8793.437 ( 0.001 ms): cc1/19097 close(fd: 21 ) = 0 8793.605 ( 0.005 ms): cc1/19097 openat(dfd: CWD, filename: 0x3dfca70 ) = 21 8793.614 ( 0.001 ms): cc1/19097 close(fd: 5 ) = 0 8793.618 ( 0.001 ms): cc1/19097 fstat(fd: 21, statbuf: 0x7ffd653ed380 ) = 0 8793.621 ( 0.002 ms): cc1/19097 read(fd: 21, buf: 0x3d41e30, count: 8192 ) = 8192 8793.626 ( 0.002 ms): cc1/19097 read(fd: 21, buf: 0x3ebf090, count: 8192 ) = 8192 8793.635 ( 0.003 ms): cc1/19097 read(fd: 21, buf: 0x3ed4730, count: 16384 ) = 8931 8793.640 ( 0.001 ms): cc1/19097 read(fd: 21, buf: 0x3ed6a13, count: 4096 ) = 0 LOST 34956 events! 9497.921 ( 0.006 ms): gcc/19180 openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY ) = -1 ENOENT No such file or directory 9497.935 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY ) = -1 ENOENT No such file or directory 9497.939 ( 0.003 ms): gcc/19180 openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY ) = 9 9497.943 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x3153568) = 0 9497.945 ( 0.006 ms): gcc/19180 read(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, buf: 0x31c00a0, count: 40574) = 40574 9497.952 ( 0.001 ms): gcc/19180 close(fd: 9</home/acme/git/linux/include/linux/page_ref.h> ) = 0 9497.959 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x31540a0, flags: NOCTTY ) = -1 ENOENT No such file or directory 9497.962 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x31540a0, flags: NOCTTY ) = -1 ENOENT No such file or directory 9497.965 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x31540a0, flags: NOCTTY ) = 9 9497.969 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x30dcf38) = 0 9497.970 ( 0.003 ms): gcc/19180 read(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, buf: 0x31b8320, count: 23058) = 23058 9497.975 ( 0.001 ms): gcc/19180 close(fd: 9</home/acme/git/linux/include/linux/page_ref.h> ) = 0 9497.979 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154020, flags: NOCTTY ) = -1 ENOENT No such file or directory 9497.982 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154020, flags: NOCTTY ) = -1 ENOENT No such file or directory 9497.986 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154020, flags: NOCTTY ) = 9 9497.989 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x3116178) = 0 9497.990 ( 0.001 ms): gcc/19180 read(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, buf: 0x31509c0, count: 1948) = 1948 9497.993 ( 0.001 ms): gcc/19180 close(fd: 9</home/acme/git/linux/include/linux/page_ref.h> ) = 0 9498.039 ( 0.003 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154060, flags: NOCTTY ) = -1 ENOENT No such file or directory 9498.043 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154060, flags: NOCTTY ) = -1 ENOENT No such file or directory 9498.046 ( 0.002 ms): gcc/19180 openat(dfd: CWD, filename: 0x3154060, flags: NOCTTY ) = 9 9498.049 ( 0.001 ms): gcc/19180 fstat(fd: 9</home/acme/git/linux/include/linux/page_ref.h>, statbuf: 0x3153a08) = 0
'trace' is just 'perf trace', perf has logic to see if argv[0] is 'trace', then it goes and does a 'perf trace'. The above case does't use bpf at all, gets details from /proc.
With bpf we get the 'filename' contents:
[root@seventh bpf]# trace -e augmented_raw_syscalls.c --filter-pids 2279,1643 <SNIP>
19766.027 ( 0.003 ms): gcc/27524 openat(dfd: CWD, filename: /lib64/libz.so.1, flags: CLOEXEC ) = 5 19766.035 ( 0.001 ms): gcc/27524 fstat(fd: 5, statbuf: 0x7ffe9323e2a0 ) = 0 19766.037 ( 0.003 ms): gcc/27524 mmap(len: 2187272, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 5 ) = 0x7fa2df435000 19766.042 ( 0.003 ms): gcc/27524 mprotect(start: 0x7fa2df44b000, len: 2093056 ) = 0 19766.046 ( 0.004 ms): gcc/27524 mmap(addr: 0x7fa2df64a000, len: 4096, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 5, off: 86016) = 0x7fa2df64a000
19766.051 ( 0.002 ms): gcc/27524 mmap(addr: 0x7fa2df64b000, len: 8, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7fa2df64b000
19766.057 ( 0.001 ms): gcc/27524 close(fd: 5 ) = 0
19766.062 ( 0.003 ms): gcc/27524 openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC ) = 5
<SNIP>
- Arnaldo
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 49 lines · Arnaldo Carvalho de Melo
Em Fri, Dec 07, 2018 at 04:11:05PM +0100, Peter Zijlstra escreveu:
Quoted 7 lines · Steven Rostedt
Quoted 5 lines · On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 4 lines
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
Quoted 8 lines
Quoted 5 lines
Quoted 1 line
IOW, what problem are we solving ?
I guess the cover letter should have had a link (or copy) of this:
That doesn't even begin to explain. Who cares about strace and why? And why is it such a bad thing to loose the occasional record etc..
The following almost addresses all the details for doing such a perf based strace tool (modulo signals), was started by Thomas a long time ago [1] and is in the tree for a long time, with BPF attached to the raw_syscalls:sys_{enter,exit} (that -e
augmented_raw_syscalls.cthing that lives intools/perf/examples/bpfnow but would be put in place transparently and pre-compiled as augmented_raw_syscalls.o) to collect pointer contents without using ptrace:For system wide stracing elliminating the feedback loop of your GUI components will most of the time work with the default ring buffer size and when it doesn't, you'll get things like that "LOST events!" message, and for such extreme cases, just use '-m' to bump the rb size some more.
# trace --filter-pids 2279,16438793.640 ( 0.001 ms): cc1/19097
read(fd: 21, buf: 0x3ed6a13, count: 4096 )= 0
LOST 34956 events!
9497.921 ( 0.006 ms): gcc/19180openat(dfd: CWD, filename: 0x3115e20, flags: NOCTTY )= -1 ENOENT No such file or directory'trace' is just 'perf trace', perf has logic to see if argv[0] is 'trace', then it goes and does a 'perf trace'. The above case does't use bpf at all, gets details from /proc.
With bpf we get the 'filename' contents:
[root@seventh bpf]# trace -e
augmented_raw_syscalls.c--filter-pids 2279,1643 <SNIP>19766.027 ( 0.003 ms): gcc/27524 openat(dfd: CWD, filename: /lib64/libz.so.1, flags: CLOEXEC ) = 5 19766.035 ( 0.001 ms): gcc/27524 fstat(fd: 5, statbuf: 0x7ffe9323e2a0 ) = 0 19766.037 ( 0.003 ms): gcc/27524 mmap(len: 2187272, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 5 ) = 0x7fa2df435000 19766.042 ( 0.003 ms): gcc/27524 mprotect(start: 0x7fa2df44b000, len: 2093056 ) = 0 19766.046 ( 0.004 ms): gcc/27524 mmap(addr: 0x7fa2df64a000, len: 4096, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 5, off: 86016) = 0x7fa2df64a000
Quoted 4 lines
19766.051 ( 0.002 ms): gcc/27524
mmap(addr: 0x7fa2df64b000, len: 8, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS)=0x7fa2df64b000
19766.057 ( 0.001 ms): gcc/27524 close(fd: 5 ) = 0
19766.062 ( 0.003 ms): gcc/27524openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC )= 5
<SNIP>
Right; and that is all nice. And exactly doesn't answer my question. Why do we care about those LOST entries so much that we have to do such horribly ugly things?
Esp. as you point out, they're clearly marked in the output and easily avoided by using a slightly larger buffer.
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 12 lines · On Sat, 8 Dec 2018 11:41:21 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 11 lines
[root@seventh bpf]# trace -e
augmented_raw_syscalls.c--filter-pids 2279,1643 <SNIP>19766.027 ( 0.003 ms): gcc/27524 openat(dfd: CWD, filename: /lib64/libz.so.1, flags: CLOEXEC ) = 5 19766.035 ( 0.001 ms): gcc/27524 fstat(fd: 5, statbuf: 0x7ffe9323e2a0 ) = 0 19766.037 ( 0.003 ms): gcc/27524 mmap(len: 2187272, prot: EXEC|READ, flags: PRIVATE|DENYWRITE, fd: 5 ) = 0x7fa2df435000 19766.042 ( 0.003 ms): gcc/27524 mprotect(start: 0x7fa2df44b000, len: 2093056 ) = 0 19766.046 ( 0.004 ms): gcc/27524 mmap(addr: 0x7fa2df64a000, len: 4096, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 5, off: 86016) = 0x7fa2df64a00019766.051 ( 0.002 ms): gcc/27524
mmap(addr: 0x7fa2df64b000, len: 8, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS)=0x7fa2df64b000
19766.057 ( 0.001 ms): gcc/27524 close(fd: 5 ) = 0
19766.062 ( 0.003 ms): gcc/27524openat(dfd: CWD, filename: /lib64/libc.so.6, flags: CLOEXEC )= 5
<SNIP>
Quoted 6 lines
Right; and that is all nice. And exactly doesn't answer my question. Why do we care about those LOST entries so much that we have to do such horribly ugly things?
Esp. as you point out, they're clearly marked in the output and easily avoided by using a slightly larger buffer.
For small cases like this a slightly larger buffer wont help. And it would suck if you are tracing something to find out why there's some kind of anomaly that takes hours to run, only to find out that the anomaly happened in the lost events.
Yes, there is a use case for a guarantee of no lost events!
-- Steve
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Peter ZijlstraQuoted 8 lines · On Fri, 7 Dec 2018 16:11:05 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 7 lines · Steven Rostedt
Quoted 4 lines · On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <[email protected]> wrote:
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
Quoted 8 lines
Quoted 5 lines
Quoted 1 line
IOW, what problem are we solving ?
I guess the cover letter should have had a link (or copy) of this:
That doesn't even begin to explain. Who cares about strace and why? And why is it such a bad thing to loose the occasional record etc..
Who cares about strace? Do I really need to answer that? It's one of the most used tools for seeing what a program is doing.
Why do we care about lost events? Because strace records *all* events, as that's what it does and that's what it always has done. It would be a break in functionality (a regression) if it were to start losing events. I use strace to see everything that an application is doing.
Peter, I think you've spent too much time in the kernel. There's a whole world out there that lives in userspace ;-)
When we discussed this at plumbers, Oracle people came to me and said how awesome it would be to run strace against their database accesses. The problem today is that strace causes such a large overhead that it isn't feasible to trace any high speed applications, especially if there are time restraints involved.
If you don't like this for perf, I'll be happy to implement something in ftrace. I just figured that the perf interface was more suitable for something like this.
-- Steve
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 15 lines · Steven Rostedt
Quoted 12 lines · On Fri, 7 Dec 2018 16:11:05 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 11 lines · Steven Rostedt
Quoted 5 lines · On Fri, 7 Dec 2018 09:58:39 +0100 Peter Zijlstra <[email protected]> wrote:
These patches give no justification *what*so*ever* for why we're doing ugly arse things like this. And why does this, whatever this is, need to be done in perf?
IOW, what problem are we solving ?
I guess the cover letter should have had a link (or copy) of this:
Quoted 7 lines
Quoted 4 lines
Quoted 1 line
That doesn't even begin to explain. Who cares about strace and why? And why is it such a bad thing to loose the occasional record etc..
Who cares about strace? Do I really need to answer that? It's one of the most used tools for seeing what a program is doing.
It's a tool I haven't used in years, given we have so many better tools around these days.
Quoted 4 lines
Why do we care about lost events? Because strace records *all* events, as that's what it does and that's what it always has done. It would be a break in functionality (a regression) if it were to start losing events. I use strace to see everything that an application is doing.
So make a new tool; break the expectation of all events. See if there's anybody that really cares.
Quoted 5 lines
When we discussed this at plumbers, Oracle people came to me and said how awesome it would be to run strace against their database accesses. The problem today is that strace causes such a large overhead that it isn't feasible to trace any high speed applications, especially if there are time restraints involved.
So have them run that perf thing acme pointed to.
So far nobody's made a good argument for why we cannot have LOST events.
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 2 lines · On Sat, 8 Dec 2018 11:44:23 +0100 Peter Zijlstra <[email protected]> wrote:
It's a tool I haven't used in years, given we have so many better tools around these days.
So because you don't use it, it's useless? As you don't care about lost events I can see why you may think there are better tools out there. But since those tools don't guarantee no lost events, they are obviously not better to those that do care about lost events.
Quoted 8 lines
Quoted 5 lines
Why do we care about lost events? Because strace records *all* events, as that's what it does and that's what it always has done. It would be a break in functionality (a regression) if it were to start losing events. I use strace to see everything that an application is doing.
So make a new tool; break the expectation of all events. See if there's anybody that really cares.
Basically you are saying, break strace and see if anyone notices?
Quoted 10 lines
Quoted 6 lines
When we discussed this at plumbers, Oracle people came to me and said how awesome it would be to run strace against their database accesses. The problem today is that strace causes such a large overhead that it isn't feasible to trace any high speed applications, especially if there are time restraints involved.
So have them run that perf thing acme pointed to.
So far nobody's made a good argument for why we cannot have LOST events.
If you don't see the use case, I'm not sure anyone can convince you. Again, I like the fact that when I do a strace of an application I know that all system calls that the application I'm tracing is recorded. I don't need to worry about what happened in the "lost events" space.
-- Steve
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 8 lines · Steven Rostedt
Quoted 5 lines · On Sat, 8 Dec 2018 11:44:23 +0100 Peter Zijlstra <[email protected]> wrote:
Quoted 4 lines
Why do we care about lost events? Because strace records *all* events, as that's what it does and that's what it always has done. It would be a break in functionality (a regression) if it were to start losing events. I use strace to see everything that an application is doing.
Quoted 4 lines
Quoted 2 lines
So make a new tool; break the expectation of all events. See if there's anybody that really cares.
Basically you are saying, break strace and see if anyone notices?
Nah, give it a new name. Clearly mark this is a new tool.
Quoted 6 lines
Quoted 6 lines
Quoted 5 lines
When we discussed this at plumbers, Oracle people came to me and said how awesome it would be to run strace against their database accesses. The problem today is that strace causes such a large overhead that it isn't feasible to trace any high speed applications, especially if there are time restraints involved.
Quoted 8 lines
Quoted 3 lines
So have them run that perf thing acme pointed to.
So far nobody's made a good argument for why we cannot have LOST events.
If you don't see the use case, I'm not sure anyone can convince you. Again, I like the fact that when I do a strace of an application I know that all system calls that the application I'm tracing is recorded. I don't need to worry about what happened in the "lost events" space.
You're the one pushing for this crap without _any_ justification. Why are you getting upset if I ask for some?
If people care so much, it shouldn't be hard to write up a coherent story on this, so far all I seem to get is: because it's always been like that.
Which really isn't much of an argument.
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Hi Peter,
Quoted 30 lines · Peter Zijlstra
Quoted 11 lines · Steven Rostedt
Quoted 7 lines · Peter Zijlstra
Quoted 4 lines
Why do we care about lost events? Because strace records *all* events, as that's what it does and that's what it always has done. It would be a break in functionality (a regression) if it were to start losing events. I use strace to see everything that an application is doing.
So make a new tool; break the expectation of all events. See if there's anybody that really cares.
Basically you are saying, break strace and see if anyone notices?
Nah, give it a new name. Clearly mark this is a new tool.
Quoted 6 lines
Quoted 6 lines
Quoted 5 lines
When we discussed this at plumbers, Oracle people came to me and said how awesome it would be to run strace against their database accesses. The problem today is that strace causes such a large overhead that it isn't feasible to trace any high speed applications, especially if there are time restraints involved.
Quoted 8 lines
Quoted 3 lines
So have them run that perf thing acme pointed to.
So far nobody's made a good argument for why we cannot have LOST events.
If you don't see the use case, I'm not sure anyone can convince you. Again, I like the fact that when I do a strace of an application I know that all system calls that the application I'm tracing is recorded. I don't need to worry about what happened in the "lost events" space.
Quoted 8 lines
You're the one pushing for this crap without _any_ justification. Why are you getting upset if I ask for some?
If people care so much, it shouldn't be hard to write up a coherent story on this, so far all I seem to get is: because it's always been like that.
Which really isn't much of an argument.
As you rightly pointed out, strace users are expecting that no events are lost because it's always been like that, and it would require some efforts to imagine what kind of things are going to break if this is no longer the case.
Last FOSDEM I attended a talk [1] by Philippe Ombredanne, he was speaking about a strace-based tool called TraceCode that constructs build graphs that are used to find out "exactly which files were built, by what and how they were transformed in multiple steps from sources to your final binaries".
Imagine you told Philippe that strace now works faster but it's no longer reliable because some events may be lost, and he would have to repeat builds under strace again and again until he is lucky. I can imagine his reaction to this piece of news, and I certainly wouldn't like to be the messenger.
btw, I didn't ask for the implementation to be ugly.
You don't have to introduce polling into the kernel if you don't want to, userspace is perfectly capable of invoking wait4(2) in a loop. Just block the tracee, notify the tracer, and let it pick up the pieces.
[1] https://archive.fosdem.org/2018/schedule/event/debugging_tools_stracing_build/
Signature · 1 line
ldv
Steven Rostedt
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 4 lines · On Thu, 13 Dec 2018 03:39:38 +0300 "Dmitry V. Levin" <[email protected]> wrote:
btw, I didn't ask for the implementation to be ugly.
You don't have to introduce polling into the kernel if you don't want to, userspace is perfectly capable of invoking wait4(2) in a loop. Just block the tracee, notify the tracer, and let it pick up the pieces.
Note, there's been some discussion offlist to only have perf set a flag when it dropped an event and have the ptrace code do the heavy lifting of blocking the task and waking it back up. I think that would be a cleaner solution and wont muck with perf as badly.
-- Steve
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 11 lines · Steven Rostedt
Quoted 4 lines · On Thu, 13 Dec 2018 03:39:38 +0300, wrote:
btw, I didn't ask for the implementation to be ugly.
You don't have to introduce polling into the kernel if you don't want to, userspace is perfectly capable of invoking wait4(2) in a loop. Just block the tracee, notify the tracer, and let it pick up the pieces.Note, there's been some discussion offlist to only have perf set a flag when it dropped an event and have the ptrace code do the heavy lifting of blocking the task and waking it back up. I think that would be a cleaner solution and wont muck with perf as badly.
Yes, if perf could be instructed to invoke something like tracehook_report_syscall_entry/exit when it drops the event of entering/exiting syscall, that should probably be enough for the ptracer to do the recovery.
Signature · 1 line
ldv
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Steven RostedtQuoted 8 lines · Steven Rostedt
Quoted 4 lines · On Thu, 13 Dec 2018 03:39:38 +0300 "Dmitry V. Levin" <[email protected]> wrote:
btw, I didn't ask for the implementation to be ugly.
You don't have to introduce polling into the kernel if you don't want to, userspace is perfectly capable of invoking wait4(2) in a loop. Just block the tracee, notify the tracer, and let it pick up the pieces.
Quoted 4 lines
Note, there's been some discussion offlist to only have perf set a flag when it dropped an event and have the ptrace code do the heavy lifting of blocking the task and waking it back up. I think that would be a cleaner solution and wont muck with perf as badly.
It's still really horrid -- the question is not if we can come up with something, anything, to make strace work. The question is if we can extend something in a sane and maintainable manner to allow this.
So there's a whole bunch of problems I see with all this, in no particular order:
- we cannot block when writing to the actual buffer, and have to unroll the callstack and bolt on the blocking manualy in a few specific sites. This is ugly, inconsistent and maintenance heavy.
- it only works for some 'magic' events that got the treatment, but not for many other you might expect it to work for with no real indication which and why.
- the wakeups side is icky; the best I can come up with is making the data page R/O and single stepping on write fault, but that isn't multi-threading safe.
Another alternative would be keeping the whole page R/O and using write(2) or an ioctl() to update the head pointer.
Again, if we're going to do this; it needs to be done well and consistent and not as a special hack to enable strace-like functionality. And without clean and sane solutions to the above I just don't see it happening.
Note that the first 2 points are equally true for ftrace; so I don't see how we could sanely add it there either.
One, very big maybe, would be to add a new tracepoint type that includes a might_sleep() and we very carefully undo all the preempt_disable and go sleep where we should. That also gives the tracepoint crud the information it needs to publish the capability to userspace.
We also have to consider (and possibly forbid) mixing blocking and !blocking events to the same buffer.
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 4 lines · Peter Zijlstra
One, very big maybe, would be to add a new tracepoint type that includes a
might_sleep()and we very carefully undo all thepreempt_disableand go sleep where we should. That also gives the tracepoint crud the information it needs to publish the capability to userspace.
Note that this includes handling fun things like the buffer getting closed while we wait.
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Peter ZijlstraQuoted 3 lines · Peter Zijlstra
- the wakeups side is icky; the best I can come up with is making the data page R/O and single stepping on write fault, but that isn't multi-threading safe.
We can emulate the instruction, that would actually work and be thread safe. Just a small matter of decoding and interpreting any possible write instruction ;-)
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Peter ZijlstraQuoted 41 lines · Peter Zijlstra
Quoted 8 lines · Steven Rostedt
Quoted 4 lines · On Thu, 13 Dec 2018 03:39:38 +0300 "Dmitry V. Levin" <[email protected]> wrote:
btw, I didn't ask for the implementation to be ugly.
You don't have to introduce polling into the kernel if you don't want to, userspace is perfectly capable of invoking wait4(2) in a loop. Just block the tracee, notify the tracer, and let it pick up the pieces.Quoted 4 lines
Note, there's been some discussion offlist to only have perf set a flag when it dropped an event and have the ptrace code do the heavy lifting of blocking the task and waking it back up. I think that would be a cleaner solution and wont muck with perf as badly.
It's still really horrid -- the question is not if we can come up with something, anything, to make strace work. The question is if we can extend something in a sane and maintainable manner to allow this.
So there's a whole bunch of problems I see with all this, in no particular order:
- we cannot block when writing to the actual buffer, and have to unroll the callstack and bolt on the blocking manualy in a few specific sites. This is ugly, inconsistent and maintenance heavy.
- it only works for some 'magic' events that got the treatment, but not for many other you might expect it to work for with no real indication which and why.
- the wakeups side is icky; the best I can come up with is making the data page R/O and single stepping on write fault, but that isn't multi-threading safe.
Another alternative would be keeping the whole page R/O and using write(2) or an
ioctl()to update the head pointer.Again, if we're going to do this; it needs to be done well and consistent and not as a special hack to enable strace-like functionality. And without clean and sane solutions to the above I just don't see it happening.
Quoted 8 lines
Note that the first 2 points are equally true for ftrace; so I don't see how we could sanely add it there either.
One, very big maybe, would be to add a new tracepoint type that includes a
might_sleep()and we very carefully undo all thepreempt_disableand go sleep where we should. That also gives the tracepoint crud the information it needs to publish the capability to userspace.
nice, I like this one.. seems like the most clean solution
jirka
Peter Zijlstra
maintainerRe: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
In reply to Jiri OlsaQuoted 10 lines · Jiri Olsa
kernel/events/core.c +6
-0@@ -10461,6 +10484,19 @@ SYSCALL_DEFINE5(perf_event_open,return -EINVAL ; } +if (attr.block) { +/* +* Allow only syscall tracepoints, check for syscall class +* is made in the tracepoint event_init callback. +*/ +if (attr.type !=PERF_TYPE_TRACEPOINT )
kernel/events/core.c SYSCALL_DEFINE5(perf_event_open, · line 10502
Quoted 10 lines
kernel/events/core.c +7
-0+return -EINVAL ; + +/* Allow to block only if we attach to a process. */ +if (pid ==-1 ) +return -EINVAL ; + } +/* Only privileged users can get physical addresses */ if ((attr.sample_type &PERF_SAMPLE_PHYS_ADDR ) &&perf_paranoid_kernel () && !capable (CAP_SYS_ADMIN ))
That's fairly horrible and will, when copied, lead to a giant mess.
Please see the whole exclusion patch set here:
https://lkml.kernel.org/r/[email protected]
PERF_PMU_CAP_BLOCK sounds like something you'd want here.
Re: [PATCH 1/8] perf: Allow to block process in syscall tracepoints
Quoted 24 lines · Peter Zijlstra
Quoted 10 lines · Jiri Olsa
kernel/events/core.c +6
-0@@ -10461,6 +10484,19 @@ SYSCALL_DEFINE5(perf_event_open,return -EINVAL ; } +if (attr.block) { +/* +* Allow only syscall tracepoints, check for syscall class +* is made in the tracepoint event_init callback. +*/ +if (attr.type !=PERF_TYPE_TRACEPOINT )kernel/events/core.c SYSCALL_DEFINE5(perf_event_open, · line 10502
Quoted 10 lines
kernel/events/core.c +7
-0+return -EINVAL ; + +/* Allow to block only if we attach to a process. */ +if (pid ==-1 ) +return -EINVAL ; + } +/* Only privileged users can get physical addresses */ if ((attr.sample_type &PERF_SAMPLE_PHYS_ADDR ) &&perf_paranoid_kernel () && !capable (CAP_SYS_ADMIN ))That's fairly horrible and will, when copied, lead to a giant mess.
Quoted 5 lines
Please see the whole exclusion patch set here:
https://lkml.kernel.org/r/[email protected]
PERF_PMU_CAP_BLOCKsounds like something you'd want here.
ok, that's better
jirka
Jiri Olsa
reviewerPATCH 2/8 perf tools: Sync uapi perf_event.h
In reply to Jiri Olsa--- tools/include/uapi/linux/perf_event.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-)
tools/include/uapi/linux/perf_event.h +2 -1
@@ -372,7 +372,8 @@ struct perf_event_attr { context_switch : 1, /* context switch data */ write_backward : 1, /* Write ring buffer from end to beginning */ namespaces : 1, /* include namespaces data */ - __reserved_1 : 35; + block : 1, /* block process if there's no space in RB (syscall tracepoints only) */ + __reserved_1 : 34;union {__u32 wakeup_events;/* wakeup every n events */
Signature · 1 line
2.17.2
Jiri Olsa
reviewerPATCH 3/8 perf record: Add --block option
In reply to Jiri OlsaAdding --block option to allow record command set block bool in struct perf_event_attr for event, like:
# perf record -e raw_syscalls:sys_enter --block ls # perf record -e raw_syscalls:sys_enter --block -p ...
It's allowed only for syscall tracepoint events
attached to process.
--- tools/perf/builtin-record.c | 9 +++++++++ tools/perf/perf.h | 1 + tools/perf/util/evsel.c | 3 +++ 3 files changed, 13 insertions(+)
tools/perf/builtin-record.c +9 -0
@@ -1937,6 +1937,8 @@ static struct option __record_options[] = { "append timestamp to output filename"),OPT_BOOLEAN (0 ,"timestamp-boundary" , &record.timestamp_boundary,"Record timestamp boundary (time of first/last samples)" ), +OPT_BOOLEAN (0 ,"block" , &record.opts.block, +"Request blocked tracing (for syscall tracepoints)" ), OPT_STRING_OPTARG_SET(0, "switch-output", &record.switch_output.str, &record.switch_output.set, "signal,size,time", "Switch output when receive SIGUSR2 or cross size,time threshold",
@@ -2116,6 +2118,13 @@ int cmd_record(int argc, const char **argv) goto out; } +if (rec->opts.block && + !target__has_task (&rec->opts.target) && + !target__none (&rec->opts.target)) { +pr_err ("Can't use --block on non task targets\n" ); + goto out; + } +/* Enable ignoring missing threads when -u/-p option is defined. */ rec->opts.ignore_missing_thread = rec->opts.target.uid !=UINT_MAX || rec->opts.target.pid;
tools/perf/perf.h +1 -0
@@ -66,6 +66,7 @@ struct record_opts {bool ignore_missing_thread;bool strict_freq;bool sample_id; +bool block;unsigned int freq;unsigned int mmap_pages;unsigned int auxtrace_mmap_pages;
tools/perf/util/evsel.c +3 -0
@@ -1045,6 +1045,9 @@ void perf_evsel__config(struct perf_evsel *evsel, struct record_opts *opts,if (opts->sample_transaction)perf_evsel__set_sample_bit (evsel,TRANSACTION ); +if (opts->block) + attr->block = true; +if (opts->running_time) { evsel->attr.read_format |= PERF_FORMAT_TOTAL_TIME_ENABLED |
Signature · 1 line
2.17.2
Jiri Olsa
reviewerPATCH 4/8 perf trace: Add --block option
In reply to Jiri OlsaAdding --block option to allow trace command pass along the --block option for record command or to set it for trace run session, like:
# perf trace --block kill # perf trace --block -p ... # perf trace -e raw_syscalls:sys_enter --block -p ...
It's allowed only for syscall tracepoint events
attached to process.
--- tools/perf/builtin-trace.c | 17 ++++++++++++++++- 1 file changed, 16 insertions(+), 1 deletion(-)
tools/perf/builtin-trace.c +16 -1
@@ -2379,10 +2379,12 @@ static int trace__record(struct trace *trace, int argc, const char **argv)unsigned int majpf_args_nr =ARRAY_SIZE (majpf_args);const char *const minpf_args[] = {"-e" ,"minor-faults" };unsigned int minpf_args_nr =ARRAY_SIZE (minpf_args); +const char *const block_args[] = {"--block" , }; +unsigned int block_args_nr =ARRAY_SIZE (block_args);/* +1 is for the event string below */ rec_argc =ARRAY_SIZE (record_args) + sc_args_nr +1 + - majpf_args_nr + minpf_args_nr + argc; + majpf_args_nr + minpf_args_nr + block_args_nr + argc; rec_argv =calloc (rec_argc +1 ,sizeof (char *));if (rec_argv ==NULL )
@@ -2416,6 +2418,9 @@ static int trace__record(struct trace *trace, int argc, const char **argv)for (i =0 ; i < minpf_args_nr; i++) rec_argv[j++] = minpf_args[i]; +if (trace->opts.block) + rec_argv[j++] = block_args[0 ]; +for (i =0 ; i < (unsigned int )argc; i++) rec_argv[j++] = argv[i];
@@ -3409,6 +3414,8 @@ int cmd_trace(int argc, const char **argv) trace__parse_events_option),OPT_BOOLEAN (0 ,"comm" , &trace.show_comm,"show the thread COMM next to its id" ), +OPT_BOOLEAN (0 ,"block" , &trace.opts.block, +"Request blocked tracing (for syscall tracepoints)" ),OPT_BOOLEAN (0 ,"tool_stats" , &trace.show_tool_stats,"show tool stats" ),OPT_CALLBACK (0 ,"expr" , &trace,"expr" ,"list of syscalls/events to trace" , trace__parse_events_option),
@@ -3500,6 +3507,14 @@ int cmd_trace(int argc, const char **argv) "cgroup monitoring only available in system-wide mode"); } +if (trace.opts.block) { +if (!target__has_task (&trace.opts.target) && + !target__none (&trace.opts.target)) { +pr_err ("ERROR: Can't use --block on non task targets\n" ); + goto out; + } + } + evsel =bpf__setup_output_event (trace.evlist,"__augmented_syscalls__" );if (IS_ERR (evsel)) {bpf__strerror_setup_output_event (trace.evlist,PTR_ERR (evsel), bf,sizeof (bf));
Signature · 1 line
2.17.2
Jiri Olsa
reviewerPATCH 5/8 perf tools: Add block term support for tracepoints
In reply to Jiri OlsaAllow to specify 'block' term for tracepoint in the -e command line option, like:
# perf record -e raw_syscalls:sys_enter/block/ -p ... # perf trace -e raw_syscalls:sys_enter/block/ -p ...
to set this tracepoint as blocking (sets struct perf_event_attr::block)
It's allowed only for syscall tracepoint events
attached to process.
--- tools/perf/util/evsel.c | 4 ++++ tools/perf/util/evsel.h | 2 ++ tools/perf/util/parse-events.c | 8 ++++++++ tools/perf/util/parse-events.h | 1 + tools/perf/util/parse-events.l | 1 + 5 files changed, 16 insertions(+)
tools/perf/util/evsel.c +4 -0
@@ -811,6 +811,9 @@ static void apply_config_terms(struct perf_evsel *evsel,break ;case PERF_EVSEL__CONFIG_TERM_DRV_CFG :break ; +case PERF_EVSEL__CONFIG_TERM_BLOCK : + attr->block = term->val.block ?1 :0 ; +break ;default :break ; }
@@ -1655,6 +1658,7 @@ int perf_event_attr__fprintf(FILE *fp, struct perf_event_attr *attr,PRINT_ATTRf (context_switch, p_unsigned);PRINT_ATTRf (write_backward, p_unsigned);PRINT_ATTRf (namespaces, p_unsigned); +PRINT_ATTRf (block, p_unsigned);PRINT_ATTRn ("{ wakeup_events, wakeup_watermark }" , wakeup_events, p_unsigned);PRINT_ATTRf (bp_type, p_unsigned);
tools/perf/util/evsel.h +2 -0
@@ -50,6 +50,7 @@ enum term_type {PERF_EVSEL__CONFIG_TERM_OVERWRITE ,PERF_EVSEL__CONFIG_TERM_DRV_CFG ,PERF_EVSEL__CONFIG_TERM_BRANCH , + PERF_EVSEL__CONFIG_TERM_BLOCK, }; struct perf_evsel_config_term {
@@ -67,6 +68,7 @@ struct perf_evsel_config_term {bool overwrite;char *branch;unsigned long max_events; +bool block; } val;bool weak; };
tools/perf/util/parse-events.c +8 -0
@@ -930,6 +930,7 @@ static const char *config_term_names[__PARSE_EVENTS__TERM_TYPE_NR] = { [PARSE_EVENTS__TERM_TYPE_OVERWRITE] = "overwrite", [PARSE_EVENTS__TERM_TYPE_NOOVERWRITE] = "no-overwrite", [PARSE_EVENTS__TERM_TYPE_DRV_CFG] = "driver-config", + [PARSE_EVENTS__TERM_TYPE_BLOCK] = "block", };static bool config_term_shrinked;
@@ -1041,6 +1042,9 @@ do { \case PARSE_EVENTS__TERM_TYPE_MAX_EVENTS :CHECK_TYPE_VAL (NUM );break ; +case PARSE_EVENTS__TERM_TYPE_BLOCK : +CHECK_TYPE_VAL (NUM ); +break ;default : err->str =strdup ("unknown term" ); err->idx = term->err_term;
@@ -1091,6 +1095,7 @@ static int config_term_tracepoint(struct perf_event_attr *attr,case PARSE_EVENTS__TERM_TYPE_MAX_EVENTS :case PARSE_EVENTS__TERM_TYPE_OVERWRITE :case PARSE_EVENTS__TERM_TYPE_NOOVERWRITE : +case PARSE_EVENTS__TERM_TYPE_BLOCK :return config_term_common (attr, term, err);default :if (err) {
@@ -1179,6 +1184,9 @@ do { \case PARSE_EVENTS__TERM_TYPE_DRV_CFG :ADD_CONFIG_TERM (DRV_CFG , drv_cfg, term->val.str);break ; +case PARSE_EVENTS__TERM_TYPE_BLOCK : +ADD_CONFIG_TERM (BLOCK , block, term->val.num ?1 :0 ); +break ;default :break ; }
tools/perf/util/parse-events.h +1 -0
@@ -75,6 +75,7 @@ enum {PARSE_EVENTS__TERM_TYPE_NOOVERWRITE ,PARSE_EVENTS__TERM_TYPE_OVERWRITE ,PARSE_EVENTS__TERM_TYPE_DRV_CFG , +PARSE_EVENTS__TERM_TYPE_BLOCK , __PARSE_EVENTS__TERM_TYPE_NR, };
tools/perf/util/parse-events.l +1 -0
@@ -274,6 +274,7 @@ inherit { return term(yyscanner, PARSE_EVENTS__TERM_TYPE_INHERIT); } no-inherit { return term(yyscanner, PARSE_EVENTS__TERM_TYPE_NOINHERIT); } overwrite { return term(yyscanner, PARSE_EVENTS__TERM_TYPE_OVERWRITE); } no-overwrite { return term(yyscanner, PARSE_EVENTS__TERM_TYPE_NOOVERWRITE); } +block { return term(yyscanner, PARSE_EVENTS__TERM_TYPE_BLOCK); } , { return ','; } "/" { BEGIN(INITIAL); return '/'; } {name_minus} { return str(yyscanner, PE_NAME); }
Signature · 1 line
2.17.2
Jiri Olsa
reviewerPATCH 6/8 perf tools: Add ordered_events__flush_time interface
In reply to Jiri OlsaAdding OE_FLUSH__TIME flush type, to be able to flush only certain amount of the queue based on the provided timestamp. It will be used in following patches.
--- tools/perf/util/ordered-events.c | 23 +++++++++++++++++++---- tools/perf/util/ordered-events.h | 2 ++ 2 files changed, 21 insertions(+), 4 deletions(-)
tools/perf/util/ordered-events.c +19 -4
@@ -219,8 +219,7 @@ int ordered_events__queue(struct ordered_events *oe, union perf_event *event,return 0 ; } -static int __ordered_events__flush (struct ordered_events *oe, -bool show_progress) +static int do_flush (struct ordered_events *oe,bool show_progress) {struct list_head *head = &oe->events;struct ordered_event *tmp, *iter;
@@ -263,7 +262,8 @@ static int __ordered_events__flush(struct ordered_events *oe,return 0 ; } -int ordered_events__flush (struct ordered_events *oe,enum oe_flush how) +static int __ordered_events__flush (struct ordered_events *oe,enum oe_flush how, +u64 time) {static const char *const str[] = {"NONE" ,
@@ -302,6 +302,11 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how)break ; } +case OE_FLUSH__TIME : + oe->next_flush = time; + show_progress = false; +break ; +case OE_FLUSH__ROUND :case OE_FLUSH__NONE :default :
@@ -312,7 +317,7 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how) str[how], oe->nr_events);pr_oe_time (oe->max_timestamp,"max_timestamp\n" ); - err =__ordered_events__flush (oe, show_progress); + err =do_flush (oe, show_progress);if (!err) {if (how ==OE_FLUSH__ROUND )
@@ -328,6 +333,16 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how)return err; } +int ordered_events__flush (struct ordered_events *oe,enum oe_flush how) +{ +return __ordered_events__flush (oe, how,0 ); +} + +int ordered_events__flush_time (struct ordered_events *oe,u64 time) +{ +return __ordered_events__flush (oe,OE_FLUSH__TIME , time); +} +void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data) {
tools/perf/util/ordered-events.h +2 -0
@@ -19,6 +19,7 @@ enum oe_flush {OE_FLUSH__ROUND ,OE_FLUSH__HALF ,OE_FLUSH__TOP , + OE_FLUSH__TIME, };struct ordered_events ;
@@ -55,6 +56,7 @@ int ordered_events__queue(struct ordered_events *oe, union perf_event *event, u64 timestamp, u64 file_offset);void ordered_events__delete (struct ordered_events *oe,struct ordered_event *event);int ordered_events__flush (struct ordered_events *oe,enum oe_flush how); +int ordered_events__flush_time (struct ordered_events *oe,u64 time);void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data);void ordered_events__free (struct ordered_events *oe);
Signature · 1 line
2.17.2
tip-bot for Jiri Olsa
merge bot[tip:perf/core] perf ordered_events: Add ordered_events__flush_time interface
perf ordered_events: Add ordered_events__flush_time interface
Commit-ID: a4a77b93ae0bfd752caad14a34fa9465ea6d30a9 Gitweb: https://git.kernel.org/tip/a4a77b93ae0bfd752caad14a34fa9465ea6d30a9 Author: Jiri Olsa <[email protected]> AuthorDate: Wed, 5 Dec 2018 17:05:07 +0100 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Thu, 6 Dec 2018 16:43:28 -0300
perf ordered_events: Add ordered_events__flush_time interface
Add OE_FLUSH__TIME flush type, to be able to flush only certain amount of the queue based on the provided timestamp. It will be used in the following patches.
--- tools/perf/util/ordered-events.c | 23 +++++++++++++++++++---- tools/perf/util/ordered-events.h | 2 ++ 2 files changed, 21 insertions(+), 4 deletions(-)
tools/perf/util/ordered-events.c +19 -4
@@ -219,8 +219,7 @@ int ordered_events__queue(struct ordered_events *oe, union perf_event *event,return 0 ; } -static int __ordered_events__flush (struct ordered_events *oe, -bool show_progress) +static int do_flush (struct ordered_events *oe,bool show_progress) {struct list_head *head = &oe->events;struct ordered_event *tmp, *iter;
@@ -263,7 +262,8 @@ static int __ordered_events__flush(struct ordered_events *oe,return 0 ; } -int ordered_events__flush (struct ordered_events *oe,enum oe_flush how) +static int __ordered_events__flush (struct ordered_events *oe,enum oe_flush how, +u64 timestamp) {static const char *const str[] = {"NONE" ,
@@ -302,6 +302,11 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how)break ; } +case OE_FLUSH__TIME : + oe->next_flush = timestamp; + show_progress = false; +break ; +case OE_FLUSH__ROUND :case OE_FLUSH__NONE :default :
@@ -312,7 +317,7 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how) str[how], oe->nr_events);pr_oe_time (oe->max_timestamp,"max_timestamp\n" ); - err =__ordered_events__flush (oe, show_progress); + err =do_flush (oe, show_progress);if (!err) {if (how ==OE_FLUSH__ROUND )
@@ -328,6 +333,16 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how)return err; } +int ordered_events__flush (struct ordered_events *oe,enum oe_flush how) +{ +return __ordered_events__flush (oe, how,0 ); +} + +int ordered_events__flush_time (struct ordered_events *oe,u64 timestamp) +{ +return __ordered_events__flush (oe,OE_FLUSH__TIME , timestamp); +} +void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data) {
tools/perf/util/ordered-events.h +2 -0
@@ -19,6 +19,7 @@ enum oe_flush {OE_FLUSH__ROUND ,OE_FLUSH__HALF ,OE_FLUSH__TOP , + OE_FLUSH__TIME, };struct ordered_events ;
@@ -55,6 +56,7 @@ int ordered_events__queue(struct ordered_events *oe, union perf_event *event, u64 timestamp, u64 file_offset);void ordered_events__delete (struct ordered_events *oe,struct ordered_event *event);int ordered_events__flush (struct ordered_events *oe,enum oe_flush how); +int ordered_events__flush_time (struct ordered_events *oe,u64 timestamp);void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data);void ordered_events__free (struct ordered_events *oe);
tip-bot for Jiri Olsa
merge bot[tip:perf/core] perf ordered_events: Add ordered_events__flush_time interface
In reply to Jiri Olsaperf ordered_events: Add ordered_events__flush_time interface
Commit-ID: 68ca5d07de207e56f57e887de23b03fbc1ebc2a6 Gitweb: https://git.kernel.org/tip/68ca5d07de207e56f57e887de23b03fbc1ebc2a6 Author: Jiri Olsa <[email protected]> AuthorDate: Wed, 5 Dec 2018 17:05:07 +0100 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 17 Dec 2018 15:02:12 -0300
perf ordered_events: Add ordered_events__flush_time interface
Add OE_FLUSH__TIME flush type, to be able to flush only certain amount of the queue based on the provided timestamp. It will be used in the following patches.
--- tools/perf/util/ordered-events.c | 23 +++++++++++++++++++---- tools/perf/util/ordered-events.h | 2 ++ 2 files changed, 21 insertions(+), 4 deletions(-)
tools/perf/util/ordered-events.c +19 -4
@@ -219,8 +219,7 @@ int ordered_events__queue(struct ordered_events *oe, union perf_event *event,return 0 ; } -static int __ordered_events__flush (struct ordered_events *oe, -bool show_progress) +static int do_flush (struct ordered_events *oe,bool show_progress) {struct list_head *head = &oe->events;struct ordered_event *tmp, *iter;
@@ -263,7 +262,8 @@ static int __ordered_events__flush(struct ordered_events *oe,return 0 ; } -int ordered_events__flush (struct ordered_events *oe,enum oe_flush how) +static int __ordered_events__flush (struct ordered_events *oe,enum oe_flush how, +u64 timestamp) {static const char *const str[] = {"NONE" ,
@@ -302,6 +302,11 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how)break ; } +case OE_FLUSH__TIME : + oe->next_flush = timestamp; + show_progress = false; +break ; +case OE_FLUSH__ROUND :case OE_FLUSH__NONE :default :
@@ -312,7 +317,7 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how) str[how], oe->nr_events);pr_oe_time (oe->max_timestamp,"max_timestamp\n" ); - err =__ordered_events__flush (oe, show_progress); + err =do_flush (oe, show_progress);if (!err) {if (how ==OE_FLUSH__ROUND )
@@ -328,6 +333,16 @@ int ordered_events__flush(struct ordered_events *oe, enum oe_flush how)return err; } +int ordered_events__flush (struct ordered_events *oe,enum oe_flush how) +{ +return __ordered_events__flush (oe, how,0 ); +} + +int ordered_events__flush_time (struct ordered_events *oe,u64 timestamp) +{ +return __ordered_events__flush (oe,OE_FLUSH__TIME , timestamp); +} +void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data) {
tools/perf/util/ordered-events.h +2 -0
@@ -19,6 +19,7 @@ enum oe_flush {OE_FLUSH__ROUND ,OE_FLUSH__HALF ,OE_FLUSH__TOP , + OE_FLUSH__TIME, };struct ordered_events ;
@@ -55,6 +56,7 @@ int ordered_events__queue(struct ordered_events *oe, union perf_event *event, u64 timestamp, u64 file_offset);void ordered_events__delete (struct ordered_events *oe,struct ordered_event *event);int ordered_events__flush (struct ordered_events *oe,enum oe_flush how); +int ordered_events__flush_time (struct ordered_events *oe,u64 timestamp);void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data);void ordered_events__free (struct ordered_events *oe);
Jiri Olsa
reviewerPATCH 7/8 perf trace: Move event delivery to deliver_event function
In reply to Jiri OlsaMoving event delivery code to deliver_event function, so it's easier to add conditional ordered delivery coming in following patches.
--- tools/perf/builtin-trace.c | 25 ++++++++++++++++--------- 1 file changed, 16 insertions(+), 9 deletions(-)
tools/perf/builtin-trace.c +16 -9
@@ -2641,6 +2641,21 @@ static int trace__set_filter_pids(struct trace *trace)return err; } +static int deliver_event (struct trace *trace,union perf_event *event) +{ +struct perf_evlist *evlist = trace->evlist; +struct perf_sample sample; +int err; + + err =perf_evlist__parse_sample (evlist, event, &sample); +if (err) +fprintf (trace->output,"Can't parse sample, err = %d, skipping...\n" , err); +else +trace__handle_event (trace, event, &sample); + +return 0 ; +} +static int trace__run (struct trace *trace,int argc,const char **argv) {struct perf_evlist *evlist = trace->evlist;
@@ -2806,18 +2821,10 @@ static int trace__run(struct trace *trace, int argc, const char **argv)continue ;while ((event =perf_mmap__read_event (md)) !=NULL ) { -struct perf_sample sample; - ++trace->nr_events; - err =perf_evlist__parse_sample (evlist, event, &sample); -if (err) { -fprintf (trace->output,"Can't parse sample, err = %d, skipping...\n" , err); - goto next_event; - } +deliver_event (trace, event); -trace__handle_event (trace, event, &sample); -next_event:perf_mmap__consume (md);if (interrupted)
Signature · 1 line
2.17.2
tip-bot for Jiri Olsa
merge bot[tip:perf/core] perf trace: Move event delivery to a new deliver_event() function
perf trace: Move event delivery to a new deliver_event() function
Commit-ID: b2595c9b1e5ad11db05c6767e6d00cd03d76c96e Gitweb: https://git.kernel.org/tip/b2595c9b1e5ad11db05c6767e6d00cd03d76c96e Author: Jiri Olsa <[email protected]> AuthorDate: Wed, 5 Dec 2018 17:05:08 +0100 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Thu, 6 Dec 2018 16:43:28 -0300
perf trace: Move event delivery to a new deliver_event() function
Mov event delivery code to a new trace__deliver_event() function, so it's easier to add ordered delivery coming in the following patches.
--- tools/perf/builtin-trace.c | 25 ++++++++++++++++--------- 1 file changed, 16 insertions(+), 9 deletions(-)
tools/perf/builtin-trace.c +16 -9
@@ -2637,6 +2637,21 @@ static int trace__set_filter_pids(struct trace *trace)return err; } +static int trace__deliver_event (struct trace *trace,union perf_event *event) +{ +struct perf_evlist *evlist = trace->evlist; +struct perf_sample sample; +int err; + + err =perf_evlist__parse_sample (evlist, event, &sample); +if (err) +fprintf (trace->output,"Can't parse sample, err = %d, skipping...\n" , err); +else +trace__handle_event (trace, event, &sample); + +return 0 ; +} +static int trace__run (struct trace *trace,int argc,const char **argv) {struct perf_evlist *evlist = trace->evlist;
@@ -2802,18 +2817,10 @@ again:continue ;while ((event =perf_mmap__read_event (md)) !=NULL ) { -struct perf_sample sample; - ++trace->nr_events; - err =perf_evlist__parse_sample (evlist, event, &sample); -if (err) { -fprintf (trace->output,"Can't parse sample, err = %d, skipping...\n" , err); - goto next_event; - } +trace__deliver_event (trace, event); -trace__handle_event (trace, event, &sample); -next_event:perf_mmap__consume (md);if (interrupted)
tip-bot for Jiri Olsa
merge bot[tip:perf/core] perf trace: Move event delivery to a new deliver_event() function
In reply to Jiri Olsaperf trace: Move event delivery to a new deliver_event() function
Commit-ID: 1f44b3e2fc5d7a2c5f6d1e67c80ebc226d6bd25f Gitweb: https://git.kernel.org/tip/1f44b3e2fc5d7a2c5f6d1e67c80ebc226d6bd25f Author: Jiri Olsa <[email protected]> AuthorDate: Wed, 5 Dec 2018 17:05:08 +0100 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 17 Dec 2018 15:02:17 -0300
perf trace: Move event delivery to a new deliver_event() function
Mov event delivery code to a new trace__deliver_event() function, so it's easier to add ordered delivery coming in the following patches.
--- tools/perf/builtin-trace.c | 25 ++++++++++++++++--------- 1 file changed, 16 insertions(+), 9 deletions(-)
tools/perf/builtin-trace.c +16 -9
@@ -2637,6 +2637,21 @@ static int trace__set_filter_pids(struct trace *trace)return err; } +static int trace__deliver_event (struct trace *trace,union perf_event *event) +{ +struct perf_evlist *evlist = trace->evlist; +struct perf_sample sample; +int err; + + err =perf_evlist__parse_sample (evlist, event, &sample); +if (err) +fprintf (trace->output,"Can't parse sample, err = %d, skipping...\n" , err); +else +trace__handle_event (trace, event, &sample); + +return 0 ; +} +static int trace__run (struct trace *trace,int argc,const char **argv) {struct perf_evlist *evlist = trace->evlist;
@@ -2802,18 +2817,10 @@ again:continue ;while ((event =perf_mmap__read_event (md)) !=NULL ) { -struct perf_sample sample; - ++trace->nr_events; - err =perf_evlist__parse_sample (evlist, event, &sample); -if (err) { -fprintf (trace->output,"Can't parse sample, err = %d, skipping...\n" , err); - goto next_event; - } +trace__deliver_event (trace, event); -trace__handle_event (trace, event, &sample); -next_event:perf_mmap__consume (md);if (interrupted)
Jiri Olsa
reviewerPATCH 8/8 perf trace: Add ordered processing for --block option
In reply to Jiri OlsaAdding support to sort the trace events if --block option is set. In this mode we don't loose events, and we are potentionally slow by definition, because the traced process could be blocked.
In this case it makes sense to sort events and provide the precise outcome of ordered events.
--- tools/perf/builtin-trace.c | 59 +++++++++++++++++++++++++++++++- tools/perf/util/ordered-events.c | 11 ++++++ tools/perf/util/ordered-events.h | 1 + 3 files changed, 70 insertions(+), 1 deletion(-)
tools/perf/builtin-trace.c +58 -1
@@ -127,6 +127,11 @@ struct trace {bool force;bool vfs_getname;int trace_pgfaults; + +struct { +struct ordered_events data; +u64 last; + } oe; };struct tp_field {
@@ -2656,6 +2661,43 @@ static int deliver_event(struct trace *trace, union perf_event *event)return 0 ; } + +static int flush_ordered_events (struct trace *trace) +{ +u64 first =ordered_events__first_time (&trace->oe.data); +u64 flush = trace->oe.last -NSEC_PER_SEC ; + +/* Is there some thing to flush.. */ +if (first && first < flush) +return ordered_events__flush_time (&trace->oe.data, flush); + +return 0 ; +} + +static int deliver_ordered_event (struct trace *trace,union perf_event *event) +{ +struct perf_evlist *evlist = trace->evlist; +int err; + + err =perf_evlist__parse_sample_timestamp (evlist, event, &trace->oe.last); +if (err && err !=-1 ) +return err; + + err =ordered_events__queue (&trace->oe.data, event, trace->oe.last,0 ); +if (err) +return err; + +return flush_ordered_events (trace); +} + +static int ordered_events__deliver_event (struct ordered_events *oe, +struct ordered_event *event) +{ + struct trace *trace = container_of(oe, struct trace, oe.data); + +return deliver_event (trace, event->event); +} +static int trace__run (struct trace *trace,int argc,const char **argv) {struct perf_evlist *evlist = trace->evlist;
@@ -2823,7 +2865,13 @@ static int trace__run(struct trace *trace, int argc, const char **argv)while ((event =perf_mmap__read_event (md)) !=NULL ) { ++trace->nr_events; -deliver_event (trace, event); +if (trace->opts.block) { + err =deliver_ordered_event (trace, event); +if (err) + goto out_disable; + }else { +deliver_event (trace, event); + }perf_mmap__consume (md);
@@ -2846,6 +2894,9 @@ static int trace__run(struct trace *trace, int argc, const char **argv) draining = true; goto again; + }else { +if (trace->opts.block &&flush_ordered_events (trace)) + goto out_disable; } }else { goto again;
@@ -2856,6 +2907,9 @@ static int trace__run(struct trace *trace, int argc, const char **argv)perf_evlist__disable (evlist); +if (trace->opts.block) +ordered_events__flush (&trace->oe.data,OE_FLUSH__FINAL ); +if (!err) {if (trace->summary)trace__fprintf_thread_summary (trace, trace->output);
@@ -3520,6 +3574,9 @@ int cmd_trace(int argc, const char **argv)pr_err ("ERROR: Can't use --block on non task targets\n" ); goto out; } + +ordered_events__init (&trace.oe.data, ordered_events__deliver_event, &trace); +ordered_events__set_copy_on_queue (&trace.oe.data, true); } evsel =bpf__setup_output_event (trace.evlist,"__augmented_syscalls__" );
tools/perf/util/ordered-events.c +11 -0
@@ -343,6 +343,17 @@ int ordered_events__flush_time(struct ordered_events *oe, u64 time)return __ordered_events__flush (oe,OE_FLUSH__TIME , time); } +u64 ordered_events__first_time (struct ordered_events *oe) +{ +struct ordered_event *event; + +if (list_empty (&oe->events)) +return 0 ; + + event = list_first_entry(&oe->events, struct ordered_event, list); +return event->timestamp; +} +void ordered_events__init (struct ordered_events *oe,ordered_events__deliver_t deliver,void *data) {
tools/perf/util/ordered-events.h +1 -0
@@ -61,6 +61,7 @@ void ordered_events__init(struct ordered_events *oe, ordered_events__deliver_t d void *data);void ordered_events__free (struct ordered_events *oe);void ordered_events__reinit (struct ordered_events *oe); +u64 ordered_events__first_time (struct ordered_events *oe);static inline void ordered_events__set_alloc_size (struct ordered_events *oe,u64 size)
Signature · 1 line
2.17.2
tip-bot for Jiri Olsa
merge bot[tip:perf/core] perf trace: Add ordered processing
perf trace: Add ordered processing
Commit-ID: 4085fed6373f15892959e3392efe5552504cfc94 Gitweb: https://git.kernel.org/tip/4085fed6373f15892959e3392efe5552504cfc94 Author: Jiri Olsa <[email protected]> AuthorDate: Wed, 5 Dec 2018 17:05:09 +0100 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Thu, 6 Dec 2018 16:43:28 -0300
perf trace: Add ordered processing
Sort events to provide the precise outcome of ordered events, just like is done with 'perf report' and 'perf top'.
--- tools/perf/builtin-trace.c | 52 +++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 51 insertions(+), 1 deletion(-)
tools/perf/builtin-trace.c +51 -1
@@ -127,6 +127,10 @@ struct trace {bool force;bool vfs_getname;int trace_pgfaults; +struct { +struct ordered_events data; +u64 last; + } oe; };struct tp_field {
@@ -2652,6 +2656,42 @@ static int trace__deliver_event(struct trace *trace, union perf_event *event)return 0 ; } +static int trace__flush_ordered_events (struct trace *trace) +{ +u64 first =ordered_events__first_time (&trace->oe.data); +u64 flush = trace->oe.last -NSEC_PER_SEC ; + +/* Is there some thing to flush.. */ +if (first && first < flush) +return ordered_events__flush_time (&trace->oe.data, flush); + +return 0 ; +} + +static int trace__deliver_ordered_event (struct trace *trace,union perf_event *event) +{ +struct perf_evlist *evlist = trace->evlist; +int err; + + err =perf_evlist__parse_sample_timestamp (evlist, event, &trace->oe.last); +if (err && err !=-1 ) +return err; + + err =ordered_events__queue (&trace->oe.data, event, trace->oe.last,0 ); +if (err) +return err; + +return trace__flush_ordered_events (trace); +} + +static int ordered_events__deliver_event (struct ordered_events *oe, +struct ordered_event *event) +{ + struct trace *trace = container_of(oe, struct trace, oe.data); + +return trace__deliver_event (trace, event->event); +} +static int trace__run (struct trace *trace,int argc,const char **argv) {struct perf_evlist *evlist = trace->evlist;
@@ -2819,7 +2859,9 @@ again:while ((event =perf_mmap__read_event (md)) !=NULL ) { ++trace->nr_events; -trace__deliver_event (trace, event); + err =trace__deliver_ordered_event (trace, event); +if (err) + goto out_disable;perf_mmap__consume (md);
@@ -2842,6 +2884,9 @@ again: draining = true; goto again; + }else { +if (trace__flush_ordered_events (trace)) + goto out_disable; } }else { goto again;
@@ -2852,6 +2897,8 @@ out_disable:perf_evlist__disable (evlist); +ordered_events__flush (&trace->oe.data,OE_FLUSH__FINAL ); +if (!err) {if (trace->summary)trace__fprintf_thread_summary (trace, trace->output);
@@ -3562,6 +3609,9 @@ int cmd_trace(int argc, const char **argv) } } +ordered_events__init (&trace.oe.data, ordered_events__deliver_event, &trace); +ordered_events__set_copy_on_queue (&trace.oe.data, true); +/* * If we are augmenting syscalls, then combine what we put in the * __augmented_syscalls__ BPF map with what is in the
tip-bot for Jiri Olsa
merge bot[tip:perf/core] perf trace: Add ordered processing
In reply to Jiri Olsaperf trace: Add ordered processing
Commit-ID: 028713aa8389d960cb1935a9954327bdaa163cf8 Gitweb: https://git.kernel.org/tip/028713aa8389d960cb1935a9954327bdaa163cf8 Author: Jiri Olsa <[email protected]> AuthorDate: Wed, 5 Dec 2018 17:05:09 +0100 Committer: Arnaldo Carvalho de Melo <[email protected]> CommitDate: Mon, 17 Dec 2018 15:21:17 -0300
perf trace: Add ordered processing
Sort events to provide the precise outcome of ordered events, just like is done with 'perf report' and 'perf top'.
--- tools/perf/builtin-trace.c | 52 +++++++++++++++++++++++++++++++++++++++++++++- 1 file changed, 51 insertions(+), 1 deletion(-)
tools/perf/builtin-trace.c +51 -1
@@ -127,6 +127,10 @@ struct trace {bool force;bool vfs_getname;int trace_pgfaults; +struct { +struct ordered_events data; +u64 last; + } oe; };struct tp_field {
@@ -2652,6 +2656,42 @@ static int trace__deliver_event(struct trace *trace, union perf_event *event)return 0 ; } +static int trace__flush_ordered_events (struct trace *trace) +{ +u64 first =ordered_events__first_time (&trace->oe.data); +u64 flush = trace->oe.last -NSEC_PER_SEC ; + +/* Is there some thing to flush.. */ +if (first && first < flush) +return ordered_events__flush_time (&trace->oe.data, flush); + +return 0 ; +} + +static int trace__deliver_ordered_event (struct trace *trace,union perf_event *event) +{ +struct perf_evlist *evlist = trace->evlist; +int err; + + err =perf_evlist__parse_sample_timestamp (evlist, event, &trace->oe.last); +if (err && err !=-1 ) +return err; + + err =ordered_events__queue (&trace->oe.data, event, trace->oe.last,0 ); +if (err) +return err; + +return trace__flush_ordered_events (trace); +} + +static int ordered_events__deliver_event (struct ordered_events *oe, +struct ordered_event *event) +{ + struct trace *trace = container_of(oe, struct trace, oe.data); + +return trace__deliver_event (trace, event->event); +} +static int trace__run (struct trace *trace,int argc,const char **argv) {struct perf_evlist *evlist = trace->evlist;
@@ -2819,7 +2859,9 @@ again:while ((event =perf_mmap__read_event (md)) !=NULL ) { ++trace->nr_events; -trace__deliver_event (trace, event); + err =trace__deliver_ordered_event (trace, event); +if (err) + goto out_disable;perf_mmap__consume (md);
@@ -2842,6 +2884,9 @@ again: draining = true; goto again; + }else { +if (trace__flush_ordered_events (trace)) + goto out_disable; } }else { goto again;
@@ -2852,6 +2897,8 @@ out_disable:perf_evlist__disable (evlist); +ordered_events__flush (&trace->oe.data,OE_FLUSH__FINAL ); +if (!err) {if (trace->summary)trace__fprintf_thread_summary (trace, trace->output);
@@ -3562,6 +3609,9 @@ int cmd_trace(int argc, const char **argv) } } +ordered_events__init (&trace.oe.data, ordered_events__deliver_event, &trace); +ordered_events__set_copy_on_queue (&trace.oe.data, true); +/* * If we are augmenting syscalls, then combine what we put in the * __augmented_syscalls__ BPF map with what is in the