Jeffrey reported the following over email: "A couple of months ago, I noticed that the entry into sleep mode for my ASUS C100P (Flip) had become unreliable. Whenever I close the lid, the screen goes black as expected. However, sometimes the laptop stays on instead of going to sleep, even when the screen goes black.

When this happens and I open the lid, the screen turns on and the laptop works normally -- exactly like it does when the laptop had entered sleep successfully. However, when sleep is malfunctioning, I notice that the laptop becomes warm in my bag and the battery is eventually drained.

Sometimes, when the laptop is in sleep mode, I notice that the power light is blinking irregularly (blinking slows down and then speeds up) rather than at a steady frequency. I'm not sure if this is related.

How should I begin troubleshooting this -- does it sound like an OEM issue or a Chrome OS issue? The screen always turns off, so the switch isn't to blame."

Followed by http://feedback/#/Report/73709912719 from a device on 60.0.3112.114: "Laptop lid closed around 6:40 PM PDT [on September 19]. Took laptop out of bag at 11:17 PDT, and it was warm and still turned on."

The powerd.LATEST file is so long that the feedback only contains the tail end of it, starting at 22:12:10. That's enough to see that the laptop has its lid closed and is stuck in the following cycle, though:

1. powerd tries to suspend due to the lid being closed.
2. powerd_suspend fails with exit code 2 (wake event received).
3. powerd tries to suspend again.
4. powerd_suspend exits with 0 (success) 2-3 seconds later.
5. powerd sees that the lid is still closed and goes back to 1.

Here's what that looks like in the logs:

[0919/221308:INFO:state_controller.cc(931)] Ready to perform lid-closed action (suspend)
[0919/221308:INFO:suspender.cc(402)] Starting request 76625373
[0919/221308:INFO:daemon.cc(602)] Reading wakeup count from /sys/power/wakeup_count
[0919/221308:INFO:daemon.cc(606)] Read wakeup count 55582
[0919/221308:INFO:internal_backlight_controller.cc(699)] Setting resume brightness to 253 (100%)
[0919/221308:INFO:suspend_delay_controller.cc(140)] Announcing suspend request 76625373 with 2 pending delay(s) and 0 outstanding delay(s) from previous request
[0919/221308:INFO:daemon.cc(777)] On battery at 55%, 3.892/7.130Ah at 0.035A, 0s until empty (calculating)
[0919/221308:INFO:suspend_delay_controller.cc(86)] Got notification that delay 76611585 (shill) is ready for suspend request 76625373 from :1.9
[0919/221308:INFO:suspend_delay_controller.cc(86)] Got notification that delay 76611590 (chrome) is ready for suspend request 76625373 from :1.6887
[0919/221308:INFO:suspend_delay_controller.cc(232)] Notifying observers that suspend is ready
[0919/221308:INFO:suspender.cc(473)] Starting suspend
[0919/221308:INFO:main.cc(257)] Running "/usr/bin/powerd_setuid_helper --action=mosys_eventlog --mosys_eventlog_code=0xa7"
[0919/221310:INFO:main.cc(257)] Running "/usr/bin/powerd_setuid_helper --action=suspend  --suspend_wakeup_count_valid --suspend_wakeup_count=55582"
[0919/221311:ERROR:main.cc(263)] Command failed with exit status 2
[0919/221311:INFO:daemon.cc(698)] powerd_suspend returned 2
[0919/221311:INFO:main.cc(238)] Launching "/usr/bin/powerd_setuid_helper --action=mosys_eventlog --mosys_eventlog_code=0xa8"
[0919/221311:WARNING:suspender.cc(559)] Suspend attempt #1 canceled due to wake event
[0919/221321:INFO:suspender.cc(473)] Starting suspend
[0919/221321:INFO:main.cc(257)] Running "/usr/bin/powerd_setuid_helper --action=mosys_eventlog --mosys_eventlog_code=0xa7"
[0919/221322:INFO:main.cc(257)] Running "/usr/bin/powerd_setuid_helper --action=suspend"
[0919/221324:INFO:daemon.cc(698)] powerd_suspend returned 0
[0919/221324:INFO:main.cc(238)] Launching "/usr/bin/powerd_setuid_helper --action=mosys_eventlog --mosys_eventlog_code=0xa8"
[0919/221324:INFO:suspender.cc(429)] Finishing request 76625373 successfully
[0919/221324:INFO:state_controller.cc(362)] Lid still closed after resuming from lid-close-triggered suspend; repeating lid-closed action
[0919/221324:INFO:state_controller.cc(931)] Ready to perform lid-closed action (suspend)
...

Here's what /var/log/messages contains (including the point where I think the kernel switched from suspending to resuming):

...
2017-09-19T23:16:35.163100-07:00 INFO kernel: [161289.295502] calling  ff930000.vop+ @ 10313, parent: none, cb: pm_genpd_suspend_noirq
2017-09-19T23:16:35.163102-07:00 INFO kernel: [161289.295574] call ff930000.vop+ returned 0 after 61 usecs
2017-09-19T23:16:35.163107-07:00 INFO kernel: [161289.295597] PM: noirq suspend of devices complete after 0.589 msecs
2017-09-19T23:16:35.163109-07:00 NOTICE kernel: [161289.295604] Disabling non-boot CPUs ...
2017-09-19T23:16:35.163112-07:00 NOTICE kernel: [161289.296250] CPU1: shutdown
2017-09-19T23:16:35.163114-07:00 NOTICE kernel: [161289.298109] CPU2: shutdown
2017-09-19T23:16:35.163116-07:00 NOTICE kernel: [161289.299911] CPU3: shutdown
2017-09-19T23:16:35.163118-07:00 INFO kernel: [161289.301369] Enabling non-boot CPUs ...
2017-09-19T23:16:35.163120-07:00 NOTICE kernel: [161289.302561] CPU1: Booted secondary processor
2017-09-19T23:16:35.163122-07:00 INFO kernel: [161289.302773] CPU1 is up
2017-09-19T23:16:35.163127-07:00 NOTICE kernel: [161289.303914] CPU2: Booted secondary processor
2017-09-19T23:16:35.163129-07:00 INFO kernel: [161289.304091] CPU2 is up
2017-09-19T23:16:35.163131-07:00 NOTICE kernel: [161289.305268] CPU3: Booted secondary processor
2017-09-19T23:16:35.163133-07:00 INFO kernel: [161289.305484] CPU3 is up
2017-09-19T23:16:35.163135-07:00 INFO kernel: [161289.305521] calling  ff930000.vop+ @ 10313, parent: none, cb: pm_genpd_resume_noirq
...
2017-09-19T23:16:35.169601-07:00 INFO kernel: [161289.678352] PM: resume of devices complete after 371.844 msecs
2017-09-19T23:16:35.169604-07:00 DEBUG kernel: [161289.678660] PM: Finishing wakeup.
2017-09-19T23:16:35.169605-07:00 NOTICE kernel: [161289.678664] Restarting tasks ... 
2017-09-19T23:16:35.169610-07:00 ERR kernel: [161289.681938] elants_i2c 3-0010: unknown packet ff ff ff ff
2017-09-19T23:16:35.176206-07:00 NOTICE kernel: [161289.687619] done.
2017-09-19T23:16:35.176225-07:00 INFO kernel: [161289.687692] PM: suspend exit 2017-09-20 06:16:35.169695167 UTC
2017-09-19T23:16:35.177369-07:00 NOTICE powerd_suspend[10319]: wake source: unknown
2017-09-19T23:16:35.194098-07:00 NOTICE powerd_suspend[10325]: Resume finished
...

I don't know what was causing this. Anyone else know?

We discussed a workaround at issue 624203 last year, which I suspect I should implement since this can clearly still happen and the user experience when it does is terrible. :-(