Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MacBook Pro sleep failed with IINA open but video stoped #4354

Closed
1 task
songzhao831 opened this issue Apr 16, 2023 · 9 comments
Closed
1 task

MacBook Pro sleep failed with IINA open but video stoped #4354

songzhao831 opened this issue Apr 16, 2023 · 9 comments

Comments

@songzhao831
Copy link

System and IINA version:
MACos 13, Intel CPU

  • macOS
  • IINA
    1.3.1 build 133
    Expected behavior:
    After the video playing stop, Mac OS could go to sleep.

Actual behavior:
MacOS sleep is blocked by IINA.

Crash report:
<img width="980" alt="image" src="https://user-images.githubusercontent.com/7333870/232286997-cc6f8532-02c4-4003-8f8f-e8497e046233.png">



mpv log:

Steps to reproduce:
There is a playlist, after the playlist done, the video stop. but it still block the system go to sleep, please check above screenshot.

Could be reproduced systematically.

  • MPV does not have this problem.

How often does this happen?
Systematically.

@low-batt low-batt self-assigned this Apr 23, 2023
@low-batt
Copy link
Contributor

Did not reproduce for me. Sort of…

What specific version of macOS Ventura are you running? Click on  and select About This Mac. There will be a version number in the entry for macOS.

I ran my test with IINA 1.3.1 on my MacBookPro18,2 with the M1 Mac chip under the latest release of macOS Ventura, 13.3.1. IINA did not prevent sleep.

Then I tested the latest development version of IINA. And the problem reproduced. Disturbing that you are experiencing a problem with IINA 1.3.1 and I am not. That suggests either there are two problems in this area and what I reproduced could be a different problem or there are other factors that trigger this problem.

Similar to many open source projects IINA is layered on top of other projects. For audio/video playback IINA is using a library from the mpv project. For this reason the issue template contains the following checkbox:

<!-- If your issue is related to playback, please check whether mpv has the same problem. If so, this might not be an issue with IINA but rather an bug with mpv. Try reporting an issue there. -->

  • MPV does not have this problem.

If the mpv player exhibits the same problem it is likely the root cause resides in code from that project and an issue must be opened in the mpv's projects GitHub repository: mpv issues. IINA refers to this as an "upstream" issue. For such issues the project that owns the code will need to investigate and fix the problem. Once that project has released a new version with the fix, the IINA project will need to upgrade to the fixed version.

I reproduced the problem with mpv 0.35.1. I am about to enter an issue with that project.

@12TARDIS
Copy link

12TARDIS commented Jul 6, 2023

I am running OSX 13.4 (Ventura) on Macbook Air 2018. Iina 1.3.1 Build 133

I have encountered this problem as well. Iina prevents sleep when "auto-pause" is used. I don't know how to check MPV or I'd provide those details.

Steps to reproduce:
Load a video from a folder containing additional videos (or load a playlist)
In General Settings
Behavior
select "keep window open after playback finishes"
Playlist
uncheck "play next item automatically"

Expected behaviour: video playback pauses/stops automatically at end of current video and "sleep prevention" is released. (Activity Monitor changes to "no")

Actual behaviour: video playback pauses but "sleep prevention" remains (Activity Monitor shows "yes")

If I physically press pause (IE use the space bar), then sleep prevention is released as expected. It seems it's only when using the auto-pause/stop feature that this is a problem.

I know this wasn't an issue when I had to switch to VCL for some editing needs in Jan 2023, but I was still on Catalina then, so I don't know if this is a build issue or a Ventura issue.

I joined just to supply this additional information. Hope it helps!

@low-batt
Copy link
Contributor

low-batt commented Jul 6, 2023

@12TARDIS Thank you very much for posting the detailed instructions for reproducing this issue. That you took the time to create a GitHub account and report this is appreciated.

With your instructions I was able to reproduce the behavior I believe @songzhao831 reported. I ran a series of tests. This was the results:

IINA mpv Mac macOS Preventing Sleep
1.1.2 0.32.0 MacBookPro16,1 10.15.7 no
1.3.1 0.34.1 MacBookAir8,2 10.15.7 YES
1.3.1 0.34.1 MacBookPro18,2 13.4 YES
develop 16d275c 0.35.0-419-gf79458476b-dirty MacBookPro18,2 13.4 no

That last entry was with a development version of IINA using a newer version of mpv that has been patched to fix the problem with preventing sleep. This patched version of mpv will be used in the next version of IINA which I keep hearing is about to be released.

Where macOS comes into play is that it is the macOS daemon coreaudiod that is preventing sleep on behalf of IINA because mpv has not stopped the audio unit. As can be seen above I was able to reproduce this under macOS Catalina, so this is not new macOS behavior.

This finding is distressing as it indicates there is more to this mpv issue than was known when the patch was coded. Fortunately it appears the patch addresses this way of triggering the problem as well.

When the new version of IINA is released you should see IINA continuing to prevent sleep for a few seconds after playback has been paused. Then IINA should stop blocking sleep. As reconnecting to wireless audio devices has a noticeable delay, waiting to stop audio reduces the delay in resuming playback when the user is quickly pausing and resuming.

@12TARDIS
Copy link

12TARDIS commented Jul 7, 2023

Thank you for the in-depth explanation. I know enough about programming to be 'dangerous'.

It's still strange to me that it's only the "auto-pause" that causes the issue. When I physically press pause it works as expected. Have you any insight for that? I would think if it were something on Apple's CoreAudio side, that it would be an issue regardless of 'auto' or 'click' pause.

I just booted my 2012 MBP out of curiosity. I still have Monterey on it because of 3 programs that will always be on 32-bit. The issue with 1.3.1 build 133 exists there too just FYI.

I'm glad the problem is being addressed. The entire reason I discovered Iina is because VLC has this problem and they keep saying "we fixed it" (but only "stop" has ever released the prevent sleep on all of my Macs) and I needed to find an app that actually worked the way I wanted it to.

@low-batt
Copy link
Contributor

low-batt commented Jul 7, 2023

On this:

It's still strange to me that it's only the "auto-pause" that causes the issue. When I physically press pause it works as expected. Have you any insight for that?

I can guess, but not knowing for sure is what I found to be distressing about this new information. Here is what is known…

The root cause has to do with these two Apple Audio Toolbox APIs:

When I first investigated this issue I missed that "auto-pause" triggers it. I reproduced it with mpv 0.35.1. Starting with that version of mpv the behavior is consistent in that physically pressing pause now prevents sleep as well.

The change to make this always occur was traced to the fix for issue mpv-player/mpv#10270. That fix can be found in PR mpv-player/mpv#10953.

That investigation correctly identified that AudioOutputUnitStart was taking a long time after a call to AudioOutputUnitStop when using wireless audio devices. The fix changed the code to use AudioUnitReset instead of AudioOutputUnitStop. This corrected the lagging when seeking or quickly pausing and resuming.

My guess is that "auto-pause" was already only calling AudioUnitReset instead of AudioOutputUnitStop. I am not a mpv developer, so I'd have to dig into the mpv sources to know for sure.

There were two problems that were missed with this fix. It is worse than just preventing sleep. The macOS coreaudiod remains active and is consuming CPU. This regression has been reported in issue mpv-player/mpv#11617. A proposed fix can be found in PR mpv-player/mpv#11667. Lots of discussion about the problem can be found there if you want to know more.

On this:

VLC has this problem and they keep saying "we fixed it"

Playing a video with VLC 3.0.18 and pausing playback:

low-batt@gag ~$ pmset -g assertions
2023-07-07 00:51:47 -0400 
Assertion status system-wide:
   BackgroundTask                 0
   ApplePushServiceTask           0
   UserIsActive                   1
   PreventUserIdleDisplaySleep    0
   PreventSystemSleep             0
   ExternalMedia                  0
   InternalPreventDisplaySleep    1
   PreventUserIdleSystemSleep     1
   NetworkClientActive            0
Listed by owning process:
   pid 119(powerd): [0x0003620500018740] 00:47:28 PreventUserIdleSystemSleep named: "Powerd - Prevent sleep while display is on"  
   pid 119(powerd): [0x00036ccc00109787] 00:01:29 InternalPreventDisplaySleep named: "com.apple.powermanagement.delayDisplayOff"  
	Timeout will fire in 210 secs Action=TimeoutActionTurnOff
   pid 46837(VLC): [0x00036cc8000987bf] 00:01:33 UserIsActive named: "VLC media playback"  
	Timeout will fire in 1706 secs Action=TimeoutActionRelease
   pid 197(coreaudiod): [0x00036cc8000187b8] 00:01:33 PreventUserIdleSystemSleep named: "com.apple.audio.BuiltInSpeakerDevice.context.preventuseridlesleep"  
	Created for PID: 46837. 
   pid 172(WindowServer): [0x00027c7100098b75] 00:00:00 UserIsActive named: "com.apple.iohideventsystem.queue.tickle serviceID:1000009e7 service:AppleHIDKeyboardEventDriverV2 product:Apple Internal Keyboard / Trackpad eventType:3"  
	Timeout will fire in 1800 secs Action=TimeoutActionRelease
No kernel assertions.
low-batt@gag ~$ 

VLC has an open assertion with power management indicating "user is active".
And coreaudiod is preventing sleep on behalf of VLC.
Checking CPU usage in Activity Monitor shows coreaudiod consuming 13% CPU.
And of course Activity Monitor shows VLC is preventing sleep.

Maybe VLC was fixed at some point and somebody unfixed it?

@12TARDIS
Copy link

12TARDIS commented Jul 7, 2023

You are amazing to share all of this detail. It helps me to understand what happened, even if tracing the 'why' is more difficult. Also helps me to know where to look for different issues, now that I know which processes are involved. For now, I've downgraded, just so I have this feature functional. (I accept the risks.)

I hope the deeper issues get ironed out on the MPV side, as I can see how if those aren't addressed, it will just make the problems bigger down the line - especially as Apple seems to want to impose their desires on users. It's getting ridiculous that I can't use certain commands in terminal any more. (Don't get me started on "any button" boots/wakes the machine or I can't turn off "lift lid to wake" via terminal any more.)

With VLC, I don't think they EVER fixed it for Mac - coreaudio never turned off if you were in 'pause'. I've used it off and on since 2005 (I was on a PC then). I have a love/hate relationship with it. It's great for editing, converting files, etc. I hated that the developers never seemed to care about Mac users and issues we would raise.

@low-batt
Copy link
Contributor

low-batt commented Jul 7, 2023

I strongly believe in sharing information concerning problems when people express interest. The more eyes and brains on a problem the more likely someone will notice something everyone else has overlooked. In the case at hand it was missed that the problem appears when the Play next item automatically IINA setting is disabled.

The IINA development team considers inappropriately preventing sleep a critical problem that must be fixed. The next release is in progress and should fix this problem.

I too am unhappy that the ability to customize macOS is being eliminated. Customizations that could be accomplished using the defaults command have disappeared with each new macOS release.

@low-batt
Copy link
Contributor

low-batt commented Apr 9, 2024

@12TARDIS For an unrelated issue I was investigating VLC 3.0.20 behavior and noticed this in the VLC file log:

macosx debug: Releasing IOKit monitor sleep blocker (40281)

When I saw that log message I thought of this:

The entire reason I discovered Iina is because VLC has this problem and they keep saying "we fixed it"

I am guessing that log message means the developers really did make and effort to fix the problem and think the fix worked. But it is not fixed…

With VLC playing we can see VLC is preventing the display from sleeping:

low-batt@gag ~$ pmset -g
System-wide power settings:
Currently in use:
 standby              1
 Sleep On Power Button 1
 hibernatefile        /var/vm/sleepimage
 powernap             1
 networkoversleep     0
 disksleep            10
 sleep                1 (sleep prevented by coreaudiod, powerd)
 hibernatemode        3
 ttyskeepawake        1
 displaysleep         20 (display sleep prevented by VLC)
 tcpkeepalive         1
 powermode            0
 womp                 0
low-batt@gag ~$

And indeed when playback is paused VLC removes that assertion:

low-batt@gag ~$ pmset -g
System-wide power settings:
Currently in use:
 standby              1
 Sleep On Power Button 1
 hibernatefile        /var/vm/sleepimage
 powernap             1
 networkoversleep     0
 disksleep            10
 sleep                1 (sleep prevented by coreaudiod, powerd)
 hibernatemode        3
 ttyskeepawake        1
 displaysleep         20
 tcpkeepalive         1
 powermode            0
 womp                 0
low-batt@gag ~$ 

From that output it does not look like VLC is preventing sleep. Only coreaudiod and powerd are. But upon a closer look:

low-batt@gag ~$ pmset -g assertions
2024-04-08 22:59:50 -0400 
Assertion status system-wide:
   BackgroundTask                 0
   ApplePushServiceTask           0
   UserIsActive                   1
   PreventUserIdleDisplaySleep    0
   PreventSystemSleep             0
   ExternalMedia                  0
   PreventUserIdleSystemSleep     1
   NetworkClientActive            0
Listed by owning process:
   pid 192(coreaudiod): [0x000983fe00019d51] 00:19:13 PreventUserIdleSystemSleep named: "com.apple.audio.BuiltInSpeakerDevice.context.preventuseridlesleep"  
	Created for PID: 28849. 
   pid 174(WindowServer): [0x0009822e00099ce2] 00:00:00 UserIsActive named: "com.apple.iohideventsystem.queue.tickle serviceID:10007843c service:AppleHIDKeyboardEventDriverV2 product:Apple Internal Keyboard / Trackpad eventType:3"  
	Timeout will fire in 1200 secs Action=TimeoutActionRelease
   pid 28849(VLC): [0x000983fe00099d58] 00:10:58 UserIsActive named: "VLC media playback"  
	Timeout will fire in 542 secs Action=TimeoutActionRelease
   pid 120(powerd): [0x0009822f00019ce7] 00:26:55 PreventUserIdleSystemSleep named: "Powerd - Prevent sleep while display is on"  
No kernel assertions.
low-batt@gag ~$ 

The coreaudiod assertion was:

Created for PID: 28849.

That is VLC's PID. VLC has not called AudioOutputUnitStop. As a result audio is still active causing coreaudiod to consume CPU and block sleep.

If you still desire to have a working VLC, explain that the problem was only half fixed and point them to this comment and the mpv issue mpv-player/mpv#11617 for technical details on the problem and how it was fixed.

@low-batt
Copy link
Contributor

low-batt commented Apr 9, 2024

IINA fixed this issue by applying a patch to mpv. I've been leaving this issue open until mpv fixes the problem so as to not forget that the patch needs to be applied. The good news is that mpv has merged a fix and mpv issue mpv-player/mpv#11617 is now closed.

Closing this issue as fixed.

@low-batt low-batt closed this as completed Apr 9, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants