Metal error: Execution of the command buffer was aborted...

[aerofly]

With one of the last updates to MoltenVK we now observe random fatal crashes with our Apps on Mac OS 10.14, e.g. we get the following error:

Execution of the command buffer was aborted due to an error during execution. Ignored (for causing prior/excessive GPU errors) (IOAF code 4)

This error is new and shows up since one of the last updates that were made to MoltenVK. When using a previous version of MoltenVK ( around April 2019 ), our Apps are working fine again. Vulkan functions themselves do not return any error at all, all we get is the above error numerous times.

It also makes a big difference if we run our App direct from Xcode or from outside. It also makes a difference if we use

    mvkConfig.synchronousQueueSubmits     = true; //false;
    mvkConfig.presentWithCommandBuffer    = true; //false;

With both options set to 'true' our App runs a little more stable but eventually also crashes.

When running direct from Xcode we actually do NOT observe the crash.

Any idea what's causing this? What was the breaking change that would cause such a crash even though our code base didn't change?

[cdavis5e]

I suspect this is caused by #591.

Prior to this error, are you seeing command buffers time out? You're not waiting for a semaphore before signaling it, are you?

[billhollings]

FWIW...I am seeing this also occur regularly on an older device (MacBook 2014 NV GPU)...but not on a later device (MacBook Pro 2017 AMD GPU).

[aerofly]

@cdavis5e : I do not see any command buffer timeout, nor any other Vulkan errors when this error is reported. When we submit a command buffer using vkQueueSubmit we also add a semaphore to wait on. So I 'think' we are doing everything correctly. What do I need to modify in MoltenVK to restore the old behaviour, so I can verify it's the new method you suggested in #591?

I can trigger this crash reproducible now, even from Xcode, when setting prefillMetalCommandBuffers = false.

I am seeing this on a MacBookPro 2017 with Radeon Pro 560.

[aerofly]

Just a quick note: When I add vkQueueWaitIdle per frame or vkDeviceWaitIdle everything is fine, of course at a much reduced frame rate. So it's either something wrong on our side or in the latest MoltenVK implementation.
We pretty much follow the rules on how to synchronize command buffers and the swap chain images, so I have no idea where to look?

[cdavis5e]

What do I need to modify in MoltenVK to restore the old behaviour, so I can verify it's the new method you suggested in #591?

Set MVKPhysicalDeviceMetalFeatures::events to false. Or rather, stop setting it to true.

For iOS:

MoltenVK/MoltenVK/MoltenVK/GPUObjects/MVKDevice.mm

Line 739 in 5dcc6d7

_metalFeatures.events = true;

For macOS:

MoltenVK/MoltenVK/MoltenVK/GPUObjects/MVKDevice.mm

Line 796 in 5dcc6d7

_metalFeatures.events = true;

[cdavis5e]

I do not see any command buffer timeout, nor any other Vulkan errors when this error is reported.

I mean, are you seeing any Metal errors being reported by the command buffer? You can add some diagnostic code, like in this diff, to do that.

That particular error you cited occurs when command buffers fail one too many times, so the system revokes access to the device.

[aerofly]

No, I do not see any Metal errors being reported. I even added an output each time the completion handler is called to see the function is properly called, but no error is received there. The first output I get is an error like this:

Execution of the command buffer was aborted due to an error during execution. Caused GPU Timeout Error (IOAF code 2)

When I set

_metalFeatures.events = false;

our app works just fine and I no longer observe the issues I described.
I do not have any insight into how MoltenVK really works, but I can of course try to do some experiments to see if the fault is on our side or the MoltenVK side.
But our App runs on iOS, Mac OS, Windows and Linux and with various GPUs and we never observed any validation errors or GPU hangs there.

[cdavis5e]

Execution of the command buffer was aborted due to an error during execution. Caused GPU Timeout Error (IOAF code 2)

This is what I was looking for.

What's happening I suspect is that the semaphore wait value is being incremented before the semaphore signal is scheduled. This means that the wait for the semaphore never wakes up, leading to a timeout. When this happens too many times, Metal revokes access to the device.

I need to figure out why this is happening, because I've been seeing it myself.

[cdavis5e]

I think I know why this is happening.

Does enabling prefillMetalCommandBuffers stop these errors?

[aerofly]

As mentioned in my previous posting above, the parameter prefillMetalCommandBuffers has an effect here.

I can run this test in more detail tomorrow, but I did indeed observe that setting prefillMetalCommandBuffers to true reduced the crashes a lot, especially when setting it to true it no longer crashes our app when running directly from XCode. But it still shows up in random scenarios when executing it outside of XCode.

But let me test this more tomorrow.

[cdavis5e]

As mentioned in my previous posting above, the parameter prefillMetalCommandBuffers has an effect here.

Are you sure you're not confusing it with presentWithCommandBuffer?

[aerofly]

Ok, I just ran my tests again. With

    mvkConfig.synchronousQueueSubmits     = false;
    mvkConfig.presentWithCommandBuffer    = false;
    mvkConfig.prefillMetalCommandBuffers  = true;

I can run our App from Xcode and I do not observe any crashes. When running the App from outside Xcode I still get crashes, but the App runs a little longer before doing so, but it's not without crashes.

When setting

    mvkConfig.synchronousQueueSubmits     = false;
    mvkConfig.presentWithCommandBuffer    = false;
    mvkConfig.prefillMetalCommandBuffers  = false;

our App crashes quickly after the App starts and if running from Xcode.

So to summarize, prefillMetalCommandBuffers has an effect here.

[aerofly]

Any update on this issue?

[danginsburg]

As mentioned in #625 this issue is also reproducible for me in dota. If I run dota.sh -vulkan and the initial background image is drawn before the main menu, I almost always see the same command buffer errors as the original reporter and then fence timeouts. You may be able to use public dota as a place to repro this by dropping libMoltenVK.dylib in its game/bin/osx64 folder.

For now, I'm going to disable _metalFeatures.events in a local hack.

[aerofly]

If possible I recommend to disable _metalFeatures.events by default until the issue is resolved. The error shows up on our side for MacOS as well as iOS.
I am willing to do further tests to help find out what the issue is here.

[billhollings]

@cdavis5e Will you be having a look at trying to resolve this (and #625) this coming week, before the SDK release? If not...I think we should set _metalFeatures.events using an env var which defaults to false. I can take care of that.

[cdavis5e]

I'm probably going to take a stab at fixing this. But in case I fail to get something by the SDK release, feel free to add an environment variable to disable this by default.

[billhollings]

...feel free to add an environment variable to disable this by default.

PR #633 provides an automatic workaround for this issue by providing the environment variable MVK_ALLOW_METAL_EVENTS, which is disabled by default.

The use of Metal events is therefore disabled by default, unless the MVK_ALLOW_METAL_EVENTS environment variable is enabled at runtime by the app.

[cdavis5e]

I think I've figured out what's wrong. For real, this time.

At least in the cases I've observed, this seems to be some sort of weird race between vkAcquireNextImageKHR() signaling a semaphore and vkQueueSubmit() waiting for that semaphore. If the image does not become available until after the submission is queued, then encodeWait() will be called before encodeSignal(). Because encodeWait() increments the counter, the semaphore never gets signaled at that value, causing the submission to block forever*.

Note that vkAcquireNextImageKHR() will not necessarily call encodeSignal() right away, particularly if the image isn't ready yet, meaning that even if you call vkAcquireNextImageKHR() before vkQueueSubmit(), the actual call to encodeSignal() can be deferred until the image is presented with vkQueuePresentKHR().

This seems like an important case to handle. The whole point is that the submission shouldn't execute until the RT image has been presented and thus becomes available for rendering. I'll come up with a patch.

*In reality, the submission times out and Metal returns an error. When this happens enough, you lose the device.

[cdavis5e]

Another problem is that there is a case where the semaphore's MTLEvent won't get signaled at all, and that's when the image is presented without using a command buffer. When I made it use a command buffer if we had device-side MTLEvents, I only made it check if there were semaphores to await, not to signal. The non-command-buffer case is not really expecting to have device-side semaphores to signal (and I should probably put an MVKAssert() in there for that case). So if there are semaphores to signal, but not to await, the semaphores wouldn't get signaled properly, causing even more waits to time out. This is I suspect why turning on presentWithCommandBuffer helped a little bit, though it didn't fix the problem.

[aerofly]

Thank you for your update on this issue. We would be happy to assist you here with testing.

[tasku12]

Hi there. I am using MoltenVK on a large 3D iOS project. When I have _metalFeatures.events = true;
I have a significant increase in frame rate which is fantastic. Although I am not getting the same kind of errors as mentioned above I am noticing a very aggressive increase in memory pressure with this event enabled. I am getting out of memory crashes on iOS as soon as loading into one of my levels. From what I can tell from the memory profiler so far the offending code is in MVKSwapchainImage::signalWhenAvailable. I am not an expert with Objective-C or Metal. My project is 98% C++ code. Would love to know if anyone else is seeing increased memory usage due to the use of metalFeautres.events.

[billhollings]

@danginsburg, @aerofly, @tasku12

Can you retest enabling MTLEvents for semaphores with latest MoltenVK code, please? If you are still encountering issues, please provide as much info as you can for us to replicate it or trace it here.

MoltenVK now logs whether or not it is using MTLEvents for semaphores. You can search the logs for "MTLEvent" to confirm status.

There has been a fair bit of work in the past couple of months that have impacted swap chain sync code...and in PR #724 I have streamlined the swap chain sync code.

MoltenVK passes exactly the same set of 3,200 CTS semaphore tests with or without using native MTLEvents in the semaphores. Unfortunately, CTS does not exercise swap chain surface presentation very much, so there still may be room for issues that CTS is not catching.

@danginsburg I've run against Dota2, but can't see any issues flipping back and forth between using and not using native MTLEvents for semaphores. It might be I'm not hitting the part of the app that triggers the issue. If it is still happening, can you point me to how I can trigger it here, please?

[aerofly]

@billhollings
Of course, give me a some time to do extensive tests and I will report back.

[cdavis5e]

I wonder if it would help to delay incrementing the semaphore counter until the command buffer is scheduled.

[aerofly]

@cdavis5e I can run this test if you let me know what to modify on the code

@billhollings I ran the above tests on another Mac with a AMD Radeon Pro 580 GPU and 8 GB of RAM. The results are different here and I do observe more 'hangs'.

With this setting: MTLEvents=on, synchronousQueueSubmits=true, prefillMetalCommandBuffers=false, maxActiveMetalCommandBuffersPerQueue=8 and running the app outside of Xcode, I observe the following:

• On some occasions the App starts fine and has good performance.
• On other occasions the App just hangs ( it's reporting the command buffer error again )
• On yet other occasions, the App sometimes hangs for a few seconds but then all of the sudden it recovers and runs at full speed again

It also seems very unpredictable.

This looks a little bit like a synchronisation issue somewhere, but I do not have enough inside into MoltenVK to check and see where this might happen.
the app again works with a good performance, but lower as with prefillMetalCommandBuffers=false

[billhollings]

The smaller values of maxActiveMetalCommandBuffersPerQueue likely cause some unintended CPU metering as a side-effect, because Metal will block queue submissions on the CPU when it runs out of MTLCommandBuffers, until one is freed up by the GPU.

Interesting that this metering causes the problem to go away. It would be interesting to see if further reducing the value of maxActiveMetalCommandBuffersPerQueue below 8 on the AMD Radeon Pro 580 GPU also eliminates the problem there (albeit possibly at a performance cost).

This, and @cdavis5e's comment:

I wonder if it would help to delay incrementing the semaphore counter until the command buffer is scheduled.

lead me to wonder if...depending on the threading model of the app...the MTLEvent counter was being overly-incremented by the queuing of two consecutive semaphore wait requests before a signal is able to be queued. In that case...the first MTLEvent counter value would not be signalled...causing the GPU to indefinitely stall on that wait.

All of which lead me to review whether MTLFence would be a better choice for implementing GPU semaphores after all. MTLFence, unlike MTLEvent, does not require a counting value, and seems to be a more basic...wait-and-signal model. I'm wondering if using MTLFence might handle a possible queuing of multiple waits...before a signal is queued that will release them all.

PR #728 adds the MVK_ALLOW_METAL_FENCES env var, which will cause MoltenVK to use MTLFence for Vulkan semaphore synchronization. This env var is used in the same way MVK_ALLOW_METAL_EVENTS is...and is disabled by default. MVK_ALLOW_METAL_EVENTS is also still supported. If both are enabled, MVK_ALLOW_METAL_FENCES will take priority.

The following log entry will appear if that env var is successfully enabled:

[mvk-info] Using MTLFence for semaphores.

@aerofly Can you give it a spin, and report back, please?

[aerofly]

@billhollings Thank you for working on this issue. I tried your new code with all 3 variations on how synchronisation is performed, e.g. MTLEvent, MTLFence and software emulation. Using the mvk-Info I verified that the proper synchronisation was indeed used. I also tried on iOS and Mac OS. My observations are still extremely strange and crashes and halts happen in various test scenarious. To summarise:

Depending on what synchronisation I use ( event, fence or emulation ) and if I use synchronousQueueSubmit and how I set maxActiveMetalCommandBuffersPerQueue, I get mixed results on iOS and Mac OS, but I still do observe crashes and halts, both on iOS and Mac OS. Crashes and halts also appear with MTLFence used.

So before I do further extensive testing, I would like to ask or discuss one thought:

Could it be that the actual issues I observe ( and possibly others as well ) are not really related to the fact how you do synchronisation for command buffer submission, but it's rather a bug (either on my side or in MoltenVK ) between proper inter command buffer synchronization?

Let me quickly outline on what our app is doing, I am sure other developers might use similar steps. This holds for Mac OS and iOS, since our app runs almost the same code on both platforms. So a frame is usually working like this:

1. We render into 1 or up to 4 2D textures. After rendering to them we create the mipmaps for them. Those textures are used in rendering step 3).
2. For shadow mapping purposes, we then render to a depth map ( possibly a texture array, depending on quality settings, on iOS this is just a normal 2D texture ).
3. We then render the actual 3D scene into yet another texture. The rendering of the 3D scene uses the textures of step 1) and the depth map of step 2)
4. We then come to the final rendering step that renders the texture of step 3) onto the screen.

If you think this has nothing to do with it, I will proceed with testing and report back the findings.

If you think this might be related to the issues, I will try to do tests and enable/disable some rendering steps to see what happens then.

We pass Vulkan validation on Windows and Android so far. I am not saying it's not our fault here, but we do not observe issues on other platforms, so I have no idea where to look in our code for issues.

[cdavis5e]

@cdavis5e I can run this test if you let me know what to modify on the code

This patch will do it.

[aerofly]

@cdavis5e Thank you for this small patch. My report is below.

@billhollings One of the 'hangs' and crashes I observed in my previous postings were caused by a real driver issue that happens only on AMD Radeon 570/580 GPUs. I found this rather by accident, because this bug exists on Windows as well. It was confirmed by AMD and caused the driver to crash the whole system. The bug happens in certain situations when using triangle strips with uint16 indices and the primitive restart index. If I replace the code with not using the primitive restart index, a lot of 'hangs' and 'crashes' are gone.

So with the fix I just described and when using MVK_ALLOW_METAL_FENCES set to 1, and with the following mvkConfig options, our app now runs stable for at least 1 hour ( didn't test longer ) on iOS as well as Mac OS:

mvkConfig.debugMode                   = false;
mvkConfig.synchronousQueueSubmits     = false;
mvkConfig.presentWithCommandBuffer    = false;
mvkConfig.fullImageViewSwizzle        = false;
mvkConfig.prefillMetalCommandBuffers  = false;
mvkConfig.switchSystemGPU             = true;
mvkConfig.shaderConversionFlipVertexY = true;
mvkConfig.supportLargeQueryPools      = false;

Setting mvkConfig.synchronousQueueSubmits = true however, I still run into hangs either with MTLEvent or with MTLFences enabled. Performance when using mvkConfig.synchronousQueueSubmits = false however is already very good, so there is no need ( at least for our app ) to enable this feature.

Setting mvkConfig.prefillMetalCommandBuffers = true our app runs fine again, but I do not see any difference in performance.

As for cdavis5e code change, I did the tests with and without his change, but the results were pretty much the same. However on iOS with his change I had a more stable frame rate compared to the previous version. Maybe others can try his change and see what they observe.

To summarise: With the latest MoltenVK version and when setting the config options as above I can now confirm our app runs fine on iOS as well as Mac OS. I just would like to point out that mvkConfig.synchronousQueueSubmits = true can still cause issues.

[cdavis5e]

We need to figure out MTLEvents eventually. Part of the reason I initially selected them is that MTLFences can't be shared with other processes, but MTLSharedEvents can. This will be important for supporting the VK_KHR_external_semaphore extension.

[cdavis5e]

The other reason I didn't use MTLFence is that, based on whatever information I could find, MTLFences operate at the command encoder level. So a MTLFence on the last command encoder wouldn't necessarily prevent any of the prior command encoders from running. At least, that's what I was afraid of. It might explain the results from #486.

[aerofly]

@cdavis5e I understand the need for MTLEvent, but unfortunately
it's currently not as stable as the solution with MTLFence. I did run extensive tests on Mac OS with MVK_ALLOW_METAL_EVENTS enabled and MVK_ALLOW_METAL_FENCES disabled, but I do get command buffer issues after a while. With MVK_ALLOW_METAL_FENCES enabled I get create performance and can run our app without any issues so far. This is all with your small patch applied.

I can of course run those tests again if something changes in MoltenVK, I think this is a top priority to get this part of MoltenVK into a stable form.

[billhollings]

@cdavis5e

Your point about VK_KHR_external_semaphoreis definitely an important consideration.

based on whatever information I could find, MTLFences operate at the command encoder level

Yeah...Apple is typically obscure on explaining fences. The docs define MTLFence as:

An object that can capture, track, and manage resource dependencies across command encoders.

And the old Metal Programming Guide provides some practical examples. See Listing 13-4 on that page for an example that spans two MTLCommandBuffers.

@aerofly

Setting mvkConfig.synchronousQueueSubmits = true however, I still run into hangs either with MTLEvent or with MTLFences enabled.

Interesting. I'm glad you can work around this by disabling at little cost. But I'd like to understand more about this so we can fix it.

What do you mean by "hangs"?

Does either of vkQueueSubmit() or vkQueuePresentKHR() simply stop in its execution...and if so...which one...and where does it hang (ie- waiting on a semaphore...or in the middle of submitting a command)?

Or do you mean that the app stalls in some other way?

[aerofly]

@billhollings After I circumvented the real driver bug I mentioned before, a 'hang' or better stall is caused if the command buffer is aborted. When using mvkConfig.synchronousQueueSubmits = false, a 'stall' causes a frozen screen in our app but we can still use it, e.g. it receives input events and we can exit normally. Sometimes, after a few seconds I even see an 'older frame' and then it stalls again.

Let me run a few tests to see where it actually stalls, but with mvkConfig.synchronousQueueSubmits = false I can still call vkQueueSubmit and vkQueuePresentKHR, they just have no effect any longer.

But let me runs more tests to give you a more qualified answer. I will add some log output around the wait and signal statements inside MoltenVK to see where this is the case.

[tasku12]

I unfortunately can not easily switch to the newest version of Molten due to linking it statically in my project and having a very old C++ memory manager that globally overrides new and delete. This causes me to have to replace all the stl containers that are being used in molten with my own versions that use custom allocators so that I do not end up with mismatched new and deletes.

In regards to MVK_ALLOW_METAL_EVENTS I see really good framerate compared with it being off. However I am investigating visual artifacts appearing in my game when metal events is enabled. If metal events are disabled or if I remove the sempahore waits I am seeing visual artifacts in my game. I am not sure if this has to do with improper synchronization in my rendering code or if this is an error with synchronization due to metal events being on.

In the next month or so I might have the bandwidth to get latest molten and try with the new fences. If the molten team has time in the future it would be beneficial to have an official way to provide custom allocator for all the stl containers being used by the library.

[billhollings]

@aerofly

let me runs more tests to give you a more qualified answer. I will add some log output around the wait and signal statements inside MoltenVK to see where this is the case.

Were you able to better understand how and where the hangs are occurring when enabling MVK_ALLOW_METAL_FENCES (with either synchronousQueueSubmits = false/true)?

As per my note in the related issue...I'd like to enable MVK_ALLOW_METAL_FENCES by default.

[aerofly]

Sorry, I did not yet perform any tests yet with MVK_ALLOW_METAL_FENCES enabled and synchronousQueueSubmits = false. Let me see if I can perform some tests shortly. I need to add a few debug outputs to see where it might hang.

By the way we have some Apps live in the AppStore for iOS and MacOS that use the latest MoltenVK and MVK_ALLOW_METAL_FENCES enabled and synchronousQueueSubmits = true. So far no users have reported any issues.

[billhollings]

By the way we have some Apps live in the AppStore for iOS and MacOS that use the latest MoltenVK and MVK_ALLOW_METAL_FENCES enabled and synchronousQueueSubmits = true. So far no users have reported any issues.

That is great news!

However...I'm confused as to how this aligns with your earlier comments above:

Setting mvkConfig.synchronousQueueSubmits = true however, I still run into hangs either with MTLEvent or with MTLFences enabled.

and

When using mvkConfig.synchronousQueueSubmits = false, a 'stall' causes a frozen screen in our app but we can still use it

I had taken these to indicate that you were experiencing hangs with synchronousQueueSubmits set to either false or true...and that the hang when it was set to false was recoverable (a visual glitch)...but was not recoverable (an actual hang) when it was set to true.

Perhaps I'm misunderstanding the situation. Can you clarify, please?

The default setting for synchronousQueueSubmits is true...so if that is working for you with MVK_ALLOW_METAL_FENCES also enabled...then that's a good indication that we could enable MVK_ALLOW_METAL_FENCES by default.

[aerofly]

Sorry, my previous posting was a typo, I think there are too many combinations one can test :)

Anyway, here is the correct information:

MVK_ALLOW_METAL_FENCES enabled / synchronousQueueSubmits = true -> works
MVK_ALLOW_METAL_FENCES enabled / synchronousQueueSubmits = false -> random hangs

If I set MVK_ALLOW_METAL_FENCES disabled but MVK_ALLOW_METAL_EVENTS enabled I get:

MVK_ALLOW_METAL_EVENTS enabled / synchronousQueueSubmits = true -> random hangs
MVK_ALLOW_METAL_EVENTS enabled / synchronousQueueSubmits = false -> random hangs

'random hangs' means, that our App no longer renders after a few seconds. But this is erradic, the hangs occur in various cases and sometimes early, sometimes later. Sometimes our App even runs fine for 1 minute or more.

But let me run the tests again to give you more insight into where the 'hangs' occur. Since our renderer is not CPU limited, there is no issue for us to set synchronousQueueSubmits = true, so we see no performance benefit from setting synchronousQueueSubmits = false

[billhollings]

PR #760 now enables MVK_ALLOW_METAL_FENCES by default.