Performance issue with debugPrintfEXT using Vulkan 1.1

[SaschaWillems]

Environment:

• OS: Windows 11
• GPU and driver version: NVIDIA RTX 4070 538.42
• SDK or header version if building from repo: SDK 1.3.275
• Options enabled (synchronization, best practices, etc.): -

Describe the Issue

When using debugPrintfEXT along with VkValidationFeaturesEXT to fetch the debug output with a debug messenger callback, performance is so severely impacted, that the application is no longer interactive.

The setup:

Application:

    std::vector<VkValidationFeatureEnableEXT>  validation_feature_enables = {VK_VALIDATION_FEATURE_ENABLE_DEBUG_PRINTF_EXT};
    std::vector<VkValidationFeatureDisableEXT> disables{};

    VkValidationFeaturesEXT validation_features{VK_STRUCTURE_TYPE_VALIDATION_FEATURES_EXT};
    validation_features.enabledValidationFeatureCount = 1;
    validation_features.pEnabledValidationFeatures    = validation_feature_enables.data();
    validation_features.pDisabledValidationFeatures   = 0;
    validation_features.pDisabledValidationFeatures   = disables.data();

    VkApplicationInfo app_info{VK_STRUCTURE_TYPE_APPLICATION_INFO};
    app_info.pApplicationName = "Shader debugprintf";
    app_info.pEngineName      = "Vulkan Samples";
    app_info.apiVersion       = VK_API_VERSION_1_2;

    std::vector<const char *> validation_layers = {"VK_LAYER_KHRONOS_validation"};

    VkInstanceCreateInfo instance_create_info{VK_STRUCTURE_TYPE_INSTANCE_CREATE_INFO};
    instance_create_info.ppEnabledExtensionNames = enabled_extensions.data();
    instance_create_info.enabledExtensionCount   = static_cast<uint32_t>(enabled_extensions.size());
    instance_create_info.pApplicationInfo        = &app_info;
    instance_create_info.pNext                   = &validation_features;
    instance_create_info.ppEnabledLayerNames     = validation_layers.data();
    instance_create_info.enabledLayerCount       = static_cast<uint32_t>(validation_layers.size());

    VkInstance vulkan_instance;
    result = vkCreateInstance(&instance_create_info, nullptr, &vulkan_instance);

    VkDebugUtilsMessengerCreateInfoEXT debug_utils_messenger_create_info{VK_STRUCTURE_TYPE_DEBUG_UTILS_MESSENGER_CREATE_INFO_EXT};
    debug_utils_messenger_create_info.messageSeverity = VK_DEBUG_UTILS_MESSAGE_SEVERITY_INFO_BIT_EXT;
    debug_utils_messenger_create_info.messageType     = VK_DEBUG_UTILS_MESSAGE_TYPE_VALIDATION_BIT_EXT;
    debug_utils_messenger_create_info.pfnUserCallback = debug_utils_message_callback;

    VK_CHECK(vkCreateDebugUtilsMessengerEXT(vulkan_instance, &debug_utils_messenger_create_info, nullptr, &debug_utils_messenger));

Vertex shader:

    if (gl_VertexIndex == 0) {
        debugPrintfEXT("Position = %v4f", outPos);
    }

After some debugging with a minimal sample, I noticed that this only happens with Vulkan 1.1 (set in VkApplicationInfo). Using any other api version, performance is fine.

Summary:

• VK_API_VERSION_1_0:
  • Debug output works, performance is fine, even though it shouldn't work at all with VK 1.0
• VK_API_VERSION_1_1:
  • Debug output works, severe slowdown, application is pretty much unusable
• VK_API_VERSION_1_2 and VK_API_VERSION_1_3:
  • Debug output works, performance is fine

I can only imagine that the combination of debugPrintfEXT, VkValidationFeaturesEXT and VK_API_VERSION_1_1 triggers an odd constellation in the layers that somehow causes a severe slowdown.

Expected behavior

Using debugPrintfEXT with VkValidationFeaturesEXT shows the same performance no matter what API version.

Valid Usage ID n/a

Additional context n/a

[spencer-lunarg]

I have zero explanation, but thanks for doing some debugging to narrow down this to being a strange Vulkan 1.1 issue

I will try and reproduce and figure out what is going on

[SaschaWillems]

Oddly, I can no longer reproduce this. I had multiple SDKs installed, removed all of them and only installed the most recent one. So most probably this was a problem with my setup. Sorry for the noise.

[spencer-lunarg]

ok, if you see it again PLEASE report it

[SaschaWillems]

Reopening this. I have submitted a PR for a shader debugprintf sample at https://github.com/KhronosGroup/Vulkan-Samples/pull/945#pullrequestreview-1922345768 and one of the reviewers seems to have the exact same problem.

I couldn't reproduce it on my machine after cleaning up SDK installs.

[SaschaWillems]

In case you need a repo, we have merged the shader debugprintf sample at https://github.com/KhronosGroup/Vulkan-Samples

I can now reproduce this most of the time, and others have reported that problem too. It may be the sample's fault after all, though I can't seem to see why.

[spencer-lunarg]

we have merged the shader debugprintf sample

Yep I saw and plan to use that!

I have as of 2 days ago, started to really get working on Debug PrintF again, it had not had any real attention towards it and so hopefully very soon (pending I'm off next week) get fixed soon

Thanks for keeping this issue alive

[SRSaunders]

I can also confirm the following results for the same shader_debugprintf sample on macOS Ventura (modified to enable the portability enumeration extension and flag), using Vulkan SDK 1.3.283.0:

• VK_API_VERSION_1_0:
  • Debug output works, performance is fine
• VK_API_VERSION_1_1:
  • Debug output works, severe slowdown, application is pretty much unusable
• VK_API_VERSION_1_2 and VK_API_VERSION_1_3:
  • Debug output works, performance is fine