Message ID | 20221118150751.469393-13-nathanl@linux.ibm.com (mailing list archive) |
---|---|
State | Changes Requested |
Headers | show |
Series | RTAS maintenance | expand |
On Sat Nov 19, 2022 at 1:07 AM AEST, Nathan Lynch wrote: > Add two sets of tracepoints to be used around RTAS entry: > > * rtas_input/rtas_output, which emit the function name, its inputs, > the returned status, and any other outputs. These produce an API-level > record of OS<->RTAS activity. > > * rtas_ll_entry/rtas_ll_exit, which are lower-level and emit the > entire contents of the parameter block (aka rtas_args) on entry and > exit. Likely useful only for debugging. > > With uses of these tracepoints in do_enter_rtas() to be added in the > following patch, examples of get-time-of-day and event-scan functions > as rendered by trace-cmd (with some multi-line formatting manually > imposed on the rtas_ll_* entries to avoid extremely long lines in the > commit message): > > cat-36800 [059] 4978.518303: rtas_input: get-time-of-day arguments: > cat-36800 [059] 4978.518306: rtas_ll_entry: token=3 nargs=0 nret=8 > params: [0]=0x00000000 [1]=0x00000000 [2]=0x00000000 [3]=0x00000000 > [4]=0x00000000 [5]=0x00000000 [6]=0x00000000 [7]=0x00000000 > [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 > [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 > cat-36800 [059] 4978.518366: rtas_ll_exit: token=3 nargs=0 nret=8 > params: [0]=0x00000000 [1]=0x000007e6 [2]=0x0000000b [3]=0x00000001 > [4]=0x00000000 [5]=0x0000000e [6]=0x00000008 [7]=0x2e0dac40 > [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 > [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 > cat-36800 [059] 4978.518366: rtas_output: get-time-of-day status: 0, other outputs: 2022 11 1 0 14 8 772648000 > > kworker/39:1-336 [039] 4982.731623: rtas_input: event-scan arguments: 4294967295 0 80484920 2048 > kworker/39:1-336 [039] 4982.731626: rtas_ll_entry: token=6 nargs=4 nret=1 > params: [0]=0xffffffff [1]=0x00000000 [2]=0x04cc1a38 [3]=0x00000800 > [4]=0x00000000 [5]=0x0000000e [6]=0x00000008 [7]=0x2e0dac40 > [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 > [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 > kworker/39:1-336 [039] 4982.731676: rtas_ll_exit: token=6 nargs=4 nret=1 > params: [0]=0xffffffff [1]=0x00000000 [2]=0x04cc1a38 [3]=0x00000800 > [4]=0x00000001 [5]=0x0000000e [6]=0x00000008 [7]=0x2e0dac40 > [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 > [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 > kworker/39:1-336 [039] 4982.731677: rtas_output: event-scan status: 1, other outputs: > > Signed-off-by: Nathan Lynch <nathanl@linux.ibm.com> > --- > arch/powerpc/include/asm/trace.h | 116 +++++++++++++++++++++++++++++++ > 1 file changed, 116 insertions(+) > > diff --git a/arch/powerpc/include/asm/trace.h b/arch/powerpc/include/asm/trace.h > index 08cd60cd70b7..e7a301c9eb95 100644 > --- a/arch/powerpc/include/asm/trace.h > +++ b/arch/powerpc/include/asm/trace.h > @@ -119,6 +119,122 @@ TRACE_EVENT_FN_COND(hcall_exit, > ); > #endif > > +#ifdef CONFIG_PPC_RTAS > + > +#include <asm/rtas-types.h> > + > +/* > + * Since stop-self is how CPUs go offline on RTAS platforms, > + * these tracepoints are conditional. > + */ > + > +TRACE_EVENT_CONDITION(rtas_input, > + > + TP_PROTO(struct rtas_args *rtas_args, const char *name), > + > + TP_ARGS(rtas_args, name), > + > + TP_CONDITION(cpu_online(raw_smp_processor_id())), > + > + TP_STRUCT__entry( > + __field(__u32, nargs) > + __string(name, name) > + __dynamic_array(__u32, inputs, be32_to_cpu(rtas_args->nargs)) > + ), > + > + TP_fast_assign( > + __entry->nargs = be32_to_cpu(rtas_args->nargs); > + __assign_str(name, name); > + be32_to_cpu_array(__get_dynamic_array(inputs), rtas_args->args, __entry->nargs); > + ), > + > + TP_printk("%s arguments: %s", __get_str(name), > + __print_array(__get_dynamic_array(inputs), __entry->nargs, 4) > + ) > +); > + > +TRACE_EVENT_CONDITION(rtas_output, > + > + TP_PROTO(struct rtas_args *rtas_args, const char *name), > + > + TP_ARGS(rtas_args, name), > + > + TP_CONDITION(cpu_online(raw_smp_processor_id())), > + > + TP_STRUCT__entry( > + __field(__u32, nr_other) > + __field(__s32, status) > + __string(name, name) > + __dynamic_array(__u32, other_outputs, be32_to_cpu(rtas_args->nret) - 1) > + ), > + > + TP_fast_assign( > + __entry->nr_other = be32_to_cpu(rtas_args->nret) - 1; > + __entry->status = be32_to_cpu(rtas_args->rets[0]); > + __assign_str(name, name); > + be32_to_cpu_array(__get_dynamic_array(other_outputs), > + &rtas_args->rets[1], __entry->nr_other); > + ), > + > + TP_printk("%s status: %d, other outputs: %s", __get_str(name), __entry->status, > + __print_array(__get_dynamic_array(other_outputs), > + __entry->nr_other, 4) > + ) > +); > + > +DECLARE_EVENT_CLASS(rtas_parameter_block, > + > + TP_PROTO(struct rtas_args *rtas_args), > + > + TP_ARGS(rtas_args), > + > + TP_STRUCT__entry( > + __field(u32, token) > + __field(u32, nargs) > + __field(u32, nret) > + __array(__u32, params, 16) > + ), > + > + TP_fast_assign( > + __entry->token = be32_to_cpu(rtas_args->token); > + __entry->nargs = be32_to_cpu(rtas_args->nargs); > + __entry->nret = be32_to_cpu(rtas_args->nret); > + be32_to_cpu_array(__entry->params, rtas_args->args, ARRAY_SIZE(rtas_args->args)); > + ), > + > + TP_printk("token=%u nargs=%u nret=%u params:" > + " [0]=0x%08x [1]=0x%08x [2]=0x%08x [3]=0x%08x" > + " [4]=0x%08x [5]=0x%08x [6]=0x%08x [7]=0x%08x" > + " [8]=0x%08x [9]=0x%08x [10]=0x%08x [11]=0x%08x" > + " [12]=0x%08x [13]=0x%08x [14]=0x%08x [15]=0x%08x", You could justify these since you went to the trouble to format them nicely. Not a big deal though. Reviewed-by: Nicholas Piggin <npiggin@gmail.com> > + __entry->token, __entry->nargs, __entry->nret, > + __entry->params[0], __entry->params[1], __entry->params[2], __entry->params[3], > + __entry->params[4], __entry->params[5], __entry->params[6], __entry->params[7], > + __entry->params[8], __entry->params[9], __entry->params[10], __entry->params[11], > + __entry->params[12], __entry->params[13], __entry->params[14], __entry->params[15] > + ) > +); > + > +DEFINE_EVENT_CONDITION(rtas_parameter_block, rtas_ll_entry, > + > + TP_PROTO(struct rtas_args *rtas_args), > + > + TP_ARGS(rtas_args), > + > + TP_CONDITION(cpu_online(raw_smp_processor_id())) > +); > + > +DEFINE_EVENT_CONDITION(rtas_parameter_block, rtas_ll_exit, > + > + TP_PROTO(struct rtas_args *rtas_args), > + > + TP_ARGS(rtas_args), > + > + TP_CONDITION(cpu_online(raw_smp_processor_id())) > +); > + > +#endif /* CONFIG_PPC_RTAS */ > + > #ifdef CONFIG_PPC_POWERNV > extern int opal_tracepoint_regfunc(void); > extern void opal_tracepoint_unregfunc(void); > -- > 2.37.1
diff --git a/arch/powerpc/include/asm/trace.h b/arch/powerpc/include/asm/trace.h index 08cd60cd70b7..e7a301c9eb95 100644 --- a/arch/powerpc/include/asm/trace.h +++ b/arch/powerpc/include/asm/trace.h @@ -119,6 +119,122 @@ TRACE_EVENT_FN_COND(hcall_exit, ); #endif +#ifdef CONFIG_PPC_RTAS + +#include <asm/rtas-types.h> + +/* + * Since stop-self is how CPUs go offline on RTAS platforms, + * these tracepoints are conditional. + */ + +TRACE_EVENT_CONDITION(rtas_input, + + TP_PROTO(struct rtas_args *rtas_args, const char *name), + + TP_ARGS(rtas_args, name), + + TP_CONDITION(cpu_online(raw_smp_processor_id())), + + TP_STRUCT__entry( + __field(__u32, nargs) + __string(name, name) + __dynamic_array(__u32, inputs, be32_to_cpu(rtas_args->nargs)) + ), + + TP_fast_assign( + __entry->nargs = be32_to_cpu(rtas_args->nargs); + __assign_str(name, name); + be32_to_cpu_array(__get_dynamic_array(inputs), rtas_args->args, __entry->nargs); + ), + + TP_printk("%s arguments: %s", __get_str(name), + __print_array(__get_dynamic_array(inputs), __entry->nargs, 4) + ) +); + +TRACE_EVENT_CONDITION(rtas_output, + + TP_PROTO(struct rtas_args *rtas_args, const char *name), + + TP_ARGS(rtas_args, name), + + TP_CONDITION(cpu_online(raw_smp_processor_id())), + + TP_STRUCT__entry( + __field(__u32, nr_other) + __field(__s32, status) + __string(name, name) + __dynamic_array(__u32, other_outputs, be32_to_cpu(rtas_args->nret) - 1) + ), + + TP_fast_assign( + __entry->nr_other = be32_to_cpu(rtas_args->nret) - 1; + __entry->status = be32_to_cpu(rtas_args->rets[0]); + __assign_str(name, name); + be32_to_cpu_array(__get_dynamic_array(other_outputs), + &rtas_args->rets[1], __entry->nr_other); + ), + + TP_printk("%s status: %d, other outputs: %s", __get_str(name), __entry->status, + __print_array(__get_dynamic_array(other_outputs), + __entry->nr_other, 4) + ) +); + +DECLARE_EVENT_CLASS(rtas_parameter_block, + + TP_PROTO(struct rtas_args *rtas_args), + + TP_ARGS(rtas_args), + + TP_STRUCT__entry( + __field(u32, token) + __field(u32, nargs) + __field(u32, nret) + __array(__u32, params, 16) + ), + + TP_fast_assign( + __entry->token = be32_to_cpu(rtas_args->token); + __entry->nargs = be32_to_cpu(rtas_args->nargs); + __entry->nret = be32_to_cpu(rtas_args->nret); + be32_to_cpu_array(__entry->params, rtas_args->args, ARRAY_SIZE(rtas_args->args)); + ), + + TP_printk("token=%u nargs=%u nret=%u params:" + " [0]=0x%08x [1]=0x%08x [2]=0x%08x [3]=0x%08x" + " [4]=0x%08x [5]=0x%08x [6]=0x%08x [7]=0x%08x" + " [8]=0x%08x [9]=0x%08x [10]=0x%08x [11]=0x%08x" + " [12]=0x%08x [13]=0x%08x [14]=0x%08x [15]=0x%08x", + __entry->token, __entry->nargs, __entry->nret, + __entry->params[0], __entry->params[1], __entry->params[2], __entry->params[3], + __entry->params[4], __entry->params[5], __entry->params[6], __entry->params[7], + __entry->params[8], __entry->params[9], __entry->params[10], __entry->params[11], + __entry->params[12], __entry->params[13], __entry->params[14], __entry->params[15] + ) +); + +DEFINE_EVENT_CONDITION(rtas_parameter_block, rtas_ll_entry, + + TP_PROTO(struct rtas_args *rtas_args), + + TP_ARGS(rtas_args), + + TP_CONDITION(cpu_online(raw_smp_processor_id())) +); + +DEFINE_EVENT_CONDITION(rtas_parameter_block, rtas_ll_exit, + + TP_PROTO(struct rtas_args *rtas_args), + + TP_ARGS(rtas_args), + + TP_CONDITION(cpu_online(raw_smp_processor_id())) +); + +#endif /* CONFIG_PPC_RTAS */ + #ifdef CONFIG_PPC_POWERNV extern int opal_tracepoint_regfunc(void); extern void opal_tracepoint_unregfunc(void);
Add two sets of tracepoints to be used around RTAS entry: * rtas_input/rtas_output, which emit the function name, its inputs, the returned status, and any other outputs. These produce an API-level record of OS<->RTAS activity. * rtas_ll_entry/rtas_ll_exit, which are lower-level and emit the entire contents of the parameter block (aka rtas_args) on entry and exit. Likely useful only for debugging. With uses of these tracepoints in do_enter_rtas() to be added in the following patch, examples of get-time-of-day and event-scan functions as rendered by trace-cmd (with some multi-line formatting manually imposed on the rtas_ll_* entries to avoid extremely long lines in the commit message): cat-36800 [059] 4978.518303: rtas_input: get-time-of-day arguments: cat-36800 [059] 4978.518306: rtas_ll_entry: token=3 nargs=0 nret=8 params: [0]=0x00000000 [1]=0x00000000 [2]=0x00000000 [3]=0x00000000 [4]=0x00000000 [5]=0x00000000 [6]=0x00000000 [7]=0x00000000 [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 cat-36800 [059] 4978.518366: rtas_ll_exit: token=3 nargs=0 nret=8 params: [0]=0x00000000 [1]=0x000007e6 [2]=0x0000000b [3]=0x00000001 [4]=0x00000000 [5]=0x0000000e [6]=0x00000008 [7]=0x2e0dac40 [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 cat-36800 [059] 4978.518366: rtas_output: get-time-of-day status: 0, other outputs: 2022 11 1 0 14 8 772648000 kworker/39:1-336 [039] 4982.731623: rtas_input: event-scan arguments: 4294967295 0 80484920 2048 kworker/39:1-336 [039] 4982.731626: rtas_ll_entry: token=6 nargs=4 nret=1 params: [0]=0xffffffff [1]=0x00000000 [2]=0x04cc1a38 [3]=0x00000800 [4]=0x00000000 [5]=0x0000000e [6]=0x00000008 [7]=0x2e0dac40 [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 kworker/39:1-336 [039] 4982.731676: rtas_ll_exit: token=6 nargs=4 nret=1 params: [0]=0xffffffff [1]=0x00000000 [2]=0x04cc1a38 [3]=0x00000800 [4]=0x00000001 [5]=0x0000000e [6]=0x00000008 [7]=0x2e0dac40 [8]=0x00000000 [9]=0x00000000 [10]=0x00000000 [11]=0x00000000 [12]=0x00000000 [13]=0x00000000 [14]=0x00000000 [15]=0x00000000 kworker/39:1-336 [039] 4982.731677: rtas_output: event-scan status: 1, other outputs: Signed-off-by: Nathan Lynch <nathanl@linux.ibm.com> --- arch/powerpc/include/asm/trace.h | 116 +++++++++++++++++++++++++++++++ 1 file changed, 116 insertions(+)