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

Significant performance regression in macOS 10.14 #354

Closed
prof-foster opened this issue Sep 27, 2018 · 27 comments
Closed

Significant performance regression in macOS 10.14 #354

prof-foster opened this issue Sep 27, 2018 · 27 comments

Comments

@prof-foster
Copy link

Performance on ...

  • iMac Pro
  • macOS 10.14

... with both a fresh install of SolveSpace version 2.3 and a fresh build from GitHub has regressed to the point of not being usable. Creating a line and moving the second point results in a redraw time of roughly 1 sec.

Apple has announced that OpenGL is being deprecated starting with 10.14, but I haven't seen any references online to performance issues. In the short term I'm wondering about the possibility of a quick performance fix. In the longer term is SolveSpace still going to be feasible on macOS?

@whitequark
Copy link
Contributor

Unfortunately it is not possible for me to do any fixes to SolveSpace under macOS 10.14 because I do not own any Apple hardware and so I use a VM (OSXKVM) to do all development work and there's currently no way to run anything newer than 10.12 in a VM. Worse still, anything newer than 10.9 is absurdly slow when using software rendering, and I do not have GPU passthrough working yet.

@whitequark
Copy link
Contributor

That said, if you could use Xcode to profile SolveSpace, I might be able to fix it without even having access to a macOS 10.14 machine.

@prof-foster
Copy link
Author

prof-foster commented Sep 27, 2018

I'm new to profiling but happy to help. I'm currently trying to follow the build instructions using the "generate an XCode project" path in order to generate a binary that I can profile at the function call level. I had to start again from "scratch" as CMake error-ed out.

Looks like the error is continuing:

-- Performing Test USE_LOONGSON_MMI - Failed
CMake Error at extlib/pixman/CMakeLists.txt:95 (if):
  if given arguments:

    "EQUAL" "4"

  Unknown arguments specified

This is after a brew reinstall cmake

@whitequark
Copy link
Contributor

What is your cmake version?

@prof-foster
Copy link
Author

prof-foster commented Sep 28, 2018

cmake version 3.12.2 installed as follows:

$ brew reinstall cmake
==> Reinstalling cmake
==> Downloading https://homebrew.bintray.com/bottles/cmake-3.12.2.mojave.bottle.tar.gz
Already downloaded: /Users/jafoster/Library/Caches/Homebrew/downloads/39c2f688611df67dad1815faf296167cafc669472e60e74b900d819111d8b456--cmake-3.12.2.mojave.bottle.tar.gz
==> Pouring cmake-3.12.2.mojave.bottle.tar.gz

FWIW it looks like Mohave can be run underneath OSXKVM (but I haven't tried it myself).

@whitequark
Copy link
Contributor

The CI uses 3.11.4, any chance you could try that?

@prof-foster
Copy link
Author

Homebrew was being ... difficult ... but also just released cmake 3.12.3 and it seems to have worked. Now I need to figure out how to make a debug build and run it under Instruments. However.

Having just made a screencast (see attached) it looks like what's happening is that macOS isn't allowing screen updates until the mouse stops moving. Which has the feel (so someone like me who isn't an OpenGL person) of being one of those "one line fixes" once the cause has been identified.
solvespace-slow.mp4.zip

@whitequark
Copy link
Contributor

Oh! I've seen that before. I know approximately what the cause is. I'll need to think a bit about the best way to fix it.

@whitequark
Copy link
Contributor

OK, this is the similar SDL bug: https://bugzilla.libsdl.org/show_bug.cgi?id=4272

@redmanduck
Copy link

Anyone got a workaround for this?

@mePy2
Copy link

mePy2 commented Feb 15, 2019

Hi, I’m on macOS 10.14 too and actually the program doesn’t startup! I downloaded the .dmg file from GitHub.
About OpenGL... the option would be to port it to Metal 2, right?

@whitequark
Copy link
Contributor

Hi, I’m on macOS 10.14 too and actually the program doesn’t startup! I downloaded the .dmg file from GitHub.

Currently, you need to build from source.

About OpenGL... the option would be to port it to Metal 2, right?

Not exactly. Apple has never been developer-friendly, but their latest changes are outright hostile for open-source software. Unless someone donates me hardware that can run 10.14, there will be no further updates and no support.

@mePy2
Copy link

mePy2 commented Feb 15, 2019

Hi, thanks for the fast reply.
Yes, I need to build it from source.

May someone help you? I’m new to development, but I would like to help somehow. If you know what to do I can try to do it.

@whitequark
Copy link
Contributor

You could try to "port" it to Metal using one of the OpenGL-to-Metal translation layers out there.

@troughton
Copy link
Contributor

troughton commented May 13, 2019

Looking into it, this doesn't seem like an OpenGL issue (although there are separate OpenGL performance issues I'll get to later). For the specific problem in the video of drawing a line segment to the mouse location, the graphic of the line is for some reason tracking behind the actual mouse position. Printing out within OpenGl3Renderer::DoStippledLine and GraphicsWindow::MouseMoved (and filtering out stippled lines that aren't the one we're interested in), we see:

0: Drawing stippled line between (-35.27, 40.00, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 363.72, 44.34
1: Drawing stippled line between (72.74, 8.87, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 340.80, 59.23
2: Drawing stippled line between (72.74, 8.87, 0.00) and (-35.33, 40.00, 0.00)
3: Drawing stippled line between (68.16, 11.85, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 311.54, 79.93
4: Drawing stippled line between (68.16, 11.85, 0.00) and (-35.33, 40.00, 0.00)
5: Drawing stippled line between (62.31, 15.99, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 299.49, 91.77
6: Drawing stippled line between (59.90, 18.35, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 299.49, 92.09
7: Drawing stippled line between (59.90, 18.42, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 299.17, 92.41
8: Drawing stippled line between (59.90, 18.42, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 298.85, 92.41
9: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 289.94, 100.02
10: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 285.02, 104.52
11: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 282.46, 106.77
12: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 273.89, 112.58
13: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 268.10, 116.27
14: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 267.46, 116.59
15: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 254.73, 122.15
16: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 217.69, 137.71
17: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 196.25, 144.19
18: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 185.22, 141.05
19: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 179.06, 129.02
20: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 181.27, 109.14
21: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 191.09, 76.49
22: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 197.18, 28.34
23: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 192.87, -11.48
24: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 170.48, -58.68
25: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 139.73, -110.19
26: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 123.33, -148.52
27: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 116.91, -161.64
28: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 106.46, -165.09
29: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 103.41, -164.45
30: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 105.53, -153.48
31: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 116.67, -103.21
32: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 145.02, -40.57
33: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 184.04, 8.77
34: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 199.57, 46.50
35: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 205.00, 92.71
36: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 203.52, 122.27
37: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 201.25, 132.97
38: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 200.29, 134.89
39: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 195.59, 133.20
40: Drawing stippled line between (59.77, 18.48, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 180.45, 117.01
41: Drawing stippled line between (36.09, 23.40, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 151.46, 58.06
42: Drawing stippled line between (36.09, 23.40, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 124.34, -40.00
43: Drawing stippled line between (24.87, -8.00, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 104.44, -104.13
44: Drawing stippled line between (24.87, -8.00, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 92.73, -116.93
45: Drawing stippled line between (18.55, -23.39, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 79.22, -123.78
46: Drawing stippled line between (18.55, -23.39, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to 29.66, -139.34
47: Drawing stippled line between (5.93, -27.87, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to -23.28, -137.99
48: Drawing stippled line between (5.93, -27.87, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to -69.90, -109.71
49: Drawing stippled line between (-13.98, -21.94, 0.00) and (-35.33, 40.00, 0.00)
Mouse moved to -100.58, -80.68

i.e. the mouse motion is getting picked up but it's not getting through to the rendering code (and I don't know how many steps before that).


In terms of the OpenGL rendering, CPU usage is way higher than it needs to be because rendering is done into an offscreen buffer, meaning the result has to be copied from the GPU to the CPU, undergo colour-space and format conversion, be copied into a texture buffer, and then rendered again. It's a pretty simple change to render directly to the screen instead (which I think is what happens on other platforms), but some flickering occurs that I haven't figured out yet.

@whitequark
Copy link
Contributor

It's a pretty simple change to render directly to the screen instead (which I think is what happens on other platforms), but some flickering occurs that I haven't figured out yet.

Yes. I've spent a very large amount of time trying to do it without an off-screen buffer but it never worked. IIRC the main issue preventing direct rendering was the editor overlay, so please make sure that still works.

@whitequark
Copy link
Contributor

i.e. the mouse motion is getting picked up but it's not getting through to the rendering code (and I don't know how many steps before that).

In general this happens as a result of high CPU load. Take a look at how the havePainted variable is used. I'm not sure what's the best way to handle it--maybe add a timer?

@troughton
Copy link
Contributor

troughton commented May 13, 2019

Yes. I've spent a very large amount of time trying to do it without an off-screen buffer but it never worked. IIRC the main issue preventing direct rendering was the editor overlay, so please make sure that still works.

The flickering appears to be whenever the draw calls change (including when hovering over the editor overlay). My guess would be that it's due to all the glGenBuffer calls every frame, rather than just using persistent buffers for each frame's data and streaming to them with glBufferSubData. Is that something you've tried? It doesn't look trivial based on the code's architecture.

In general this happens as a result of high CPU load. Take a look at how the havePainted variable is used. I'm not sure what's the best way to handle it--maybe add a timer?

Is there another variable that might be controlling the updates for line segment drawing? havePainted doesn't seem to have an impact on that in particular, and CPU usage is sitting at ~15%.

@whitequark
Copy link
Contributor

My guess would be that it's due to all the glGenBuffer calls every frame, rather than just using a single buffer for each frame's data and streaming to it with glBufferSubData. Is that something you've tried? It doesn't look trivial based on the code's architecture.

I haven't tried that. Before you've mentioned it I wasn't even aware that it could be a problem.

Maybe the buffers could be created once, persisted inside the various Renderers and then glBufferSubData could be used with the persistent handle? I'm not sure what happens if a context is invalidated, like in WebGL.

Is there another variable that might be controlling the updates for line segment drawing? havePainted doesn't seem to have an impact on that in particular, and CPU usage is sitting at ~15%.

I took another look and I think what might be happening is that in MouseMoved, you have the Invalidate() call and havePainted = false assignment. havePainted primarily affects the way the solver behaves (it inhibits the solver if there were no repaints, since solving is expensive), and it might actually be working correctly in this case. But what might happen here is that the view is invalidated over and over and never actually painted.

@troughton
Copy link
Contributor

My guess would be that it's due to all the glGenBuffer calls every frame, rather than just using a single buffer for each frame's data and streaming to it with glBufferSubData. Is that something you've tried? It doesn't look trivial based on the code's architecture.

I haven't tried that. Before you've mentioned it I wasn't even aware that it could be a problem.

Maybe the buffers could be created once, persisted inside the various Renderers and then glBufferSubData could be used with the persistent handle? I'm not sure what happens if a context is invalidated, like in WebGL.

It's definitely not recommended to be recreating buffers every frame, and although the driver should be able to handle it in the case of transient buffers (as most Windows drivers seem to) I wouldn't be surprised if that's a problem on macOS. How much it's worth addressing given OpenGL support on macOS has maybe a couple more years to live I'm not sure; however, a Metal implementation would have the same design issue.

I made a start on the change in https://github.com/troughton/solvespace/tree/gl-no-buffer-genning, although I doubt I'll have more time to work on it. The core issue is that the buffer storage needs to be preallocated each frame (and the driver will reuse a previous buffer if it's large enough); you could either just set a maximum size, or you somehow need to know the total vertex/index counts in advance. That branch doesn't properly work because FlushFrame() is called multiple times in a frame, so the vertex/index counts are all off.

Is there another variable that might be controlling the updates for line segment drawing? havePainted doesn't seem to have an impact on that in particular, and CPU usage is sitting at ~15%.

I took another look and I think what might be happening is that in MouseMoved, you have the Invalidate() call and havePainted = false assignment. havePainted primarily affects the way the solver behaves (it inhibits the solver if there were no repaints, since solving is expensive), and it might actually be working correctly in this case. But what might happen here is that the view is invalidated over and over and never actually painted.

I'll note that hard-coding havePainted to false or true doesn't seem to have any effect, and that the view definitely gets redrawn (since line highlights show); however, that's not to say something similar isn't going on.

@whitequark
Copy link
Contributor

Thanks. I would probably not finish this on my own any time soon either but it still might be useful in the future.

@zhuowei
Copy link
Contributor

zhuowei commented May 13, 2019

@whitequark @troughton It's worth noting that the mouse movements are getting through to some parts of the UI: the circle tool doesn't have any lag at all.

It's not the fault of the batched drawing support, either: the red outline around the line when I use the line tool is also lagging (tested by disabling OpenGl3RendererBatch::Draw).

See https://drive.google.com/file/d/1LHFkRHH1MsSDFu3th4zZMXDgInU4ENI5/view?usp=sharing : The circle tool doesn't have lag, and the purple dot at the bottom-right corner of the square seems to update as the mouse moves even though the rest of the square doesn't.

(MacBook Pro (Retina, 13-inch, Early 2015), macOS Mojave 10.14.4, latest master branch)

Edit: I think @troughton's idea about the solver being overwhelmed might be correct. I made Solvespace ignore 3/4 of the mouse events received, and the line drawing seems to be smoother.

@solvespace solvespace deleted a comment May 14, 2019
@solvespace solvespace deleted a comment May 14, 2019
@thaytan
Copy link

thaytan commented May 14, 2019

Just to add another data point - the slowdown is only while initially creating a line or rectangle contour for me. After they are created, moving any control point is smooth and fast.

@redmanduck
Copy link

Just want to add, that the performance regression only occurs on macOS Mojave when using Retina Display, if I use external monitor (FHD) it is fine - smooth as butter. However, I'm not sure about using external 4K display.

@vespakoen
Copy link
Contributor

vespakoen commented Nov 21, 2019

Guys, try adding this to cmake/MacOSBundleInfo.plist.in (inside of the <dict></dict> section):

        <key>NSHighResolutionCapable</key>
        <string>False</string>

Not tested it a lot but seems to speed things up a lot!

@whitequark
Copy link
Contributor

Fixed in 9b61f98.

@vespakoen
Copy link
Contributor

vespakoen commented Nov 23, 2019

Here is a macOS build from the latest master 54015b6
I signed and notarised it using my Apple Developer account for anyone interested to check it out.

solvespace.zip

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

8 participants