Re: [PATCH v5] PM: sleep: Expose last succeeded resumed timestamp in sysfs

[Masami Hiramatsu (Google) <mhiramat@kernel.org>]

On Tue, 12 Dec 2023 15:57:52 +0100
"Rafael J. Wysocki" <rafael@kernel.org> wrote:

> On Tue, Dec 12, 2023 at 3:32 PM Masami Hiramatsu <mhiramat@kernel.org> wrote:
> >
> > Hi Rafael,
> >
> > On Tue, 12 Dec 2023 14:39:17 +0100
> > "Rafael J. Wysocki" <rafael@kernel.org> wrote:
> >
> > > On Mon, Nov 27, 2023 at 11:38 AM Masami Hiramatsu (Google)
> > > <mhiramat@kernel.org> wrote:
> > > >
> > > > From: Masami Hiramatsu <mhiramat@kernel.org>
> > > >
> > > > Expose last succeeded resumed timestamp as last_success_resume_time
> > > > attribute of suspend_stats in sysfs.
> > > >
> > > > There are some printk()s for printing the similar resume timing to
> > > > dmesg, but those are recorded with local_clock(), and user can not
> > > > compare it with current time. We also have tracing events but it
> > > > requires CAP_SYS_ADMIN to use it.
> > > >
> > > > This suspend_stats attribute is easy to access and only expose the
> > > > timestamp in CLOCK_MONOTONIC.
> > >
> > > Why CLOCK_MONOTONIC?
> >
> > CLOCK_MONOTONIC is the simplest clock which can be used in both user
> > space and kernel space. If we use the CLOCK_LOCAL here, user can not
> > know the actual time delta from the succeeded resume.
> 
> So what does user space need to do to use this value?

This will be used to measure the delay of the user-space resuming as a
metric of system health.

> > >
> > > > So user can find the actual resumed
> > > > time and measure the elapsed time from the time when the kernel
> > > > finished the resume to the user-space action (e.g. display the UI).
> > >
> > > Can you please say a bit more about why this is useful?
> >
> > This is a reference timestamp from the user space to measure their
> > processing time for resuming. The kernel side is OK to just trace
> > or printk the each component or subsystem internally. But the user
> > space needs to know when the kernel resume has been done for measuring
> > its component or processes done.
> 
> Why does it need to know that?

For the metrics, the kernel side resume time and user-side resume time are
important to know if any update caused regressions and separate the issue.

> 
> > Actually this is obscure because the
> > end of resuming in userspace is defined by the user-space application
> > or desktop systems. But anyway if there is a reference point, user
> > process can calculate the delta at any point from that.
> >
> > >
> > > The time stamp is taken at the point when user space has been already
> > > running for some time, so what's the exact benefit of it?
> >
> > Yes, but that timestamp can be scheduled afterwards so it may not
> > be so accurate. This can provide the accurate time of the kernel
> > resume.
> 
> I'm talking about the timestamp added by this patch, that is
> /sys/power/suspend_stats/last_success_resume_time.
> 
> By the time ktime_get_ts64() in pm_suspend() is called, user space has
> already been thawed and is running, so why is this useful?

Aaah, good catch! It should be right before thawing process, right?

Thank you,

-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>