Merged, big thanks ! Julien
On 23-Aug-2016 07:37:01 PM, Mathieu Desnoyers wrote: > - 3 sizeof() issues (using pointer size rather than object size), > - state tracking merge issue on switch in: the get following the > insertion may not get the same node when there are duplicates, > - also features a refactoring of keys: add a "p" parent field for the > type. > - PID 0 needs to be compared with its cpu ID too. > > Signed-off-by: Mathieu Desnoyers <mathieu.desnoy...@efficios.com> > --- > examples/rt.c | 164 > +++++++++++++++++++++++++++++++----------------------- > latency_tracker.h | 7 +++ > tracker.c | 20 ++++++- > 3 files changed, 120 insertions(+), 71 deletions(-) > > diff --git a/examples/rt.c b/examples/rt.c > index f9703ca..7b3b2b3 100644 > --- a/examples/rt.c > +++ b/examples/rt.c > @@ -139,53 +139,59 @@ enum event_out_types { > OUT_NO_CB = 4, > }; > > +struct generic_key_t { > + enum rt_key_type type; > +} __attribute__((__packed__)); > + > struct do_irq_key_t { > + struct generic_key_t p; > unsigned int cpu; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct local_timer_key_t { > + struct generic_key_t p; > unsigned int cpu; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct hrtimer_key_t { > + struct generic_key_t p; > unsigned int cpu; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct hardirq_key_t { > + struct generic_key_t p; > unsigned int cpu; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct raise_softirq_key_t { > + struct generic_key_t p; > unsigned int cpu; > unsigned int vector; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct softirq_key_t { > + struct generic_key_t p; > unsigned int cpu; > int pid; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct waking_key_t { > + struct generic_key_t p; > + int cpu; > int pid; > - enum rt_key_type type; > } __attribute__((__packed__)); > > struct switch_key_t { > + struct generic_key_t p; > + int cpu; > int pid; > - enum rt_key_type type; > } __attribute__((__packed__)); > > #define MAX_COOKIE_SIZE 32 > struct work_begin_key_t { > + struct generic_key_t p; > char cookie[MAX_COOKIE_SIZE]; > int cookie_size; > - enum rt_key_type type; > } __attribute__((__packed__)); > > /* Keep up-to-date with a list of all key structs. */ > @@ -445,6 +451,7 @@ static > int entry_do_irq(struct kretprobe_instance *p, struct pt_regs *regs) > { > enum latency_tracker_event_in_ret ret; > + struct latency_tracker_event *s; > struct do_irq_key_t key; > u64 now; > > @@ -452,26 +459,20 @@ int entry_do_irq(struct kretprobe_instance *p, struct > pt_regs *regs) > return 0; > > now = trace_clock_monotonic_wrapper(); > + key.p.type = KEY_DO_IRQ; > key.cpu = smp_processor_id(); > - key.type = KEY_DO_IRQ; > - ret = _latency_tracker_event_in(tracker, &key, sizeof(key), 1, now, > - NULL); > + ret = _latency_tracker_event_in_get(tracker, &key, sizeof(key), 1, now, > + NULL, &s); > if (ret != LATENCY_TRACKER_OK) { > failed_event_in++; > return 0; > } > + WARN_ON_ONCE(!s); > > if (config.text_breakdown) { > - struct latency_tracker_event *s; > - > - s = latency_tracker_get_event(tracker, &key, sizeof(key)); > - if (!s) { > - BUG_ON(1); > - return 0; > - } > append_delta_ts(s, KEY_DO_IRQ, "do_IRQ", now, 0, NULL, 0); > - latency_tracker_put_event(s); > } > + latency_tracker_put_event(s); > > #ifdef DEBUG > printk("%llu do_IRQ (cpu %u)\n", trace_clock_monotonic_wrapper(), > @@ -488,8 +489,8 @@ int exit_do_irq(struct kretprobe_instance *p, struct > pt_regs *regs) > > if (!config.irq_tracing) > return 0; > + key.p.type = KEY_DO_IRQ; > key.cpu = smp_processor_id(); > - key.type = KEY_DO_IRQ; > latency_tracker_event_out(tracker, &key, > sizeof(key), OUT_IRQHANDLER_NO_CB, 0); > > @@ -618,15 +619,13 @@ struct latency_tracker_event *event_transition(void > *key_in, int key_in_len, > } > orig_ts = latency_tracker_event_get_start_ts(event_in); > > - ret = _latency_tracker_event_in(tracker, key_out, > - key_out_len, unique, orig_ts, NULL); > + ret = _latency_tracker_event_in_get(tracker, key_out, > + key_out_len, unique, orig_ts, NULL, &event_out); > if (ret != LATENCY_TRACKER_OK) { > - goto end_del; > failed_event_in++; > - } > - event_out = latency_tracker_get_event(tracker, key_out, key_out_len); > - if (!event_out) > goto end_del; > + } > + WARN_ON_ONCE(!event_out); > data_out = (struct event_data *) > latency_tracker_event_get_priv_data(event_out); > if (!data_out) { > BUG_ON(1); > @@ -679,6 +678,7 @@ out: > LT_PROBE_DEFINE(local_timer_entry, int vector) > { > enum latency_tracker_event_in_ret ret; > + struct latency_tracker_event *s; > struct local_timer_key_t key; > u64 now; > > @@ -686,26 +686,20 @@ LT_PROBE_DEFINE(local_timer_entry, int vector) > goto end; > > now = trace_clock_monotonic_wrapper(); > + key.p.type = KEY_TIMER_INTERRUPT; > key.cpu = smp_processor_id(); > - key.type = KEY_TIMER_INTERRUPT; > - ret = _latency_tracker_event_in(tracker, &key, sizeof(key), 1, now, > - NULL); > + ret = _latency_tracker_event_in_get(tracker, &key, sizeof(key), 1, now, > + NULL, &s); > if (ret != LATENCY_TRACKER_OK) { > failed_event_in++; > goto end; > } > - > + WARN_ON_ONCE(!s); > if (config.text_breakdown) { > - struct latency_tracker_event *s; > - s = latency_tracker_get_event(tracker, &key, sizeof(key)); > - if (!s) { > - BUG_ON(1); > - goto end; > - } > append_delta_ts(s, KEY_TIMER_INTERRUPT, "local_timer_entry", > now, > vector, NULL, 0); > - latency_tracker_put_event(s); > } > + latency_tracker_put_event(s); > > #ifdef DEBUG > printk("%llu local_timer_entry (cpu %u)\n", > trace_clock_monotonic_wrapper(), > @@ -722,8 +716,8 @@ LT_PROBE_DEFINE(local_timer_exit, int vector) > > if (!config.timer_tracing) > goto end; > + local_timer_key.p.type = KEY_TIMER_INTERRUPT; > local_timer_key.cpu = smp_processor_id(); > - local_timer_key.type = KEY_TIMER_INTERRUPT; > latency_tracker_event_out(tracker, &local_timer_key, > sizeof(local_timer_key), OUT_IRQHANDLER_NO_CB, 0); > end: > @@ -743,11 +737,11 @@ LT_PROBE_DEFINE(irq_handler_entry, int irq, struct > irqaction *action) > goto end; > } > > + do_irq_key.p.type = KEY_DO_IRQ; > do_irq_key.cpu = smp_processor_id(); > - do_irq_key.type = KEY_DO_IRQ; > > + hardirq_key.p.type = KEY_HARDIRQ; > hardirq_key.cpu = smp_processor_id(); > - hardirq_key.type = KEY_HARDIRQ; > > s = event_transition(&do_irq_key, sizeof(do_irq_key), &hardirq_key, > sizeof(hardirq_key), 0, 1, 0); > @@ -777,8 +771,8 @@ LT_PROBE_DEFINE(irq_handler_exit, int irq, struct > irqaction *action, > goto end; > } > > + hardirq_key.p.type = KEY_HARDIRQ; > hardirq_key.cpu = smp_processor_id(); > - hardirq_key.type = KEY_HARDIRQ; > > if (config.text_breakdown) { > struct latency_tracker_event *s; > @@ -809,12 +803,16 @@ LT_PROBE_DEFINE(softirq_raise, unsigned int vec_nr) > if (config.softirq_filter > 0 && config.softirq_filter != vec_nr) > goto end; > > + switch_key.p.type = KEY_SWITCH; > switch_key.pid = current->pid; > - switch_key.type = KEY_SWITCH; > + if (!current->pid) > + switch_key.cpu = smp_processor_id(); > + else > + switch_key.cpu = -1; > > + raise_softirq_key.p.type = KEY_RAISE_SOFTIRQ; > raise_softirq_key.cpu = smp_processor_id(); > raise_softirq_key.vector = vec_nr; > - raise_softirq_key.type = KEY_RAISE_SOFTIRQ; > > s = event_transition(&switch_key, sizeof(switch_key), > &raise_softirq_key, sizeof(raise_softirq_key), 0, 0, 1); > @@ -841,12 +839,12 @@ LT_PROBE_DEFINE(softirq_raise, unsigned int vec_nr) > if (config.softirq_filter > 0 && config.softirq_filter != vec_nr) > goto end; > > + hardirq_key.p.type = KEY_HARDIRQ; > hardirq_key.cpu = smp_processor_id(); > - hardirq_key.type = KEY_HARDIRQ; > > + raise_softirq_key.p.type = KEY_RAISE_SOFTIRQ; > raise_softirq_key.cpu = smp_processor_id(); > raise_softirq_key.vector = vec_nr; > - raise_softirq_key.type = KEY_RAISE_SOFTIRQ; > > s = event_transition(&hardirq_key, sizeof(hardirq_key), > &raise_softirq_key, sizeof(raise_softirq_key), 0, 0, 1); > @@ -874,17 +872,17 @@ LT_PROBE_DEFINE(softirq_entry, unsigned int vec_nr) > if (config.softirq_filter > 0 && config.softirq_filter != vec_nr) > goto end; > > + raise_softirq_key.p.type = KEY_RAISE_SOFTIRQ; > raise_softirq_key.cpu = smp_processor_id(); > raise_softirq_key.vector = vec_nr; > - raise_softirq_key.type = KEY_RAISE_SOFTIRQ; > > /* > * Insert the softirq_entry event. > * TODO: Use the CPU as key on non-RT kernel and PID on PREEMPT_RT. > */ > + softirq_key.p.type = KEY_SOFTIRQ; > softirq_key.cpu = smp_processor_id(); > softirq_key.pid = current->pid; > - softirq_key.type = KEY_SOFTIRQ; > > do { > s = event_transition(&raise_softirq_key, > sizeof(raise_softirq_key), > @@ -912,15 +910,15 @@ LT_PROBE_DEFINE(hrtimer_expire_entry, struct hrtimer > *hrtimer, > > if (!config.timer_tracing) > goto end; > + local_timer_key.p.type = KEY_TIMER_INTERRUPT; > local_timer_key.cpu = smp_processor_id(); > - local_timer_key.type = KEY_TIMER_INTERRUPT; > > /* > * Insert the hrtimer_expire_entry event. > * TODO: Use the CPU as key on non-RT kernel and PID on PREEMPT_RT. > */ > + hrtimer_key.p.type = KEY_HRTIMER; > hrtimer_key.cpu = smp_processor_id(); > - hrtimer_key.type = KEY_HRTIMER; > > s = event_transition(&local_timer_key, sizeof(local_timer_key), > &hrtimer_key, sizeof(hrtimer_key), 0, 1, 0); > @@ -943,15 +941,15 @@ LT_PROBE_DEFINE(hrtimer_expire_exit, struct timer_list > *timer) > > if (!config.timer_tracing) > goto end; > + hrtimer_key.p.type = KEY_HRTIMER; > hrtimer_key.cpu = smp_processor_id(); > - hrtimer_key.type = KEY_HRTIMER; > > /* > * Insert the hrtimer_expire_entry event. > * TODO: Use the CPU as key on non-RT kernel and PID on PREEMPT_RT. > */ > + hrtimer_key.p.type = KEY_HRTIMER; > hrtimer_key.cpu = smp_processor_id(); > - hrtimer_key.type = KEY_HRTIMER; > > latency_tracker_event_out(tracker, &hrtimer_key, sizeof(hrtimer_key), > OUT_IRQHANDLER_NO_CB, 0); > @@ -970,9 +968,9 @@ LT_PROBE_DEFINE(softirq_exit, unsigned int vec_nr) > /* > * Just cleanup the softirq_entry event > */ > + softirq_key.p.type = KEY_SOFTIRQ; > softirq_key.cpu = smp_processor_id(); > softirq_key.pid = current->pid; > - softirq_key.type = KEY_SOFTIRQ; > if (config.text_breakdown) { > struct latency_tracker_event *s; > > @@ -996,11 +994,11 @@ void irq_waking(struct waking_key_t *waking_key) > struct latency_tracker_event *s; > struct do_irq_key_t do_irq_key; > > + do_irq_key.p.type = KEY_DO_IRQ; > do_irq_key.cpu = smp_processor_id(); > - do_irq_key.type = KEY_DO_IRQ; > > s = event_transition(&do_irq_key, sizeof(do_irq_key), > - waking_key, sizeof(waking_key), 0, 0, 1); > + waking_key, sizeof(*waking_key), 0, 0, 1); > if (!s) > return; > append_delta_ts(s, KEY_WAKEUP, "to sched_waking", 0, waking_key->pid, > @@ -1018,12 +1016,12 @@ void softirq_waking(struct waking_key_t *waking_key) > struct softirq_key_t softirq_key; > struct latency_tracker_event *s; > > + softirq_key.p.type = KEY_SOFTIRQ; > softirq_key.cpu = smp_processor_id(); > softirq_key.pid = current->pid; > - softirq_key.type = KEY_SOFTIRQ; > > s = event_transition(&softirq_key, sizeof(softirq_key), > - waking_key, sizeof(waking_key), 0, 0, 1); > + waking_key, sizeof(*waking_key), 0, 0, 1); > if (!s) > return; > append_delta_ts(s, KEY_WAKEUP, "to sched_waking", 0, waking_key->pid, > @@ -1045,10 +1043,10 @@ int hrtimer_waking(struct waking_key_t *waking_key) > struct latency_tracker_event *s; > > /* TODO: PREEMPT_RT */ > + hrtimer_key.p.type = KEY_HRTIMER; > hrtimer_key.cpu = smp_processor_id(); > - hrtimer_key.type = KEY_HRTIMER; > s = event_transition(&hrtimer_key, sizeof(hrtimer_key), > - waking_key, sizeof(waking_key), 0, 0, 1); > + waking_key, sizeof(*waking_key), 0, 0, 1); > if (!s) > return 0; > append_delta_ts(s, KEY_WAKEUP, "to sched_waking", 0, waking_key->pid, > @@ -1069,11 +1067,15 @@ void thread_waking(struct waking_key_t *waking_key) > struct latency_tracker_event *s; > u64 now = trace_clock_monotonic_wrapper(); > > + switch_key.p.type = KEY_SWITCH; > switch_key.pid = current->pid; > - switch_key.type = KEY_SWITCH; > + if (!current->pid) > + switch_key.cpu = smp_processor_id(); > + else > + switch_key.cpu = -1; > > s = event_transition(&switch_key, sizeof(switch_key), waking_key, > - sizeof(waking_key), 0, 0, 1); > + sizeof(*waking_key), 0, 0, 1); > if (s) { > /* switch_in after a waking */ > append_delta_ts(s, KEY_WAKEUP, "to sched_waking", now, > @@ -1118,8 +1120,12 @@ LT_PROBE_DEFINE(sched_waking, struct task_struct *p, > int success) > * target process. > */ > > + waking_key.p.type = KEY_WAKEUP; > waking_key.pid = p->pid; > - waking_key.type = KEY_WAKEUP; > + if (!p->pid) > + waking_key.cpu = smp_processor_id(); > + else > + waking_key.cpu = -1; > > /* In order of nesting */ > if (in_nmi()) { > @@ -1158,14 +1164,22 @@ void sched_switch_in(struct task_struct *next) > int nr_found = 0, ret; > u64 now = trace_clock_monotonic_wrapper(); > > + switch_key.p.type = KEY_SWITCH; > switch_key.pid = next->pid; > - switch_key.type = KEY_SWITCH; > + if (!next->pid) > + switch_key.cpu = smp_processor_id(); > + else > + switch_key.cpu = -1; > > /* We can switch from a wakeup/waking or after being preempted */ > > /* sched in */ > + waking_key.p.type = KEY_WAKEUP; > waking_key.pid = next->pid; > - waking_key.type = KEY_WAKEUP; > + if (!next->pid) > + waking_key.cpu = smp_processor_id(); > + else > + waking_key.cpu = -1; > > /* switch after one or multiple waking */ > do { > @@ -1226,8 +1240,12 @@ void sched_switch_out(struct task_struct *prev, struct > task_struct *next) > u64 now = trace_clock_monotonic_wrapper(); > > /* switch out */ > + switch_key.p.type = KEY_SWITCH; > switch_key.pid = prev->pid; > - switch_key.type = KEY_SWITCH; > + if (!prev->pid) > + switch_key.cpu = smp_processor_id(); > + else > + switch_key.cpu = -1; > /* Handle duplicates */ > for (;;) { > if (config.text_breakdown) { > @@ -1385,8 +1403,12 @@ ssize_t write_work_done(struct file *filp, const char > __user *ubuf, > * The current process should be tracked otherwise we can't > * link this event to an origin. > */ > + switch_key.p.type = KEY_SWITCH; > switch_key.pid = current->pid; > - switch_key.type = KEY_SWITCH; > + if (!current->pid) > + switch_key.cpu = smp_processor_id(); > + else > + switch_key.cpu = -1; > s = latency_tracker_get_event(tracker, &switch_key, > sizeof(switch_key)); > if (!s) > @@ -1398,8 +1420,8 @@ ssize_t write_work_done(struct file *filp, const char > __user *ubuf, > sizeof(switch_key), > OUT_WORK_DONE, now); > } else { > + work_begin_key.p.type = KEY_WORK_BEGIN; > work_begin_key.cookie_size = r; > - work_begin_key.type = KEY_WORK_BEGIN; > > s = latency_tracker_get_event(tracker, &work_begin_key, > sizeof(work_begin_key)); > @@ -1469,11 +1491,15 @@ ssize_t write_work_begin(struct file *filp, const > char __user *ubuf, > * The current process should be tracked otherwise we can't link > * this event to an origin. > */ > + switch_key.p.type = KEY_SWITCH; > switch_key.pid = current->pid; > - switch_key.type = KEY_SWITCH; > + if (!current->pid) > + switch_key.cpu = smp_processor_id(); > + else > + switch_key.cpu = -1; > > + work_begin_key.p.type = KEY_WORK_BEGIN; > work_begin_key.cookie_size = r; > - work_begin_key.type = KEY_WORK_BEGIN; > > /* > * From now on, only a work_done event can complete this branch. > diff --git a/latency_tracker.h b/latency_tracker.h > index 0bccb8d..c276b1a 100644 > --- a/latency_tracker.h > +++ b/latency_tracker.h > @@ -32,6 +32,7 @@ > #define DEFAULT_THRESHOLD 1000000000 > > struct latency_tracker_event_ctx; > +struct latency_tracker_event; > > struct latency_tracker_key { > size_t key_len; > @@ -216,6 +217,12 @@ enum latency_tracker_event_in_ret > latency_tracker_event_in( > void *key, size_t key_len, > unsigned int unique, void *priv); > > +enum latency_tracker_event_in_ret _latency_tracker_event_in_get( > + struct latency_tracker *tracker, > + void *key, size_t key_len, > + unsigned int unique, u64 ts_override, > + void *priv, struct latency_tracker_event **new_event); > + > enum latency_tracker_event_in_ret _latency_tracker_event_in( > struct latency_tracker *tracker, > void *key, size_t key_len, unsigned int unique, > diff --git a/tracker.c b/tracker.c > index 1c502e1..b3deba6 100644 > --- a/tracker.c > +++ b/tracker.c > @@ -550,11 +550,11 @@ void latency_tracker_timeout_cb(struct latency_tracker > *tracker, > tracker->cb(&ctx); > } > > -enum latency_tracker_event_in_ret _latency_tracker_event_in( > +enum latency_tracker_event_in_ret _latency_tracker_event_in_get( > struct latency_tracker *tracker, > void *key, size_t key_len, > unsigned int unique, u64 ts_override, > - void *priv) > + void *priv, struct latency_tracker_event **new_event) > { > struct latency_tracker_event *s, *old_s; > int ret; > @@ -618,6 +618,10 @@ enum latency_tracker_event_in_ret > _latency_tracker_event_in( > &tracker->timeout_tail, &s->u.timeout_node); > } > > + if (new_event) { > + kref_get(&s->refcount); > + *new_event = s; > + } > /* > * If we specify the unique property, get rid of other duplicate keys > * without calling the callback. > @@ -653,6 +657,18 @@ end: > #endif > return ret; > } > +EXPORT_SYMBOL_GPL(_latency_tracker_event_in_get); > + > +enum latency_tracker_event_in_ret _latency_tracker_event_in( > + struct latency_tracker *tracker, > + void *key, size_t key_len, > + unsigned int unique, u64 ts_override, > + void *priv) > +{ > + return _latency_tracker_event_in_get(tracker, > + key, key_len, unique, ts_override, > + priv, NULL); > +} > EXPORT_SYMBOL_GPL(_latency_tracker_event_in); > > enum latency_tracker_event_in_ret latency_tracker_event_in( > -- > 2.1.4 > _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev