How to disable Metal compiler warnings for SceneKit / ARKit?

SceneKit is still logging all these warnings and performance is still bad in iOS 14.2 Beta 1 and macOS 11.0 Beta 7.

I'm getting the same error when using SceneKit simple scene with Physically Based Shading on Xcode 12, performance is bad

Same problem with our game.
Loading is very slow!

2020-09-24 17:03:40.041014+0200 King of the Beach iOS[29368:2866029] [Metal Compiler Warning] Warning: Compilation succeeded with: 



programsource:95:26: warning: unused function 'reduceop'

    static inline float4 reduceop(float4 d0, float4 d1)

                         ^

programsource:581:26: warning: unused variable 'scnshadowsamplerordz'

static constexpr sampler scnshadowsamplerordz = sampler(coord::normalized, filter::linear, mipfilter::none, address::clamptoedge, comparefunc::greaterequal);

                         ^

2020-09-24 17:03:40.212448+0200 King of the Beach iOS[29368:2866029] [Metal Compiler Warning] Warning: Compilation succeeded with: 



programsource:95:26: warning: unused function 'reduceop'

    static inline float4 reduceop(float4 d0, float4 d1)

                         ^

programsource:581:26: warning: unused variable 'scnshadowsamplerordz'

static constexpr sampler scnshadowsamplerordz = sampler(coord::normalized, filter::linear, mipfilter::none, address::clamptoedge, comparefunc::greaterequal);

Using Instruments and SceneKit profiling I've found shader compilation in our app is about 100x slower in iOS 14.0 & 14.2 vs. 13.7. For example, 200ms vs. 2ms. This is probably due to the excessive logging, but there could also be other issues.

The same problem occurs in macOS Big Sur Beta for the Catalyst version of our app.

Here's a sample profile loading a scene in our app:

iOS 13.7

Start Duration Stage
00:01.991.065 743.46 µs Compile shader
00:01.992.512 738.50 µs Compile shader
00:01.994.517 1.83 ms Compile shader
00:02.004.412 7.75 ms Compile shader
00:02.014.193 1.59 ms Compile shader
00:02.017.340 1.59 ms Compile shader
00:02.231.516 1.78 ms Compile shader
00:02.235.465 2.22 ms Compile shader
00:02.238.922 1.27 ms Compile shader
00:02.240.839 612.17 µs Compile shader
00:02.241.988 1.71 ms Compile shader
00:02.245.526 1.13 ms Compile shader
00:02.248.269 2.40 ms Compile shader
00:02.251.258 3.53 ms Compile shader
00:02.255.415 1.76 ms Compile shader
00:02.257.790 1.24 ms Compile shader
00:02.261.007 1.39 ms Compile shader
00:02.263.038 662.88 µs Compile shader
00:02.264.685 633.46 µs Compile shader
00:02.268.135 1.29 ms Compile shader
00:02.270.013 625.88 µs Compile shader
00:02.271.579 1.57 ms Compile shader
00:02.275.123 1.42 ms Compile shader
00:02.277.399 664.29 µs Compile shader
00:02.279.553 858.88 µs Compile shader
00:02.323.472 1.96 ms Compile shader
00:02.709.819 2.77 ms Compile shader
00:02.713.130 1.89 ms Compile shader
00:02.742.231 1.28 ms Compile shader
00:02.755.714 750.38 µs Compile shader


iOS 14.2

Start Duration Stage
00:03.268.055 1.04 ms Compile shader
00:03.272.247 939.42 µs Compile shader
00:03.275.733 1.09 ms Compile shader
00:03.278.655 823.42 µs Compile shader
00:03.297.285 247.30 ms Compile shader
00:03.545.357 211.33 ms Compile shader
00:03.757.419 206.94 ms Compile shader
00:03.965.727 205.61 ms Compile shader
00:04.172.686 206.78 ms Compile shader
00:04.390.671 208.49 ms Compile shader
00:04.603.269 206.41 ms Compile shader
00:04.810.495 208.02 ms Compile shader
00:05.027.189 118.36 ms Compile shader
00:05.157.610 842.29 µs Compile shader
00:05.159.270 227.94 ms Compile shader
00:05.395.161 228.50 ms Compile shader
00:05.624.389 207.48 ms Compile shader
00:05.832.939 207.77 ms Compile shader
00:06.041.442 204.93 ms Compile shader
00:06.247.441 207.00 ms Compile shader
00:06.455.536 206.45 ms Compile shader
00:06.662.692 116.07 ms Compile shader
00:06.779.364 116.29 ms Compile shader

I've silenced the warnings by crudely referencing the internal variable and function being complained about. For every node that has geometry add the following shader modifier code:

Code Block 
scn::reduce_op(vec4(0, 0, 0, 0), vec4(0, 0, 0, 0));
const metal::sampler s = scn_shadow_sampler_ord_z;
while (&s > &s) {
	break;
}

For example:

Code Block 
myNode.geometry?.shaderModifiers?[SCNShaderModifierEntryPoint.surface] =
	"""
	scn::reduce_op(vec4(0, 0, 0, 0), vec4(0, 0, 0, 0));
	const metal::sampler s = scn_shadow_sampler_ord_z;
	while (&s > &s) {
		break;
	}
	"""

Courance, that's an interesting idea. But I tried it with all my loaded .scn and .usdz models and while it seems to reduce the logging, it doesn't improve the performance. Shader compile times are still around 200ms instead of 2ms. Do you think I might be doing it wrong?

Code Block 
if let node = SCNReferenceNode(url: url) {
    node.load()
    node.enumerateChildNodes { (node, stop) in
        if let geometry = node.geometry {
            let shader = """
                scn::reduce_op(vec4(0, 0, 0, 0), vec4(0, 0, 0, 0));
                const metal::sampler s = scn_shadow_sampler_ord_z;
                while (&s > &s) {
                    break;
                }
            """
            geometry.shaderModifiers = [.surface : shader]
        }
    }
}

Same here :(
My simple SceneKit app loads 2-3 seconds longer since Xcode 12 & iOS 14 update.
Who have SampleApp/PerfTestResults, please post bug report to Apple.

@lenk I've just investigated with the profiler and don't see any difference in load times with the code snippet in place. I'm going to remove it from my project. It's nice to silence the warnings but if there's no performance improvement it just introduces unnecessary risk, e.g. changes to the CommonProfile shader.

The excessive logging is now gone in iOS 14.2 Beta 2, but the compile time is still very bad. SceneKit shader compilation is still about 100x slower in iOS 14.2 Beta 2 than in iOS 13.7. I re-ran my tests with Instruments and unfortunately the results are very similar to 14.0 and 14.2 Beta 1. The warning logging may have just been an indication of a deeper problem rather than the cause of the bad performance.

Same problems here. Get the error when adding any nodes to the scene.
Also performance is bad.

Xcode 12.0.1 on Catalina 10.15.7

Has there been any updates on this? We've noticed a big spike in the time spent compiling shaders for dynamic objects we add to our ARKit scene. The problem persists even when the logs are silenced with Courance's method.

Until this is fixed by Apple, does anyone know if it is possible to shift the compilation to a background thread? Currently the main ARKit thread is freezing when we import our models which causes the app to lose tracking and give an overall bad experience. I don't mind the extra time spent compiling, but the way it causes so much stuttering is really frustrating.

Alternatively, I've done a small test using a custom SCNProgram referencing some basic vertex and fragment shaders written in a metal file. I'm guessing when you do this, the shader is compiled at build-time because it completely removes the issue. We need to use the Scenekit PBR shaders though which would be a mammoth task to try and recreate.

@nickfromnelson Just filed a feedback with sample project and Instruments trace (FB8891233).

Thanks @jmousse. I really hope this gets addressed quickly. The issue is quite obviously present even in the Apple supplied sample project: https://developer.apple.com/documentation/arkit/world_tracking/placing_objects_and_handling_3d_interaction.

On my iPhone X the scene freezes each time an object is added.

The warning logging has been fixed in iOS 14.2, but the performance problems still happen consistently in iOS 14.2 and in the latest macOS 11.0.1 RC2.

I decided to dig into the performance problems with Xcode a bit more and basically I found that SceneKit is using MTLDevice.newLibraryWithSource to synchronously compile a roughly 4,200 line (~144KB) Metal shader source string. This is happening in the render loop which is apparently invoked as a CADisplayLink handler, which is why the whole UI hangs for seconds at a time.

To verify that this is the problem, I captured one of the SceneKit shader source strings and options with a breakpoint and used them in a simple test program to compile and time it 50 times. On an iPad Pro, each compilation takes about 200 msec. On an iPad 6th Gen, that takes about 340 msec per compilation. This matches what I’m seeing using Instruments in our real SceneKit-based app. It appears that the compilation is happening on the GPU and not the CPU.

If no changes are made to the source string between compiles, it appears that MTLDevice keeps a (hash-based?) cache and so the subsequent compilations are more like 6 msec. For the test program, I appended a space character each iteration to the source string, so I was able to force it to recompile every iteration. SceneKit appears to make changes to the source and recompiles it when each set of new nodes with meshes or lights are added to the scene, which again explains what I see with Instruments.

Just to see what the what a “minimal” Metal shader compile time is like, I tried it with a simple 24-line source string with only a vertex and fragment shader and it takes about 8 msec per compile.

I’m not sure what Apple is going to do to avoid recompiling that four-thousand line source file during frame update, but the current design seems like it doesn’t work well. I've passed along all of this (in more detail) via Feedback to Apple.

Nice investigation @lenk.

I copied what you did and also managed to track down the raw shader string that Scenekit is injecting. ( I used a symbolic break on -[MTLDebugDevice newLibraryWithSource:options:error:]).

From what I can see, the same master-shader is used every time (labeled as Common Profile v2), but the preprocessorMacros options passed in are different depending on the node. The master-shader is stripped down based on the preprocessor values and then I guess cached against those options?

I see someone has uploaded the Common Profile shader to Github - you can see some of the different preprocessor macros scattered throughout.

The shader compile time problem is still happening in the latest iOS 14.3 Beta. I've attached shader compile times using Instruments running our app on an iPad running 14.3 Beta.

It's such a pity that with all of Apple's focus on 3D, AR and GPU performance, especially with the new M1 chip-based Macs, that they haven't resolved such a big performance problem yet. When users get frustrated with our app's UI appearing to hang for seconds at a time, they're unlikely to stick around to appreciate the beautiful billions of triangles-per-second rendering. I sure wish we could come up with a workaround for this.

Start Duration Stage
00:00.067.901 350.18 ms Compile shader
00:00.483.174 382.15 ms Compile shader
00:00.893.477 383.61 ms Compile shader
00:01.342.543 368.81 ms Compile shader
00:01.713.172 355.37 ms Compile shader
00:02.076.597 400.08 ms Compile shader
00:02.521.364 389.56 ms Compile shader
00:02.911.883 352.88 ms Compile shader
00:03.266.651 347.64 ms Compile shader
00:04.025.355 494.98 ms Compile shader
00:04.527.612 392.55 ms Compile shader
00:04.953.428 408.40 ms Compile shader
00:05.362.909 370.68 ms Compile shader
00:05.736.013 368.20 ms Compile shader

I am also experiencing performance issues with iOS 14.
Is there any bug report / open radar we can follow to receive any update on this?

It appears in iOS 14, there was a change to the Metal compiler to output all errors and warning to a log file. There is not (yet) a way to silence this.

Can one (or many of you) create a request via Feedback Assistant? Please repost the FB number here to help us route this.

Thanks.

An update on this: The logging should be gone with iOS 14.2 Beta 2. However there are still some compile time performance issues to be worked out.

Found FBs in this post below:
FB8891233
and Feedback ID FB8618939

Unfortunately I've verified with Instruments that the performance problem still has not been fixed in iOS 14.3 RC.

The UI hangs are a really bad experience. In our app loading multiple models into a scene, we see hangs like this being logged in the Console app:

Code Block 
com.apple.hangtracer	Hang detected: 10.03s (always-on hang reporting)
com.apple.hangtracer	Hang detected: 1.55s (always-on hang reporting)

So this is understandably frustrating and being investigated.

Note, however, that Metal will cache the fully compiled shaders in a file system cache after each reboot. So subsequent executions of your app should not exhibit these stalls.

Also, so that it doesn't interfere with the UI, you may want to experiment with forcing the shader compilation during your app's initial load time. Perhaps perform some dummy rendering off-screen (I unfortunately am not knowledgeable about how you'd do this with SceneKit)..

Graphics and Games Engineer : Thank you for your response.

The Metal cache is helpful, but for some reason it is either too small or fails much of the time. During my investigations, for some scenes, the "compile time" is indeed a couple of milliseconds, so it must be hitting the cache. But I cannot figure out a pattern or how to get the cache to work all the time. Is there some way to adjust the size? I see what looks like the cache in Library/Caches/app-id/com.apple.metal/functions.list, functions.data, libraries.list, libraries.data, so I see it written when a scene is loaded and shaders are compiled. Is there doc on how it works? I'm also not sure what you mean by "...after each reboot."

At least for our app, SceneKit scenes ARE the app UI, so there really isn't a way to show something else while the shaders compile. I'd be happy if there was some way to just get the shader compilation off the frame refresh (CADisplayLink) so it wouldn't hang the entire app UI. If you have some suggestions on how to achieve that, it'd be super appreciated.

Hello,

I am having significant issues on iOS 14 as well – to the point where the whole Scene and overlaying UI freeze up completely.
I've tested the same exact build on two iPhone 7, one running iOS 13.6 and the other 14.2.
The iOS 13 device had pretty good performance in general but more importantly never caused the complete app to freeze.

Here a side by side comparison: streamable.com/wx2at9 (please paste manually as the forum does not allow me to post the full URL).

The scene is actually quite simple and is displaying only a couple elements at a time (mostly downloaded USDZs or planes with a SpriteKit texture applied).

It almost seems like the GPU chokes up at some point and the only option then is to force quit the app.

Please note that I'm initially adding all objects to the scene and then call SCNView's prepare method https://developer.apple.com/documentation/scenekit/scnscenerenderer/1523375-prepare which should afaik precompile the shaders (and it worked in the past).

The freezes also occurred on more modern devices e.g an iPhone XS and 11.

Since a while I've noticed even on my 2020 iPad Pro that it drops frames when displaying certain nodes (with PBR shaders) for the first time – even after preparing the scene.
Radar and sample project: FB8244426

We have the same issue within our main app as well as the App Clip version and it's quite frustrating as we now can't promote them as planned and first have to figure out a workaround for this issue or wait for a solution.

I really like SceneKit and it's features though I am aware that the focus now lies on RealityKit. But until it is ready for primetime – for us once custom shaders, particle systems, transparent textures and a couple more things are supported – it would be great to get this fixed.

arthurfromberlin: Sounds like you're encountering similar problems. You can see it via Instruments / SceneKit by just running a sample app made using the standard Game template in Xcode.

BTW: I have tried (and even shipped) many different attempts to use both the synchronous and background versions of the SCNView.prepare method. I have had many problems with both of them. The background version crashes (at least since iOS 13) if the view is removed from the UIWindow (e.g., user changes views). I've debugged this and it's lacking a check for a null window but so far have not been able to convince Apple to fix it (FB7716713 May 27, 2020). Trying to use the synchronous version on a non-main DispatchQueue also crashes randomly and, at least for our app, actually makes it slower when it doesn't crash (FB5418811 Feb 11, 2019). Both of them seem to still cause the the shaders to be compiled during the CADisplayLink frame refresh, so they hang the whole app UI anyway. I've removed all uses of prepare from our app, at least until the bugs are fixed.

I agree with your assessment of RealityKit also: not a replacement for the functionality of SceneKit yet with a few too many missing features.