Contribute
Register

Laptop won't sleep/shutdown after a few hours of uptime

Status
Not open for further replies.

vbo

Joined
Jul 13, 2014
Messages
284
Here's a weird one: I have perfect sleep/restart/shutdown on my laptop as long as I don't use it for too long :)
After a few hours of uptime (makes no sense but I want to say the cutoff is about 2 or 3 hours), the laptop freezes on sleep/shutdown (screen goes dark, network interface goes down, but keyboard backlight still on). If I instead try to restart after a few hours, the laptop shuts down.

Since I thought it might be an ACPI issue, I traced _PTS with RehabMan's ACPIDebug kext. Works fine (enters and exits) when I sleep any number of times before a couple hours of uptime. After that, _PTS enter isn't even logged.

I then added a _TTS method since it's called earlier in the sleep process per the ACPI specs:
Normal:
Code:
Nov  6 18:22:51 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x3, }
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: { "_PTS enter", 0x3, }
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: "_PTS exit"
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: { "_WAK enter", 0x3, }
Nov  6 18:39:49 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x0, }
After a few hours:
Code:
Nov  6 21:25:19 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x3, }
Nov  6 21:33:50 localhost bootlog[0]: BOOT_TIME 1415327630 0
(The ACPIDebug log is literally the last line logged before I had to force shutdown and reboot manually).

I'm attaching the 2 full sleep traces above, as well as a copy of my patched dsdt in case anyone has any idea how to proceed. I just have no idea how to start debugging this.
 

Attachments

  • sleep_ok.txt
    9.6 KB · Views: 370
  • sleep_nok.txt
    2.9 KB · Views: 267
  • dsdt.dsl.zip
    44 KB · Views: 217

RehabMan

Moderator
Joined
May 3, 2012
Messages
186,727
Motherboard
Intel DH67BL
CPU
i7-2600K
Graphics
HD 3000
Mac
  1. MacBook Air
Mobile Phone
  1. iOS
Here's a weird one: I have perfect sleep/restart/shutdown on my laptop as long as I don't use it for too long :)
After a few hours of uptime (makes no sense but I want to say the cutoff is about 2 or 3 hours), the laptop freezes on sleep/shutdown (screen goes dark, network interface goes down, but keyboard backlight still on). If I instead try to restart after a few hours, the laptop shuts down.

Since I thought it might be an ACPI issue, I traced _PTS with RehabMan's ACPIDebug kext. Works fine (enters and exits) when I sleep any number of times before a couple hours of uptime. After that, _PTS enter isn't even logged.

I then added a _TTS method since it's called earlier in the sleep process per the ACPI specs:
Normal:
Code:
Nov  6 18:22:51 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x3, }
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: { "_PTS enter", 0x3, }
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: "_PTS exit"
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: { "_WAK enter", 0x3, }
Nov  6 18:39:49 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x0, }
After a few hours:
Code:
Nov  6 21:25:19 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x3, }
Nov  6 21:33:50 localhost bootlog[0]: BOOT_TIME 1415327630 0
(The ACPIDebug log is literally the last line logged before I had to force shutdown and reboot manually).

One problem with using ACPIDebug for actions which result in a lockup (or inability to wake from sleep), is that ACPIDebug.kext doesn't get a chance to poll the RMDT device to check for new logs. Since you can't communicate directly/immediately from ACPI to a kext, the RMDT maintains a FIFO queue, and ACPIDebug polls for additions to that queue every 100ms, clearing them as they are logged. If the system crashes before ACPIDebug has a chance to check for them, then the logs are simply lost. This makes ACPIDebug not a great tool for such scenarios. It would be better if we had a way to immediately log output from ACPI.
 

vbo

Joined
Jul 13, 2014
Messages
284
One problem with using ACPIDebug for actions which result in a lockup (or inability to wake from sleep), is that ACPIDebug.kext doesn't get a chance to poll the RMDT device to check for new logs. Since you can't communicate directly/immediately from ACPI to a kext, the RMDT maintains a FIFO queue, and ACPIDebug polls for additions to that queue every 100ms, clearing them as they are logged. If the system crashes before ACPIDebug has a chance to check for them, then the logs are simply lost. This makes ACPIDebug not a great tool for such scenarios. It would be better if we had a way to immediately log output from ACPI.
Understood. Have you ever seen something like this in your experience where the difference between working and non-working features seems to be based on system uptime? Any pointers where to start looking?

Actually I just noticed in the timestamps that I posted above that _WAK is entered immediately after _PTS exits, even though the actual wake event is 15 minutes later. Here's the same log with a the wake reason timestamp added in:
Code:
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: { "_PTS enter", 0x3, }
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: "_PTS exit"
Nov  6 [B]18:22:52[/B] mba kernel[0]: ACPIDebug: { "_WAK enter", 0x3, }
Nov  6 [B]18:39:48[/B] mba kernel[0]: Wake reason: PWRB EHC2 XHC (User)
Nov  6 18:39:48 mba kernel[0]: No interval found for . Using 8000000
Nov  6 18:39:48 mba kernel[0]: Previous sleep cause: 5
...
Nov  6 18:39:49 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x0, }
 

RehabMan

Moderator
Joined
May 3, 2012
Messages
186,727
Motherboard
Intel DH67BL
CPU
i7-2600K
Graphics
HD 3000
Mac
  1. MacBook Air
Mobile Phone
  1. iOS
Understood. Have you ever seen something like this in your experience where the difference between working and non-working features seems to be based on system uptime? Any pointers where to start looking?

Actually I just noticed in the timestamps that I posted above that _WAK is entered immediately after _PTS exits, even though the actual wake event is 15 minutes later. Here's the same log with a the wake reason timestamp added in:
Code:
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: { "_PTS enter", 0x3, }
Nov  6 18:22:52 mba kernel[0]: ACPIDebug: "_PTS exit"
Nov  6 [B]18:22:52[/B] mba kernel[0]: ACPIDebug: { "_WAK enter", 0x3, }
Nov  6 [B]18:39:48[/B] mba kernel[0]: Wake reason: PWRB EHC2 XHC (User)
Nov  6 18:39:48 mba kernel[0]: No interval found for . Using 8000000
Nov  6 18:39:48 mba kernel[0]: Previous sleep cause: 5
...
Nov  6 18:39:49 mba kernel[0]: ACPIDebug: { "_TTS enter with state", 0x0, }

That's pretty weird. Almost hard to believe. I find I can't trust the order of system.log output (from IOLog). I've seen IOLog mix up the order (a bit of an edge case... calling IOLog from an interrupt handler, but...)
 

vbo

Joined
Jul 13, 2014
Messages
284
That's pretty weird. Almost hard to believe. I find I can't trust the order of system.log output (from IOLog). I've seen IOLog mix up the order (a bit of an edge case... calling IOLog from an interrupt handler, but...)

Weird indeed. And I'm not sure it's related to the real freeze issue, since when these occur _PTS isn't even reached, let alone _WAK (unless as you mentioned the freezes occur just before the kext has a chance to poll).
I'll keep poking around - if you have any ideas, let me know.
 

RehabMan

Moderator
Joined
May 3, 2012
Messages
186,727
Motherboard
Intel DH67BL
CPU
i7-2600K
Graphics
HD 3000
Mac
  1. MacBook Air
Mobile Phone
  1. iOS
Weird indeed. And I'm not sure it's related to the real freeze issue, since when these occur _PTS isn't even reached, let alone _WAK (unless as you mentioned the freezes occur just before the kext has a chance to poll).

It is hard to prove that (quoted bold ^^^) given that you don't know whether they weren't reached, or their output was never noticed by ACPIDebug and never logged via IOLog.
 

vbo

Joined
Jul 13, 2014
Messages
284
Update: After noticing that _WAK was never exiting (laptop seemed happy enough waking this way though), I tracked that one down to my mistake of not renaming B0D3 to HDAU in the DSDT to balance the changes in the graphics ssdt. With that out of the way, _WAK was exiting but I lost trackpad on wake.. 1 step forward, 1 step back :)
I traced that issue down to this innocuous instruction:
Code:
 Store (OSTY, \_SB.PCI0.LPCB.EC0.ACOS)
(For the curious minded, OSTY is an index into the main GNVS operation region, and ACOS is part of the EC as shown above. Both are initialized to the same values based on different OS signature in _REG method of EC0, but since there's no initialization values for the windows 2006/Darwin OSYS, they must be left uninitialized. Somehow storing whatever is in OSTY in EC0 ACOS on wake wasn't playing nice with the trackpad).
Anyhoo, I removed that statement and now all is well: _WAK exits and trackpad is happy.

Since it's way too hard to diagnose exactly what happens over the course of 2 or 3 hours to trigger a lockup on sleep/shutdown, I'm just hacking away at parts of the DSDT, testing that it doesn't break anything on normal sleep/shutdown. I removed the WMI device definition and the 120+ references to it in _Qxx methods (thank heavens for patchmatic) as that seems like a good candidate to mess things up. Now that I'm looking into the dsdt more closely, there's a bunch of device definitions in there that do mot match the hardware on this machine, like a dozen different trackpads, a lan controller, a SDHC card reader, etc.. but these probably don't hurt as they're likely not called?

RehabMan: Do you remember what VPC0 device is (PNP id?) on your U430 (I see you delete it in your remove_wmi patch)? I'm in a deleting stuffs mood!
 

RehabMan

Moderator
Joined
May 3, 2012
Messages
186,727
Motherboard
Intel DH67BL
CPU
i7-2600K
Graphics
HD 3000
Mac
  1. MacBook Air
Mobile Phone
  1. iOS
... but since there's no initialization values for the windows 2006/Darwin OSYS, they must be left uninitialized. Somehow storing whatever is in OSTY in EC0 ACOS on wake wasn't playing nice with the trackpad).

Either that or your SystemMemory regions are floating and so you have garbage there (probably all FF).

... dozen different trackpads, a lan controller, a SDHC card reader, etc.. but these probably don't hurt as they're likely not called?

Correct.

RehabMan: Do you remember what VPC0 device is (PNP id?) on your U430 (I see you delete it in your remove_wmi patch)? I'm in a deleting stuffs mood!

It is a sink for Notifies (originating from EC queries). On Windows, the hotkey driver would connect to it to make the various special Fn+ keys work.
 

vbo

Joined
Jul 13, 2014
Messages
284
It is a sink for Notifies (originating from EC queries). On Windows, the hotkey driver would connect to it to make the various special Fn+ keys work.
Thanks - seems like on this particular machine it's handled directly by the WMI device as I removed ~25 Notify to the WMI in _Qxx after deleting the device.
I'll let the laptop run for a few hours and see how it goes with these changes.
 

RehabMan

Moderator
Joined
May 3, 2012
Messages
186,727
Motherboard
Intel DH67BL
CPU
i7-2600K
Graphics
HD 3000
Mac
  1. MacBook Air
Mobile Phone
  1. iOS
Thanks - seems like on this particular machine it's handled directly by the WMI device as I removed ~25 Notify to the WMI in _Qxx after deleting the device.
I'll let the laptop run for a few hours and see how it goes with these changes.

The WMI device is not used on OS X. Your deletions in patched files used on OS X will not affect the ACPI used on Windows.
 
Status
Not open for further replies.
Top