Scarfski/filament
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

vulkan: address debugUtils bug (#6904)

Browse Source 
vkCmdEndDebugUtilsLabelEXT expects that a label was "pushed" onto
the command queue (as described in the spec). It is possible to push
labels across command buffers, but the pushed label must still be in
the queue (unexecuted) when End is called. This implies that we need
to make sure the labels are in a good state (all popped) when
vkQueueSubmit is called.

- We add a stack to carry the labels across vkQueueSubmit.
- Also add CPU time durations between push and pop to provide rough
  CPU execution times (in debug).
- Add systrace markers for Android systrace
This commit is contained in:
Powei Feng
2023-06-15 11:27:48 -07:00
committed by GitHub
parent 432b5d0427
commit 5c11b237f3
6 changed files with 226 additions and 85 deletions
Download Patch File Download Diff File Expand all files Collapse all files

160
filament/backend/src/vulkan/VulkanCommands.cpp
View File

@@ -22,6 +22,8 @@
#include "VulkanCommands.h"
#include "VulkanConstants.h"
#include "VulkanContext.h"
#include "VulkanDriver.h"
#include <utils/Log.h>
#include <utils/Panic.h>
@@ -32,6 +34,8 @@ using namespace utils;
namespace filament::backend {
using Timestamp = VulkanGroupMarkers::Timestamp;
VulkanCmdFence::VulkanCmdFence(VkDevice device, bool signaled) : device(device) {
VkFenceCreateInfo fenceCreateInfo { .sType = VK_STRUCTURE_TYPE_FENCE_CREATE_INFO };
if (signaled) {
@@ -64,10 +68,51 @@ static VkCommandPool createPool(VkDevice device, uint32_t queueFamilyIndex) {
}
VulkanCommands::VulkanCommands(VkDevice device, VkQueue queue, uint32_t queueFamilyIndex) : mDevice(device),
mQueue(queue), mPool(createPool(mDevice, queueFamilyIndex)) {
VkSemaphoreCreateInfo sci { .sType = VK_STRUCTURE_TYPE_SEMAPHORE_CREATE_INFO };
for (auto& semaphore : mSubmissionSignals) {
void VulkanGroupMarkers::push(std::string const& marker, Timestamp start) noexcept {
mMarkers.push(marker);
#if FILAMENT_VULKAN_VERBOSE
mTimestamps.push(start.time_since_epoch().count() > 0.0
? start
: std::chrono::high_resolution_clock::now());
#endif
}
std::pair<std::string, Timestamp> VulkanGroupMarkers::pop() noexcept {
auto const marker = mMarkers.top();
mMarkers.pop();
#if FILAMENT_VULKAN_VERBOSE
auto const topTimestamp = mTimestamps.top();
mTimestamps.pop();
return std::make_pair(marker, topTimestamp);
#else
return std::make_pair(marker, Timestamp{});
#endif
}
std::pair<std::string, Timestamp> VulkanGroupMarkers::top() const {
assert_invariant(!empty());
auto const marker = mMarkers.top();
#if FILAMENT_VULKAN_VERBOSE
auto const topTimestamp = mTimestamps.top();
return std::make_pair(marker, topTimestamp);
#else
return std::make_pair(marker, Timestamp{});
#endif
}
bool VulkanGroupMarkers::empty() const noexcept {
return mMarkers.empty();
}
VulkanCommands::VulkanCommands(VkDevice device, VkQueue queue, uint32_t queueFamilyIndex,
VulkanContext* context)
: mDevice(device),
mQueue(queue),
mPool(createPool(mDevice, queueFamilyIndex)),
mContext(context) {
VkSemaphoreCreateInfo sci{.sType = VK_STRUCTURE_TYPE_SEMAPHORE_CREATE_INFO};
for (auto& semaphore: mSubmissionSignals) {
vkCreateSemaphore(mDevice, &sci, nullptr, &semaphore);
}
}
@@ -139,6 +184,13 @@ VulkanCommandBuffer const& VulkanCommands::get(bool blockOnGC) {
mObserver->onCommandBuffer(*mCurrent);
}
// We push the current markers onto a temporary stack. This must be placed after mCurrent is set
// to the new command buffer since pushGroupMarker also calls get().
while (mCarriedOverMarkers && !mCarriedOverMarkers->empty()) {
auto [marker, time] = mCarriedOverMarkers->pop();
pushGroupMarker(marker.c_str(), time);
}
return *mCurrent;
}
@@ -195,6 +247,17 @@ bool VulkanCommands::flush() {
<< io::endl;
}
// Before actually submitting, we need to pop any leftover group markers.
while (mGroupMarkers && !mGroupMarkers->empty()) {
if (!mCarriedOverMarkers) {
mCarriedOverMarkers = std::make_unique<VulkanGroupMarkers>();
}
auto const [marker, time] = mGroupMarkers->top();
mCarriedOverMarkers->push(marker, time);
// We still need to call through to vkCmdEndDebugUtilsLabelEXT.
popGroupMarker();
}
auto& cmdfence = mCurrent->fence;
std::unique_lock<utils::Mutex> lock(cmdfence->mutex);
cmdfence->status.store(VK_NOT_READY);
@@ -270,7 +333,94 @@ void VulkanCommands::updateFences() {
}
}
} // namespace filament::backend
void VulkanCommands::pushGroupMarker(char const* str, VulkanGroupMarkers::Timestamp timestamp) {
#if FILAMENT_VULKAN_VERBOSE
// If the timestamp is not 0, then we are carrying over a marker across buffer submits.
// If it is 0, then this is a normal marker push and we should just print debug line as usual.
if (timestamp.time_since_epoch().count() == 0.0) {
utils::slog.d << "----> " << str << utils::io::endl;
}
#endif
// TODO: Add group marker color to the Driver API
const VkCommandBuffer cmdbuffer = get().cmdbuffer;
if (!mGroupMarkers) {
mGroupMarkers = std::make_unique<VulkanGroupMarkers>();
}
mGroupMarkers->push(str, timestamp);
if (mContext->isDebugUtilsSupported()) {
VkDebugUtilsLabelEXT labelInfo = {
.sType = VK_STRUCTURE_TYPE_DEBUG_UTILS_LABEL_EXT,
.pLabelName = str,
.color = {0, 1, 0, 1},
};
vkCmdBeginDebugUtilsLabelEXT(cmdbuffer, &labelInfo);
} else if (mContext->isDebugMarkersSupported()) {
VkDebugMarkerMarkerInfoEXT markerInfo = {
.sType = VK_STRUCTURE_TYPE_DEBUG_MARKER_MARKER_INFO_EXT,
.pMarkerName = str,
.color = {0.0f, 1.0f, 0.0f, 1.0f},
};
vkCmdDebugMarkerBeginEXT(cmdbuffer, &markerInfo);
}
}
void VulkanCommands::popGroupMarker() {
assert_invariant(mGroupMarkers);
if (!mGroupMarkers->empty()) {
const VkCommandBuffer cmdbuffer = get().cmdbuffer;
#if FILAMENT_VULKAN_VERBOSE
auto const [marker, startTime] = mGroupMarkers->pop();
auto const endTime = std::chrono::high_resolution_clock::now();
std::chrono::duration<double> diff = endTime - startTime;
utils::slog.d << "<---- " << marker << " elapsed: " << (diff.count() * 1000) << " ms\n"
<< utils::io::flush;
#else
mGroupMarkers->pop();
#endif
if (mContext->isDebugUtilsSupported()) {
vkCmdEndDebugUtilsLabelEXT(cmdbuffer);
} else if (mContext->isDebugMarkersSupported()) {
vkCmdDebugMarkerEndEXT(cmdbuffer);
}
} else if (mCarriedOverMarkers && !mCarriedOverMarkers->empty()) {
// It could be that pop is called between flush() and get() (new command buffer), in which
// case the marker is in "carried over" state. We'd just remove that
mCarriedOverMarkers->pop();
}
}
void VulkanCommands::insertEventMarker(char const* string, uint32_t len) {
VkCommandBuffer const cmdbuffer = get().cmdbuffer;
if (mContext->isDebugUtilsSupported()) {
VkDebugUtilsLabelEXT labelInfo = {
.sType = VK_STRUCTURE_TYPE_DEBUG_UTILS_LABEL_EXT,
.pLabelName = string,
.color = {1, 1, 0, 1},
};
vkCmdInsertDebugUtilsLabelEXT(cmdbuffer, &labelInfo);
} else if (mContext->isDebugMarkersSupported()) {
VkDebugMarkerMarkerInfoEXT markerInfo = {
.sType = VK_STRUCTURE_TYPE_DEBUG_MARKER_MARKER_INFO_EXT,
.pMarkerName = string,
.color = {0.0f, 1.0f, 0.0f, 1.0f},
};
vkCmdDebugMarkerInsertEXT(cmdbuffer, &markerInfo);
}
}
std::string VulkanCommands::getTopGroupMarker() const {
if (!mGroupMarkers || mGroupMarkers->empty()) {
return "";
}
return std::get<0>(mGroupMarkers->top());
}
}// namespace filament::backend
#if defined(_MSC_VER)
#pragma warning( pop )

45
filament/backend/src/vulkan/VulkanCommands.h
View File

@@ -26,8 +26,31 @@
#include <atomic>
#include <chrono>
#include <stack>
#include <string>
#include <utility>
namespace filament::backend {
struct VulkanContext;
class VulkanGroupMarkers {
public:
using Timestamp = std::chrono::time_point<std::chrono::high_resolution_clock>;
void push(std::string const& marker, Timestamp start = {}) noexcept;
std::pair<std::string, Timestamp> pop() noexcept;
std::pair<std::string, Timestamp> top() const;
bool empty() const noexcept;
private:
std::stack<std::string> mMarkers;
#if FILAMENT_VULKAN_VERBOSE
std::stack<Timestamp> mTimestamps;
#endif
};
// Wrapper to enable use of shared_ptr for implementing shared ownership of low-level Vulkan fences.
struct VulkanCmdFence {
VulkanCmdFence(VkDevice device, bool signaled = false);
@@ -86,7 +109,8 @@ public:
//
class VulkanCommands {
public:
VulkanCommands(VkDevice device, VkQueue queue, uint32_t queueFamilyIndex);
VulkanCommands(VkDevice device, VkQueue queue, uint32_t queueFamilyIndex,
VulkanContext* context);
~VulkanCommands();
// Creates a "current" command buffer if none exists, otherwise returns the current one.
@@ -121,11 +145,21 @@ class VulkanCommands {
// The observer's event handler can only be called during get().
void setObserver(CommandBufferObserver* observer) { mObserver = observer; }
void pushGroupMarker(char const* str, VulkanGroupMarkers::Timestamp timestamp = {});
void popGroupMarker();
void insertEventMarker(char const* string, uint32_t len);
std::string getTopGroupMarker() const;
private:
static constexpr int CAPACITY = VK_MAX_COMMAND_BUFFERS;
const VkDevice mDevice;
const VkQueue mQueue;
const VkCommandPool mPool;
VkDevice const mDevice;
VkQueue const mQueue;
VkCommandPool const mPool;
VulkanContext const* mContext;
VulkanCommandBuffer* mCurrent = nullptr;
VkSemaphore mSubmissionSignal = {};
VkSemaphore mInjectedSignal = {};
@@ -133,6 +167,9 @@ class VulkanCommands {
VkSemaphore mSubmissionSignals[CAPACITY] = {};
size_t mAvailableCount = CAPACITY;
CommandBufferObserver* mObserver = nullptr;
std::unique_ptr<VulkanGroupMarkers> mGroupMarkers;
std::unique_ptr<VulkanGroupMarkers> mCarriedOverMarkers;
};
} // namespace filament::backend

2
filament/backend/src/vulkan/VulkanContext.cpp
View File

@@ -15,6 +15,8 @@
*/
#include "VulkanContext.h"
#include "VulkanCommands.h"
#include "VulkanHandles.h"
#include "VulkanMemory.h"
#include "VulkanTexture.h"

2
filament/backend/src/vulkan/VulkanContext.h
View File

@@ -17,7 +17,6 @@
#ifndef TNT_FILAMENT_BACKEND_VULKANCONTEXT_H
#define TNT_FILAMENT_BACKEND_VULKANCONTEXT_H
#include "VulkanCommands.h"
#include "VulkanConstants.h"
#include "VulkanImageUtility.h"
#include "VulkanPipelineCache.h"
@@ -38,6 +37,7 @@ struct VulkanSwapChain;
struct VulkanTexture;
class VulkanStagePool;
struct VulkanTimerQuery;
struct VulkanCommandBuffer;
struct VulkanAttachment {
VulkanTexture* texture;

101
filament/backend/src/vulkan/VulkanDriver.cpp
View File

@@ -30,16 +30,12 @@
#include <utils/CString.h>
#include <utils/FixedCapacityVector.h>
#include <utils/Panic.h>
#include <utils/Systrace.h>
#ifndef NDEBUG
#include <set>
#endif
#if FILAMENT_VULKAN_VERBOSE
#include <stack>
static std::stack<std::string> renderPassMarkers;
#endif
using namespace bluevk;
using utils::FixedCapacityVector;
@@ -186,7 +182,7 @@ VulkanDriver::VulkanDriver(VulkanPlatform* platform, VulkanContext const& contex
#endif
mTimestamps = std::make_unique<VulkanTimestamps>(mPlatform->getDevice());
mCommands = std::make_unique<VulkanCommands>(mPlatform->getDevice(),
mPlatform->getGraphicsQueue(), mPlatform->getGraphicsQueueFamilyIndex());
mPlatform->getGraphicsQueue(), mPlatform->getGraphicsQueueFamilyIndex(), &mContext);
mCommands->setObserver(&mPipelineCache);
mPipelineCache.setDevice(mPlatform->getDevice(), mAllocator);
@@ -1146,15 +1142,18 @@ void VulkanDriver::beginRenderPass(Handle<HwRenderTarget> rth, const RenderPassP
VkFramebuffer vkfb = mFramebufferCache.getFramebuffer(fbkey);
// Assign a label to the framebuffer for debugging purposes.
if (UTILS_UNLIKELY(mContext.isDebugUtilsSupported()) && !mCurrentDebugMarker.empty()) {
const VkDebugUtilsObjectNameInfoEXT info = {
VK_STRUCTURE_TYPE_DEBUG_UTILS_OBJECT_NAME_INFO_EXT,
nullptr,
VK_OBJECT_TYPE_FRAMEBUFFER,
reinterpret_cast<uint64_t>(vkfb),
mCurrentDebugMarker.c_str(),
};
vkSetDebugUtilsObjectNameEXT(mPlatform->getDevice(), &info);
if (UTILS_UNLIKELY(mContext.isDebugUtilsSupported())) {
auto const topMarker = mCommands->getTopGroupMarker();
if (!topMarker.empty()) {
const VkDebugUtilsObjectNameInfoEXT info = {
VK_STRUCTURE_TYPE_DEBUG_UTILS_OBJECT_NAME_INFO_EXT,
nullptr,
VK_OBJECT_TYPE_FRAMEBUFFER,
reinterpret_cast<uint64_t>(vkfb),
topMarker.c_str(),
};
vkSetDebugUtilsObjectNameEXT(mPlatform->getDevice(), &info);
}
}
// The current command buffer now owns a reference to the render target and its attachments.
@@ -1375,75 +1374,29 @@ void VulkanDriver::bindSamplers(uint32_t index, Handle<HwSamplerGroup> sbh) {
}
void VulkanDriver::insertEventMarker(char const* string, uint32_t len) {
constexpr float MARKER_COLOR[] = { 0.0f, 1.0f, 0.0f, 1.0f };
VkCommandBuffer const cmdbuffer = mCommands->get().cmdbuffer;
if (mContext.isDebugUtilsSupported()) {
VkDebugUtilsLabelEXT labelInfo = {
.sType = VK_STRUCTURE_TYPE_DEBUG_UTILS_LABEL_EXT,
.pLabelName = string,
.color = {1, 1, 0, 1},
};
vkCmdInsertDebugUtilsLabelEXT(cmdbuffer, &labelInfo);
} else if (mContext.isDebugMarkersSupported()) {
VkDebugMarkerMarkerInfoEXT markerInfo = {};
markerInfo.sType = VK_STRUCTURE_TYPE_DEBUG_MARKER_MARKER_INFO_EXT;
memcpy(markerInfo.color, &MARKER_COLOR[0], sizeof(MARKER_COLOR));
markerInfo.pMarkerName = string;
vkCmdDebugMarkerInsertEXT(cmdbuffer, &markerInfo);
}
mCommands->insertEventMarker(string, len);
}
void VulkanDriver::pushGroupMarker(char const* string, uint32_t len) {
#if FILAMENT_VULKAN_VERBOSE
renderPassMarkers.push(std::string(string));
utils::slog.d << "----> " << string << utils::io::endl;
#endif
// TODO: Add group marker color to the Driver API
constexpr float MARKER_COLOR[] = { 0.0f, 1.0f, 0.0f, 1.0f };
const VkCommandBuffer cmdbuffer = mCommands->get().cmdbuffer;
if (mContext.isDebugUtilsSupported()) {
VkDebugUtilsLabelEXT labelInfo = {
.sType = VK_STRUCTURE_TYPE_DEBUG_UTILS_LABEL_EXT,
.pLabelName = string,
.color = {0, 1, 0, 1},
};
vkCmdBeginDebugUtilsLabelEXT(cmdbuffer, &labelInfo);
mCurrentDebugMarker = string;
} else if (mContext.isDebugMarkersSupported()) {
VkDebugMarkerMarkerInfoEXT markerInfo = {};
markerInfo.sType = VK_STRUCTURE_TYPE_DEBUG_MARKER_MARKER_INFO_EXT;
memcpy(markerInfo.color, &MARKER_COLOR[0], sizeof(MARKER_COLOR));
markerInfo.pMarkerName = string;
vkCmdDebugMarkerBeginEXT(cmdbuffer, &markerInfo);
void VulkanDriver::pushGroupMarker(char const* string, uint32_t) {
// Turns out all the markers are 0-terminated, so we can just pass it without len.
mCommands->pushGroupMarker(string);
{
SYSTRACE_CONTEXT();
SYSTRACE_NAME_BEGIN(string);
}
}
void VulkanDriver::popGroupMarker(int) {
#if FILAMENT_VULKAN_VERBOSE
std::string const& marker = renderPassMarkers.top();
renderPassMarkers.pop();
utils::slog.d << "<---- " << marker << utils::io::endl;
#endif
const VkCommandBuffer cmdbuffer = mCommands->get().cmdbuffer;
if (mContext.isDebugUtilsSupported()) {
vkCmdEndDebugUtilsLabelEXT(cmdbuffer);
mCurrentDebugMarker.clear();
} else if (mContext.isDebugMarkersSupported()) {
vkCmdDebugMarkerEndEXT(cmdbuffer);
mCommands->popGroupMarker();
{
SYSTRACE_CONTEXT();
SYSTRACE_NAME_END();
}
}
void VulkanDriver::startCapture(int) {
void VulkanDriver::startCapture(int) {}
}
void VulkanDriver::stopCapture(int) {
}
void VulkanDriver::stopCapture(int) {}
void VulkanDriver::readPixels(Handle<HwRenderTarget> src, uint32_t x, uint32_t y,
uint32_t width, uint32_t height, PixelBufferDescriptor&& pbd) {

1
filament/backend/src/vulkan/VulkanDriver.h
View File

@@ -148,7 +148,6 @@ private:
VmaAllocator mAllocator = VK_NULL_HANDLE;
VkDebugReportCallbackEXT mDebugCallback = VK_NULL_HANDLE;
VkDebugUtilsMessengerEXT mDebugMessenger = VK_NULL_HANDLE;
std::string mCurrentDebugMarker;
VulkanContext mContext = {};
HandleAllocatorVK mHandleAllocator;