From 2e49bdf4cbf6a605b42e9945cb081f14c275c899 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Tue, 1 Jul 2025 15:16:03 -0700 Subject: [PATCH] Add counter value collection --- profiler/src/profiler/TracyView_ZoneInfo.cpp | 10 ++++ public/client/TracyRocprof.cpp | 58 ++++++++++++++++---- public/common/TracyQueue.hpp | 15 ++++- server/TracyEvent.hpp | 4 ++ server/TracyWorker.cpp | 32 ++++++++++- server/TracyWorker.hpp | 1 + 6 files changed, 105 insertions(+), 15 deletions(-) diff --git a/profiler/src/profiler/TracyView_ZoneInfo.cpp b/profiler/src/profiler/TracyView_ZoneInfo.cpp index e145e8dc..fd70b831 100644 --- a/profiler/src/profiler/TracyView_ZoneInfo.cpp +++ b/profiler/src/profiler/TracyView_ZoneInfo.cpp @@ -1579,6 +1579,11 @@ void View::DrawGpuInfoWindow() TextFocused( "Delay to execution:", TimeToString( AdjustGpuTime( ev.GpuStart(), begin, drift ) - ev.CpuStart() ) ); } + TextFocused( "Query ID:", RealToString(ev.query_id) ); + for (int i = 0; i < ev.note_count; i++ ) { + TextFocused( RealToString(ev.note_ids[i]), RealToString(ev.note_vals[i]) ); + } + ImGui::Separator(); std::vector zoneTrace; @@ -2046,6 +2051,11 @@ void View::ZoneTooltip( const GpuEvent& ev ) TextFocused( "Delay to execution:", TimeToString( AdjustGpuTime( ev.GpuStart(), begin, drift ) - ev.CpuStart() ) ); } + TextFocused( "Query ID:", RealToString(ev.query_id) ); + for (int i = 0; i < ev.note_count; i++ ) { + TextFocused( RealToString(ev.note_ids[i]), RealToString(ev.note_vals[i]) ); + } + ImGui::EndTooltip(); } diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index bfaf2420..b225249c 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -28,9 +28,11 @@ } \ } +#define USE_CALIBRATION 0 + namespace { - + using kernel_symbol_data_t = rocprofiler_callback_tracing_code_object_kernel_symbol_register_data_t; struct ToolData @@ -47,6 +49,7 @@ struct ToolData std::unordered_map client_kernels; std::unordered_map launch_start_times; std::unordered_map launch_end_times; + std::unordered_map dispatch_query_id; std::unique_ptr cal_thread; std::mutex mut{}; }; @@ -69,7 +72,7 @@ uint8_t gpu_context_allocate(ToolData * data) { clock_gettime(CLOCK_BOOTTIME, &ts); uint64_t cpu_timestamp = Profiler::GetTime(); uint64_t gpu_timestamp = ((uint64_t)ts.tv_sec * 1000000000) + ts.tv_nsec; - bool is_calibrated = true; + bool is_calibrated = USE_CALIBRATION; float timestamp_period = 1.0f; data->previous_cpu_time = cpu_timestamp; @@ -140,14 +143,16 @@ uint64_t kernel_src_loc(ToolData *data, uint64_t kernel_id) { void record_interval(ToolData *data, rocprofiler_timestamp_t start_timestamp, rocprofiler_timestamp_t end_timestamp, uint64_t src_loc, rocprofiler_dispatch_id_t dispatch_id) { - + uint16_t query_id = 0; uint8_t context_id = data->context_id; - + { auto _lk = std::unique_lock{data->mut}; query_id = data->query_id; data->query_id++; + if (dispatch_id != UINT64_MAX) + data->dispatch_query_id[dispatch_id] = query_id; } uint64_t cpu_start_time = 0, cpu_end_time = 0; @@ -228,6 +233,7 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, ToolData * data = static_cast(callback_data); if (!data->init) return; + double sum; for(size_t i = 0; i < record_count; ++i) { int64_t profilerTime = Profiler::GetTime(); TracyLfqPrepare( QueueType::PlotDataDouble ); @@ -235,6 +241,33 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, MemWrite( &item->plotDataDouble.time, profilerTime ); MemWrite( &item->plotDataDouble.val, record_data[i].counter_value ); TracyLfqCommit; + + sum += record_data[i].counter_value; + } + + uint16_t query_id = 0; + { + auto _lk = std::unique_lock{data->mut}; + if (data->dispatch_query_id.count(dispatch_data.dispatch_info.dispatch_id)) { + query_id = data->dispatch_query_id[dispatch_data.dispatch_info.dispatch_id]; + } else { + fprintf(stderr, "oops\n"); + } + } + + if (record_count > 0) { + //fprintf(stderr, "a %lu\n", dispatch_data.dispatch_info.dispatch_id); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneAnnotation); + auto _counter_id = rocprofiler_counter_id_t{}; + ROCPROFILER_CALL(rocprofiler_query_record_counter_id(record_data[0].id, &_counter_id), + "query record counter id"); + tracy::MemWrite(&item->zoneAnnotation.noteId, _counter_id.handle); + fprintf(stderr, "note %lu\n", _counter_id.handle); + tracy::MemWrite(&item->zoneAnnotation.queryId, query_id); + tracy::MemWrite(&item->zoneAnnotation.value, sum); + tracy::MemWrite(&item->zoneAnnotation.context, data->context_id); + tracy::Profiler::QueueSerialFinish(); } } @@ -253,7 +286,7 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, assert(callback_data != nullptr); ToolData * data = static_cast(callback_data); if (!data->init) return; - + /** * This simple example uses the same profile counter set for all agents. * We store this in a cache to prevent constructing many identical profile counter @@ -416,13 +449,15 @@ void calibration_thread(void * ptr) { data->init = true; +#if USE_CALIBRATION while (data->init) { timespec ts; - // HSA performs a linear interpolation of GPU time to CLOCK_BOOTTIME. However, this is subject to network time updates and can drift relative to tracy's clock. + // HSA performs a linear interpolation of GPU time to CLOCK_BOOTTIME. However, this is + // subject to network time updates and can drift relative to tracy's clock. clock_gettime(CLOCK_BOOTTIME, &ts); int64_t cpu_timestamp = Profiler::GetTime(); int64_t gpu_timestamp = ts.tv_nsec + ts.tv_sec * 1e9L; - + if (cpu_timestamp > data->previous_cpu_time) { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuCalibration); @@ -436,6 +471,7 @@ void calibration_thread(void * ptr) { sleep(1); } +#endif } int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) @@ -468,7 +504,7 @@ int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) tool_callback_tracing_callback, user_data), "callback tracing service failed to configure"); - + ROCPROFILER_CALL( rocprofiler_configure_callback_tracing_service(get_client_ctx(), ROCPROFILER_CALLBACK_TRACING_MEMORY_COPY, @@ -477,7 +513,7 @@ int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) tool_callback_tracing_callback, user_data), "callback tracing service failed to configure"); - + ROCPROFILER_CALL( rocprofiler_start_context( get_client_ctx() ), "start context" ); return 0; @@ -485,7 +521,7 @@ int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) void tool_fini( void* tool_data_v ) { rocprofiler_stop_context(get_client_ctx()); - + ToolData * data = static_cast(tool_data_v); data->init = false; data->cal_thread.reset(); @@ -514,4 +550,4 @@ extern "C" return &cfg; } -} \ No newline at end of file +} diff --git a/public/common/TracyQueue.hpp b/public/common/TracyQueue.hpp index daef3ec1..12ee4cf9 100644 --- a/public/common/TracyQueue.hpp +++ b/public/common/TracyQueue.hpp @@ -111,6 +111,7 @@ enum class QueueType : uint8_t SecondStringData, MemNamePayload, ThreadGroupHint, + GpuZoneAnnotation, StringData, ThreadName, PlotName, @@ -331,7 +332,7 @@ struct QueuePlotDataInt : public QueuePlotDataBase int64_t val; }; -struct QueuePlotDataFloat : public QueuePlotDataBase +struct QueuePlotDataFloat : public QueuePlotDataBase { float val; }; @@ -446,6 +447,14 @@ struct QueueGpuZoneEnd uint8_t context; }; +struct QueueGpuZoneAnnotation +{ + int64_t noteId; + double value; + uint16_t queryId; + uint8_t context; +}; + struct QueueGpuTime { int64_t gpuTime; @@ -467,7 +476,7 @@ struct QueueGpuTimeSync int64_t cpuTime; uint8_t context; }; - + struct QueueGpuContextName { uint8_t context; @@ -789,6 +798,7 @@ struct QueueItem QueueSourceCodeNotAvailable sourceCodeNotAvailable; QueueFiberEnter fiberEnter; QueueFiberLeave fiberLeave; + QueueGpuZoneAnnotation zoneAnnotation; }; }; #pragma pack( pop ) @@ -900,6 +910,7 @@ static constexpr size_t QueueDataSize[] = { sizeof( QueueHeader ), // second string data sizeof( QueueHeader ) + sizeof( QueueMemNamePayload ), sizeof( QueueHeader ) + sizeof( QueueThreadGroupHint ), + sizeof( QueueHeader ) + sizeof( QueueGpuZoneAnnotation ), // GPU zone annotation // keep all QueueStringTransfer below sizeof( QueueHeader ) + sizeof( QueueStringTransfer ), // string data sizeof( QueueHeader ) + sizeof( QueueStringTransfer ), // thread name diff --git a/server/TracyEvent.hpp b/server/TracyEvent.hpp index 33e81f24..6e2949a4 100644 --- a/server/TracyEvent.hpp +++ b/server/TracyEvent.hpp @@ -412,6 +412,10 @@ struct GpuEvent uint64_t _gpuStart_child1; uint64_t _gpuEnd_child2; Int24 callstack; + uint16_t query_id; + int64_t note_ids[10]; + double note_vals[10]; + uint8_t note_count; }; enum { GpuEventSize = sizeof( GpuEvent ) }; diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index e7f76961..94e50fad 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -741,7 +741,7 @@ Worker::Worker( FileRead& f, EventType::Type eventMask, bool bgTasks, bool allow { m_data.stringData.reserve_exact( sz, m_slab ); } - + for( uint64_t i=0; iSetGpuEnd( -1 ); zone->callstack.SetVal( 0 ); zone->SetChild( -1 ); + zone->query_id = ev.queryId; uint64_t ztid; if( ctx->thread == 0 ) @@ -5981,7 +5985,7 @@ void Worker::ProcessGpuCalibration( const QueueGpuCalibration& ev ) ctx->calibratedGpuTime = gpuTime; ctx->calibratedCpuTime = TscTime( ev.cpuTime ); } - + void Worker::ProcessGpuTimeSync( const QueueGpuTimeSync& ev ) { auto ctx = m_gpuCtxMap[ev.context]; @@ -6013,6 +6017,22 @@ void Worker::ProcessGpuContextName( const QueueGpuContextName& ev ) ctx->name = StringIdx( idx ); } +void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) +{ + auto ctx = m_gpuCtxMap[ev.context]; + assert( ctx ); + // TODO: Get thread ID properly + // TODO: Search for the query from the back + assert( ctx->threadData.size() ); + assert( ctx->threadData.begin()->second.timeline.size() ); + auto & zone = ctx->threadData.begin()->second.timeline.back(); + assert( zone->query_id == ev.queryId ); + assert( zone->note_count < 10 ); + zone->note_ids[zone->note_count] = ev.noteId; + zone->note_vals[zone->note_count] = ev.value; + zone->note_count++; +} + MemEvent* Worker::ProcessMemAllocImpl( MemData& memdata, const QueueMemAlloc& ev ) { if( memdata.active.find( ev.ptr ) != memdata.active.end() ) @@ -7788,6 +7808,10 @@ void Worker::ReadTimeline( FileRead& f, Vector>& _vec, uint6 refGpuTime += tgpu; zone->SetCpuEnd( refTime ); zone->SetGpuEnd( refGpuTime ); + f.Read(zone->query_id); + f.Read(zone->note_count); + f.Read(zone->note_ids); + f.Read(zone->note_vals); } while( ++zone != end ); } @@ -8511,6 +8535,10 @@ void Worker::WriteTimelineImpl( FileWrite& f, const V& vec, int64_t& refTime, in WriteTimeOffset( f, refTime, v.CpuEnd() ); WriteTimeOffset( f, refGpuTime, v.GpuEnd() ); + f.Write( &v.query_id , sizeof(v.query_id) ); + f.Write( &v.note_count , sizeof(v.note_count) ); + f.Write( &v.note_ids , sizeof(v.note_ids) ); + f.Write( &v.note_vals , sizeof(v.note_vals) ); } } diff --git a/server/TracyWorker.hpp b/server/TracyWorker.hpp index f95d5ba7..fd1dc8ee 100644 --- a/server/TracyWorker.hpp +++ b/server/TracyWorker.hpp @@ -740,6 +740,7 @@ private: tracy_force_inline void ProcessGpuCalibration( const QueueGpuCalibration& ev ); tracy_force_inline void ProcessGpuTimeSync( const QueueGpuTimeSync& ev ); tracy_force_inline void ProcessGpuContextName( const QueueGpuContextName& ev ); + tracy_force_inline void ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ); tracy_force_inline MemEvent* ProcessMemAlloc( const QueueMemAlloc& ev ); tracy_force_inline MemEvent* ProcessMemAllocNamed( const QueueMemAlloc& ev ); tracy_force_inline MemEvent* ProcessMemFree( const QueueMemFree& ev );