[v2] PM: runtime: add tracepoint for runtime_status changes
Commit Message
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>
---
V1 -> V2: Modified enum value definition as per reviewer comments.
---
drivers/base/power/runtime.c | 1 +
include/trace/events/rpm.h | 42 ++++++++++++++++++++++++++++++++++++
2 files changed, 43 insertions(+)
Comments
On Wed, Feb 21, 2024 at 8:49 PM Vilas Bhat <vilasbhat@google.com> wrote:
>
> 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>
> ---
> V1 -> V2: Modified enum value definition as per reviewer comments.
> ---
> drivers/base/power/runtime.c | 1 +
> include/trace/events/rpm.h | 42 ++++++++++++++++++++++++++++++++++++
> 2 files changed, 43 insertions(+)
>
> 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..bd120e23ce12 100644
> --- a/include/trace/events/rpm.h
> +++ b/include/trace/events/rpm.h
> @@ -101,6 +101,48 @@ TRACE_EVENT(rpm_return_int,
> __entry->ret)
> );
>
> +#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")
> +
> +/* Enums require being exported to userspace, for user tool parsing. */
> +#undef EM
> +#undef EMe
> +#define EM(a, b) TRACE_DEFINE_ENUM(a);
> +#define EMe(a, b) TRACE_DEFINE_ENUM(a);
> +
> +RPM_STATUS_STRINGS
> +
> +/*
> + * Now redefine the EM() and EMe() macros to map the enums to the strings that
> + * will be printed in the output.
> + */
> +#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))
> +);
> +
> #endif /* _TRACE_RUNTIME_POWER_H */
>
> /* This part must be outside protection */
> --
Applied as 6.9 material, thanks!
@@ -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;
}
@@ -101,6 +101,48 @@ TRACE_EVENT(rpm_return_int,
__entry->ret)
);
+#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")
+
+/* Enums require being exported to userspace, for user tool parsing. */
+#undef EM
+#undef EMe
+#define EM(a, b) TRACE_DEFINE_ENUM(a);
+#define EMe(a, b) TRACE_DEFINE_ENUM(a);
+
+RPM_STATUS_STRINGS
+
+/*
+ * Now redefine the EM() and EMe() macros to map the enums to the strings that
+ * will be printed in the output.
+ */
+#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))
+);
+
#endif /* _TRACE_RUNTIME_POWER_H */
/* This part must be outside protection */