Войти
ПрограммированиеФорумГрафика

[Vulkan] Некорректные результаты при измерении времени с использованием timestamp query

#0
0:30, 10 июля 2021

Привет.
Я пытаюсь измерить время исполнения моего буфера команд используя timestamp query.

Вот как я это делаю:

void MainWindow::updateCommandBuffer(int imageIndex)
{
  //Start recording
  if (vkBeginCommandBuffer(commandBuffers[imageIndex], &beginInfo) != VK_SUCCESS) {
    throw MakeErrorInfo("Failed to begin recording command buffer!");
  }

  vkCmdResetQueryPool(commandBuffers[imageIndex], queryPools[imageIndex], 0, 2);
  vkCmdWriteTimestamp(commandBuffers[imageIndex], VK_PIPELINE_STAGE_TOP_OF_PIPE_BIT, queryPools[imageIndex], 0);

  vkCmdBeginRenderPass(commandBuffers[imageIndex], &renderPassInfo, VK_SUBPASS_CONTENTS_INLINE);
  vkCmdBindPipeline(commandBuffers[imageIndex], VK_PIPELINE_BIND_POINT_GRAPHICS, graphicsPipeline);

  vkCmdBindVertexBuffers(commandBuffers[imageIndex], 0, 1, vertexBuffers, offsets);
  vkCmdBindIndexBuffer(commandBuffers[imageIndex], indexBuffer, 0, VK_INDEX_TYPE_UINT16);
  vkCmdBindDescriptorSets(commandBuffers[imageIndex], VK_PIPELINE_BIND_POINT_GRAPHICS, pipelineLayout, 0, 1, &descriptorSets[imageIndex], 0, nullptr);
  for (size_t i = 0; i < iterationsNumber; ++i) {
    vkCmdDrawIndexed(commandBuffers[imageIndex], static_cast<uint32_t>(indices.size()), 1, 0, 0, 0);
  }
  vkCmdEndRenderPass(commandBuffers[imageIndex]);

  vkCmdWriteTimestamp(commandBuffers[imageIndex], VK_PIPELINE_STAGE_BOTTOM_OF_PIPE_BIT, queryPools[imageIndex], 1);
  if (vkEndCommandBuffer(commandBuffers[imageIndex]) != VK_SUCCESS) {
    throw MakeErrorInfo("Failed to record command buffer!");
  }
}
Вот я установил метку в вершине конвейера и в конце.
(подсмотрел тут)

Всё что я рендерю, это окошко imgui и текстурированные квадраты.
Если iterationsNumber равно 1, то я получаю немного странные результаты:
Total frametime: 0.354 ms
Square command buffer rendertime: 0.016 ms

Тут ещё можно поверить что рендер моего командного буфера занимает столько времени по сравнению с всем временем.
totalframetime измеряет imgui и это время верно.

Однако если я установлю iterationsNumber равным 2000, то получу следующие цифры:
Total frametime: 5.483 ms
Squares command buffers rendertime: 2.331 ms

И это уже бред полнейший, не может же время рендера imgui окошка измениться.
Вот как это выглядит:
Изображение

А вот как выглядит код рендера(тут можно глянуть как я вычисляю время исполнения фреймбуфера):

+ Показать

Timestamp'ы вроде как правильно, однако время они измеряют неверно.
Почему так и как решить?


#1
4:35, 10 июля 2021

Забудь о правильном измерении времени с помощью timestamp. Он годится для относительного измерения, чтобы оценить какой из шейдеров быстрее, например.

#2
7:13, 10 июля 2021

нажо результат умножать на timestampPeriod

#3
9:20, 10 июля 2021

MikeNew
> Забудь о правильном измерении времени с помощью timestamp.

научи как правильно мерять

#4
10:46, 10 июля 2021

innuendo
> научи как правильно мерять
Самое главное - надо выставить стабильную частоту на ГПУ, иначе даже вендорский профайлер выдает бОльшее время, чем замеренное в приложении, где постоянная нагрузка.

#5
10:50, 10 июля 2021

mrjbom
А total frame time как считаешь?

#6
11:11, 10 июля 2021

/A\

float nanosecondsInTimestamp = deviceProperties.limits.timestampPeriod;
float timestampValueInMilliseconds = ((timestampsResults[1] - timestampsResults[0]) * nanosecondsInTimestamp) / 1000000;
Умножаю
#7
11:12, 10 июля 2021

HolyDel
total frametime считает imgui, но это время полностью верное, проверял с помощью renderdoc.

#8
12:06, 10 июля 2021

innuendo
> научи как правильно мерять
Ты сам прекрасно знаешь что никак.

#9
12:19, 10 июля 2021

MikeNew
Приплыли, не уж то в моём конкретном случае нельзя адекватно измерить время? Можно. Вот и как это сделать?

#10
14:23, 10 июля 2021

mrjbom
> Вот и как это сделать?
Можешь попробовать залочить частоту видеокарты, как посоветовали выше, может поможет.

#11
(Правка: 4:11) 3:25, 11 июля 2021

Вставь VK_QUERY_RESULT_WAIT_BIT, если хочешь мерить как у тебя в коде(frame in flight в теории должен избавить от этого флага, но нет. Можешь сделать с чеком значения в пуле на доступность). И кажется у тебя buffer  on flight зависит от числа изображений в swap chain, что не правильно. Так же не исключай то что GPU, не догружен, из-за загрузки CPU. Чекни в отладчике, а-ля RGP или в RenderDoc(на AMD там не верное время будет, потому что баг время не домножается timestamp period, а у NV timestamp period =  1.0 поэтому результаты корректные будут

#12
(Правка: 14:19) 14:18, 11 июля 2021

IBets
> Вставь VK_QUERY_RESULT_WAIT_BIT, если хочешь мерить как у тебя в коде(frame in
> flight в теории должен избавить от этого флага, но нет. Можешь сделать с чеком
> значения в пуле на доступность)
Ну VK_QUERY_RESULT_WAIT_BIT использовать не хочу, т.к. тогда поток будет ждать готовности результатов, а значит я не смогу отправить следующий кадр в работу. Получится, что пока у меня будет рендериться один кадр, остальные будут впустую ждать, хотя могли бы отправиться на рендер.
Я пробовал страховаться используя VK_QUERY_RESULT_WITH_AVAILABILITY_BIT, дабы быть уверенным в том, что результаты в пуле корректные, однако и это не помогает и результаты несмотря на статус готовности не меняются, значит время верное.

А вообще, я полагаю, что время работы vkQueuePresentKHR так-же возрастает при рендере 2000 квадратов, а значит это лишнее время может взяться и оттуда.

RenderDoc выдаёт иные результаты, но дело в том, что он не может выступать нормальным профайлером т.к. измеряет время вызовов не реальное, а "виртуальное", просто ставив timestamp и "прикидывая".
Хотел найти нормальные профайлеры, но профайлер от Nvidia на моей GTX 1080 не поддерживает возможность профилировать Vulkan.

#13
14:50, 11 июля 2021

mrjbom
> но профайлер от Nvidia на моей GTX 1080 не поддерживает возможность профилировать Vulkan.
Раньше поддерживал, может надо более старую версию скачать, у них есть неприятная особенность поддерживать только свежие видеокарты.

ПрограммированиеФорумГрафика