View Bug Details

IDProjectCategoryView StatusLast Update
0002184DCP-o-maticBugspublic2023-09-01 21:51
Reporterrobn Assigned Tocarl  
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
PlatformApple M1OSmacOSOS Version12.2
Target Version2.16.x 
Summary0002184: DOM Encode Server halves performance when screen is locked on macOS
Description

I noticed that the performance (CPU usage and fps) of the DOM Encode Server is
significantly reduced when the screen is locked on my Mac mini M1.

It is probably something the OS does to the DOM process.
But I also noticed that this does not happen to Davinci Resolve rendering jobs.
So maybe something can be done programatically to prevent this happening.

I use the Mac mini as a remote encoding host on the network.
It is a M1 Mac mini running MacOS 12.2 (Monterey)
The main DOM process is running on a Linux machine.

I tested with DOM 2.16.0 (both on the encoding Mac and the main Linux machine)

Steps To Reproduce
  • start the DOM encode server on the Mac
  • start a DCP rendering a DCP on the main Linux machine
  • start a "top" command in a remote shell on the Mac
  • observe a %CPU of approx. 750%
  • lock the screen on the Mac
  • after a minute or so: observe a %CPU of approx. 450% (and a reduced fps in the main DOM)

After unlocking the screen the %CPU is restored to 750%.

TagsNo tags attached.
Branch2184-macos-sleep
Estimated weeks required
Estimated work requiredUndecided

Activities

carl

2022-02-17 07:12

administrator   ~0004878

Could you please try the build from here: https://dcpomatic.com/temp/2184-macos-sleep/c3ce1bf/osx-10.10/
to see if it works any better?

robn

2022-02-17 08:53

reporter   ~0004879

The observed %CPU goes to approx. 680% (instead of approx. 450%).
This is still a bit lower than with an unlocked screen (750%).

But the framerate does not appear to really suffer from it.
A more controlled benchmark would be needed to exactly determine this:
it's a bit hard to see watching the fps number in the DOM GUI with real footage that
causes constantly changing framerate performance ..

It's also possible that the percentages shown by "top" have a slightly different meaning
when the screen is locked vs. normal.

But this change is definitely a big improvement!

carl

2022-02-17 08:56

administrator   ~0004880

Thanks for checking it. I guess a really good test would be to transcode the same DCP twice, once with the server kept awake (by moving the mouse or whatever) and once without, and to see how long it took in each case.

carl

2022-02-17 08:59

administrator   ~0004881

@carl merged this change to v2.16.x as c3ce1bf707fb5308f4b96cb96ed6e8d29335a319

robn

2022-02-17 08:59

reporter   ~0004882

Already working on it .. :-)

carl

2022-02-17 09:00

administrator   ~0004883

Amazing, thanks!

robn

2022-02-17 18:49

reporter   ~0004885

I tested with 10 minutes of blu-ray content (14400 frames)
and with the "Only servers encode" setting enabled.

The results:

2.16.1 + screen unlocked: 8.92 fps
2.16.1 + screen locked: 2.50 fps
2184-macos-sleep + screen unlocked: 8.93 fps
2184-macos-sleep + screen locked: 8.73 fps

So the fix almost completely restores the screen-locked performance!
And there is no difference when the screen is unlocked.

PS: the fps in the log file is only presented as an integer (for example "2" instead of "2.50").
Maybe it's better to add some decimals to the number!

carl

2022-02-17 19:21

administrator   ~0004886

Great! Thanks for checking it out.

Which log file are you talking about with the integer FPS?

robn

2022-02-17 19:45

reporter   ~0004887

I get a file called "log" in the project directory.
The last line after a job is something like this:

   "Thu 17 Feb 2022 08:41:49 PM CET: Transcode job completed successfully: 2 fps"

Maybe the content depends on the settings?

robn

2022-02-17 19:46

reporter   ~0004888

These are my Log settings

log_settings.png (12,460 bytes)   
log_settings.png (12,460 bytes)   

carl

2022-02-17 20:38

administrator   ~0004889

Got it, thanks!

carl

2022-02-17 20:47

administrator   ~0004890

I've added a fix for the decimal places in the log locally.

Bug History

Date Modified Username Field Change
2022-02-09 05:07 robn New Bug
2022-02-09 12:30 carl Assigned To => carl
2022-02-09 12:30 carl Status new => acknowledged
2022-02-09 12:31 carl Severity tweak => minor
2022-02-09 12:31 carl Target Version => 2.16.x
2022-02-09 12:31 carl Estimated work required => Undecided
2022-02-16 23:57 carl Status acknowledged => in progress
2022-02-16 23:57 carl Branch => 2184-macos-sleep
2022-02-17 07:12 carl Status in progress => feedback
2022-02-17 07:12 carl Note Added: 0004878
2022-02-17 08:53 robn Note Added: 0004879
2022-02-17 08:53 robn Status feedback => assigned
2022-02-17 08:56 carl Note Added: 0004880
2022-02-17 08:59 carl Note Added: 0004881
2022-02-17 08:59 robn Note Added: 0004882
2022-02-17 09:00 carl Note Added: 0004883
2022-02-17 09:00 carl Status assigned => feedback
2022-02-17 18:49 robn Note Added: 0004885
2022-02-17 18:49 robn Status feedback => assigned
2022-02-17 19:21 carl Note Added: 0004886
2022-02-17 19:33 carl Status assigned => feedback
2022-02-17 19:45 robn Note Added: 0004887
2022-02-17 19:45 robn Status feedback => assigned
2022-02-17 19:46 robn Note Added: 0004888
2022-02-17 19:46 robn File Added: log_settings.png
2022-02-17 20:38 carl Note Added: 0004889
2022-02-17 20:47 carl Status assigned => resolved
2022-02-17 20:47 carl Resolution open => fixed
2022-02-17 20:47 carl Note Added: 0004890
2023-09-01 21:51 carl Status resolved => closed