printf: More test and doc cleanup

docs/debug_printf.md

@@ -25,6 +25,21 @@ The Debug Printf settings are managed by configuring the Validation Layer. These
 
 Debug Printf settings can also be managed using the [Vulkan Configurator](https://vulkan.lunarg.com/doc/sdk/latest/windows/vkconfig.html) included with the Vulkan SDK.
 
+### Settings
+
+> All settings are found in Vulkan Configurator (`VkConfig`)
+
+There are currently 3 environmental variables that are used for settings in Debug PrintF
+
+- `VK_LAYER_PRINTF_TO_STDOUT` will print to `stdout` **instead** of the normal Debug Callback
+    - `VK_LAYER_PRINTF_TO_STDOUT=1` turn on
+    - `VK_LAYER_PRINTF_TO_STDOUT=0` turn off
+- `VK_LAYER_PRINTF_VERBOSE` will print extra information which pipeline, shader, command, etc, the printf message came from
+    - `VK_LAYER_PRINTF_VERBOSE=1` turn on
+    - `VK_LAYER_PRINTF_VERBOSE=0` turn off
+- `VK_LAYER_PRINTF_BUFFER_SIZE` size of buffer to allocate to put printf message too (this is shared across all calls in a single `vkQueueSubmit`)
+    - `VK_LAYER_PRINTF_BUFFER_SIZE=1024` default size
+
 ## Using Debug Printf in GLSL Shaders
 
 To use Debug Printf in GLSL shaders, you need to enable the GL_EXT_debug_printf extension.
@@ -35,35 +50,35 @@ Here is a very simple example:
 #version 450
 #extension GL_EXT_debug_printf : enable
 void main() {
-float myfloat = 3.1415f;
-debugPrintfEXT("My float is %f", myfloat);
+    float myfloat = 3.1415f;
+    debugPrintfEXT("My float is %f", myfloat);
 }
 ```
-Then use glslangValidator to generate SPIR-V to use in vkCreateShaderModule.
-"glslangvalidator --target-env vulkan1.2 -e main -o shader.vert.spv shader.vert" would be one
+Then use `glslangValidator` to generate SPIR-V to use in `vkCreateShaderModule`.
+`glslangvalidator --target-env vulkan1.2 -e main -o shader.vert.spv shader.vert` would be one
 example of compiling shader.vert
 
-Note that every time this shader is executed, "My float is 3.141500" will be printed. If this were
+Note that every time this shader is executed, `My float is 3.141500` will be printed. If this were
 in a vertex shader and a triangle was drawn, it would be printed 3 times.
 
-Note also that the VK_KHR_shader_non_semantic_info device extension must be enabled in
+Note also that the `VK_KHR_shader_non_semantic_info` device extension must be enabled in
 the Vulkan application using this shader.
 
 ## Using Debug Printf in HLSL Shaders
 
 In HLSL, debug printf can be invoked as follows:
 ```
 void main() {
-float myfloat = 3.1415;
-printf("My float is %f", myfloat);
+    float myfloat = 3.1415;
+    printf("My float is %f", myfloat);
 }
 ```
-Use glslangValidator or dxc to generate SPIR-V for this shader.
+Use `glslangValidator` or `dxc` to generate SPIR-V for this shader.
 For instance:
-glslangValidator.exe -D --target-env vulkan1.2 -e main -o shader.vert.spvx shader.vert
-dxc.exe -spirv -E main -T ps_6_0 -fspv-target-env=vulkan1.2 shader.vert -Fo shader.vert.spv
+- `glslangValidator.exe -D --target-env vulkan1.2 -e main -o shader.vert.spv shader.vert`
+- `dxc.exe -spirv -E main -T ps_6_0 -fspv-target-env=vulkan1.2 shader.vert -Fo shader.vert.spv`
 
-Note that the VK_KHR_shader_non_semantic_info device extension must also be enabled in
+Note that the `VK_KHR_shader_non_semantic_info` device extension must also be enabled in
 the Vulkan application using this shader.
 
 ## Using Debug Printf in SPIR-V Shaders
@@ -74,25 +89,27 @@ However, in some cases, developers may wish to insert Debug Printfs directly int
 To execute debug printfs in a SPIR-V shader, a developer will need the following two
 instructions specified:
 
+```
 OpExtension "SPV_KHR_non_semantic_info"
 %N0 = OpExtInstImport NonSemantic.DebugPrintf
+```
 
 Debug printf operations can then be specified in any function with the following instruction:
-%NN = OpExtInst %void %N0 1 %N1 %N2 %N3 ...
+`%NN = OpExtInst %void %N0 1 %N1 %N2 %N3` ...
 where:
-* N0 is the result id of the OpExtInstImport NonSemantic.DebugPrintf
-* 1 is the opcode of the DebugPrintf instruction in NonSemantic.DebugPrintf
-* N1 is the result of an OpString containing the format for the debug printf
-* N2, N3, ... are result ids of scalar and vector values to be printed
-* NN is the result id of the debug printf operation. This value is undefined.
+* `N0` is the result id of the OpExtInstImport NonSemantic.DebugPrintf
+* `1` is the opcode of the DebugPrintf instruction in NonSemantic.DebugPrintf
+* `N1` is the result of an OpString containing the format for the debug printf
+* `N2`, `N3`, ... are result ids of scalar and vector values to be printed
+* `NN` is the result id of the debug printf operation. This value is undefined.
 
-Note that the VK_KHR_shader_non_semantic_info device extension must also be enabled in
+Note that the `VK_KHR_shader_non_semantic_info` device extension must also be enabled in
 the Vulkan application using this shader.
 
 ## Debug Printf Output
 The strings resulting from a Debug Printf will, by default, be sent to the debug callback
 which is either specified by the app, or by default sent to stdout.
-They are sent at the VK_DEBUG_REPORT_INFORMATION_BIT_EXT or VK_DEBUG_UTILS_MESSAGE_SEVERITY_INFO_BIT_EXT
+They are sent at the `VK_DEBUG_REPORT_INFORMATION_BIT_EXT` or `VK_DEBUG_UTILS_MESSAGE_SEVERITY_INFO_BIT_EXT`
 level.
 
 ## Debug Printf messages in RenderDoc
@@ -106,8 +123,8 @@ Using the debugmarker sample from Sascha Willems' Vulkan samples repository:
 ![Rd Frame](images/rd_frame.png)
 
 2. Edit the shader:
-- Add "#extension GL_EXT_debug_printf : enable" to beginning of shader
-- Add "debugPrintfEXT("Position = %v4f", pos);" to shader after pos definition
+- Add `#extension GL_EXT_debug_printf : enable` to beginning of shader
+- Add `debugPrintfEXT("Position = %v4f", pos);` to shader after pos definition
 - Hit Refresh
 
 ![Refresh](images/refresh.png)
@@ -119,18 +136,18 @@ The vkCmdDrawIndexed in question now has 51 messages.
 
 ## Debug Printf messages from Validation Layers via VkConfig (Vulkan Configurator)
 
-Here's an example of adding a Debug Printf statement to the shader in the vkcube demo (from
-the Vulkan-Tools repository), and then using VkConfig to enable Debug Printf, launch vkcube,
+Here's an example of adding a Debug Printf statement to the shader in the `vkcube` demo (from
+the `Vulkan-Tools` repository), and then using `VkConfig` to enable Debug Printf, launch vkcube,
 and see the Debug Printf output.
 1. Add Debug Printf to the vkcube demo:
- - Add VK_KHR_shader_non_semantic_info to cube's CreateDevice
- - Add extension and debugPrintfEXT call to the shader
- - Use glslangvalidator to compile the new shader
+ - Add `VK_KHR_shader_non_semantic_info` to cube's `CreateDevice` function
+ - Add extension and `debugPrintfEXT` call to the shader
+ - Use `glslangvalidator` to compile the new shader
  - (Offscreen) Rebuild vkcube
 
 ![Add Dbpf](images/add_dbpf.png)
 
-2. Configure VkConfig to enable Debug Printf
+2. Configure `VkConfig` to enable Debug Printf
  - Set Shader Printf Preset
  - Set the executable path to the vkcube demo and add --c 1 to the command line to render one frame
  - Click the "Launch" button
@@ -172,16 +189,19 @@ Would print **"Unsigned long as decimal 2305843009213693953 and as hex 0x2000000
 
 ### Limitations
 * Debug Printf cannot be used at the same time as GPU Assisted Validation.
+  * https://github.com/KhronosGroup/Vulkan-ValidationLayers/issues/8192
 * Debug Printf consumes a descriptor set. If your application uses every last
 descriptor set on the GPU, Debug Printf will not work.
+  * Suggest using `VK_VALIDATION_FEATURE_ENABLE_GPU_ASSISTED_RESERVE_BINDING_SLOT_EXT`
 * Debug Printf consumes device memory on the GPU. Large or numerous Debug Printf
 messages can exhaust device memory. See settings above to control
 buffer size.
-* Validation Layers version: 1.2.135.0 or later is required
+  * Can be controlled with `VK_LAYER_PRINTF_BUFFER_SIZE`
+* Validation Layers version: `1.2.135.0` or later is required
 * Vulkan API version 1.1 or greater is required
-* VkPhysicalDevice features: fragmentStoresAndAtomics and vertexPipelineStoresAndAtomics
+* VkPhysicalDevice features: `fragmentStoresAndAtomics` and `vertexPipelineStoresAndAtomics`
 are required
-* The VK_KHR_shader_non_semantic_info extension must be supported and enabled
+* The `VK_KHR_shader_non_semantic_info` extension must be supported and enabled
 * RenderDoc release 1.14 or later
 * When using Debug Printf with a debug callback, it is recommended to disable validation,
 as the debug level of INFO or DEBUG causes the validation layers to produce many messages
@@ -191,8 +211,7 @@ unrelated to Debug Printf, making it difficult to find the desired output.
 Documentation for the GL_EXT_debug_printf extension can be found
 [here](https://github.com/KhronosGroup/GLSL/blob/main/extensions/ext/GLSL_EXT_debug_printf.txt)
 
-There is a validation layer test that demonstrates the simple and programmatic use of Debug
-Printf. It is called "NegativeDebugPrintf.BasicUsage" and is in `tests/unit/debug_printf.cpp` 
-in the Vulkan-ValidationLayers repository.
+There are many validation layer test that demonstrates the simple and programmatic use of Debug
+Printf. See `tests/unit/debug_printf.cpp` in the Vulkan-ValidationLayers repository.
 
 Earlier implementations implicitly included stage specific built-in variables such as `gl_InvocationID`, `gl_VertexID` and `gl_FragCoord` in Debug Printf messages. This functionality has been removed because it made Debug Printf unusable in shader modules that defined entry points for multiple pipeline stages. If necessary, you can add these values to your printf statements explicitly. However, you must then make sure that the printf statement can only be executed from a pipeline stage where the built-in variable is available.

layers/gpu/debug_printf/debug_printf.cpp

@@ -397,8 +397,10 @@ void Validator::AnalyzeAndGenerateMessage(VkCommandBuffer command_buffer, VkQueu
         index += debug_record->size;
     }
     if ((index - spvtools::kDebugOutputDataOffset) != expect) {
-        InternalWarning(queue, loc,
-                        "Debug Printf message was truncated, likely due to a buffer size that was too small for the message");
+        std::stringstream message;
+        message << "Debug Printf message was truncated, likely due to a buffer size (" << printf_settings.buffer_size
+                << ") that was too small for the message. (This can be adjusted with VK_LAYER_PRINTF_BUFFER_SIZE or vkconfig)";
+        InternalWarning(queue, loc, message.str().c_str());
     }
     memset(debug_output_buffer, 0, 4 * (debug_output_buffer[spvtools::kDebugOutputSizeOffset] + spvtools::kDebugOutputDataOffset));
 }

tests/unit/debug_printf.cpp

@@ -531,6 +531,173 @@ TEST_F(NegativeDebugPrintf, Empty) {
     m_errorMonitor->VerifyFound();
 }
 
+TEST_F(NegativeDebugPrintf, MultipleFunctions) {
+    RETURN_IF_SKIP(InitDebugPrintfFramework());
+    RETURN_IF_SKIP(InitState());
+
+    char const *shader_source = R"glsl(
+        #version 450
+        #extension GL_EXT_debug_printf : enable
+        int data = 0;
+
+        void fn2(bool x) {
+            if (x) {
+                debugPrintfEXT("fn2 x [%d]", data++);
+            } else {
+                debugPrintfEXT("fn2 !x [%d]", data++);
+            }
+        }
+
+        void fn1() {
+            debugPrintfEXT("fn1 [%d]", data++);
+            fn2(true);
+            fn2(false);
+        }
+
+        void main() {
+            debugPrintfEXT("START");
+            fn1();
+            debugPrintfEXT("END");
+        }
+    )glsl";
+
+    CreateComputePipelineHelper pipe(*this);
+    pipe.cs_ = std::make_unique<VkShaderObj>(this, shader_source, VK_SHADER_STAGE_COMPUTE_BIT);
+    pipe.CreateComputePipeline();
+
+    m_commandBuffer->begin();
+    vk::CmdBindPipeline(m_commandBuffer->handle(), VK_PIPELINE_BIND_POINT_COMPUTE, pipe.Handle());
+    vk::CmdDispatch(m_commandBuffer->handle(), 1, 1, 1);
+    m_commandBuffer->end();
+
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "START");
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "fn1 [0]");
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "fn2 x [1]");
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "fn2 !x [2]");
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "END");
+    m_default_queue->Submit(*m_commandBuffer);
+    m_default_queue->Wait();
+    m_errorMonitor->VerifyFound();
+}
+
+TEST_F(NegativeDebugPrintf, Fragment) {
+    RETURN_IF_SKIP(InitDebugPrintfFramework());
+    RETURN_IF_SKIP(InitState());
+    InitRenderTarget();
+    char const *shader_source = R"glsl(
+        #version 450
+        #extension GL_EXT_debug_printf : enable
+        layout(location = 0) out vec4 outColor;
+
+        void main() {
+            if (gl_FragCoord.x > 10 && gl_FragCoord.x < 11) {
+                if (gl_FragCoord.y > 10 && gl_FragCoord.y < 12) {
+                    debugPrintfEXT("gl_FragCoord.xy %1.2f, %1.2f\n", gl_FragCoord.x, gl_FragCoord.y);
+                }
+            }
+            outColor = gl_FragCoord;
+        }
+    )glsl";
+    VkShaderObj vs(this, kVertexDrawPassthroughGlsl, VK_SHADER_STAGE_VERTEX_BIT);
+    VkShaderObj fs(this, shader_source, VK_SHADER_STAGE_FRAGMENT_BIT);
+
+    CreatePipelineHelper pipe(*this);
+    pipe.shader_stages_ = {vs.GetStageCreateInfo(), fs.GetStageCreateInfo()};
+    pipe.CreateGraphicsPipeline();
+
+    m_commandBuffer->begin();
+    m_commandBuffer->BeginRenderPass(m_renderPassBeginInfo);
+    vk::CmdBindPipeline(m_commandBuffer->handle(), VK_PIPELINE_BIND_POINT_GRAPHICS, pipe.Handle());
+    vk::CmdDraw(m_commandBuffer->handle(), 3, 1, 0, 0);
+    m_commandBuffer->EndRenderPass();
+    m_commandBuffer->end();
+
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "gl_FragCoord.xy 10.50, 10.50");
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "gl_FragCoord.xy 10.50, 11.50");
+    m_default_queue->Submit(*m_commandBuffer);
+    m_default_queue->Wait();
+    m_errorMonitor->VerifyFound();
+}
+
+TEST_F(NegativeDebugPrintf, HLSL) {
+    TEST_DESCRIPTION("Make sure HLSL input works");
+    RETURN_IF_SKIP(InitDebugPrintfFramework());
+    RETURN_IF_SKIP(InitState());
+
+    // [numthreads(64, 1, 1)]
+    // void main(uint2 launchIndex: SV_DispatchThreadID) {
+    //     if (launchIndex.x > 1 && launchIndex.x < 4) {
+    //         printf("launchIndex %v2d", launchIndex);
+    //    }
+    // }
+    char const *shader_source = R"(
+               OpCapability Shader
+               OpExtension "SPV_KHR_non_semantic_info"
+         %29 = OpExtInstImport "NonSemantic.DebugPrintf"
+               OpMemoryModel Logical GLSL450
+               OpEntryPoint GLCompute %main "main" %launchIndex
+               OpExecutionMode %main LocalSize 64 1 1
+         %27 = OpString "launchIndex %v2d"
+               OpSource HLSL 500
+               OpName %main "main"
+               OpName %launchIndex "launchIndex"
+               OpDecorate %launchIndex BuiltIn GlobalInvocationId
+       %void = OpTypeVoid
+          %3 = OpTypeFunction %void
+       %uint = OpTypeInt 32 0
+     %v2uint = OpTypeVector %uint 2
+%_ptr_Function_v2uint = OpTypePointer Function %v2uint
+     %uint_0 = OpConstant %uint 0
+%_ptr_Function_uint = OpTypePointer Function %uint
+     %uint_1 = OpConstant %uint 1
+       %bool = OpTypeBool
+     %uint_4 = OpConstant %uint 4
+     %v3uint = OpTypeVector %uint 3
+%_ptr_Input_v3uint = OpTypePointer Input %v3uint
+%launchIndex = OpVariable %_ptr_Input_v3uint Input
+       %main = OpFunction %void None %3
+          %5 = OpLabel
+      %param = OpVariable %_ptr_Function_v2uint Function
+         %35 = OpLoad %v3uint %launchIndex
+         %36 = OpCompositeExtract %uint %35 0
+         %37 = OpCompositeExtract %uint %35 1
+         %38 = OpCompositeConstruct %v2uint %36 %37
+               OpStore %param %38
+         %43 = OpAccessChain %_ptr_Function_uint %param %uint_0
+         %44 = OpLoad %uint %43
+         %45 = OpUGreaterThan %bool %44 %uint_1
+         %46 = OpAccessChain %_ptr_Function_uint %param %uint_0
+         %47 = OpLoad %uint %46
+         %48 = OpULessThan %bool %47 %uint_4
+         %49 = OpLogicalAnd %bool %45 %48
+               OpSelectionMerge %53 None
+               OpBranchConditional %49 %50 %53
+         %50 = OpLabel
+         %51 = OpLoad %v2uint %param
+         %52 = OpExtInst %void %29 1 %27 %51
+               OpBranch %53
+         %53 = OpLabel
+               OpReturn
+               OpFunctionEnd
+
+    )";
+
+    CreateComputePipelineHelper pipe(*this);
+    pipe.cs_ = std::make_unique<VkShaderObj>(this, shader_source, VK_SHADER_STAGE_COMPUTE_BIT, SPV_ENV_VULKAN_1_0, SPV_SOURCE_ASM);
+    pipe.CreateComputePipeline();
+
+    m_commandBuffer->begin();
+    vk::CmdBindPipeline(m_commandBuffer->handle(), VK_PIPELINE_BIND_POINT_COMPUTE, pipe.Handle());
+    vk::CmdDispatch(m_commandBuffer->handle(), 1, 1, 1);
+    m_commandBuffer->end();
+
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "launchIndex 2, 0");
+    m_errorMonitor->SetDesiredFailureMsg(kInformationBit, "launchIndex 3, 0");
+    m_default_queue->Submit(*m_commandBuffer);
+    m_default_queue->Wait();
+    m_errorMonitor->VerifyFound();
+}
+
 TEST_F(NegativeDebugPrintf, MultiDraw) {
     TEST_DESCRIPTION("Verify that calls to debugPrintfEXT are received in debug stream");
     AddRequiredExtensions(VK_EXT_MULTI_DRAW_EXTENSION_NAME);
@@ -2218,4 +2385,34 @@ TEST_F(NegativeDebugPrintf, DISABLED_ShaderObjectMultiCreate) {
     for (uint32_t i = 0; i < 2; ++i) {
         vk::DestroyShaderEXT(m_device->handle(), shaders[i], nullptr);
     }
-}
+}
+
+TEST_F(NegativeDebugPrintf, OverflowBuffer) {
+    TEST_DESCRIPTION("go over the default VK_LAYER_PRINTF_BUFFER_SIZE limit");
+    RETURN_IF_SKIP(InitDebugPrintfFramework());
+    RETURN_IF_SKIP(InitState());
+
+    char const *shader_source = R"glsl(
+        #version 450
+        #extension GL_EXT_debug_printf : enable
+        layout(local_size_x = 8, local_size_y = 8, local_size_z = 1) in;
+        void main() {
+            debugPrintfEXT("WorkGroup %v3u | Invocation %v3u\n", gl_WorkGroupID, gl_LocalInvocationID);
+        }
+    )glsl";
+
+    CreateComputePipelineHelper pipe(*this);
+    pipe.cs_ = std::make_unique<VkShaderObj>(this, shader_source, VK_SHADER_STAGE_COMPUTE_BIT);
+    pipe.CreateComputePipeline();
+
+    m_commandBuffer->begin();
+    vk::CmdBindPipeline(m_commandBuffer->handle(), VK_PIPELINE_BIND_POINT_COMPUTE, pipe.Handle());
+    vk::CmdDispatch(m_commandBuffer->handle(), 4, 4, 1);
+    m_commandBuffer->end();
+
+    m_errorMonitor->SetDesiredWarning(
+        "Debug Printf message was truncated, likely due to a buffer size (1024) that was too small for the message");
+    m_default_queue->Submit(*m_commandBuffer);
+    m_default_queue->Wait();
+    m_errorMonitor->VerifyFound();
+}