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"); +} +