Lid switch triggered suspend takes much longer than UI triggered suspend

Bug #1829399 reported by Chris Gregan on 2019-05-16

This bug report will be marked for expiration in 56 days if no further activity occurs. (find out why)

8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
linux (Ubuntu)
Undecided
Unassigned

Bug Description

IBM T460
5.0.0-13-generic #14-Ubuntu SMP Mon Apr 15 14:59:14 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux

When triggering a suspend even from the lid switch of my Lenovo T460 it takes 30 seconds to reach suspend state. Several others with different models of Lenovo laptops have also reproduced this issue.

It seems this is isolated to the lid switch as UI triggered suspend (alt+power icon) is far faster.

Chris Gregan (cgregan) wrote :
Chris Gregan (cgregan) wrote :

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1829399

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

Changed in linux (Ubuntu):
status: New → Incomplete
tags: added: disco
Andrea Righi (arighi) wrote :

Hi Chris, just to make sure I understand (from a kernel perspective), can you confirm that `echo mem > /sys/power/state` is also fast at reaching the suspend state?

In that case it would be interesting to check if there's a delay at detecting the state of the lid switch. For this, could you run the following command in a bash session:

$ while :; do echo `date` - `cat /proc/acpi/button/lid/LID0/state`; sleep 1; done

Close the lid, re-open it and you should notice something like this:

Thu May 16 17:50:42 CEST 2019 - state: open
Thu May 16 17:50:43 CEST 2019 - state: open
Thu May 16 17:50:44 CEST 2019 - state: open
Thu May 16 17:50:45 CEST 2019 - state: closed
Thu May 16 17:50:46 CEST 2019 - state: closed
Thu May 16 17:50:47 CEST 2019 - state: closed
Thu May 16 17:50:48 CEST 2019 - state: open
Thu May 16 17:50:49 CEST 2019 - state: open
Thu May 16 17:50:50 CEST 2019 - state: open
^C

Note that I have set the "lid close action" to do nothing, in this way we can better isolate the problem. Thanks.

This is interesting.

`echo mem > /sys/power/state`
This command was instant S3. The screen went black and the power light
immediately began to blink.

However...for lid switch the power light takes around 10 seconds to begin
to pulse, but the state immediately switches.

Fri 17 May 2019 09:48:22 AM CEST - state: open
Fri 17 May 2019 09:48:23 AM CEST - state: open
Fri 17 May 2019 09:48:24 AM CEST - state: open
Fri 17 May 2019 09:48:25 AM CEST - state: closed
Fri 17 May 2019 09:48:26 AM CEST - state: closed
Fri 17 May 2019 09:48:27 AM CEST - state: closed

It seems although detection if immediate, it takes 10 seconds to process?

On Thu, May 16, 2019 at 6:05 PM Andrea Righi <email address hidden>
wrote:

> Hi Chris, just to make sure I understand (from a kernel perspective),
> can you confirm that `echo mem > /sys/power/state` is also fast at
> reaching the suspend state?
>
> In that case it would be interesting to check if there's a delay at
> detecting the state of the lid switch. For this, could you run the
> following command in a bash session:
>
> $ while :; do echo `date` - `cat /proc/acpi/button/lid/LID0/state`;
> sleep 1; done
>
> Close the lid, re-open it and you should notice something like this:
>
> Thu May 16 17:50:42 CEST 2019 - state: open
> Thu May 16 17:50:43 CEST 2019 - state: open
> Thu May 16 17:50:44 CEST 2019 - state: open
> Thu May 16 17:50:45 CEST 2019 - state: closed
> Thu May 16 17:50:46 CEST 2019 - state: closed
> Thu May 16 17:50:47 CEST 2019 - state: closed
> Thu May 16 17:50:48 CEST 2019 - state: open
> Thu May 16 17:50:49 CEST 2019 - state: open
> Thu May 16 17:50:50 CEST 2019 - state: open
> ^C
>
> Note that I have set the "lid close action" to do nothing, in this way
> we can better isolate the problem. Thanks.
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1829399
>
> Title:
> Lid switch triggered suspend takes much longer than UI triggered
> suspend
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1829399/+subscriptions
>

--

Chris Gregan
Engineering Manager
Solutions QA/Techops
<email address hidden>

Chris Gregan (cgregan) wrote :
Download full text (4.3 KiB)

Looks like it was actually longer than 10 seconds as I opened the lid 1 sec
after the power light began to pulse.

Fri 17 May 2019 09:48:20 AM CEST - state: open
Fri 17 May 2019 09:48:21 AM CEST - state: open
Fri 17 May 2019 09:48:22 AM CEST - state: open
Fri 17 May 2019 09:48:23 AM CEST - state: open
Fri 17 May 2019 09:48:24 AM CEST - state: open
Fri 17 May 2019 09:48:25 AM CEST - state: closed
Fri 17 May 2019 09:48:26 AM CEST - state: closed
Fri 17 May 2019 09:48:27 AM CEST - state: closed
Fri 17 May 2019 09:48:28 AM CEST - state: closed
Fri 17 May 2019 09:48:29 AM CEST - state: closed
Fri 17 May 2019 09:48:30 AM CEST - state: closed
Fri 17 May 2019 09:48:31 AM CEST - state: closed
Fri 17 May 2019 09:48:33 AM CEST - state: closed
Fri 17 May 2019 09:48:34 AM CEST - state: closed
Fri 17 May 2019 09:48:35 AM CEST - state: closed
Fri 17 May 2019 09:48:36 AM CEST - state: closed
Fri 17 May 2019 09:48:37 AM CEST - state: closed
Fri 17 May 2019 09:48:38 AM CEST - state: closed
Fri 17 May 2019 09:48:39 AM CEST - state: closed
Fri 17 May 2019 09:48:40 AM CEST - state: closed
Fri 17 May 2019 09:48:41 AM CEST - state: closed
Fri 17 May 2019 09:48:42 AM CEST - state: closed
Fri 17 May 2019 09:48:43 AM CEST - state: closed
Fri 17 May 2019 09:48:44 AM CEST - state: closed
Fri 17 May 2019 09:48:45 AM CEST - state: closed
Fri 17 May 2019 09:48:46 AM CEST - state: closed
Fri 17 May 2019 09:48:47 AM CEST - state: closed
Fri 17 May 2019 09:48:48 AM CEST - state: closed
Fri 17 May 2019 09:48:49 AM CEST - state: closed
Fri 17 May 2019 09:48:50 AM CEST - state: closed
Fri 17 May 2019 09:48:51 AM CEST - state: closed
Fri 17 May 2019 09:48:52 AM CEST - state: closed
Fri 17 May 2019 09:48:53 AM CEST - state: closed
Fri 17 May 2019 09:48:54 AM CEST - state: closed
Fri 17 May 2019 09:48:55 AM CEST - state: closed
Fri 17 May 2019 09:49:00 AM CEST - state: open
Fri 17 May 2019 09:49:02 AM CEST - state: open
Fri 17 May 2019 09:49:03 AM CEST - state: open
^C

On Fri, May 17, 2019 at 9:52 AM Chris Gregan <email address hidden>
wrote:

> This is interesting.
>
> `echo mem > /sys/power/state`
> This command was instant S3. The screen went black and the power light
> immediately began to blink.
>
> However...for lid switch the power light takes around 10 seconds to begin
> to pulse, but the state immediately switches.
>
> Fri 17 May 2019 09:48:22 AM CEST - state: open
> Fri 17 May 2019 09:48:23 AM CEST - state: open
> Fri 17 May 2019 09:48:24 AM CEST - state: open
> Fri 17 May 2019 09:48:25 AM CEST - state: closed
> Fri 17 May 2019 09:48:26 AM CEST - state: closed
> Fri 17 May 2019 09:48:27 AM CEST - state: closed
>
> It seems although detection if immediate, it takes 10 seconds to process?
>
> On Thu, May 16, 2019 at 6:05 PM Andrea Righi <email address hidden>
> wrote:
>
>> Hi Chris, just to make sure I understand (from a kernel perspective),
>> can you confirm that `echo mem > /sys/power/state` is also fast at
>> reaching the suspend state?
>>
>> In that case it would be interesting to check if there's a delay at
>> detecting the state of the lid switch. For this, could you run the
>> following command in a bash session:
>>
>> $ while :; do echo `date` - `cat ...

Read more...

Andrea Righi (arighi) wrote :

Alright, the fact that `echo mem > /sys/power/state` is fast means that the delay issue is not in the "suspend" path and we also know that it's not even in the detection path (/proc/acpi/button/lid/LID0/state). So the delay must be somewhere between the detection of the event and the delivery of the proper suspend action, that should be driven by systemd, more exactly systemd-logind.

At this point I think it would interesting to take a look at journalctl, more exactly the timestamps and messages around a line like "systemd-logind[...]: Lid closed.". This should give us an idea how fast systemd detected the event and how fast it processed it.

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers