Skip to content

Commit 88f4829

Browse files
tylertmstylertms
committed
Pipeline logging lint fix
1 parent 523fb33 commit 88f4829

3 files changed

Lines changed: 116 additions & 45 deletions

File tree

‎src/core/api/lifecycle.c‎

Lines changed: 47 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -427,24 +427,26 @@ static VKRT_Result createInstanceAndDevice(VKRT* vkrt, const VKRT_CreateInfo* cr
427427
return VKRT_SUCCESS;
428428
}
429429

430-
static VKRT_Result createRenderBackendResources(VKRT* vkrt) {
430+
static VKRT_Result createSwapChainBackendResources(VKRT* vkrt) {
431431
if (!vkrt) return VKRT_ERROR_INVALID_ARGUMENT;
432432
uint64_t stepStartTime = 0u;
433433

434-
if (!vkrt->runtime.headless) {
435-
glfwPollEvents();
436-
stepStartTime = getMicroseconds();
437-
if (createSwapChain(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
438-
logStepTime("Swapchain created", stepStartTime);
434+
if (vkrt->runtime.headless) return VKRT_SUCCESS;
439435

440-
stepStartTime = getMicroseconds();
441-
if (createImageViews(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
442-
logStepTime("Swapchain image views created", stepStartTime);
443-
}
436+
glfwPollEvents();
437+
stepStartTime = getMicroseconds();
438+
if (createSwapChain(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
439+
logStepTime("Swapchain created", stepStartTime);
444440

445441
stepStartTime = getMicroseconds();
446-
if (createCommandPool(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
447-
logStepTime("Command pool created", stepStartTime);
442+
if (createImageViews(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
443+
logStepTime("Swapchain image views created", stepStartTime);
444+
return VKRT_SUCCESS;
445+
}
446+
447+
static VKRT_Result createPipelineBackendResources(VKRT* vkrt) {
448+
if (!vkrt) return VKRT_ERROR_INVALID_ARGUMENT;
449+
uint64_t stepStartTime = 0u;
448450

449451
stepStartTime = getMicroseconds();
450452
if (vkrtEnsureTextureBindings(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
@@ -465,6 +467,12 @@ static VKRT_Result createRenderBackendResources(VKRT* vkrt) {
465467
stepStartTime = getMicroseconds();
466468
if (createComputePipeline(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
467469
logStepTime("Compute pipeline created", stepStartTime);
470+
return VKRT_SUCCESS;
471+
}
472+
473+
static VKRT_Result createSceneBackendResources(VKRT* vkrt) {
474+
if (!vkrt) return VKRT_ERROR_INVALID_ARGUMENT;
475+
uint64_t stepStartTime = 0u;
468476

469477
stepStartTime = getMicroseconds();
470478
if (createGPUImages(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
@@ -485,6 +493,12 @@ static VKRT_Result createRenderBackendResources(VKRT* vkrt) {
485493
stepStartTime = getMicroseconds();
486494
if (createDescriptorSet(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
487495
logStepTime("Descriptor set created", stepStartTime);
496+
return VKRT_SUCCESS;
497+
}
498+
499+
static VKRT_Result createExecutionBackendResources(VKRT* vkrt) {
500+
if (!vkrt) return VKRT_ERROR_INVALID_ARGUMENT;
501+
uint64_t stepStartTime = 0u;
488502

489503
stepStartTime = getMicroseconds();
490504
if (createShaderBindingTable(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
@@ -501,6 +515,27 @@ static VKRT_Result createRenderBackendResources(VKRT* vkrt) {
501515
stepStartTime = getMicroseconds();
502516
if (createSyncObjects(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
503517
logStepTime("Synchronization objects created", stepStartTime);
518+
return VKRT_SUCCESS;
519+
}
520+
521+
static VKRT_Result createRenderBackendResources(VKRT* vkrt) {
522+
if (!vkrt) return VKRT_ERROR_INVALID_ARGUMENT;
523+
524+
uint64_t stepStartTime = getMicroseconds();
525+
if (createSwapChainBackendResources(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
526+
logStepTime("Swapchain backend resources ready", stepStartTime);
527+
528+
stepStartTime = getMicroseconds();
529+
if (createPipelineBackendResources(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
530+
logStepTime("Pipeline backend resources ready", stepStartTime);
531+
532+
stepStartTime = getMicroseconds();
533+
if (createSceneBackendResources(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
534+
logStepTime("Scene backend resources ready", stepStartTime);
535+
536+
stepStartTime = getMicroseconds();
537+
if (createExecutionBackendResources(vkrt) != VKRT_SUCCESS) return VKRT_ERROR_OPERATION_FAILED;
538+
logStepTime("Execution backend resources ready", stepStartTime);
504539

505540
return VKRT_SUCCESS;
506541
}

‎src/core/render/accel/sbt.c‎

Lines changed: 23 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,27 @@ typedef struct ShaderBindingTableBuildOutput {
1717
VkStridedDeviceAddressRegionKHR* tables;
1818
} ShaderBindingTableBuildOutput;
1919

20+
static void logShaderBindingTableHandlesReady(
21+
const char* label,
22+
uint64_t startTime,
23+
uint32_t groupCount,
24+
VkDeviceSize stride,
25+
VkDeviceSize sbtSize
26+
) {
27+
LOG_TRACE(
28+
"%s SBT handles fetched and staged in %.3f ms (%u groups, stride %llu, size %llu bytes)",
29+
label ? label : "RT",
30+
(double)(getMicroseconds() - startTime) / 1e3,
31+
groupCount,
32+
(unsigned long long)stride,
33+
(unsigned long long)sbtSize
34+
);
35+
}
36+
37+
static void logShaderBindingTableUploaded(const char* label, uint64_t startTime) {
38+
LOG_TRACE("%s SBT uploaded in %.3f ms", label ? label : "RT", (double)(getMicroseconds() - startTime) / 1e3);
39+
}
40+
2041
static void destroyShaderBindingTableStageResources(VKRT* vkrt, VkBuffer buffer, VkDeviceMemory memory) {
2142
if (!vkrt) return;
2243
if (buffer != VK_NULL_HANDLE) vkDestroyBuffer(vkrt->core.device, buffer, NULL);
@@ -222,14 +243,7 @@ static VKRT_Result createShaderBindingTableForPipeline(
222243
) != VKRT_SUCCESS) {
223244
return VKRT_ERROR_OPERATION_FAILED;
224245
}
225-
LOG_TRACE(
226-
"%s SBT handles fetched and staged in %.3f ms (%u groups, stride %llu, size %llu bytes)",
227-
label ? label : "RT",
228-
(double)(getMicroseconds() - handlesStartTime) / 1e3,
229-
groupCount,
230-
(unsigned long long)stride,
231-
(unsigned long long)sbtSize
232-
);
246+
logShaderBindingTableHandlesReady(label, handlesStartTime, groupCount, stride, sbtSize);
233247

234248
uint64_t uploadStartTime = getMicroseconds();
235249
if (createShaderBindingTableDeviceBuffer(vkrt, sbtSize, &output) != VKRT_SUCCESS) {
@@ -255,11 +269,7 @@ static VKRT_Result createShaderBindingTableForPipeline(
255269
hitGroupCount,
256270
output.tables
257271
);
258-
LOG_TRACE(
259-
"%s SBT uploaded in %.3f ms",
260-
label ? label : "RT",
261-
(double)(getMicroseconds() - uploadStartTime) / 1e3
262-
);
272+
logShaderBindingTableUploaded(label, uploadStartTime);
263273

264274
return VKRT_SUCCESS;
265275
}

‎src/core/render/pipeline_rt.c‎

Lines changed: 46 additions & 20 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
#include "debug.h"
22
#include "pipeline.h"
33
#include "pipeline_internal.h"
4+
#include "platform.h"
45
#include "shaders.h"
56
#include "vkrt_internal.h"
67
#include "vkrt_types.h"
@@ -9,6 +10,40 @@
910
#include <stdint.h>
1011
#include <vulkan/vulkan_core.h>
1112

13+
static void logRayTracingPipelineCreateResult(const char* label, uint64_t startTime, VkResult result) {
14+
LOG_TRACE(
15+
"%s vkCreateRayTracingPipelinesKHR returned %d in %.3f ms (synchronous)",
16+
label,
17+
(int)result,
18+
(double)(getMicroseconds() - startTime) / 1e3
19+
);
20+
}
21+
22+
static void logElapsedTraceMs(const char* label, uint64_t startTime) {
23+
LOG_TRACE("%s in %.3f ms", label, (double)(getMicroseconds() - startTime) / 1e3);
24+
}
25+
26+
static void logMainRayTracingPipelineCreated(
27+
uint64_t startTime,
28+
VkBool32 useSerShaders,
29+
VkRayTracingInvocationReorderModeNV serReorderingHintMode,
30+
uint32_t shaderStageCount,
31+
uint32_t shaderGroupCount
32+
) {
33+
LOG_TRACE(
34+
"Main RT pipeline created. Variant: %s, SER hint: %s, Shader Stages: %u, Shader Groups: %u, in %.3f ms",
35+
useSerShaders ? "SER" : "default",
36+
serReorderingHintMode == VK_RAY_TRACING_INVOCATION_REORDER_MODE_REORDER_EXT ? "reorder" : "none",
37+
shaderStageCount,
38+
shaderGroupCount,
39+
(double)(getMicroseconds() - startTime) / 1e3
40+
);
41+
}
42+
43+
static void logSelectionRayTracingPipelineCreated(uint64_t startTime) {
44+
LOG_TRACE("Selection RT pipeline created in %.3f ms", (double)(getMicroseconds() - startTime) / 1e3);
45+
}
46+
1247
static VkResult createRayTracingPipelineTracked(
1348
VKRT* vkrt,
1449
const char* label,
@@ -27,12 +62,7 @@ static VkResult createRayTracingPipelineTracked(
2762
NULL,
2863
outPipeline
2964
);
30-
LOG_TRACE(
31-
"%s vkCreateRayTracingPipelinesKHR returned %d in %.3f ms (synchronous)",
32-
label,
33-
(int)result,
34-
(double)(getMicroseconds() - createStartTime) / 1e3
35-
);
65+
logRayTracingPipelineCreateResult(label, createStartTime, result);
3666
return result;
3767
}
3868

@@ -50,7 +80,7 @@ VKRT_Result createRayTracingPipeline(VKRT* vkrt) {
5080
if (createRayTracingShaderModules(vkrt, &shaderVariant, &modules) != VKRT_SUCCESS) {
5181
return VKRT_ERROR_SHADER_COMPILATION_FAILED;
5282
}
53-
LOG_TRACE("Main RT shader modules created in %.3f ms", (double)(getMicroseconds() - shaderModuleStartTime) / 1e3);
83+
logElapsedTraceMs("Main RT shader modules created", shaderModuleStartTime);
5484

5585
VkPipelineShaderStageCreateInfo shaderStages[] = {
5686
makePipelineShaderStageInfo(VK_SHADER_STAGE_RAYGEN_BIT_KHR, modules.rayGen[VKRT_MAIN_RAYGEN_GROUP_RGB]),
@@ -112,16 +142,15 @@ VKRT_Result createRayTracingPipeline(VKRT* vkrt) {
112142
vkrt->core.rayTracingPipeline = VK_NULL_HANDLE;
113143
return VKRT_ERROR_OPERATION_FAILED;
114144
}
115-
LOG_TRACE("Main RT stack sizes queried in %.3f ms", (double)(getMicroseconds() - stackSizeStartTime) / 1e3);
145+
logElapsedTraceMs("Main RT stack sizes queried", stackSizeStartTime);
116146

117147
destroyRayTracingShaderModules(vkrt, &modules);
118-
LOG_TRACE(
119-
"Main RT pipeline created. Variant: %s, SER hint: %s, Shader Stages: %u, Shader Groups: %u, in %.3f ms",
120-
useSerShaders ? "SER" : "default",
121-
vkrt->core.serReorderingHintMode == VK_RAY_TRACING_INVOCATION_REORDER_MODE_REORDER_EXT ? "reorder" : "none",
148+
logMainRayTracingPipelineCreated(
149+
startTime,
150+
useSerShaders,
151+
vkrt->core.serReorderingHintMode,
122152
(uint32_t)VKRT_ARRAY_COUNT(shaderStages),
123-
(uint32_t)VKRT_ARRAY_COUNT(shaderGroups),
124-
(double)(getMicroseconds() - startTime) / 1e3
153+
(uint32_t)VKRT_ARRAY_COUNT(shaderGroups)
125154
);
126155
return VKRT_SUCCESS;
127156
}
@@ -144,10 +173,7 @@ VKRT_Result createSelectionRayTracingPipeline(VKRT* vkrt) {
144173
createShaderModule(vkrt, shaderSelectRahitData, shaderSelectRahitSize, &anyHitModule) != VKRT_SUCCESS) {
145174
goto cleanup;
146175
}
147-
LOG_TRACE(
148-
"Selection RT shader modules created in %.3f ms",
149-
(double)(getMicroseconds() - shaderModuleStartTime) / 1e3
150-
);
176+
logElapsedTraceMs("Selection RT shader modules created", shaderModuleStartTime);
151177

152178
VkPipelineShaderStageCreateInfo shaderStages[] = {
153179
makePipelineShaderStageInfo(VK_SHADER_STAGE_RAYGEN_BIT_KHR, rayGenModule),
@@ -190,10 +216,10 @@ VKRT_Result createSelectionRayTracingPipeline(VKRT* vkrt) {
190216
vkrt->core.selectionRayTracingPipeline = VK_NULL_HANDLE;
191217
goto cleanup;
192218
}
193-
LOG_TRACE("Selection RT stack size queried in %.3f ms", (double)(getMicroseconds() - stackSizeStartTime) / 1e3);
219+
logElapsedTraceMs("Selection RT stack size queried", stackSizeStartTime);
194220

195221
result = VKRT_SUCCESS;
196-
LOG_TRACE("Selection RT pipeline created in %.3f ms", (double)(getMicroseconds() - startTime) / 1e3);
222+
logSelectionRayTracingPipelineCreated(startTime);
197223

198224
cleanup:
199225
if (rayGenModule != VK_NULL_HANDLE) vkDestroyShaderModule(vkrt->core.device, rayGenModule, NULL);

0 commit comments

Comments
 (0)