[v4] sched_ext: Add trace point to sched_ext core events

[PATCH v4 2/2] sched_ext: Add trace point to track sched_ext core events

Posted by Changwoo Min 11 months, 1 week ago

Add tracing support to track sched_ext core events
(/sched_ext/sched_ext_event). This may be useful for debugging sched_ext
schedulers that trigger a particular event.

The trace point can be used as other trace points, so it can be used in,
for example, `perf trace` and BPF programs, as follows:

======
$> sudo perf trace -e sched_ext:sched_ext_event --filter 'name == "SCX_EV_ENQ_SLICE_DFL"'
======

======
struct tp_sched_ext_event {
	struct trace_entry ent;
	u32 __data_loc_name;
	s64 delta;
};

SEC("tracepoint/sched_ext/sched_ext_event")
int rtp_add_event(struct tp_sched_ext_event *ctx)
{
	char event_name[128];
	unsigned short offset = ctx->__data_loc_name & 0xFFFF;
        bpf_probe_read_str((void *)event_name, 128, (char *)ctx + offset);

	bpf_printk("name %s   delta %lld", event_name, ctx->delta);
	return 0;
}
======

Signed-off-by: Changwoo Min <changwoo@igalia.com>
---
 include/trace/events/sched_ext.h | 19 +++++++++++++++++++
 kernel/sched/ext.c               |  2 ++
 2 files changed, 21 insertions(+)

diff --git a/include/trace/events/sched_ext.h b/include/trace/events/sched_ext.h
index fe19da7315a9..50e4b712735a 100644
--- a/include/trace/events/sched_ext.h
+++ b/include/trace/events/sched_ext.h
@@ -26,6 +26,25 @@ TRACE_EVENT(sched_ext_dump,
 	)
 );
 
+TRACE_EVENT(sched_ext_event,
+	    TP_PROTO(const char *name, __s64 delta),
+	    TP_ARGS(name, delta),
+
+	TP_STRUCT__entry(
+		__string(name, name)
+		__field(	__s64,		delta		)
+	),
+
+	TP_fast_assign(
+		__assign_str(name);
+		__entry->delta		= delta;
+	),
+
+	TP_printk("name %s delta %lld",
+		  __get_str(name), __entry->delta
+	)
+);
+
 #endif /* _TRACE_SCHED_EXT_H */
 
 /* This part must be outside protection */
diff --git a/kernel/sched/ext.c b/kernel/sched/ext.c
index 686629a860f3..debcd1cf2de9 100644
--- a/kernel/sched/ext.c
+++ b/kernel/sched/ext.c
@@ -1554,6 +1554,7 @@ static DEFINE_PER_CPU(struct scx_event_stats, event_stats_cpu);
  */
 #define scx_add_event(name, cnt) do {						\
 	this_cpu_add(event_stats_cpu.name, cnt);				\
+	trace_sched_ext_event(#name, cnt);					\
 } while(0)
 
 /**
@@ -1565,6 +1566,7 @@ static DEFINE_PER_CPU(struct scx_event_stats, event_stats_cpu);
  */
 #define __scx_add_event(name, cnt) do {						\
 	__this_cpu_add(event_stats_cpu.name, cnt);				\
+	trace_sched_ext_event(#name, cnt);					\
 } while(0)
 
 /**
-- 
2.48.1

Re: [PATCH v4 2/2] sched_ext: Add trace point to track sched_ext core events

Posted by Andrea Righi 11 months, 1 week ago

On Tue, Mar 04, 2025 at 07:49:00PM +0900, Changwoo Min wrote:
> Add tracing support to track sched_ext core events
> (/sched_ext/sched_ext_event). This may be useful for debugging sched_ext
> schedulers that trigger a particular event.
> 
> The trace point can be used as other trace points, so it can be used in,
> for example, `perf trace` and BPF programs, as follows:
> 
> ======
> $> sudo perf trace -e sched_ext:sched_ext_event --filter 'name == "SCX_EV_ENQ_SLICE_DFL"'
> ======
> 
> ======
> struct tp_sched_ext_event {
> 	struct trace_entry ent;
> 	u32 __data_loc_name;
> 	s64 delta;
> };
> 
> SEC("tracepoint/sched_ext/sched_ext_event")
> int rtp_add_event(struct tp_sched_ext_event *ctx)
> {
> 	char event_name[128];
> 	unsigned short offset = ctx->__data_loc_name & 0xFFFF;
>         bpf_probe_read_str((void *)event_name, 128, (char *)ctx + offset);
> 
> 	bpf_printk("name %s   delta %lld", event_name, ctx->delta);
> 	return 0;
> }
> ======
> 
> Signed-off-by: Changwoo Min <changwoo@igalia.com>
> ---
>  include/trace/events/sched_ext.h | 19 +++++++++++++++++++
>  kernel/sched/ext.c               |  2 ++
>  2 files changed, 21 insertions(+)
> 
> diff --git a/include/trace/events/sched_ext.h b/include/trace/events/sched_ext.h
> index fe19da7315a9..50e4b712735a 100644
> --- a/include/trace/events/sched_ext.h
> +++ b/include/trace/events/sched_ext.h
> @@ -26,6 +26,25 @@ TRACE_EVENT(sched_ext_dump,
>  	)
>  );
>  
> +TRACE_EVENT(sched_ext_event,
> +	    TP_PROTO(const char *name, __s64 delta),
> +	    TP_ARGS(name, delta),
> +
> +	TP_STRUCT__entry(
> +		__string(name, name)
> +		__field(	__s64,		delta		)

nit: there's an extra space/tab after delta.

But apart than that LGTM.

Acked-by: Andrea Righi <arighi@nvidia.com>

-Andrea

> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(name);
> +		__entry->delta		= delta;
> +	),
> +
> +	TP_printk("name %s delta %lld",
> +		  __get_str(name), __entry->delta
> +	)
> +);
> +
>  #endif /* _TRACE_SCHED_EXT_H */
>  
>  /* This part must be outside protection */
> diff --git a/kernel/sched/ext.c b/kernel/sched/ext.c
> index 686629a860f3..debcd1cf2de9 100644
> --- a/kernel/sched/ext.c
> +++ b/kernel/sched/ext.c
> @@ -1554,6 +1554,7 @@ static DEFINE_PER_CPU(struct scx_event_stats, event_stats_cpu);
>   */
>  #define scx_add_event(name, cnt) do {						\
>  	this_cpu_add(event_stats_cpu.name, cnt);				\
> +	trace_sched_ext_event(#name, cnt);					\
>  } while(0)
>  
>  /**
> @@ -1565,6 +1566,7 @@ static DEFINE_PER_CPU(struct scx_event_stats, event_stats_cpu);
>   */
>  #define __scx_add_event(name, cnt) do {						\
>  	__this_cpu_add(event_stats_cpu.name, cnt);				\
> +	trace_sched_ext_event(#name, cnt);					\
>  } while(0)
>  
>  /**
> -- 
> 2.48.1
>

Re: [PATCH v4 2/2] sched_ext: Add trace point to track sched_ext core events

Posted by Tejun Heo 11 months, 1 week ago

On Tue, Mar 04, 2025 at 01:20:17PM +0100, Andrea Righi wrote:
> On Tue, Mar 04, 2025 at 07:49:00PM +0900, Changwoo Min wrote:
> > Add tracing support to track sched_ext core events
> > (/sched_ext/sched_ext_event). This may be useful for debugging sched_ext
> > schedulers that trigger a particular event.
> > 
> > The trace point can be used as other trace points, so it can be used in,
> > for example, `perf trace` and BPF programs, as follows:
> > 
> > ======
> > $> sudo perf trace -e sched_ext:sched_ext_event --filter 'name == "SCX_EV_ENQ_SLICE_DFL"'
> > ======
> > 
> > ======
> > struct tp_sched_ext_event {
> > 	struct trace_entry ent;
> > 	u32 __data_loc_name;
> > 	s64 delta;
> > };
> > 
> > SEC("tracepoint/sched_ext/sched_ext_event")
> > int rtp_add_event(struct tp_sched_ext_event *ctx)
> > {
> > 	char event_name[128];
> > 	unsigned short offset = ctx->__data_loc_name & 0xFFFF;
> >         bpf_probe_read_str((void *)event_name, 128, (char *)ctx + offset);
> > 
> > 	bpf_printk("name %s   delta %lld", event_name, ctx->delta);
> > 	return 0;
> > }
> > ======
> > 
> > Signed-off-by: Changwoo Min <changwoo@igalia.com>
> > ---
> >  include/trace/events/sched_ext.h | 19 +++++++++++++++++++
> >  kernel/sched/ext.c               |  2 ++
> >  2 files changed, 21 insertions(+)
> > 
> > diff --git a/include/trace/events/sched_ext.h b/include/trace/events/sched_ext.h
> > index fe19da7315a9..50e4b712735a 100644
> > --- a/include/trace/events/sched_ext.h
> > +++ b/include/trace/events/sched_ext.h
> > @@ -26,6 +26,25 @@ TRACE_EVENT(sched_ext_dump,
> >  	)
> >  );
> >  
> > +TRACE_EVENT(sched_ext_event,
> > +	    TP_PROTO(const char *name, __s64 delta),
> > +	    TP_ARGS(name, delta),
> > +
> > +	TP_STRUCT__entry(
> > +		__string(name, name)
> > +		__field(	__s64,		delta		)
> 
> nit: there's an extra space/tab after delta.

I think it's one of common formatting styles for tp definitions. If we don't
like it, we can just them in the future.

> But apart than that LGTM.
> 
> Acked-by: Andrea Righi <arighi@nvidia.com>

Applied to sched_ext/for-6.15.

Thanks.

-- 
tejun