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

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

Hi,

On Sun, 29 Oct 2023 05:16:49 -0700
Randy Dunlap <rdunlap@infradead.org> wrote:

> Hi.
> 
> On 10/28/23 19:54, Masami Hiramatsu (Google) wrote:
> > On Sat, 28 Oct 2023 09:48:36 -0700
> > Randy Dunlap <rdunlap@infradead.org> wrote:
> > 
> >> Hi,
> >>
> >> On 10/28/23 05:53, Masami Hiramatsu (Google) wrote:
> >>> From: Masami Hiramatsu <mhiramat@kernel.org>
> >>>
> >>> Expose last succeeded resumed timestamp as last_success_resume_time
> >>> attribute of suspend_stats in sysfs. This timestamp is recorded in
> >>> CLOCK_MONOTONIC. 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 go into the use-case a bit more, please?
> >> You have said "what", but not "why".
> >> What do you (or google) plan to do with this?
> 
> and what about this part of my questions? ^^^^^^^^^

Oh, sorry I missed it.
I would like to know the actual (accurate) elapsed time from
the succeeded kernel resume time to displaying UI so that we can
identify the user visible (noticable) resume delay happens in the
kernel or the user resume process.

The kernel side will be recorded on the dmesg if we use PRINTK_TIME,
but the PRINTK_TIME is recorded by local_clock(), we can not know
the actual time in the user space. I also considered to expose
current local_clock() by introducing CLOCK_LOCAL, but that may be
more user-space intrusive change, so I chose this way.

Thank you,

> 
> 
> >>
> >>>
> >>> Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> >>> ---
> >>>  Changes in v3:
> >>>   - Add (unsigned long long) casting for %llu.
> >>>   - Add a line after last_success_resume_time_show().
> >>>  Changes in v2:
> >>>   - Use %llu instead of %lu for printing u64 value.
> >>>   - Remove unneeded indent spaces from the last_success_resume_time
> >>>     line in the debugfs suspend_stat file.
> >>> ---
> >>>  Documentation/ABI/testing/sysfs-power |   10 ++++++++++
> >>>  include/linux/suspend.h               |    2 ++
> >>>  kernel/power/main.c                   |   15 +++++++++++++++
> >>>  kernel/power/suspend.c                |    1 +
> >>>  4 files changed, 28 insertions(+)
> >>>
> >>> diff --git a/Documentation/ABI/testing/sysfs-power b/Documentation/ABI/testing/sysfs-power
> >>> index a3942b1036e2..63659765dee1 100644
> >>> --- a/Documentation/ABI/testing/sysfs-power
> >>> +++ b/Documentation/ABI/testing/sysfs-power
> >>> @@ -442,6 +442,16 @@ Description:
> >>>  		'total_hw_sleep' and 'last_hw_sleep' may not be accurate.
> >>>  		This number is measured in microseconds.
> >>>  
> >>> +What:		/sys/power/suspend_stats/last_success_resume_time
> >>> +Date:		Oct 2023
> >>> +Contact:	Masami Hiramatsu <mhiramat@kernel.org>
> >>> +Description:
> >>> +		The /sys/power/suspend_stats/last_success_resume_time file
> >>> +		contains the timestamp of when the kernel successfully
> >>> +		resumed from suspend/hibernate.
> >>> +		This floating number is measured in seconds by monotonic
> >>
> >> What does "floating" mean here?  Not floating point...
> > 
> > Oops, it should be "floating point number".
> > 
> > Thank you!
> > 
> >>
> >>
> >>> +		clock.
> >>> +
> >>>  What:		/sys/power/sync_on_suspend
> >>>  Date:		October 2019
> >>>  Contact:	Jonas Meurer <jonas@freesources.org>
> >>
> >> [snip]
> >>
> >> Thanks.
> >> -- 
> >> ~Randy
> > 
> > 
> 
> -- 
> ~Randy


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