From 05bd7410903a035fa066b1a08cb90c302af4f751 Mon Sep 17 00:00:00 2001 From: Jim Blackler Date: Tue, 22 Sep 2026 00:45:48 +0000 Subject: [PATCH] debug_marker: publish object names in a SQL-visible form as well The layer already records every object name the application sets and writes it as a VulkanApiEvent.VkDebugUtilsObjectName packet. trace_processor keeps those in a private lookup that it consults only while parsing GpuRenderStageEvent, so they become render pass, render target and command buffer names on GPU queue slices and are reachable no other way. A name on a buffer or image is parsed and then never surfaced, and nothing in SQL can see any of them. That leaves consumers outside the GPU render stage path with no way to identify the objects they are reporting on. Sherlock's Vulkan memory snapshot is the immediate case: it lists live allocations by handle, and a 64-bit handle tells a developer nothing about which texture or vertex buffer is holding the memory. Emit each name a second time as a "VulkanObjectName" instant event. Instants land in the slice table with their arguments intact, so a consumer can join a name to any object, of any type, by handle. Neither representation subsumes the other - the packet is the only form the render stage parser reads, the slice is the only form SQL can see - so both are written. A name is a few dozen bytes and is written once per naming call, not per frame. Both emissions go through a new Emit(), which also removes the copy of the packet-writing code that SetDebugObjectName and EmitAllDebugMarkers each carried. Session-start replay therefore publishes both representations too, which is what keeps names visible to a session that attaches after the application has already named its objects. Set timestamp_clock_id on the raw packet. This is not cosmetic. The SDK only publishes TracePacketDefaults, which carry timestamp_clock_id = the incremental clock, once a sequence actually writes a track event. Until this change the layer wrote nothing but raw packets, so no defaults were emitted and the absolute boot-time timestamp was read as boot time. Adding the instant event makes the SDK publish those defaults, and a packet that sets a timestamp without naming a clock then inherits the incremental one - so an absolute boot-time value is read as a delta of however long the device has been up. Measured on a ten second capture: the sequence clock advanced by 1.7 hours per name, every incremental state clear briefly reset it, and 4524 of 4535 name slices landed days past the end of the trace, where a consumer filtering on ts would never see them. The other layers are unaffected; this is the only one that writes a raw packet alongside its track events. Nothing else changes: the same names, at the same points, from the same layer. Consumers that want names in the memory snapshot must record with this layer enabled, which is deliberate - no other layer duplicates its bookkeeping. --- layersvt/debug_marker/debug_marker.cpp | 62 ++++-- layersvt/debug_marker/debug_marker.h | 11 ++ layersvt/test/test_debugmarker.cpp | 258 +++++++++++++++++++++++++ 3 files changed, 311 insertions(+), 20 deletions(-) diff --git a/layersvt/debug_marker/debug_marker.cpp b/layersvt/debug_marker/debug_marker.cpp index 6f21ff4795..60b058350a 100644 --- a/layersvt/debug_marker/debug_marker.cpp +++ b/layersvt/debug_marker/debug_marker.cpp @@ -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 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 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 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); } } diff --git a/layersvt/debug_marker/debug_marker.h b/layersvt/debug_marker/debug_marker.h index b705cefbfb..575d6371a8 100644 --- a/layersvt/debug_marker/debug_marker.h +++ b/layersvt/debug_marker/debug_marker.h @@ -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. diff --git a/layersvt/test/test_debugmarker.cpp b/layersvt/test/test_debugmarker.cpp index e1f2325d2f..56d0d122c1 100644 --- a/layersvt/test/test_debugmarker.cpp +++ b/layersvt/test/test_debugmarker.cpp @@ -15,12 +15,172 @@ #include "layer_test_helper.h" #include "../debug_marker/debug_marker.h" +#include "../debug_marker/debug_marker_perfetto.h" #include #include +#include #include +#include +#include +#include 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 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 StopAndReadTrace(std::unique_ptr 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 raw_packets; + std::vector instants; + bool saw_incremental_default_clock = false; +}; + +DecodedTrace DecodeTrace(const std::vector& raw_trace) { + DecodedTrace result; + // Per-sequence interned tables for event_names and debug_annotation_names. + std::unordered_map> event_names; + std::unordered_map> annotation_names; + + perfetto::protos::pbzero::Trace::Decoder trace( + reinterpret_cast(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(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(){}; @@ -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(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(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(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"); +} +