While paused mpv prevents sleep on Mac, consumes CPU

[low-batt]

Important Information

Provide following Information:

• mpv version: master
• macOS Version: 13.3.1
• Source of the mpv binary or bundle: My own build using mpv-build and Xcode 14.3
• If known which version of mpv introduced the problem: 0.35.1?
• Possible screenshot or video of visual glitches: N/A

Reproduction steps

• Start playing a video that has an audio track with mpv
• Pause playback
• Start Activity Monitor
• Check the Columns menu item under the View menu and ensure Preventing Sleep is enabled
• Find the entry for mpv in Activity Monitor
• The Preventing Sleep column contains Yes
• coreaudiod consumes CPU until mpv terminates

The video must have an audio track or the problem will not occur.

Expected behavior

The Mac is allowed to sleep if mpv is not actively playing a video.

Actual behavior

• Activity Monitor reports mpv is preventing sleep
• coreaudiod consumes CPU

This does not occur when the same video is played with QuickTime.

In addition to my own build of mpv, I also reproduced this behavior using the 0.35.1 release from stolendata.

Testing with the 0.35.0 release from stolendata as well as the 0.34.1 release I am unable to reproduce either of these bad behaviors. After pausing Activity Monitor no longer reports mpv is preventing sleep and coreaudiod CPU use goes to zero.

However this results conflicts with a report from an IINA 1.3.1 user in issue iina/iina#4354. That report is what caused me to notice this behavior. IINA 1.3.1 uses mpv 0.34.1. The user reporting the issue has an Intel Mac running macOS Ventura. Unfortunately they did not report the specific macOS version. My testing was done on a MacBookPro18,2 with the M1 Mac chip under the latest release of Ventura and I was unable to reproduce the problem with IINA 1.3.1. A development version of IINA using mpv 0.35.1 reproduces the problem.

I'm very troubled that I can not explain why the user is experiencing this with IINA 1.3.1. Maybe there is another problem lurking in this area? Or they are running an earlier version of Ventura? This is why I put a question mark at the end of my answer to If known which version of mpv introduced the problem.

Using Terminal to inspect active power management system assertions with this command:

pmset -g assertions

Shows:

• Only the expected assertions before starting the test
• mpv creates an assertion to prevent sleep while playing the video
• coreaudiod creates an assertion on behalf of mpv
• mpv releases its assertion when playback is paused
• coreaudiod does not release its assertion, preventing sleep
• When mpv terminates coreaudiod releases the assertion

This confirms that when playback is paused mpv is calling IOPMAssertionRelease to allow the Mac to sleep. Sleep is being prevented because coreaudiod created an assertion on behalf of mpv and that assertion is still active. As coreaudiod created the assertion on behalf o mpv, Activity Monitor reports mpv is preventing sleep.

Using 0.35.0 and 0.34.1 the same behavior of coreaudiod posting an assertion on behalf of mpv is seen, but when mpv is paused both assertions are released.

pmset assertions:

low-batt@gag ~$  pmset -g assertions
2023-04-23 11:55:35 -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 172(WindowServer): [0x00006c37000995f6] 00:00:00 UserIsActive named: "com.apple.iohideventsystem.queue.tickle serviceID:1000009e0 service:AppleHIDKeyboardEventDriverV2 product:Apple Internal Keyboard / Trackpad eventType:3"  
	Timeout will fire in 1800 secs Action=TimeoutActionRelease
   pid 119(powerd): [0x0001b7690001838b] 01:09:14 PreventUserIdleSystemSleep named: "Powerd - Prevent sleep while display is on"  
   pid 119(powerd): [0x0001c6a2001082fa] 00:04:17 InternalPreventDisplaySleep named: "com.apple.powermanagement.delayDisplayOff"  
	Timeout will fire in 42 secs Action=TimeoutActionTurnOff
No kernel assertions.
low-batt@gag ~$  pmset -g assertions
2023-04-23 11:56:16 -0400 
Assertion status system-wide:
   BackgroundTask                 0
   ApplePushServiceTask           0
   UserIsActive                   1
   PreventUserIdleDisplaySleep    1
   PreventSystemSleep             0
   ExternalMedia                  0
   InternalPreventDisplaySleep    1
   PreventUserIdleSystemSleep     1
   NetworkClientActive            0
Listed by owning process:
   pid 119(powerd): [0x0001b7690001838b] 01:09:55 PreventUserIdleSystemSleep named: "Powerd - Prevent sleep while display is on"  
   pid 119(powerd): [0x0001c6a2001082fa] 00:04:58 InternalPreventDisplaySleep named: "com.apple.powermanagement.delayDisplayOff"  
	Timeout will fire in 1 secs Action=TimeoutActionTurnOff
   pid 54365(mpv): [0x0001c7c6000584c2] 00:00:06 PreventUserIdleDisplaySleep named: "io.mpv.video_playing_back"  
   pid 190(coreaudiod): [0x0001c7c6000184bc] 00:00:06 PreventUserIdleSystemSleep named: "com.apple.audio.BuiltInSpeakerDevice.context.preventuseridlesleep"  
	Created for PID: 54365. 
   pid 172(WindowServer): [0x00006c37000995f6] 00:00:00 UserIsActive named: "com.apple.iohideventsystem.queue.tickle serviceID:1000009e0 service:AppleHIDKeyboardEventDriverV2 product:Apple Internal Keyboard / Trackpad eventType:3"  
	Timeout will fire in 1800 secs Action=TimeoutActionRelease
No kernel assertions.
low-batt@gag ~$  pmset -g assertions
2023-04-23 11:56:33 -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): [0x0001b7690001838b] 01:10:13 PreventUserIdleSystemSleep named: "Powerd - Prevent sleep while display is on"  
   pid 119(powerd): [0x0001c7d9001082fa] 00:00:04 InternalPreventDisplaySleep named: "com.apple.powermanagement.delayDisplayOff"  
	Timeout will fire in 295 secs Action=TimeoutActionTurnOff
   pid 172(WindowServer): [0x00006c37000995f6] 00:00:00 UserIsActive named: "com.apple.iohideventsystem.queue.tickle serviceID:1000009e0 service:AppleHIDKeyboardEventDriverV2 product:Apple Internal Keyboard / Trackpad eventType:3"  
	Timeout will fire in 1800 secs Action=TimeoutActionRelease
   pid 190(coreaudiod): [0x0001c7c6000184bc] 00:00:23 PreventUserIdleSystemSleep named: "com.apple.audio.BuiltInSpeakerDevice.context.preventuseridlesleep"  
	Created for PID: 54365. 
No kernel assertions.
low-batt@gag ~$  pmset -g assertions
2023-04-23 11:56:53 -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 172(WindowServer): [0x00006c37000995f6] 00:00:00 UserIsActive named: "com.apple.iohideventsystem.queue.tickle serviceID:1000009e0 service:AppleHIDKeyboardEventDriverV2 product:Apple Internal Keyboard / Trackpad eventType:3"  
	Timeout will fire in 1800 secs Action=TimeoutActionRelease
   pid 119(powerd): [0x0001b7690001838b] 01:10:32 PreventUserIdleSystemSleep named: "Powerd - Prevent sleep while display is on"  
   pid 119(powerd): [0x0001c7d9001082fa] 00:00:24 InternalPreventDisplaySleep named: "com.apple.powermanagement.delayDisplayOff"  
	Timeout will fire in 276 secs Action=TimeoutActionTurnOff
No kernel assertions.
low-batt@gag ~$ 

Using Terminal to monitor CPU usage with this command:

while true; do ps -e -o 'args,%cpu,cputime' | grep 'coreaudiod\|mpv' | grep -v grep; sleep 5; done

Shows:

• coreaudiod is idle before mpv is started
• Both consume CPU while playing
• mpv CPU drops to near 0 while paused
• coreaudiod continues to use a significant amount of CPU
• coreaudiod drops to 0 after quitting mpv

With 0.35.0 and 0.34.1 coreaudiod CPU use drops to zero when playback is paused.

CPU usage:

low-batt@gag ~$ while true; do ps -e -o 'args,%cpu,cputime' | grep 'coreaudiod\|mpv' | grep -v grep; sleep 5; done
/usr/sbin/coreaudiod                                               0.0  25:03.81
/usr/sbin/coreaudiod                                               0.0  25:03.81
/usr/sbin/coreaudiod                                              11.2  25:04.21
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M  28.5   0:00.87
/usr/sbin/coreaudiod                                              11.2  25:04.80
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M  18.7   0:01.85
/usr/sbin/coreaudiod                                              10.5  25:05.41
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M  18.7   0:02.87
/usr/sbin/coreaudiod                                              10.2  25:05.97
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M  33.6   0:03.96
/usr/sbin/coreaudiod                                              13.2  25:06.60
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M   0.4   0:04.29
/usr/sbin/coreaudiod                                              13.0  25:07.26
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M   0.3   0:04.33
/usr/sbin/coreaudiod                                              13.8  25:07.94
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M   0.6   0:04.36
/usr/sbin/coreaudiod                                              13.5  25:08.60
./mpv/build/mpv --log-file=mpv.log --no-config /Users/low-batt/M   0.7   0:04.40
/usr/sbin/coreaudiod                                               0.0  25:08.82
/usr/sbin/coreaudiod                                               0.0  25:08.82
/usr/sbin/coreaudiod                                               0.0  25:08.82
^C
low-batt@gag ~$ 

This is how I ran mpv for the test:

low-batt@gag mpv-build (master %=)$ ./mpv/build/mpv --log-file=mpv.log --no-config ~/Movies/Airplaneski.mp4 
 (+) Video --vid=1 (*) (h264 682x438 25.000fps)
 (+) Audio --aid=1 (*) (aac 2ch 48000Hz)
AO: [coreaudio] 48000Hz stereo 2ch floatp
VO: [libmpv] 682x438 => 683x438 yuv420p
(Paused) AV: 00:00:19 / 01:11:53 (0%) A-V:  0.000

Exiting... (Quit)
low-batt@gag mpv-build (master %=)$ 

Log file

mpv.log

Sample files

The issue is not sensitive to the video being played other than it must have an audio track.

[krackers]

I confirmed via before/after that this is due to 39f7f83

Perhaps we should in fact call AudioUnitStop, but only when the playback is also paused?

[low-batt]

In order to not waste energy it is desirable for IINA to shutdown some of its threads when playback is paused. However doing so introduced a lag for users that quickly paused and then resumed playback. What IINA is doing now is starting a timer with a few seconds delay when playback is paused. If playback resumes before the timer fires then the timer is canceled. Only if the timer fires and shuts down the threads do the threads have to be restarted. This avoids a lag for users "seeking" using quick pause/resume cycles.

Maybe mpv should do something similar and stop audio if playback has been paused for a while.

[krackers]

I don't know if mpv devs would want to apply this to all AOs? Since wireless deices only seem to be an issue with coreaudio, I'd assume an AO-specific solution would be preferable, if it can be done cleanly. You could probably hack in something with a dispatch_after/dispatch_cancel but I don't know if AudioUnit methods are thread-safe. (I think they might be, since looking at https://lists.apple.com/archives/coreaudio-api/2016/Sep/msg00023.html and https://lists.apple.com/archives/coreaudio-api/2005/Dec/msg00042.html they say

According to one discussion on this list, for example AudioOutputUnitStop() waits until a rendering cycle ends
in case it's called from outside of the audio thread. Which means CoreAudio has proper synchronization mechanisms in place.

But then you probably still need explicit synchronization anyway since you don't want a stop to be issued after the audio unit is already uninitialized. (If we're using libdispatch, you might as well use that for the synchronization by doing all these operations on a serial queue)