diff mbox series

[v1] PM: runtime: add tracepoint for runtime_status changes

Message ID 20240221164112.846409-1-vilasbhat@google.com
State New
Headers
Series [v1] PM: runtime: add tracepoint for runtime_status changes |

Commit Message

Vilas Bhat Feb. 21, 2024, 4:41 p.m. UTC 
  Existing runtime PM ftrace events (`rpm_suspend`, `rpm_resume`,
`rpm_return_int`) offer limited visibility into the exact timing of device
runtime power state transitions, particularly when asynchronous operations
are involved. When the `rpm_suspend` or `rpm_resume` functions are invoked
with the `RPM_ASYNC` flag, a return value of 0 i.e., success merely
indicates that the device power state request has been queued, not that
the device has yet transitioned.

A new ftrace event, `rpm_status`, is introduced. This event directly logs
the `power.runtime_status` value of a device whenever it changes providing
granular tracking of runtime power state transitions regardless of
synchronous or asynchronous `rpm_suspend` / `rpm_resume` usage.

Signed-off-by: Vilas Bhat <vilasbhat@google.com>
---
 drivers/base/power/runtime.c |  1 +
 include/trace/events/rpm.h   | 36 ++++++++++++++++++++++++++++++++++++
 2 files changed, 37 insertions(+)

Comments

Steven Rostedt Feb. 21, 2024, 5:14 p.m. UTC | #1 
On Wed, 21 Feb 2024 16:41:10 +0000
Vilas Bhat <vilasbhat@google.com> wrote:


> diff --git a/include/trace/events/rpm.h b/include/trace/events/rpm.h
> index 3c716214dab1..f1dc4e95dbce 100644
> --- a/include/trace/events/rpm.h
> +++ b/include/trace/events/rpm.h
> @@ -101,6 +101,42 @@ TRACE_EVENT(rpm_return_int,
>  		__entry->ret)
>  );
>  
> +#define RPM_STATUS_STRINGS \
> +	{ RPM_INVALID, "RPM_INVALID" }, \
> +	{ RPM_ACTIVE, "RPM_ACTIVE" }, \
> +	{ RPM_RESUMING, "RPM_RESUMING" }, \
> +	{ RPM_SUSPENDED, "RPM_SUSPENDED" }, \
> +	{ RPM_SUSPENDING, "RPM_SUSPENDING" }
> +
> +/*
> + * ftrace's __print_symbolic requires that all enum values be wrapped in the
> + * TRACE_DEFINE_ENUM macro so that the enum value can be encoded in the ftrace
> + * ring buffer.
> + */
> +TRACE_DEFINE_ENUM(RPM_INVALID);
> +TRACE_DEFINE_ENUM(RPM_ACTIVE);
> +TRACE_DEFINE_ENUM(RPM_RESUMING);
> +TRACE_DEFINE_ENUM(RPM_SUSPENDED);
> +TRACE_DEFINE_ENUM(RPM_SUSPENDING);

You could do what everyone else does:

#define RPM_STATUS_STRINGS			\
	EM( RPM_INVALID, "RPM_INVALID" )	\
	EM( RPM_ACTIVE, "RPM_ACTIVE" )		\
	EM( RPM_RESUMING, "RPM_RESUMING" )	\
	EM( RPM_SUSPENDED, "RPM_SUSPENDED" )	\
	EMe( RPM_SUSPENDING, "RPM_SUSPENDING" )

#undef EM
#undef EMe
#define EM(a, b)	TRACE_DEFINE_ENUM(a);
#define EMe(a, b)	TRACE_DEFINE_ENUM(a);

RPM_STATUS_STRINGS

#undef EM
#undef EMe
#define EM(a, b)	{ a, b },
#define EMe(a, b)	{ a, b }

> +
> +TRACE_EVENT(rpm_status,
> +	TP_PROTO(struct device *dev, enum rpm_status status),
> +	TP_ARGS(dev, status),
> +
> +	TP_STRUCT__entry(
> +		__string(name,	dev_name(dev))
> +		__field(int,	status)
> +	),
> +
> +	TP_fast_assign(
> +		__assign_str(name, dev_name(dev));
> +		__entry->status = status;
> +	),
> +
> +	TP_printk("%s status=%s", __get_str(name),
> +		__print_symbolic(__entry->status, RPM_STATUS_STRINGS))

This will be what you want with that last redefine of EM*()

-- Steve


> +);
> +
>  #endif /* _TRACE_RUNTIME_POWER_H */
>  
>  /* This part must be outside protection */
Vilas Bhat Feb. 21, 2024, 5:57 p.m. UTC | #2 
On Wed, Feb 21, 2024 at 9:12 AM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Wed, 21 Feb 2024 16:41:10 +0000
> Vilas Bhat <vilasbhat@google.com> wrote:
>
>
> > diff --git a/include/trace/events/rpm.h b/include/trace/events/rpm.h
> > index 3c716214dab1..f1dc4e95dbce 100644
> > --- a/include/trace/events/rpm.h
> > +++ b/include/trace/events/rpm.h
> > @@ -101,6 +101,42 @@ TRACE_EVENT(rpm_return_int,
> >               __entry->ret)
> >  );
> >
> > +#define RPM_STATUS_STRINGS \
> > +     { RPM_INVALID, "RPM_INVALID" }, \
> > +     { RPM_ACTIVE, "RPM_ACTIVE" }, \
> > +     { RPM_RESUMING, "RPM_RESUMING" }, \
> > +     { RPM_SUSPENDED, "RPM_SUSPENDED" }, \
> > +     { RPM_SUSPENDING, "RPM_SUSPENDING" }
> > +
> > +/*
> > + * ftrace's __print_symbolic requires that all enum values be wrapped in the
> > + * TRACE_DEFINE_ENUM macro so that the enum value can be encoded in the ftrace
> > + * ring buffer.
> > + */
> > +TRACE_DEFINE_ENUM(RPM_INVALID);
> > +TRACE_DEFINE_ENUM(RPM_ACTIVE);
> > +TRACE_DEFINE_ENUM(RPM_RESUMING);
> > +TRACE_DEFINE_ENUM(RPM_SUSPENDED);
> > +TRACE_DEFINE_ENUM(RPM_SUSPENDING);
>
> You could do what everyone else does:
>
> #define RPM_STATUS_STRINGS                      \
>         EM( RPM_INVALID, "RPM_INVALID" )        \
>         EM( RPM_ACTIVE, "RPM_ACTIVE" )          \
>         EM( RPM_RESUMING, "RPM_RESUMING" )      \
>         EM( RPM_SUSPENDED, "RPM_SUSPENDED" )    \
>         EMe( RPM_SUSPENDING, "RPM_SUSPENDING" )
>
> #undef EM
> #undef EMe
> #define EM(a, b)        TRACE_DEFINE_ENUM(a);
> #define EMe(a, b)       TRACE_DEFINE_ENUM(a);
>
> RPM_STATUS_STRINGS
>
> #undef EM
> #undef EMe
> #define EM(a, b)        { a, b },
> #define EMe(a, b)       { a, b }
>

Thanks for the comment, Steven. I did notice both methods of defining
enum values for tracepoints and chose this method because it felt
clearer. Could you clarify on why the method you suggested is
preferred?

> > +
> > +TRACE_EVENT(rpm_status,
> > +     TP_PROTO(struct device *dev, enum rpm_status status),
> > +     TP_ARGS(dev, status),
> > +
> > +     TP_STRUCT__entry(
> > +             __string(name,  dev_name(dev))
> > +             __field(int,    status)
> > +     ),
> > +
> > +     TP_fast_assign(
> > +             __assign_str(name, dev_name(dev));
> > +             __entry->status = status;
> > +     ),
> > +
> > +     TP_printk("%s status=%s", __get_str(name),
> > +             __print_symbolic(__entry->status, RPM_STATUS_STRINGS))
>
> This will be what you want with that last redefine of EM*()
>
> -- Steve
>
>
> > +);
> > +
> >  #endif /* _TRACE_RUNTIME_POWER_H */
> >
> >  /* This part must be outside protection */
>
Steven Rostedt Feb. 21, 2024, 6:35 p.m. UTC | #3 
On Wed, 21 Feb 2024 09:57:03 -0800
Vilas Bhat <vilasbhat@google.com> wrote:

> > You could do what everyone else does:
> >
> > #define RPM_STATUS_STRINGS                      \
> >         EM( RPM_INVALID, "RPM_INVALID" )        \
> >         EM( RPM_ACTIVE, "RPM_ACTIVE" )          \
> >         EM( RPM_RESUMING, "RPM_RESUMING" )      \
> >         EM( RPM_SUSPENDED, "RPM_SUSPENDED" )    \
> >         EMe( RPM_SUSPENDING, "RPM_SUSPENDING" )
> >
> > #undef EM
> > #undef EMe
> > #define EM(a, b)        TRACE_DEFINE_ENUM(a);
> > #define EMe(a, b)       TRACE_DEFINE_ENUM(a);
> >
> > RPM_STATUS_STRINGS
> >
> > #undef EM
> > #undef EMe
> > #define EM(a, b)        { a, b },
> > #define EMe(a, b)       { a, b }
> >  
> 
> Thanks for the comment, Steven. I did notice both methods of defining
> enum values for tracepoints and chose this method because it felt
> clearer. Could you clarify on why the method you suggested is
> preferred?
> 

Sure. One big reason: It removes duplication.

If you add another enum to the list, you only need to update it in one
place. And it prevents the two from getting out of sync.

-- Steve
Vilas Bhat Feb. 21, 2024, 6:40 p.m. UTC | #4 
On Wed, Feb 21, 2024 at 10:33 AM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Wed, 21 Feb 2024 09:57:03 -0800
> Vilas Bhat <vilasbhat@google.com> wrote:
>
> > > You could do what everyone else does:
> > >
> > > #define RPM_STATUS_STRINGS                      \
> > >         EM( RPM_INVALID, "RPM_INVALID" )        \
> > >         EM( RPM_ACTIVE, "RPM_ACTIVE" )          \
> > >         EM( RPM_RESUMING, "RPM_RESUMING" )      \
> > >         EM( RPM_SUSPENDED, "RPM_SUSPENDED" )    \
> > >         EMe( RPM_SUSPENDING, "RPM_SUSPENDING" )
> > >
> > > #undef EM
> > > #undef EMe
> > > #define EM(a, b)        TRACE_DEFINE_ENUM(a);
> > > #define EMe(a, b)       TRACE_DEFINE_ENUM(a);
> > >
> > > RPM_STATUS_STRINGS
> > >
> > > #undef EM
> > > #undef EMe
> > > #define EM(a, b)        { a, b },
> > > #define EMe(a, b)       { a, b }
> > >
> >
> > Thanks for the comment, Steven. I did notice both methods of defining
> > enum values for tracepoints and chose this method because it felt
> > clearer. Could you clarify on why the method you suggested is
> > preferred?
> >
>
> Sure. One big reason: It removes duplication.
>
> If you add another enum to the list, you only need to update it in one
> place. And it prevents the two from getting out of sync.
>
> -- Steve

That makes sense! Thanks. I will revise the patch and send a new version soon.
diff mbox series

Patch

diff --git a/drivers/base/power/runtime.c b/drivers/base/power/runtime.c
index 05793c9fbb84..d10354847878 100644
--- a/drivers/base/power/runtime.c
+++ b/drivers/base/power/runtime.c
@@ -94,6 +94,7 @@  static void update_pm_runtime_accounting(struct device *dev)
 static void __update_runtime_status(struct device *dev, enum rpm_status status)
 {
 	update_pm_runtime_accounting(dev);
+	trace_rpm_status(dev, status);
 	dev->power.runtime_status = status;
 }
 
diff --git a/include/trace/events/rpm.h b/include/trace/events/rpm.h
index 3c716214dab1..f1dc4e95dbce 100644
--- a/include/trace/events/rpm.h
+++ b/include/trace/events/rpm.h
@@ -101,6 +101,42 @@  TRACE_EVENT(rpm_return_int,
 		__entry->ret)
 );
 
+#define RPM_STATUS_STRINGS \
+	{ RPM_INVALID, "RPM_INVALID" }, \
+	{ RPM_ACTIVE, "RPM_ACTIVE" }, \
+	{ RPM_RESUMING, "RPM_RESUMING" }, \
+	{ RPM_SUSPENDED, "RPM_SUSPENDED" }, \
+	{ RPM_SUSPENDING, "RPM_SUSPENDING" }
+
+/*
+ * ftrace's __print_symbolic requires that all enum values be wrapped in the
+ * TRACE_DEFINE_ENUM macro so that the enum value can be encoded in the ftrace
+ * ring buffer.
+ */
+TRACE_DEFINE_ENUM(RPM_INVALID);
+TRACE_DEFINE_ENUM(RPM_ACTIVE);
+TRACE_DEFINE_ENUM(RPM_RESUMING);
+TRACE_DEFINE_ENUM(RPM_SUSPENDED);
+TRACE_DEFINE_ENUM(RPM_SUSPENDING);
+
+TRACE_EVENT(rpm_status,
+	TP_PROTO(struct device *dev, enum rpm_status status),
+	TP_ARGS(dev, status),
+
+	TP_STRUCT__entry(
+		__string(name,	dev_name(dev))
+		__field(int,	status)
+	),
+
+	TP_fast_assign(
+		__assign_str(name, dev_name(dev));
+		__entry->status = status;
+	),
+
+	TP_printk("%s status=%s", __get_str(name),
+		__print_symbolic(__entry->status, RPM_STATUS_STRINGS))
+);
+
 #endif /* _TRACE_RUNTIME_POWER_H */
 
 /* This part must be outside protection */