- 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 <[email protected]> --- 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 [email protected] https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev
