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.