I am trying to have a measure of how much it takes for a frame to render in my Vulkan application. I came across this and this very helpful articles, but I think my code is not writing the timestamps appropriately. The issue is that when I read them, the time before and after the frame is always the same.
I am using multiple frames in flight, so multiple command buffers recorded, and current indicates the command buffer being recorded now. Here is the command buffer:
vkBeginCommandBuffer(cmd, ...);
vkCmdResetQueryPool(cmd, query_pool, current * 2, 2);
vkCmdWriteTimestamp(cmd, VK_PIPELINE_STAGE_TOP_OF_PIPE_BIT, query_pool, current * 2);
vkCmdBeginRenderPass(cmd, ...);
// Draw commands...
vkCmdEndRenderPass(cmd);
vkCmdWriteTimestamp(cmd, VK_PIPELINE_STAGE_BOTTOM_OF_PIPE_BIT, query_pool, current * 2 + 1);
vkEndCommandBuffer(cmd);
I tried multiple ways of querying the result, from vkGetQueryPoolResults to vkCmdCopyQueryPoolResults with a buffer, but both give the same results so I assume the issue is with writing the timestamps. Here is an example of vkGetQueryPoolResults, which is called before the same command buffer is recorded and submitted again, so that queries have time to complete:
ui64 queries[4];
VkResult result = vkGetQueryPoolResults(device, query_pool, 2 * current, 2, 4 * sizeof(ui64), queries, 2 * sizeof(ui64), VK_QUERY_RESULT_64_BIT | VK_QUERY_RESULT_WITH_AVAILABILITY_BIT);
if (result == VK_NOT_READY)
log::info("Result not ready");
else if (result == VK_SUCCESS)
log::info("Current: %d, %d %d (Availability: %d %d)", current, queries[0], queries[2], queries[1], queries[3]);
I have also tried with different flags, including VK_QUERY_RESULT_WITH_AVAILABILITY_BIT and VK_QUERY_RESULT_WITH_WAIT_BIT. The results are as follow:
[ INFO ] Current: 0, 1421658976 1421658976 (Availability: 1 1)
[ INFO ] Current: 1, 1425976254 1425976254 (Availability: 1 1)
[ INFO ] Current: 2, 1438268198 1438268198 (Availability: 1 1)
[ INFO ] Current: 0, 1442609892 1442609892 (Availability: 1 1)
[ INFO ] Current: 1, 1454983477 1454983477 (Availability: 1 1)
[ INFO ] Current: 2, 1459295156 1459295156 (Availability: 1 1)
[ INFO ] Current: 0, 1471665161 1471665161 (Availability: 1 1)
[ INFO ] Current: 1, 1475966118 1475966118 (Availability: 1 1)
[ INFO ] Current: 2, 1488409009 1488409009 (Availability: 1 1)
[ INFO ] Current: 0, 1492655837 1492655837 (Availability: 1 1)
[ INFO ] Current: 1, 1504988977 1504988977 (Availability: 1 1)
[ INFO ] Current: 2, 1509278297 1509278297 (Availability: 1 1)
As you can see, even if the timestamps change from one frame to the next, the two timestamps recorded in the same frame are always the same, which seems like it took no time to execute the draw calls. I am probably missing something trivial in writing the timestamps, but I've tried many things and always get the same. Also, I didn't mention it before but I already checked for the device to support timestamps with timestampValidBits and got the timestamp period, that in my device is 1.