diff mbox series

[v2] platform/chrome: cros_ec: Send host event for prepare/complete

Message ID 20220706205136.v2.1.Ic7a7c81f880ab31533652e0928aa6e687bb268b5@changeid (mailing list archive)
State Superseded
Headers show
Series [v2] platform/chrome: cros_ec: Send host event for prepare/complete | expand

Commit Message

Tim Van Patten July 7, 2022, 2:51 a.m. UTC
Update cros_ec_lpc_pm_ops to call cros_ec_lpc_suspend() during PM
.prepare() and cros_ec_lpc_resume() during .complete. This allows the
EC to log entry/exit of AP's suspend/resume more accurately.

Signed-off-by: Tim Van Patten <timvp@google.com>
---

Changes in v2:
- Include cros_ec_resume() return value in dev_info() output.
- Guard setting .prepare/.complete with #ifdef CONFIG_PM_SLEEP.

 drivers/platform/chrome/cros_ec_lpc.c | 14 +++++++++++---
 1 file changed, 11 insertions(+), 3 deletions(-)

Comments

Tzung-Bi Shih July 13, 2022, 2:58 a.m. UTC | #1
On Wed, Jul 06, 2022 at 08:51:39PM -0600, Tim Van Patten wrote:
> Update cros_ec_lpc_pm_ops to call cros_ec_lpc_suspend() during PM
> .prepare() and cros_ec_lpc_resume() during .complete. This allows the
> EC to log entry/exit of AP's suspend/resume more accurately.

Please be consistent.  Either way:
- .prepare and .complete.
- .prepare() and .complete().

The patch doesn't allow EC to log anything.  It makes AP emit more logs.

On the related note, the commit subject is confusing.  The patch doesn't
send "host event".  "host event" is a terminology when EC wants to notify
AP something.  Also, s/cros_ec/cros_ec_lpcs/.

> Changes in v2:
> - Include cros_ec_resume() return value in dev_info() output.
> - Guard setting .prepare/.complete with #ifdef CONFIG_PM_SLEEP.

I didn't see concerns in [1] have been addressed.

[1]: https://patchwork.kernel.org/project/chrome-platform/patch/20220701095421.1.I78ded92e416b55de31975686d34b2058d4761c07@changeid/#24920824
Tzung-Bi Shih July 14, 2022, 2:22 a.m. UTC | #2
On Wed, Jul 13, 2022 at 12:05:14PM -0600, Tim Van Patten wrote:
> This patch changes *when* the EC outputs the host command that indicates
> the AP is starting suspend and finishing resume, due to the change (in this
> patch) when the AP sends that host command.   This makes the EC's logs more
> accurate when correlating them with the AP's logs in regards to when
> suspend is started and resume is completed.   Previously, those events were
> sent when suspend/resume were already in progress.

I see.

> We'd also like to keep the new logs emitted by the AP to make it clearer
> when the AP is starting suspend and completing resume, so we can correlate
> it with the EC logs more easily.   This should aid debugging and timing
> analysis.   Since it only occurs during suspend/resume, it shouldn't flood
> the logs and follows the logging of other driver PM functions.
> 
> I didn't see concerns in [1] have been addressed.
> 
> 
> I replied to the first email stating why we want to keep the log message
> (and reiterated it above).   What's the correct process to indicate we
> don't want to make the change requested in [1]?

I didn't see the message in the v1 thread[2].  What did you mean by
"first email"?  Checked my mbox but got nothing.

Also, I found the message didn't show in [3].  I'm not sure what happened
but perhaps you should use plain text next time (see [4])?

[2]: https://patchwork.kernel.org/project/chrome-platform/patch/20220701095421.1.I78ded92e416b55de31975686d34b2058d4761c07@changeid/
[3]: https://patchwork.kernel.org/project/chrome-platform/patch/20220706205136.v2.1.Ic7a7c81f880ab31533652e0928aa6e687bb268b5@changeid/
[4]: https://www.kernel.org/doc/html/latest/process/submitting-patches.html#no-mime-no-links-no-compression-no-attachments-just-plain-text
Tim Van Patten July 14, 2022, 6:19 p.m. UTC | #3
[Resending in plain text mode]

Hi,

> Please be consistent.  Either way:
> - .prepare and .complete.
> - .prepare() and .complete().

I'll address this in the next version.

> The patch doesn't allow EC to log anything.  It makes AP emit more logs.

This patch changes when the EC outputs the host command that indicates
the AP is starting suspend and finishing resume, due to the change (in
this patch) when the AP sends that host command.   This makes the EC's
logs more accurate when correlating them with the AP's logs in regards
to when suspend is started and resume is completed.   Previously,
those events were sent when suspend/resume were already in progress.

We'd also like to keep the new logs emitted by the AP to make it
clearer when the AP is starting suspend and completing resume, so we
can correlate it with the EC logs more easily.   This should aid
debugging and timing analysis.   Since it only occurs during
suspend/resume, it shouldn't flood the logs and follows the logging of
other driver PM functions.

> I didn't see concerns in [1] have been addressed.

I replied to the first email stating why we want to keep the log
message (and reiterated it above).   What's the correct process to
indicate we don't want to make the change requested in [1]?

On Wed, Jul 13, 2022 at 12:05 PM Tim Van Patten <timvp@google.com> wrote:
>
> Hi,
>
>> Please be consistent.  Either way:
>> - .prepare and .complete.
>> - .prepare() and .complete().
>
>
> I'll address this in the next version.
>
>> The patch doesn't allow EC to log anything.  It makes AP emit more logs.
>
>
> This patch changes when the EC outputs the host command that indicates the AP is starting suspend and finishing resume, due to the change (in this patch) when the AP sends that host command.   This makes the EC's logs more accurate when correlating them with the AP's logs in regards to when suspend is started and resume is completed.   Previously, those events were sent when suspend/resume were already in progress.
>
> We'd also like to keep the new logs emitted by the AP to make it clearer when the AP is starting suspend and completing resume, so we can correlate it with the EC logs more easily.   This should aid debugging and timing analysis.   Since it only occurs during suspend/resume, it shouldn't flood the logs and follows the logging of other driver PM functions.
>
>> I didn't see concerns in [1] have been addressed.
>
>
> I replied to the first email stating why we want to keep the log message (and reiterated it above).   What's the correct process to indicate we don't want to make the change requested in [1]?
>
>
> On Tue, Jul 12, 2022 at 8:58 PM Tzung-Bi Shih <tzungbi@kernel.org> wrote:
>>
>> On Wed, Jul 06, 2022 at 08:51:39PM -0600, Tim Van Patten wrote:
>> > Update cros_ec_lpc_pm_ops to call cros_ec_lpc_suspend() during PM
>> > .prepare() and cros_ec_lpc_resume() during .complete. This allows the
>> > EC to log entry/exit of AP's suspend/resume more accurately.
>>
>> Please be consistent.  Either way:
>> - .prepare and .complete.
>> - .prepare() and .complete().
>>
>> The patch doesn't allow EC to log anything.  It makes AP emit more logs.
>>
>> On the related note, the commit subject is confusing.  The patch doesn't
>> send "host event".  "host event" is a terminology when EC wants to notify
>> AP something.  Also, s/cros_ec/cros_ec_lpcs/.
>>
>> > Changes in v2:
>> > - Include cros_ec_resume() return value in dev_info() output.
>> > - Guard setting .prepare/.complete with #ifdef CONFIG_PM_SLEEP.
>>
>> I didn't see concerns in [1] have been addressed.
>>
>> [1]: https://patchwork.kernel.org/project/chrome-platform/patch/20220701095421.1.I78ded92e416b55de31975686d34b2058d4761c07@changeid/#24920824
>
>
>
> --
>
> Tim Van Patten | ChromeOS | timvp@google.com | (720) 432-0997
Prashant Malani July 14, 2022, 6:34 p.m. UTC | #4
HI Tim,

On Wed, Jul 6, 2022 at 7:51 PM Tim Van Patten <timvp@google.com> wrote:
>
> Update cros_ec_lpc_pm_ops to call cros_ec_lpc_suspend() during PM
> .prepare() and cros_ec_lpc_resume() during .complete. This allows the
> EC to log entry/exit of AP's suspend/resume more accurately.
>
> Signed-off-by: Tim Van Patten <timvp@google.com>
> ---
>
> Changes in v2:
> - Include cros_ec_resume() return value in dev_info() output.
> - Guard setting .prepare/.complete with #ifdef CONFIG_PM_SLEEP.
>
>  drivers/platform/chrome/cros_ec_lpc.c | 14 +++++++++++---
>  1 file changed, 11 insertions(+), 3 deletions(-)
>
> diff --git a/drivers/platform/chrome/cros_ec_lpc.c b/drivers/platform/chrome/cros_ec_lpc.c
> index 7677ab3c0ead9..ce49fbc4ed2e1 100644
> --- a/drivers/platform/chrome/cros_ec_lpc.c
> +++ b/drivers/platform/chrome/cros_ec_lpc.c
> @@ -534,19 +534,27 @@ static int cros_ec_lpc_suspend(struct device *dev)
>  {
>         struct cros_ec_device *ec_dev = dev_get_drvdata(dev);
>
> +       dev_info(dev, "Prepare EC suspend\n");

This patch is doing 2 things:
1. Changing the timing of cros_ec_lpc_suspend()/resume() invocation.
2. Adding print logs for these callbacks.

Whether 2.) is necessary is already being discussed, so I won't
comment on that, but it sounds
like this should be 2 different patches.

Also, please explain what is wrong with "Previously, those events were sent when
suspend/resume were already in progress." IOW, what issue is this
solving, besides
better ordering of EC logs.

BR,

-Prashant
Tim Van Patten July 14, 2022, 8:55 p.m. UTC | #5
Hi,

We had issues measuring overall suspend and resume times, which this
patch attempts to help resolve.   As stated in the description, the EC
host command logs couldn't be used reliably, since they weren't
generated at the start of suspend/end of resume, but instead at some
point in the middle of the procedures.   This CL moves when the
commands are sent from the AP to the EC to as early/late as possible
in an attempt to deterministically capture as much of each process as
possible.

While this patch could potentially be split, both the logging and PM
changes are means to the same end: improving logging behavior to make
it easier for developers to measure suspend/resume time and aid in
debugging.   This will make it easier to bisect CLs in the event of
regressions, as well as more deterministically verify optimizations
and improvements.

@Rob Barnes Please fill in any other gaps you think are relevant.


On Thu, Jul 14, 2022 at 12:34 PM Prashant Malani <pmalani@chromium.org> wrote:
>
> HI Tim,
>
> On Wed, Jul 6, 2022 at 7:51 PM Tim Van Patten <timvp@google.com> wrote:
> >
> > Update cros_ec_lpc_pm_ops to call cros_ec_lpc_suspend() during PM
> > .prepare() and cros_ec_lpc_resume() during .complete. This allows the
> > EC to log entry/exit of AP's suspend/resume more accurately.
> >
> > Signed-off-by: Tim Van Patten <timvp@google.com>
> > ---
> >
> > Changes in v2:
> > - Include cros_ec_resume() return value in dev_info() output.
> > - Guard setting .prepare/.complete with #ifdef CONFIG_PM_SLEEP.
> >
> >  drivers/platform/chrome/cros_ec_lpc.c | 14 +++++++++++---
> >  1 file changed, 11 insertions(+), 3 deletions(-)
> >
> > diff --git a/drivers/platform/chrome/cros_ec_lpc.c b/drivers/platform/chrome/cros_ec_lpc.c
> > index 7677ab3c0ead9..ce49fbc4ed2e1 100644
> > --- a/drivers/platform/chrome/cros_ec_lpc.c
> > +++ b/drivers/platform/chrome/cros_ec_lpc.c
> > @@ -534,19 +534,27 @@ static int cros_ec_lpc_suspend(struct device *dev)
> >  {
> >         struct cros_ec_device *ec_dev = dev_get_drvdata(dev);
> >
> > +       dev_info(dev, "Prepare EC suspend\n");
>
> This patch is doing 2 things:
> 1. Changing the timing of cros_ec_lpc_suspend()/resume() invocation.
> 2. Adding print logs for these callbacks.
>
> Whether 2.) is necessary is already being discussed, so I won't
> comment on that, but it sounds
> like this should be 2 different patches.
>
> Also, please explain what is wrong with "Previously, those events were sent when
> suspend/resume were already in progress." IOW, what issue is this
> solving, besides
> better ordering of EC logs.
>
> BR,
>
> -Prashant
Prashant Malani July 14, 2022, 9:51 p.m. UTC | #6
Hi Tim,

On Thu, Jul 14, 2022 at 1:55 PM Tim Van Patten <timvp@google.com> wrote:
>
> Hi,

Please avoid top-posting [1]

>
> We had issues measuring overall suspend and resume times, which this
> patch attempts to help resolve.   As stated in the description, the EC
> host command logs couldn't be used reliably, since they weren't
> generated at the start of suspend/end of resume, but instead at some
> point in the middle of the procedures.   This CL moves when the
> commands are sent from the AP to the EC to as early/late as possible
> in an attempt to deterministically capture as much of each process as
> possible.

If the timing of the EC host command logs is unreliable, why not add
new host commands specifically for this, and then call those at the moment(s)
you deem is more appropriate, instead of moving the suspend/resume itself
(which may be introducing its own timing ramifications)?

Calling such a theoretical new EC host command from the userspace power manager
would probably accomplish the same thing.

From the kernel documentation[2], "The prepare phase is meant to
prevent races by preventing new devices from being registered; the PM core
would never know that all the children of a device had been suspended if new
children could be registered at will." and "The method may also prepare the
device or driver in some way for the upcoming system power transition, but
it should not put the device into a low-power state."

So it seems like an incorrect usage of this callback.

>
> While this patch could potentially be split, both the logging and PM
> changes are means to the same end: improving logging behavior to make
> it easier for developers to measure suspend/resume time and aid in
> debugging.

That alone is not sufficient cause to combine 2 different changes into
a single patch.
The flip side is: the patch to move the suspend/resume host commands into
prepare/complete() can itself introduce regressions. We should be able to
revert that without touching the patch adding the logging (assuming concerns
regarding that are addressed).

BR,

-Prashant

[1] See "Top-posting" in https://people.kernel.org/tglx/
[2] https://kernel.org/doc/html/latest/driver-api/pm/devices.html#entering-system-suspend




> This will make it easier to bisect CLs in the event of
> regressions, as well as more deterministically verify optimizations
> and improvements.
>
> @Rob Barnes Please fill in any other gaps you think are relevant.
>
>
> On Thu, Jul 14, 2022 at 12:34 PM Prashant Malani <pmalani@chromium.org> wrote:
> >
> > HI Tim,
> >
> > On Wed, Jul 6, 2022 at 7:51 PM Tim Van Patten <timvp@google.com> wrote:
> > >
> > > Update cros_ec_lpc_pm_ops to call cros_ec_lpc_suspend() during PM
> > > .prepare() and cros_ec_lpc_resume() during .complete. This allows the
> > > EC to log entry/exit of AP's suspend/resume more accurately.
> > >
> > > Signed-off-by: Tim Van Patten <timvp@google.com>
> > > ---
> > >
> > > Changes in v2:
> > > - Include cros_ec_resume() return value in dev_info() output.
> > > - Guard setting .prepare/.complete with #ifdef CONFIG_PM_SLEEP.
> > >
> > >  drivers/platform/chrome/cros_ec_lpc.c | 14 +++++++++++---
> > >  1 file changed, 11 insertions(+), 3 deletions(-)
> > >
> > > diff --git a/drivers/platform/chrome/cros_ec_lpc.c b/drivers/platform/chrome/cros_ec_lpc.c
> > > index 7677ab3c0ead9..ce49fbc4ed2e1 100644
> > > --- a/drivers/platform/chrome/cros_ec_lpc.c
> > > +++ b/drivers/platform/chrome/cros_ec_lpc.c
> > > @@ -534,19 +534,27 @@ static int cros_ec_lpc_suspend(struct device *dev)
> > >  {
> > >         struct cros_ec_device *ec_dev = dev_get_drvdata(dev);
> > >
> > > +       dev_info(dev, "Prepare EC suspend\n");
> >
> > This patch is doing 2 things:
> > 1. Changing the timing of cros_ec_lpc_suspend()/resume() invocation.
> > 2. Adding print logs for these callbacks.
> >
> > Whether 2.) is necessary is already being discussed, so I won't
> > comment on that, but it sounds
> > like this should be 2 different patches.
> >
> > Also, please explain what is wrong with "Previously, those events were sent when
> > suspend/resume were already in progress." IOW, what issue is this
> > solving, besides
> > better ordering of EC logs.
> >
> > BR,
> >
> > -Prashant
>
>
>
> --
>
> Tim Van Patten | ChromeOS | timvp@google.com | (720) 432-0997
Tim Van Patten July 14, 2022, 10:17 p.m. UTC | #7
Hi,

> > We had issues measuring overall suspend and resume times, which this
> > patch attempts to help resolve.   As stated in the description, the EC
> > host command logs couldn't be used reliably, since they weren't
> > generated at the start of suspend/end of resume, but instead at some
> > point in the middle of the procedures.   This CL moves when the
> > commands are sent from the AP to the EC to as early/late as possible
> > in an attempt to deterministically capture as much of each process as
> > possible.
>
> If the timing of the EC host command logs is unreliable, why not add
> new host commands specifically for this, and then call those at the moment(s)
> you deem is more appropriate, instead of moving the suspend/resume itself
> (which may be introducing its own timing ramifications)?
>
> Calling such a theoretical new EC host command from the userspace power manager
> would probably accomplish the same thing.

We investigated something like that internally initially:
https://chromium-review.googlesource.com/c/chromiumos/third_party/kernel/+/3646238)

We decided to take this simpler approach instead, since it
accomplishes the same goal without requiring new host commands.

> From the kernel documentation[2], "The prepare phase is meant to
> prevent races by preventing new devices from being registered; the PM core
> would never know that all the children of a device had been suspended if new
> children could be registered at will." and "The method may also prepare the
> device or driver in some way for the upcoming system power transition, but
> it should not put the device into a low-power state."
>
> So it seems like an incorrect usage of this callback.

Why is this usage incorrect?

Sending the message to the EC is the preparation for the AP to enter
the system power transition.   For example, it allows the EC to begin
watchdogging the AP once the suspend begins and stop once the resume
completes. This allows the EC to watchdog the entire process, without
any gaps - a beneficial side effect of this change.

> > While this patch could potentially be split, both the logging and PM
> > changes are means to the same end: improving logging behavior to make
> > it easier for developers to measure suspend/resume time and aid in
> > debugging.
>
> That alone is not sufficient cause to combine 2 different changes into
> a single patch.
> The flip side is: the patch to move the suspend/resume host commands into
> prepare/complete() can itself introduce regressions. We should be able to
> revert that without touching the patch adding the logging (assuming concerns
> regarding that are addressed).

Keeping the logging while reverting the PM change would be misleading
to developers while debugging, since the log messages are no longer
indicating the start/end of suspend/resume.

Regardless, I can move them into a separate patch if this necessary.
Prashant Malani July 14, 2022, 11:33 p.m. UTC | #8
On Thu, Jul 14, 2022 at 3:17 PM Tim Van Patten <timvp@google.com> wrote:
>
> Hi,
>
> > Calling such a theoretical new EC host command from the userspace power manager
> > would probably accomplish the same thing.
>
> We investigated something like that internally initially:
> https://chromium-review.googlesource.com/c/chromiumos/third_party/kernel/+/3646238)
>
> We decided to take this simpler approach instead, since it
> accomplishes the same goal without requiring new host commands.

- That link discusses updating the existing host command and the EC
implementations;
have you investigated adding a command for logging needs and calling it from
power_manager/powerd directly?
- That link addresses several busses (UART, SPI etc.) whereas this patch only
touches LPC. Is this intentional?

>
> > From the kernel documentation[2], "The prepare phase is meant to
> > prevent races by preventing new devices from being registered; the PM core
> > would never know that all the children of a device had been suspended if new
> > children could be registered at will." and "The method may also prepare the
> > device or driver in some way for the upcoming system power transition, but
> > it should not put the device into a low-power state."
> >
> > So it seems like an incorrect usage of this callback.
>
> Why is this usage incorrect?
>
> Sending the message to the EC is the preparation for the AP to enter
> the system power transition. For example, it allows the EC to begin
> watchdogging the AP once the suspend begins and stop once the resume
> completes. This allows the EC to watchdog the entire process, without
> any gaps - a beneficial side effect of this change.

OK. Is that all it does? Does this not allow the EC itself to enter a
deep sleep state,
or put connected peripherals and/or state machines in a low power state??

If you're still set on this approach, please update the function names;
setting the .prepare()/.complete() function pointers to
cros_ec_lpc_suspend/resume()
is inconsistent, if those functions aren't being used elsewhere in the file.

BR,

-Prashant
Tim Van Patten Aug. 1, 2022, 11:33 p.m. UTC | #9
Hi,

Sorry for the slow reply here, but I wanted to talk with Rob and Raul
to verify my understanding of the EC/AP behavior, as well as run some
additional testing.   I'll send out a new version with the updated
function names, but the rest of the patch is essentially the same.

> > > Calling such a theoretical new EC host command from the userspace power manager
> > > would probably accomplish the same thing.
> >
> > We investigated something like that internally initially:
> > https://chromium-review.googlesource.com/c/chromiumos/third_party/kernel/+/3646238)
> >
> > We decided to take this simpler approach instead, since it
> > accomplishes the same goal without requiring new host commands.
>
> - That link discusses updating the existing host command and the EC
> implementations;
> have you investigated adding a command for logging needs and calling it from
> power_manager/powerd directly?

That link is the only other investigation we've done.   We don't want
to add another host command just for logging since we already have one
that serves our purposes.

> - That link addresses several busses (UART, SPI etc.) whereas this patch only
> touches LPC. Is this intentional?

Yes, this is intentionally only focusing on the LPC EC. The LPC EC is
the only one we are interested in, as well as the only one we can
explicitly test.    The other ECs can be updated in the future if
necessary, but we don't want to introduce the possibility of unknown
side effects for platforms we can't verify.

> >
> > > From the kernel documentation[2], "The prepare phase is meant to
> > > prevent races by preventing new devices from being registered; the PM core
> > > would never know that all the children of a device had been suspended if new
> > > children could be registered at will." and "The method may also prepare the
> > > device or driver in some way for the upcoming system power transition, but
> > > it should not put the device into a low-power state."
> > >
> > > So it seems like an incorrect usage of this callback.
> >
> > Why is this usage incorrect?
> >
> > Sending the message to the EC is the preparation for the AP to enter
> > the system power transition. For example, it allows the EC to begin
> > watchdogging the AP once the suspend begins and stop once the resume
> > completes. This allows the EC to watchdog the entire process, without
> > any gaps - a beneficial side effect of this change.
>
> OK. Is that all it does? Does this not allow the EC itself to enter a
> deep sleep state,
> or put connected peripherals and/or state machines in a low power state??

The only work triggered by host command is starting/stopping the EC's
watchdogging of the AP. The work of monitoring/manipulating any other
power states is triggered by interrupts from the power signal changes
themselves.   To verify this, I removed the host command and EC
watchdogging and validated that suspend/resume behaves the same.

> If you're still set on this approach, please update the function names;
> setting the .prepare()/.complete() function pointers to
> cros_ec_lpc_suspend/resume()
> is inconsistent, if those functions aren't being used elsewhere in the file.

Done in the next patch version.

The only other thing not mentioned here is the logging that was added.

Here are the log messages without this change:
[   97.896425] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_suspend+0x0/0x55 @ 4582, parent: PNP0C09:00
[   97.896427] cros_ec_lpcs GOOG0004:00: acpi_subsys_suspend+0x0/0x55
returned 0 after 0 usecs
[   98.021116] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_suspend_late+0x0/0x4e @ 4582, parent: PNP0C09:00
[   98.021879] cros_ec_lpcs GOOG0004:00:
acpi_subsys_suspend_late+0x0/0x4e returned 0 after 741 usecs
[   98.127753] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_suspend_noirq+0x0/0x45 @ 4582, parent: PNP0C09:00
[   98.127757] cros_ec_lpcs GOOG0004:00:
acpi_subsys_suspend_noirq+0x0/0x45 returned 0 after 0 usecs
[  111.216731] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_resume_noirq+0x0/0x25 @ 4582, parent: PNP0C09:00
[  111.216746] cros_ec_lpcs GOOG0004:00:
acpi_subsys_resume_noirq+0x0/0x25 returned 0 after 0 usecs
[  111.243019] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_resume_early+0x0/0x67 @ 4582, parent: PNP0C09:00
[  111.246131] cros_ec_lpcs GOOG0004:00:
acpi_subsys_resume_early+0x0/0x67 returned 0 after 3035 usecs
[  111.247008] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_resume+0x0/0x56 @ 4582, parent: PNP0C09:00
[  111.247011] cros_ec_lpcs GOOG0004:00: acpi_subsys_resume+0x0/0x56
returned 0 after 0 usecs

Here are the log messages with the change:
[ 5510.348705] cros_ec_lpcs GOOG0004:00: Prepare EC suspend
[ 5510.352958] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_suspend+0x0/0x55 @ 17033, parent: PNP0C09:00
[ 5510.352960] cros_ec_lpcs GOOG0004:00: acpi_subsys_suspend+0x0/0x55
returned 0 after 0 usecs
[ 5510.463143] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_suspend_late+0x0/0x4e @ 17033, parent: PNP0C09:00
[ 5510.463165] cros_ec_lpcs GOOG0004:00:
acpi_subsys_suspend_late+0x0/0x4e returned 0 after 16 usecs
[ 5510.550825] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_suspend_noirq+0x0/0x45 @ 17033, parent: PNP0C09:00
[ 5510.550828] cros_ec_lpcs GOOG0004:00:
acpi_subsys_suspend_noirq+0x0/0x45 returned 0 after 0 usecs
[ 5518.065012] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_resume_noirq+0x0/0x25 @ 17033, parent: PNP0C09:00
[ 5518.065036] cros_ec_lpcs GOOG0004:00:
acpi_subsys_resume_noirq+0x0/0x25 returned 0 after 0 usecs
[ 5518.089437] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_resume_early+0x0/0x67 @ 17033, parent: PNP0C09:00
[ 5518.089455] cros_ec_lpcs GOOG0004:00:
acpi_subsys_resume_early+0x0/0x67 returned 0 after 0 usecs
[ 5518.090774] cros_ec_lpcs GOOG0004:00: calling
acpi_subsys_resume+0x0/0x56 @ 17033, parent: PNP0C09:00
[ 5518.090784] cros_ec_lpcs GOOG0004:00: acpi_subsys_resume+0x0/0x56
returned 0 after 6 usecs
[ 5518.386462] cros_ec_lpcs GOOG0004:00: EC resume completed: ret = 0

PM will call each driver regardless of whether there's anything to do
(note that the calls "complete" in 0usec), which results in a lot of
unnecessary output.   However, PM doesn't log .prepare()/.complete()
calls, so while previously we got the logging for free (due to PM
performing it for us), we need to add logging to know when the
.prepare()/.complete() calls are made.   This is why we'd like to keep
the logging, even if it's in a separate patch.

--

Tim Van Patten | ChromeOS | timvp@google.com | (720) 432-0997
diff mbox series

Patch

diff --git a/drivers/platform/chrome/cros_ec_lpc.c b/drivers/platform/chrome/cros_ec_lpc.c
index 7677ab3c0ead9..ce49fbc4ed2e1 100644
--- a/drivers/platform/chrome/cros_ec_lpc.c
+++ b/drivers/platform/chrome/cros_ec_lpc.c
@@ -534,19 +534,27 @@  static int cros_ec_lpc_suspend(struct device *dev)
 {
 	struct cros_ec_device *ec_dev = dev_get_drvdata(dev);
 
+	dev_info(dev, "Prepare EC suspend\n");
+
 	return cros_ec_suspend(ec_dev);
 }
 
-static int cros_ec_lpc_resume(struct device *dev)
+static void cros_ec_lpc_resume(struct device *dev)
 {
 	struct cros_ec_device *ec_dev = dev_get_drvdata(dev);
+	int ret;
+
+	ret = cros_ec_resume(ec_dev);
 
-	return cros_ec_resume(ec_dev);
+	dev_info(dev, "EC resume completed: ret = %d\n", ret);
 }
 #endif
 
 static const struct dev_pm_ops cros_ec_lpc_pm_ops = {
-	SET_LATE_SYSTEM_SLEEP_PM_OPS(cros_ec_lpc_suspend, cros_ec_lpc_resume)
+#ifdef CONFIG_PM_SLEEP
+	.prepare = cros_ec_lpc_suspend,
+	.complete = cros_ec_lpc_resume
+#endif
 };
 
 static struct platform_driver cros_ec_lpc_driver = {