Skip to content

debug_marker: publish object names in a SQL-visible form as well #40

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
jimblacklercorp wants to merge 1 commit into
base: main
Choose a base branch
from
+311 −20
Draft

debug_marker: publish object names in a SQL-visible form as well #40

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
62 changes: 42 additions & 20 deletions layersvt/debug_marker/debug_marker.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,41 +34,63 @@ VkInstance DebugMarker::GetVkInstance(VkPhysicalDevice phys_dev) {
return VK_NULL_HANDLE;
}

void DebugMarker::SetDebugObjectName(uint64_t device, int32_t type, uint64_t handle, const char* name) {
std::lock_guard<std::mutex> lock(mutex_);

std::string name_str = name ? name : "NULL";
debug_object_names_[std::make_pair(type, handle)] = DebugObjectName(device, type, handle, name_str);
void DebugMarker::Emit(const DebugObjectName& marker) {
const uint64_t device = marker.vk_device;
const int32_t type = marker.object_type;
const uint64_t handle = marker.handle;
const std::string name_str = marker.name;

// Representation 1: a VulkanApiEvent.VkDebugUtilsObjectName packet. trace_processor folds these
// into a private lookup that it consults only while parsing GpuRenderStageEvent, which is what
// puts render pass and render target names on GPU queue slices. The names are not reachable
// from SQL in this form.
//
// This is written as a raw trace packet rather than a track event, so it reaches every session
// in which this layer's data source is enabled, independently of category filtering.
//
// The clock id must be set explicitly. Once this sequence carries a track event, the SDK
// publishes TracePacketDefaults with timestamp_clock_id = the incremental clock, and a packet
// that sets a timestamp without naming a clock inherits it. An absolute boot-time value read
// as a delta advances the sequence clock by hours, and every later event on the sequence -
// including the VulkanObjectName instants below - inherits the corrupted base.
perfetto::TrackEvent::Trace([device, type, handle, name_str](perfetto::TrackEvent::TraceContext ctx) {
auto packet = ctx.NewTracePacket();
packet->set_timestamp(perfetto::base::GetBootTimeNs().count());
packet->set_timestamp_clock_id(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME);
auto event = packet->set_vulkan_api_event()->set_vk_debug_utils_object_name();
event->set_vk_device(device);
event->set_object_type(type);
event->set_object(handle);
event->set_object_name(name_str.c_str());
});

// Representation 2: a "VulkanObjectName" instant event. This lands in trace_processor's slice
// table with its arguments intact, so a consumer can join names to any object by handle, for
// any object type. Sherlock's Vulkan memory snapshot uses it to label buffers, images and
// device memory blocks, which representation 1 cannot do.
//
// Both are written because neither subsumes the other: the packet is the only form the GPU
// render stage parser reads, and the slice is the only form SQL can see. A name is small, so
// publishing it twice costs far less than losing either consumer.
TRACE_EVENT_INSTANT("VulkanDebugMarker", "VulkanObjectName",
"object_type", type,
"object_handle", handle,
"object_name", name_str.c_str());
}

void DebugMarker::SetDebugObjectName(uint64_t device, int32_t type, uint64_t handle, const char* name) {
std::lock_guard<std::mutex> lock(mutex_);

DebugObjectName& marker = debug_object_names_[std::make_pair(type, handle)];
marker = DebugObjectName(device, type, handle, name ? name : "NULL");

Emit(marker);
}

void DebugMarker::EmitAllDebugMarkers() {
std::lock_guard<std::mutex> lock(mutex_);
for (const auto& entry : debug_object_names_) {
const auto& marker = entry.second;
uint64_t device = marker.vk_device;
int32_t type = marker.object_type;
uint64_t handle = marker.handle;
std::string name_str = marker.name;

perfetto::TrackEvent::Trace([device, type, handle, name_str](perfetto::TrackEvent::TraceContext ctx) {
auto packet = ctx.NewTracePacket();
packet->set_timestamp(perfetto::base::GetBootTimeNs().count());
auto event = packet->set_vulkan_api_event()->set_vk_debug_utils_object_name();
event->set_vk_device(device);
event->set_object_type(type);
event->set_object(handle);
event->set_object_name(name_str.c_str());
});
Emit(entry.second);
}
}

Expand Down
11 changes: 11 additions & 0 deletions layersvt/debug_marker/debug_marker.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -112,6 +112,17 @@ class DebugMarker {
: vk_device(dev), object_type(type), handle(h), name(n) {}
};

/**
* @brief Writes one object name to every enabled tracing session.
*
* Both the live naming path and the session-start replay go through here so the two cannot
* drift apart in what they publish.
*
* @note The caller must hold mutex_.
* @param marker The object name to publish.
*/
void Emit(const DebugObjectName& marker);

std::mutex mutex_;
/**
* @brief Maps a physical device handle to its corresponding Vulkan instance handle.
Expand Down
258 changes: 258 additions & 0 deletions layersvt/test/test_debugmarker.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,12 +15,172 @@

#include "layer_test_helper.h"
#include "../debug_marker/debug_marker.h"
#include "../debug_marker/debug_marker_perfetto.h"
#include <vulkan/vulkan_core.h>
#include <gtest/gtest.h>
#include <mutex>
#include <stdlib.h>
#include <string>
#include <unordered_map>
#include <vector>

static const char* kLayerName = "VK_LAYER_GOOGLE_DebugMarker";

namespace {

void EnsureInProcessPerfettoInitialized() {
static std::once_flag init_once;
std::call_once(init_once, []() {
perfetto::TracingInitArgs args;
args.backends = perfetto::kInProcessBackend;
perfetto::Tracing::Initialize(args);
InitializeDebugMarkerPerfetto();
});
}

std::unique_ptr<perfetto::TracingSession> StartInProcessTrace() {
EnsureInProcessPerfettoInitialized();

perfetto::TraceConfig cfg;
cfg.add_buffers()->set_size_kb(1024);
auto* ds_cfg = cfg.add_data_sources()->mutable_config();
ds_cfg->set_name("track_event");

auto session = perfetto::Tracing::NewTrace(perfetto::kInProcessBackend);
session->Setup(cfg);
session->StartBlocking();
return session;
}

std::vector<char> StopAndReadTrace(std::unique_ptr<perfetto::TracingSession> session) {
perfetto::TrackEvent::Flush();
session->StopBlocking();
return session->ReadTraceBlocking();
}

struct DecodedRawObjectNamePacket {
uint64_t vk_device = 0;
int32_t object_type = 0;
uint64_t object = 0;
std::string object_name;
bool has_timestamp_clock_id = false;
uint32_t timestamp_clock_id = 0;
};

struct DecodedObjectNameInstant {
std::string event_name;
int64_t object_type = 0;
uint64_t object_handle = 0;
std::string object_name;
};

struct DecodedTrace {
std::vector<DecodedRawObjectNamePacket> raw_packets;
std::vector<DecodedObjectNameInstant> instants;
bool saw_incremental_default_clock = false;
};

DecodedTrace DecodeTrace(const std::vector<char>& raw_trace) {
DecodedTrace result;
// Per-sequence interned tables for event_names and debug_annotation_names.
std::unordered_map<uint32_t, std::unordered_map<uint64_t, std::string>> event_names;
std::unordered_map<uint32_t, std::unordered_map<uint64_t, std::string>> annotation_names;

perfetto::protos::pbzero::Trace::Decoder trace(
reinterpret_cast<const uint8_t*>(raw_trace.data()), raw_trace.size());

for (auto packet_it = trace.packet(); packet_it; ++packet_it) {
perfetto::protos::pbzero::TracePacket::Decoder packet(*packet_it);
const uint32_t seq_id = packet.trusted_packet_sequence_id();

if (packet.has_incremental_state_cleared() && packet.incremental_state_cleared()) {
event_names[seq_id].clear();
annotation_names[seq_id].clear();
}

if (packet.has_trace_packet_defaults()) {
perfetto::protos::pbzero::TracePacketDefaults::Decoder defaults(
packet.trace_packet_defaults());
if (defaults.has_timestamp_clock_id() &&
defaults.timestamp_clock_id() !=
perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME) {
result.saw_incremental_default_clock = true;
}
}

if (packet.has_interned_data()) {
perfetto::protos::pbzero::InternedData::Decoder interned(packet.interned_data());
for (auto it = interned.event_names(); it; ++it) {
perfetto::protos::pbzero::EventName::Decoder entry(*it);
event_names[seq_id][entry.iid()] = entry.name().ToStdString();
}
for (auto it = interned.debug_annotation_names(); it; ++it) {
perfetto::protos::pbzero::DebugAnnotationName::Decoder entry(*it);
annotation_names[seq_id][entry.iid()] = entry.name().ToStdString();
}
}

if (packet.has_vulkan_api_event()) {
perfetto::protos::pbzero::VulkanApiEvent::Decoder api_event(packet.vulkan_api_event());
if (api_event.has_vk_debug_utils_object_name()) {
perfetto::protos::pbzero::VulkanApiEvent_VkDebugUtilsObjectName::Decoder marker(
api_event.vk_debug_utils_object_name());
DecodedRawObjectNamePacket decoded;
decoded.vk_device = marker.vk_device();
decoded.object_type = marker.object_type();
decoded.object = marker.object();
decoded.object_name = marker.object_name().ToStdString();
decoded.has_timestamp_clock_id = packet.has_timestamp_clock_id();
decoded.timestamp_clock_id = packet.timestamp_clock_id();
result.raw_packets.push_back(std::move(decoded));
}
}

if (packet.has_track_event()) {
perfetto::protos::pbzero::TrackEvent::Decoder track_event(packet.track_event());
if (track_event.type() != perfetto::protos::pbzero::TrackEvent::TYPE_INSTANT) {
continue;
}

std::string ev_name;
if (track_event.has_name()) {
ev_name = track_event.name().ToStdString();
} else if (track_event.has_name_iid()) {
ev_name = event_names[seq_id][track_event.name_iid()];
}
if (ev_name != "VulkanObjectName") {
continue;
}

DecodedObjectNameInstant instant;
instant.event_name = std::move(ev_name);
for (auto ann_it = track_event.debug_annotations(); ann_it; ++ann_it) {
perfetto::protos::pbzero::DebugAnnotation::Decoder ann(*ann_it);
std::string key;
if (ann.has_name()) {
key = ann.name().ToStdString();
} else if (ann.has_name_iid()) {
key = annotation_names[seq_id][ann.name_iid()];
}

if (key == "object_type") {
instant.object_type = ann.has_int_value()
? ann.int_value()
: static_cast<int64_t>(ann.uint_value());
} else if (key == "object_handle") {
instant.object_handle = ann.uint_value();
} else if (key == "object_name") {
instant.object_name = ann.string_value().ToStdString();
}
}
result.instants.push_back(std::move(instant));
}
}
return result;
}

} // namespace

class DebugMarkerTests : public VkTestFramework {
public:
~DebugMarkerTests(){};
Expand Down Expand Up @@ -62,3 +222,101 @@ TEST_F(DebugMarkerTests, CombinedTest) {
DebugMarker::Get().Clear();
EXPECT_FALSE(DebugMarker::Get().HasDebugObjectName(VK_OBJECT_TYPE_INSTANCE, (uint64_t)instance, "MyInstanceRenamed"));
}

TEST_F(DebugMarkerTests, EmitsBothRawPacketAndSqlVisibleInstantEvent) {
TEST_DESCRIPTION("Verify SetDebugObjectName emits both VkDebugUtilsObjectName and a VulkanObjectName instant event");

DebugMarker::Get().Clear();
auto session = StartInProcessTrace();

DebugMarker::Get().SetDebugObjectName(0xD001, VK_OBJECT_TYPE_BUFFER, 0xB001, "VertexBuffer");
DebugMarker::Get().SetDebugObjectName(0xD001, VK_OBJECT_TYPE_IMAGE, 0xA002, "AlbedoTexture");

DecodedTrace trace = DecodeTrace(StopAndReadTrace(std::move(session)));
DebugMarker::Get().Clear();

ASSERT_EQ(trace.raw_packets.size(), 2u);
EXPECT_EQ(trace.raw_packets[0].vk_device, 0xD001u);
EXPECT_EQ(trace.raw_packets[0].object_type, VK_OBJECT_TYPE_BUFFER);
EXPECT_EQ(trace.raw_packets[0].object, 0xB001u);
EXPECT_EQ(trace.raw_packets[0].object_name, "VertexBuffer");

EXPECT_EQ(trace.raw_packets[1].vk_device, 0xD001u);
EXPECT_EQ(trace.raw_packets[1].object_type, VK_OBJECT_TYPE_IMAGE);
EXPECT_EQ(trace.raw_packets[1].object, 0xA002u);
EXPECT_EQ(trace.raw_packets[1].object_name, "AlbedoTexture");

ASSERT_EQ(trace.instants.size(), 2u);
EXPECT_EQ(trace.instants[0].object_type, VK_OBJECT_TYPE_BUFFER);
EXPECT_EQ(trace.instants[0].object_handle, 0xB001u);
EXPECT_EQ(trace.instants[0].object_name, "VertexBuffer");

EXPECT_EQ(trace.instants[1].object_type, VK_OBJECT_TYPE_IMAGE);
EXPECT_EQ(trace.instants[1].object_handle, 0xA002u);
EXPECT_EQ(trace.instants[1].object_name, "AlbedoTexture");
}

TEST_F(DebugMarkerTests, RawPacketsExplicitlySpecifyBoottimeClockId) {
TEST_DESCRIPTION("Verify raw VkDebugUtilsObjectName packets set BUILTIN_CLOCK_BOOTTIME so they do not inherit the TrackEvent incremental clock");

DebugMarker::Get().Clear();
auto session = StartInProcessTrace();

DebugMarker::Get().SetDebugObjectName(0xD001, VK_OBJECT_TYPE_BUFFER, 0xB001, "ClockCheckBuffer");

DecodedTrace trace = DecodeTrace(StopAndReadTrace(std::move(session)));
DebugMarker::Get().Clear();

// Emitting the VulkanObjectName track event causes the SDK to publish TracePacketDefaults
// with an incremental clock ID on this sequence. Every raw packet on the sequence must
// therefore carry an explicit BUILTIN_CLOCK_BOOTTIME clock ID.
EXPECT_TRUE(trace.saw_incremental_default_clock);
ASSERT_EQ(trace.raw_packets.size(), 1u);
EXPECT_TRUE(trace.raw_packets[0].has_timestamp_clock_id);
EXPECT_EQ(trace.raw_packets[0].timestamp_clock_id,
static_cast<uint32_t>(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME));
}

TEST_F(DebugMarkerTests, SessionStartReplayEmitsBothRepresentations) {
TEST_DESCRIPTION("Verify sessions that attach after objects were named receive both the raw packet and the instant event via OnStart replay");

EnsureInProcessPerfettoInitialized();
DebugMarker::Get().Clear();

// Name objects before the tracing session starts, including a rename.
DebugMarker::Get().SetDebugObjectName(0xD002, VK_OBJECT_TYPE_BUFFER, 0xB010, "OldName");
DebugMarker::Get().SetDebugObjectName(0xD002, VK_OBJECT_TYPE_BUFFER, 0xB010, "FinalBufferName");
DebugMarker::Get().SetDebugObjectName(0xD002, VK_OBJECT_TYPE_DEVICE_MEMORY, 0xC020, "SceneHeap");

// Starting the session triggers MarkerSessionObserver::OnStart -> EmitAllDebugMarkers().
auto session = StartInProcessTrace();
DecodedTrace trace = DecodeTrace(StopAndReadTrace(std::move(session)));
DebugMarker::Get().Clear();

// debug_object_names_ is ordered by (object_type, handle), so VK_OBJECT_TYPE_DEVICE_MEMORY (8)
// is replayed before VK_OBJECT_TYPE_BUFFER (9).
ASSERT_EQ(trace.raw_packets.size(), 2u);
EXPECT_EQ(trace.raw_packets[0].object_type, VK_OBJECT_TYPE_DEVICE_MEMORY);
EXPECT_EQ(trace.raw_packets[0].object, 0xC020u);
EXPECT_EQ(trace.raw_packets[0].object_name, "SceneHeap");
EXPECT_TRUE(trace.raw_packets[0].has_timestamp_clock_id);
EXPECT_EQ(trace.raw_packets[0].timestamp_clock_id,
static_cast<uint32_t>(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME));

EXPECT_EQ(trace.raw_packets[1].object_type, VK_OBJECT_TYPE_BUFFER);
EXPECT_EQ(trace.raw_packets[1].object, 0xB010u);
EXPECT_EQ(trace.raw_packets[1].object_name, "FinalBufferName");
EXPECT_TRUE(trace.raw_packets[1].has_timestamp_clock_id);
EXPECT_EQ(trace.raw_packets[1].timestamp_clock_id,
static_cast<uint32_t>(perfetto::protos::pbzero::BUILTIN_CLOCK_BOOTTIME));

ASSERT_EQ(trace.instants.size(), 2u);
EXPECT_EQ(trace.instants[0].object_type, VK_OBJECT_TYPE_DEVICE_MEMORY);
EXPECT_EQ(trace.instants[0].object_handle, 0xC020u);
EXPECT_EQ(trace.instants[0].object_name, "SceneHeap");

EXPECT_EQ(trace.instants[1].object_type, VK_OBJECT_TYPE_BUFFER);
EXPECT_EQ(trace.instants[1].object_handle, 0xB010u);
EXPECT_EQ(trace.instants[1].object_name, "FinalBufferName");
}

Loading