bf5a8c26ad
Add a tracepoint for when a CSD is queued to a remote CPU's
call_single_queue. This allows finding exactly which CPU queued a given CSD
when looking at a csd_function_{entry,exit} event, and also enables us to
accurately measure IPI delivery time with e.g. a synthetic event:
$ echo 'hist:keys=cpu,csd.hex:ts=common_timestamp.usecs' >\
/sys/kernel/tracing/events/smp/csd_queue_cpu/trigger
$ echo 'csd_latency unsigned int dst_cpu; unsigned long csd; u64 time' >\
/sys/kernel/tracing/synthetic_events
$ echo \
'hist:keys=common_cpu,csd.hex:'\
'time=common_timestamp.usecs-$ts:'\
'onmatch(smp.csd_queue_cpu).trace(csd_latency,common_cpu,csd,$time)' >\
/sys/kernel/tracing/events/smp/csd_function_entry/trigger
$ trace-cmd record -e 'synthetic:csd_latency' hackbench
$ trace-cmd report
<...>-467 [001] 21.824263: csd_queue_cpu: cpu=0 callsite=try_to_wake_up+0x2ea func=sched_ttwu_pending csd=0xffff8880076148b8
<...>-467 [001] 21.824280: ipi_send_cpu: cpu=0 callsite=try_to_wake_up+0x2ea callback=generic_smp_call_function_single_interrupt+0x0
<...>-489 [000] 21.824299: csd_function_entry: func=sched_ttwu_pending csd=0xffff8880076148b8
<...>-489 [000] 21.824320: csd_latency: dst_cpu=0, csd=18446612682193848504, time=36
Suggested-by: Valentin Schneider <vschneid@redhat.com>
Signed-off-by: Leonardo Bras <leobras@redhat.com>
Tested-and-reviewed-by: Valentin Schneider <vschneid@redhat.com>
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Link: https://lore.kernel.org/r/20230615065944.188876-7-leobras@redhat.com
73 lines
1.5 KiB
C
73 lines
1.5 KiB
C
/* SPDX-License-Identifier: GPL-2.0 */
|
|
#undef TRACE_SYSTEM
|
|
#define TRACE_SYSTEM csd
|
|
|
|
#if !defined(_TRACE_CSD_H) || defined(TRACE_HEADER_MULTI_READ)
|
|
#define _TRACE_CSD_H
|
|
|
|
#include <linux/tracepoint.h>
|
|
|
|
TRACE_EVENT(csd_queue_cpu,
|
|
|
|
TP_PROTO(const unsigned int cpu,
|
|
unsigned long callsite,
|
|
smp_call_func_t func,
|
|
struct __call_single_data *csd),
|
|
|
|
TP_ARGS(cpu, callsite, func, csd),
|
|
|
|
TP_STRUCT__entry(
|
|
__field(unsigned int, cpu)
|
|
__field(void *, callsite)
|
|
__field(void *, func)
|
|
__field(void *, csd)
|
|
),
|
|
|
|
TP_fast_assign(
|
|
__entry->cpu = cpu;
|
|
__entry->callsite = (void *)callsite;
|
|
__entry->func = func;
|
|
__entry->csd = csd;
|
|
),
|
|
|
|
TP_printk("cpu=%u callsite=%pS func=%ps csd=%p",
|
|
__entry->cpu, __entry->callsite, __entry->func, __entry->csd)
|
|
);
|
|
|
|
/*
|
|
* Tracepoints for a function which is called as an effect of smp_call_function.*
|
|
*/
|
|
DECLARE_EVENT_CLASS(csd_function,
|
|
|
|
TP_PROTO(smp_call_func_t func, struct __call_single_data *csd),
|
|
|
|
TP_ARGS(func, csd),
|
|
|
|
TP_STRUCT__entry(
|
|
__field(void *, func)
|
|
__field(void *, csd)
|
|
),
|
|
|
|
TP_fast_assign(
|
|
__entry->func = func;
|
|
__entry->csd = csd;
|
|
),
|
|
|
|
TP_printk("func=%ps, csd=%p", __entry->func, __entry->csd)
|
|
);
|
|
|
|
DEFINE_EVENT(csd_function, csd_function_entry,
|
|
TP_PROTO(smp_call_func_t func, struct __call_single_data *csd),
|
|
TP_ARGS(func, csd)
|
|
);
|
|
|
|
DEFINE_EVENT(csd_function, csd_function_exit,
|
|
TP_PROTO(smp_call_func_t func, struct __call_single_data *csd),
|
|
TP_ARGS(func, csd)
|
|
);
|
|
|
|
#endif /* _TRACE_CSD_H */
|
|
|
|
/* This part must be outside protection */
|
|
#include <trace/define_trace.h>
|