From 00648836a26dd844509ea95765394b7153d0bddd Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 9 Apr 2025 13:36:01 -0500 Subject: [PATCH 01/21] Add rocprof dispatch tracing --- CMakeLists.txt | 2 + public/TracyClient.cpp | 1 + public/client/TracyRocprof.cpp | 475 +++++++++++++++++++++++++++++++++ 3 files changed, 478 insertions(+) create mode 100644 public/client/TracyRocprof.cpp diff --git a/CMakeLists.txt b/CMakeLists.txt index bef1298c..ccf68101 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -33,6 +33,7 @@ else() endif() find_package(Threads REQUIRED) +find_package(rocprofiler-sdk REQUIRED PATHS "/opt/rocm/lib/cmake") set(TRACY_PUBLIC_DIR ${CMAKE_CURRENT_SOURCE_DIR}/public) @@ -55,6 +56,7 @@ target_link_libraries( PUBLIC Threads::Threads ${CMAKE_DL_LIBS} + rocprofiler-sdk::rocprofiler-sdk ) if(TRACY_Fortran) diff --git a/public/TracyClient.cpp b/public/TracyClient.cpp index 6224f48b..192f36e4 100644 --- a/public/TracyClient.cpp +++ b/public/TracyClient.cpp @@ -31,6 +31,7 @@ #include "client/TracyAlloc.cpp" #include "client/TracyOverride.cpp" #include "client/TracyKCore.cpp" +#include "client/TracyRocprof.cpp" #if defined(TRACY_HAS_CALLSTACK) # if TRACY_HAS_CALLSTACK == 2 || TRACY_HAS_CALLSTACK == 3 || TRACY_HAS_CALLSTACK == 4 || TRACY_HAS_CALLSTACK == 6 diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp new file mode 100644 index 00000000..251aed29 --- /dev/null +++ b/public/client/TracyRocprof.cpp @@ -0,0 +1,475 @@ +#include +#include +#include "TracyProfiler.hpp" + +#include +#include +#include +#include +#include +#include +#include + +#define ROCPROFILER_CALL( result, msg ) \ + { \ + rocprofiler_status_t CHECKSTATUS = result; \ + if( CHECKSTATUS != ROCPROFILER_STATUS_SUCCESS ) \ + { \ + std::string status_msg = rocprofiler_get_status_string( CHECKSTATUS ); \ + std::cerr << "[" #result "][" << __FILE__ << ":" << __LINE__ << "] " << msg << " failed with error code " \ + << CHECKSTATUS << ": " << status_msg << std::endl; \ + std::stringstream errmsg{}; \ + errmsg << "[" #result "][" << __FILE__ << ":" << __LINE__ << "] " << msg " failure (" << status_msg \ + << ")"; \ + throw std::runtime_error( errmsg.str() ); \ + } \ + } + +namespace +{ + +using kernel_symbol_data_t = rocprofiler_callback_tracing_code_object_kernel_symbol_register_data_t; + +struct ToolData +{ + uint32_t version; + const char* runtime_version; + uint32_t priority; + rocprofiler_client_id_t client_id; + uint8_t context_id; + bool init; + uint64_t src_loc; + uint64_t query_id; + std::unordered_map client_kernels; + std::mutex mut{}; +}; + +using namespace tracy; +const char * name = "SQ_WAVES"; + +rocprofiler_context_id_t& +get_client_ctx() +{ + static rocprofiler_context_id_t ctx{0}; + return ctx; +} + +const char * CTX_NAME = "rocprofv3"; + +uint8_t iree_tracing_gpu_context_allocate() { + + timespec ts; + 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 = false; + float timestamp_period = 1.0f; + + // Allocate the process-unique GPU context ID. There's a max of 255 available; + // if we are recreating devices a lot we may exceed that. Don't do that, or + // wrap around and get weird (but probably still usable) numbers. + uint8_t context_id = + tracy::GetGpuCtxCounter().fetch_add(1, std::memory_order_relaxed); + if (context_id >= 255) { + context_id %= 255; + } + + uint8_t context_flags = 0; + if (is_calibrated) { + // Tell tracy we'll be passing calibrated timestamps and not to mess with + // the times. We'll periodically send GpuCalibration events in case the + // times drift. + context_flags |= tracy::GpuContextCalibration; + } + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuNewContext); + tracy::MemWrite(&item->gpuNewContext.cpuTime, cpu_timestamp); + tracy::MemWrite(&item->gpuNewContext.gpuTime, gpu_timestamp); + memset(&item->gpuNewContext.thread, 0, sizeof(item->gpuNewContext.thread)); + tracy::MemWrite(&item->gpuNewContext.period, timestamp_period); + tracy::MemWrite(&item->gpuNewContext.context, context_id); + tracy::MemWrite(&item->gpuNewContext.flags, context_flags); + tracy::MemWrite(&item->gpuNewContext.type, tracy::GpuContextType::Vulkan); + tracy::Profiler::QueueSerialFinish(); + } + + // Send the name of the context along. + // NOTE: Tracy will unconditionally free the name so we must clone it here. + // Since internally Tracy will use its own rpmalloc implementation we must + // make sure we allocate from the same source. + size_t name_length = strlen(CTX_NAME); + char* cloned_name = (char*)tracy::tracy_malloc(name_length); + memcpy(cloned_name, CTX_NAME, name_length); + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuContextName); + tracy::MemWrite(&item->gpuContextNameFat.context, context_id); + tracy::MemWrite(&item->gpuContextNameFat.ptr, (uint64_t)cloned_name); + tracy::MemWrite(&item->gpuContextNameFat.size, name_length); + tracy::Profiler::QueueSerialFinish(); + } + + return context_id; +} + +uint32_t get_src_loc() { + uint32_t line = 0; + + const char * FILE_NAME = ""; + const char * FN_NAME = ""; + const char * NAME = ""; + + size_t file_name_length = strlen(FILE_NAME); + // char* file_name = (char*)tracy::tracy_malloc(file_name_length); + // memcpy(file_name, FILE_NAME, file_name_length); + + size_t fn_name_length = strlen(FN_NAME); + // char* fn_name = (char*)tracy::tracy_malloc(fn_name_length); + // memcpy(fn_name, FN_NAME, fn_name_length); + + size_t name_length = strlen(NAME); + // char* name = (char*)tracy::tracy_malloc(name_length); + // memcpy(name, NAME, name_length); + + const auto src_loc = tracy::Profiler::AllocSourceLocation( + line, FILE_NAME, file_name_length, FN_NAME, fn_name_length, + NAME, name_length); + return src_loc; +} + +void +record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, + rocprofiler_record_counter_t* record_data, + size_t record_count, + rocprofiler_user_data_t user_data , + void* callback_data_args) +{ + // std::stringstream ss; + // ss << "Dispatch_Id=" << dispatch_data.dispatch_info.dispatch_id + // << ", Kernel_id=" << dispatch_data.dispatch_info.kernel_id + // << ", Corr_Id=" << dispatch_data.correlation_id.internal << ": "; + // for(size_t i = 0; i < record_count; ++i) + // ss << "(Id: " << record_data[i].id << " Value [D]: " << record_data[i].counter_value + // << "),"; + + // auto* tool = static_cast(callback_data_args); + // if(!tool || !tool->output_stream) throw std::runtime_error{"nullptr to output stream"}; + + // auto _lk = std::unique_lock{tool->mut}; + // *tool->output_stream << "[" << __FUNCTION__ << "] " << ss.str() << "\n"; + + ToolData * data = static_cast(callback_data_args); + uint16_t query_id = 0; + uint8_t context_id = data->context_id; + uint64_t src_loc = 0; + + { + auto _lk = std::unique_lock{data->mut}; + query_id = data->query_id; + data->query_id++; + rocprofiler_kernel_id_t kid = dispatch_data.dispatch_info.kernel_id; + if (data->client_kernels.count(kid)) { + auto &sym_data = data->client_kernels[kid]; + uint32_t line = 0; + src_loc = tracy::Profiler::AllocSourceLocation( + line, NULL, 0, NULL, 0, + sym_data.kernel_name, strlen(sym_data.kernel_name)); + } + } + + + if (src_loc != 0) { + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, + tracy::QueueType::GpuZoneBeginAllocSrcLocSerial); + tracy::MemWrite(&item->gpuZoneBegin.cpuTime, tracy::Profiler::GetTime()); + tracy::MemWrite(&item->gpuZoneBegin.srcloc, (uint64_t)src_loc); + tracy::MemWrite(&item->gpuZoneBegin.thread, tracy::GetThreadHandle()); + tracy::MemWrite(&item->gpuZoneBegin.queryId, query_id); + tracy::MemWrite(&item->gpuZoneBegin.context, context_id); + tracy::Profiler::QueueSerialFinish(); + } + } else { + static const ___tracy_source_location_data src_loc = {NULL, NULL, NULL, 0, 0}; + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneBeginSerial); + tracy::MemWrite(&item->gpuZoneBegin.cpuTime, tracy::Profiler::GetTime()); + tracy::MemWrite(&item->gpuZoneBegin.srcloc, (uint64_t)&src_loc); + tracy::MemWrite(&item->gpuZoneBegin.thread, tracy::GetThreadHandle()); + tracy::MemWrite(&item->gpuZoneBegin.queryId, query_id); + tracy::MemWrite(&item->gpuZoneBegin.context, context_id); + tracy::Profiler::QueueSerialFinish(); + } + } + + + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuTime); + tracy::MemWrite(&item->gpuTime.gpuTime, dispatch_data.start_timestamp); + tracy::MemWrite(&item->gpuTime.queryId, query_id); + tracy::MemWrite(&item->gpuTime.context, context_id); + tracy::Profiler::QueueSerialFinish(); + } + + // { + // auto _lk = std::unique_lock{data->mut}; + // query_id = data->query_id; + // data->query_id++; + // } + + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneEndSerial); + tracy::MemWrite(&item->gpuZoneEnd.cpuTime, tracy::Profiler::GetTime()); + tracy::MemWrite(&item->gpuZoneEnd.thread, tracy::GetThreadHandle()); + tracy::MemWrite(&item->gpuZoneEnd.queryId, query_id); + tracy::MemWrite(&item->gpuZoneEnd.context, context_id); + tracy::Profiler::QueueSerialFinish(); + } + + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuTime); + tracy::MemWrite(&item->gpuTime.gpuTime, dispatch_data.end_timestamp); + tracy::MemWrite(&item->gpuTime.queryId, query_id); + tracy::MemWrite(&item->gpuTime.context, context_id); + tracy::Profiler::QueueSerialFinish(); + } + + // for(size_t i = 0; i < record_count; ++i) { + // int64_t profilerTime = Profiler::GetTime(); + // TracyLfqPrepare( QueueType::PlotDataDouble ); + // MemWrite( &item->plotDataDouble.name, (uint64_t)name ); + // MemWrite( &item->plotDataDouble.time, profilerTime ); + // MemWrite( &item->plotDataDouble.val, record_data[i].counter_value ); + // TracyLfqCommit; + // } +} + +void delay_init(void *user_data) { + ToolData * data = static_cast(user_data); + if (data->init) return; + data->init = true; + data->context_id = iree_tracing_gpu_context_allocate(); + std::cerr << "ctx = " << (int)data->context_id << std::endl; + + TracyLfqPrepare( QueueType::PlotConfig ); + MemWrite( &item->plotConfig.name, (uint64_t)name); + MemWrite( &item->plotConfig.type, (uint8_t)PlotFormatType::Number ); + MemWrite( &item->plotConfig.step, (uint8_t)false ); + MemWrite( &item->plotConfig.fill, (uint8_t)true ); + MemWrite( &item->plotConfig.color, 0 ); + TracyLfqCommit; + + // uint16_t query_id = data->query_id; + // uint8_t context_id = data->context_id; + // uint32_t line = 0; + + // const char * FILE_NAME = ""; + // const char * FN_NAME = ""; + // const char * NAME = ""; + + // size_t file_name_length = strlen(FILE_NAME); + // // char* file_name = (char*)tracy::tracy_malloc(file_name_length); + // // memcpy(file_name, FILE_NAME, file_name_length); + + // size_t fn_name_length = strlen(FN_NAME); + // // char* fn_name = (char*)tracy::tracy_malloc(fn_name_length); + // // memcpy(fn_name, FN_NAME, fn_name_length); + + // size_t name_length = strlen(NAME); + // // char* name = (char*)tracy::tracy_malloc(name_length); + // // memcpy(name, NAME, name_length); + + // const auto src_loc = tracy::Profiler::AllocSourceLocation( + // line, FILE_NAME, file_name_length, FN_NAME, fn_name_length, + // NAME, name_length); + // data->src_loc = src_loc; +} + +/** + * Callback from rocprofiler when an kernel dispatch is enqueued into the HSA queue. + * rocprofiler_counter_config_id_t* is a return to specify what counters to collect + * for this dispatch (dispatch_packet). This example function creates a profile + * to collect the counter SQ_WAVES for all kernel dispatch packets. + */ +void +dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, + rocprofiler_profile_config_id_t* config, + rocprofiler_user_data_t* /*user_data*/, + void* callback_data_args) +{ + delay_init(callback_data_args); + /** + * 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 + * sets. We first check the cache to see if we have already constructed a counter" + * set for the agent. If we have, return it. Otherwise, construct a new profile counter + * set. + */ + static std::shared_mutex m_mutex = {}; + static std::unordered_map profile_cache = {}; + + auto search_cache = [&]() { + if(auto pos = profile_cache.find(dispatch_data.dispatch_info.agent_id.handle); + pos != profile_cache.end()) + { + *config = pos->second; + return true; + } + return false; + }; + + { + auto rlock = std::shared_lock{m_mutex}; + if(search_cache()) return; + } + + auto wlock = std::unique_lock{m_mutex}; + if(search_cache()) return; + + // Counters we want to collect (here its SQ_WAVES) + std::set counters_to_collect = {"SQ_WAVES"}; + // GPU Counter IDs + std::vector gpu_counters; + + // Iterate through the agents and get the counters available on that agent + ROCPROFILER_CALL(rocprofiler_iterate_agent_supported_counters( + dispatch_data.dispatch_info.agent_id, + [](rocprofiler_agent_id_t, + rocprofiler_counter_id_t* counters, + size_t num_counters, + void* user_data) { + std::vector* vec = + static_cast*>(user_data); + for(size_t i = 0; i < num_counters; i++) + { + vec->push_back(counters[i]); + } + return ROCPROFILER_STATUS_SUCCESS; + }, + static_cast(&gpu_counters)), + "Could not fetch supported counters"); + + std::vector collect_counters; + // Look for the counters contained in counters_to_collect in gpu_counters + for(auto& counter : gpu_counters) + { + rocprofiler_counter_info_v0_t info; + ROCPROFILER_CALL( + rocprofiler_query_counter_info( + counter, ROCPROFILER_COUNTER_INFO_VERSION_0, static_cast(&info)), + "Could not query info"); + if(counters_to_collect.count(std::string(info.name)) > 0) + { + std::clog << "Counter: " << counter.handle << " " << info.name << "\n"; + collect_counters.push_back(counter); + } + } + + // Create a colleciton profile for the counters + rocprofiler_profile_config_id_t profile = {.handle = 0}; + ROCPROFILER_CALL(rocprofiler_create_profile_config(dispatch_data.dispatch_info.agent_id, + collect_counters.data(), + collect_counters.size(), + &profile), + "Could not construct profile cfg"); + + profile_cache.emplace(dispatch_data.dispatch_info.agent_id.handle, profile); + // Return the profile to collect those counters for this dispatch + *config = profile; +} + +using kernel_symbol_data_t = rocprofiler_callback_tracing_code_object_kernel_symbol_register_data_t; + +void +tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, + rocprofiler_user_data_t* user_data, + void* callback_data) +{ + assert(callback_data != nullptr); + ToolData * data = static_cast(callback_data); + + if(record.kind == ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT && + record.operation == ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER) + { + auto* sym_data = static_cast(record.payload); + + if(record.phase == ROCPROFILER_CALLBACK_PHASE_LOAD) + { + std::cerr << "load " << sym_data->kernel_id << " = " << sym_data->kernel_name << std::endl; + auto _lk = std::unique_lock{data->mut}; + // uint32_t line = 0; + // const auto src_loc = tracy::Profiler::AllocSourceLocation( + // line, NULL, 0, NULL, 0, + // sym_data->kernel_name, strlen(sym_data->kernel_name)); + data->client_kernels.emplace(sym_data->kernel_id, *sym_data); + } + else if(record.phase == ROCPROFILER_CALLBACK_PHASE_UNLOAD) + { + std::cerr << "unload " << sym_data->kernel_id << " = " << sym_data->kernel_name << std::endl; + auto _lk = std::unique_lock{data->mut}; + data->client_kernels.erase(sym_data->kernel_id); + } + } +} + +int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) +{ + + ROCPROFILER_CALL( rocprofiler_create_context( &get_client_ctx() ), "context creation failed" ); + + ROCPROFILER_CALL( rocprofiler_configure_callback_dispatch_counting_service( get_client_ctx(), dispatch_callback, + user_data, record_callback, user_data ), + "Could not setup counting service" ); + + + // enable the control + //tool_control_init(client_ctx); + + ROCPROFILER_CALL( + rocprofiler_configure_callback_tracing_service(get_client_ctx(), + ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT, + nullptr, + 0, + tool_callback_tracing_callback, + user_data), + "callback tracing service failed to configure"); + + ROCPROFILER_CALL( rocprofiler_start_context( get_client_ctx() ), "start context" ); + std::cerr << "init" << std::endl; + return 0; +} + +void tool_fini( void* tool_data_v ) { + rocprofiler_stop_context(get_client_ctx()); +} +} + +extern "C" +{ + rocprofiler_tool_configure_result_t* rocprofiler_configure( uint32_t version, const char* runtime_version, + uint32_t priority, rocprofiler_client_id_t* client_id ) + { + // If not the first tool to register, indicate that the tool doesn't want to do anything + if( priority > 0 ) return nullptr; + + // (optional) Provide a name for this tool to rocprofiler + client_id->name = "Tracy"; + + // (optional) create configure data + static auto data = ToolData{ version, runtime_version, priority, *client_id, 0, false, 0, 0 }; + + //std::cerr << "profile hello" << std::endl; + + // construct configure result + static auto cfg = rocprofiler_tool_configure_result_t{ sizeof( rocprofiler_tool_configure_result_t ), + &tool_init, &tool_fini, static_cast( &data ) }; + + return &cfg; + } +} \ No newline at end of file From 1517756d54f53bccb846efdb494819af587a3065 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Fri, 11 Apr 2025 16:51:31 -0500 Subject: [PATCH 02/21] Add buffer copy tracing --- public/client/TracyRocprof.cpp | 204 ++++++++++++++++----------------- 1 file changed, 97 insertions(+), 107 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 251aed29..dad9db9c 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -1,6 +1,7 @@ #include #include #include "TracyProfiler.hpp" +#include "tracy/TracyC.h" #include #include @@ -45,7 +46,7 @@ struct ToolData }; using namespace tracy; -const char * name = "SQ_WAVES"; +const char * PLOT_NAME = "SQ_WAVES"; rocprofiler_context_id_t& get_client_ctx() @@ -56,7 +57,7 @@ get_client_ctx() const char * CTX_NAME = "rocprofv3"; -uint8_t iree_tracing_gpu_context_allocate() { +uint8_t gpu_context_allocate() { timespec ts; clock_gettime(CLOCK_BOOTTIME, &ts); @@ -113,72 +114,35 @@ uint8_t iree_tracing_gpu_context_allocate() { return context_id; } -uint32_t get_src_loc() { - uint32_t line = 0; - - const char * FILE_NAME = ""; - const char * FN_NAME = ""; - const char * NAME = ""; - - size_t file_name_length = strlen(FILE_NAME); - // char* file_name = (char*)tracy::tracy_malloc(file_name_length); - // memcpy(file_name, FILE_NAME, file_name_length); - - size_t fn_name_length = strlen(FN_NAME); - // char* fn_name = (char*)tracy::tracy_malloc(fn_name_length); - // memcpy(fn_name, FN_NAME, fn_name_length); - - size_t name_length = strlen(NAME); - // char* name = (char*)tracy::tracy_malloc(name_length); - // memcpy(name, NAME, name_length); - - const auto src_loc = tracy::Profiler::AllocSourceLocation( - line, FILE_NAME, file_name_length, FN_NAME, fn_name_length, - NAME, name_length); +uint64_t kernel_src_loc(ToolData *data, uint64_t kernel_id) { + uint64_t src_loc = 0; + auto _lk = std::unique_lock{data->mut}; + rocprofiler_kernel_id_t kid = kernel_id; + if (data->client_kernels.count(kid)) { + auto &sym_data = data->client_kernels[kid]; + const char * name = sym_data.kernel_name; + size_t name_len = strlen(name); + uint32_t line = 0; + src_loc = tracy::Profiler::AllocSourceLocation( + line, NULL, 0, name, name_len, + NULL, 0); + } return src_loc; } -void -record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, - rocprofiler_record_counter_t* record_data, - size_t record_count, - rocprofiler_user_data_t user_data , - void* callback_data_args) -{ - // std::stringstream ss; - // ss << "Dispatch_Id=" << dispatch_data.dispatch_info.dispatch_id - // << ", Kernel_id=" << dispatch_data.dispatch_info.kernel_id - // << ", Corr_Id=" << dispatch_data.correlation_id.internal << ": "; - // for(size_t i = 0; i < record_count; ++i) - // ss << "(Id: " << record_data[i].id << " Value [D]: " << record_data[i].counter_value - // << "),"; - - // auto* tool = static_cast(callback_data_args); - // if(!tool || !tool->output_stream) throw std::runtime_error{"nullptr to output stream"}; - - // auto _lk = std::unique_lock{tool->mut}; - // *tool->output_stream << "[" << __FUNCTION__ << "] " << ss.str() << "\n"; - - ToolData * data = static_cast(callback_data_args); +void record_interval(ToolData *data, rocprofiler_timestamp_t start_timestamp, + rocprofiler_timestamp_t end_timestamp, + uint64_t src_loc) { + uint16_t query_id = 0; uint8_t context_id = data->context_id; - uint64_t src_loc = 0; - + { auto _lk = std::unique_lock{data->mut}; query_id = data->query_id; data->query_id++; - rocprofiler_kernel_id_t kid = dispatch_data.dispatch_info.kernel_id; - if (data->client_kernels.count(kid)) { - auto &sym_data = data->client_kernels[kid]; - uint32_t line = 0; - src_loc = tracy::Profiler::AllocSourceLocation( - line, NULL, 0, NULL, 0, - sym_data.kernel_name, strlen(sym_data.kernel_name)); - } } - if (src_loc != 0) { { auto* item = tracy::Profiler::QueueSerial(); @@ -205,22 +169,15 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, } } - { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuTime); - tracy::MemWrite(&item->gpuTime.gpuTime, dispatch_data.start_timestamp); + tracy::MemWrite(&item->gpuTime.gpuTime, start_timestamp); tracy::MemWrite(&item->gpuTime.queryId, query_id); tracy::MemWrite(&item->gpuTime.context, context_id); tracy::Profiler::QueueSerialFinish(); } - // { - // auto _lk = std::unique_lock{data->mut}; - // query_id = data->query_id; - // data->query_id++; - // } - { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneEndSerial); @@ -234,61 +191,44 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuTime); - tracy::MemWrite(&item->gpuTime.gpuTime, dispatch_data.end_timestamp); + tracy::MemWrite(&item->gpuTime.gpuTime, end_timestamp); tracy::MemWrite(&item->gpuTime.queryId, query_id); tracy::MemWrite(&item->gpuTime.context, context_id); tracy::Profiler::QueueSerialFinish(); } +} - // for(size_t i = 0; i < record_count; ++i) { - // int64_t profilerTime = Profiler::GetTime(); - // TracyLfqPrepare( QueueType::PlotDataDouble ); - // MemWrite( &item->plotDataDouble.name, (uint64_t)name ); - // MemWrite( &item->plotDataDouble.time, profilerTime ); - // MemWrite( &item->plotDataDouble.val, record_data[i].counter_value ); - // TracyLfqCommit; - // } +void +record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, + rocprofiler_record_counter_t* record_data, + size_t record_count, + rocprofiler_user_data_t /*user_data*/ , + void* callback_data_args) +{ + for(size_t i = 0; i < record_count; ++i) { + int64_t profilerTime = Profiler::GetTime(); + TracyLfqPrepare( QueueType::PlotDataDouble ); + MemWrite( &item->plotDataDouble.name, (uint64_t)PLOT_NAME ); + MemWrite( &item->plotDataDouble.time, profilerTime ); + MemWrite( &item->plotDataDouble.val, record_data[i].counter_value ); + TracyLfqCommit; + } } void delay_init(void *user_data) { ToolData * data = static_cast(user_data); if (data->init) return; data->init = true; - data->context_id = iree_tracing_gpu_context_allocate(); + data->context_id = gpu_context_allocate(); std::cerr << "ctx = " << (int)data->context_id << std::endl; TracyLfqPrepare( QueueType::PlotConfig ); - MemWrite( &item->plotConfig.name, (uint64_t)name); + MemWrite( &item->plotConfig.name, (uint64_t)PLOT_NAME); MemWrite( &item->plotConfig.type, (uint8_t)PlotFormatType::Number ); MemWrite( &item->plotConfig.step, (uint8_t)false ); MemWrite( &item->plotConfig.fill, (uint8_t)true ); MemWrite( &item->plotConfig.color, 0 ); TracyLfqCommit; - - // uint16_t query_id = data->query_id; - // uint8_t context_id = data->context_id; - // uint32_t line = 0; - - // const char * FILE_NAME = ""; - // const char * FN_NAME = ""; - // const char * NAME = ""; - - // size_t file_name_length = strlen(FILE_NAME); - // // char* file_name = (char*)tracy::tracy_malloc(file_name_length); - // // memcpy(file_name, FILE_NAME, file_name_length); - - // size_t fn_name_length = strlen(FN_NAME); - // // char* fn_name = (char*)tracy::tracy_malloc(fn_name_length); - // // memcpy(fn_name, FN_NAME, fn_name_length); - - // size_t name_length = strlen(NAME); - // // char* name = (char*)tracy::tracy_malloc(name_length); - // // memcpy(name, NAME, name_length); - - // const auto src_loc = tracy::Profiler::AllocSourceLocation( - // line, FILE_NAME, file_name_length, FN_NAME, fn_name_length, - // NAME, name_length); - // data->src_loc = src_loc; } /** @@ -415,31 +355,81 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, auto _lk = std::unique_lock{data->mut}; data->client_kernels.erase(sym_data->kernel_id); } + } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH && + record.operation == ROCPROFILER_KERNEL_DISPATCH_COMPLETE) { + auto* rdata = static_cast(record.payload); + uint64_t src_loc = kernel_src_loc(data, rdata->dispatch_info.kernel_id); + record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc); + } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_MEMORY_COPY && + record.operation != ROCPROFILER_MEMORY_COPY_NONE && + record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT) { + auto* rdata = static_cast(record.payload); + const char * name = nullptr; + switch(record.operation) { + case ROCPROFILER_MEMORY_COPY_DEVICE_TO_DEVICE: + name = "DeviceToDeviceCopy"; + break; + case ROCPROFILER_MEMORY_COPY_DEVICE_TO_HOST: + name = "DeviceToHostCopy"; + break; + case ROCPROFILER_MEMORY_COPY_HOST_TO_DEVICE: + name = "HostToDeviceCopy"; + break; + case ROCPROFILER_MEMORY_COPY_HOST_TO_HOST: + name = "HostToHostCopy"; + break; + } + size_t name_len = strlen(name); + uint64_t src_loc = tracy::Profiler::AllocSourceLocation( + 0, NULL, 0, name, name_len, + NULL, 0); + record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc); } } int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) { - + delay_init(user_data); ROCPROFILER_CALL( rocprofiler_create_context( &get_client_ctx() ), "context creation failed" ); - ROCPROFILER_CALL( rocprofiler_configure_callback_dispatch_counting_service( get_client_ctx(), dispatch_callback, - user_data, record_callback, user_data ), - "Could not setup counting service" ); + // ROCPROFILER_CALL( rocprofiler_configure_callback_dispatch_counting_service( get_client_ctx(), dispatch_callback, + // user_data, record_callback, user_data ), + // "Could not setup counting service" ); // enable the control //tool_control_init(client_ctx); + rocprofiler_tracing_operation_t ops[] = {ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER}; ROCPROFILER_CALL( rocprofiler_configure_callback_tracing_service(get_client_ctx(), ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT, - nullptr, - 0, + ops, + 1, tool_callback_tracing_callback, user_data), "callback tracing service failed to configure"); + rocprofiler_tracing_operation_t ops2[] = {ROCPROFILER_KERNEL_DISPATCH_COMPLETE}; + ROCPROFILER_CALL( + rocprofiler_configure_callback_tracing_service(get_client_ctx(), + ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH, + ops2, + 1, + 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, + nullptr, + 0, + tool_callback_tracing_callback, + user_data), + "callback tracing service failed to configure"); + + ROCPROFILER_CALL( rocprofiler_start_context( get_client_ctx() ), "start context" ); std::cerr << "init" << std::endl; return 0; From 98047ffbe211bd1cbc7b0e24e51b122e94d6b7a6 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Fri, 6 Jun 2025 22:57:12 +0000 Subject: [PATCH 03/21] Delay initialization Delay initialization until tracy is started. Removed some debug prints. --- public/client/TracyRocprof.cpp | 19 ++++++------------- 1 file changed, 6 insertions(+), 13 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index dad9db9c..5f96086e 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -6,6 +6,7 @@ #include #include #include +#include #include #include #include @@ -205,6 +206,7 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, rocprofiler_user_data_t /*user_data*/ , void* callback_data_args) { + if (!TracyIsStarted) return; for(size_t i = 0; i < record_count; ++i) { int64_t profilerTime = Profiler::GetTime(); TracyLfqPrepare( QueueType::PlotDataDouble ); @@ -220,7 +222,6 @@ void delay_init(void *user_data) { if (data->init) return; data->init = true; data->context_id = gpu_context_allocate(); - std::cerr << "ctx = " << (int)data->context_id << std::endl; TracyLfqPrepare( QueueType::PlotConfig ); MemWrite( &item->plotConfig.name, (uint64_t)PLOT_NAME); @@ -243,7 +244,9 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, rocprofiler_user_data_t* /*user_data*/, void* callback_data_args) { + if (!TracyIsStarted) return; delay_init(callback_data_args); + /** * 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 @@ -331,8 +334,10 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, rocprofiler_user_data_t* user_data, void* callback_data) { + if (!TracyIsStarted) return; assert(callback_data != nullptr); ToolData * data = static_cast(callback_data); + delay_init(callback_data); if(record.kind == ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT && record.operation == ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER) @@ -341,17 +346,11 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, if(record.phase == ROCPROFILER_CALLBACK_PHASE_LOAD) { - std::cerr << "load " << sym_data->kernel_id << " = " << sym_data->kernel_name << std::endl; auto _lk = std::unique_lock{data->mut}; - // uint32_t line = 0; - // const auto src_loc = tracy::Profiler::AllocSourceLocation( - // line, NULL, 0, NULL, 0, - // sym_data->kernel_name, strlen(sym_data->kernel_name)); data->client_kernels.emplace(sym_data->kernel_id, *sym_data); } else if(record.phase == ROCPROFILER_CALLBACK_PHASE_UNLOAD) { - std::cerr << "unload " << sym_data->kernel_id << " = " << sym_data->kernel_name << std::endl; auto _lk = std::unique_lock{data->mut}; data->client_kernels.erase(sym_data->kernel_id); } @@ -389,17 +388,12 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) { - delay_init(user_data); ROCPROFILER_CALL( rocprofiler_create_context( &get_client_ctx() ), "context creation failed" ); // ROCPROFILER_CALL( rocprofiler_configure_callback_dispatch_counting_service( get_client_ctx(), dispatch_callback, // user_data, record_callback, user_data ), // "Could not setup counting service" ); - - // enable the control - //tool_control_init(client_ctx); - rocprofiler_tracing_operation_t ops[] = {ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER}; ROCPROFILER_CALL( rocprofiler_configure_callback_tracing_service(get_client_ctx(), @@ -431,7 +425,6 @@ int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) ROCPROFILER_CALL( rocprofiler_start_context( get_client_ctx() ), "start context" ); - std::cerr << "init" << std::endl; return 0; } From 495321fc108eb6e18290df428f0f5a9e8774f5c3 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Sat, 7 Jun 2025 00:19:39 +0000 Subject: [PATCH 04/21] Record dispatch enqueue times --- public/client/TracyRocprof.cpp | 45 +++++++++++++++++++++++++--------- 1 file changed, 34 insertions(+), 11 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 5f96086e..30a67cbe 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -43,6 +43,8 @@ struct ToolData uint64_t src_loc; uint64_t query_id; std::unordered_map client_kernels; + std::unordered_map launch_start_times; + std::unordered_map launch_end_times; std::mutex mut{}; }; @@ -133,7 +135,7 @@ 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) { + uint64_t src_loc, rocprofiler_dispatch_id_t dispatch_id) { uint16_t query_id = 0; uint8_t context_id = data->context_id; @@ -144,12 +146,24 @@ void record_interval(ToolData *data, rocprofiler_timestamp_t start_timestamp, data->query_id++; } + uint64_t cpu_start_time = 0, cpu_end_time = 0; + if (dispatch_id == UINT64_MAX) { + cpu_start_time = tracy::Profiler::GetTime(); + cpu_end_time = tracy::Profiler::GetTime(); + } else { + auto _lk = std::unique_lock{data->mut}; + cpu_start_time = data->launch_start_times.at(dispatch_id); + cpu_end_time = data->launch_end_times.at(dispatch_id); + data->launch_start_times.erase(dispatch_id); + data->launch_end_times.erase(dispatch_id); + } + if (src_loc != 0) { { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneBeginAllocSrcLocSerial); - tracy::MemWrite(&item->gpuZoneBegin.cpuTime, tracy::Profiler::GetTime()); + tracy::MemWrite(&item->gpuZoneBegin.cpuTime, cpu_start_time); tracy::MemWrite(&item->gpuZoneBegin.srcloc, (uint64_t)src_loc); tracy::MemWrite(&item->gpuZoneBegin.thread, tracy::GetThreadHandle()); tracy::MemWrite(&item->gpuZoneBegin.queryId, query_id); @@ -161,7 +175,7 @@ void record_interval(ToolData *data, rocprofiler_timestamp_t start_timestamp, { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneBeginSerial); - tracy::MemWrite(&item->gpuZoneBegin.cpuTime, tracy::Profiler::GetTime()); + tracy::MemWrite(&item->gpuZoneBegin.cpuTime, cpu_start_time); tracy::MemWrite(&item->gpuZoneBegin.srcloc, (uint64_t)&src_loc); tracy::MemWrite(&item->gpuZoneBegin.thread, tracy::GetThreadHandle()); tracy::MemWrite(&item->gpuZoneBegin.queryId, query_id); @@ -182,7 +196,7 @@ void record_interval(ToolData *data, rocprofiler_timestamp_t start_timestamp, { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneEndSerial); - tracy::MemWrite(&item->gpuZoneEnd.cpuTime, tracy::Profiler::GetTime()); + tracy::MemWrite(&item->gpuZoneEnd.cpuTime, cpu_end_time); tracy::MemWrite(&item->gpuZoneEnd.thread, tracy::GetThreadHandle()); tracy::MemWrite(&item->gpuZoneEnd.queryId, query_id); tracy::MemWrite(&item->gpuZoneEnd.context, context_id); @@ -354,11 +368,20 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, auto _lk = std::unique_lock{data->mut}; data->client_kernels.erase(sym_data->kernel_id); } - } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH && - record.operation == ROCPROFILER_KERNEL_DISPATCH_COMPLETE) { + } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH) { auto* rdata = static_cast(record.payload); - uint64_t src_loc = kernel_src_loc(data, rdata->dispatch_info.kernel_id); - record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc); + if (record.operation == ROCPROFILER_KERNEL_DISPATCH_ENQUEUE) { + if (record.phase == ROCPROFILER_CALLBACK_PHASE_ENTER) { + auto _lk = std::unique_lock{data->mut}; + data->launch_start_times.emplace(rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime()); + } else if (record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT) { + auto _lk = std::unique_lock{data->mut}; + data->launch_end_times.emplace(rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime()); + } + } else if (record.operation == ROCPROFILER_KERNEL_DISPATCH_COMPLETE) { + uint64_t src_loc = kernel_src_loc(data, rdata->dispatch_info.kernel_id); + record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc, rdata->dispatch_info.dispatch_id); + } } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_MEMORY_COPY && record.operation != ROCPROFILER_MEMORY_COPY_NONE && record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT) { @@ -382,7 +405,7 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, uint64_t src_loc = tracy::Profiler::AllocSourceLocation( 0, NULL, 0, name, name_len, NULL, 0); - record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc); + record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc, UINT64_MAX); } } @@ -404,12 +427,12 @@ int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) user_data), "callback tracing service failed to configure"); - rocprofiler_tracing_operation_t ops2[] = {ROCPROFILER_KERNEL_DISPATCH_COMPLETE}; + rocprofiler_tracing_operation_t ops2[] = {ROCPROFILER_KERNEL_DISPATCH_COMPLETE, ROCPROFILER_KERNEL_DISPATCH_ENQUEUE}; ROCPROFILER_CALL( rocprofiler_configure_callback_tracing_service(get_client_ctx(), ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH, ops2, - 1, + 2, tool_callback_tracing_callback, user_data), "callback tracing service failed to configure"); From 86de39704ffac3afe8d686630defefd0d2453a78 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Fri, 20 Jun 2025 18:35:23 +0000 Subject: [PATCH 05/21] Add calibration thread Synchronizes the GPU timeline periodically. This is needed to counter network time updates that cause drift in the GPU and CPU timeline. Signed-off-by: Eric Eaton --- public/client/TracyRocprof.cpp | 92 +++++++++++++++++++++++----------- 1 file changed, 64 insertions(+), 28 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 30a67cbe..bfaf2420 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -1,6 +1,7 @@ #include #include #include "TracyProfiler.hpp" +#include "TracyThread.hpp" #include "tracy/TracyC.h" #include @@ -42,9 +43,11 @@ struct ToolData bool init; uint64_t src_loc; uint64_t query_id; + int64_t previous_cpu_time; std::unordered_map client_kernels; std::unordered_map launch_start_times; std::unordered_map launch_end_times; + std::unique_ptr cal_thread; std::mutex mut{}; }; @@ -60,14 +63,15 @@ get_client_ctx() const char * CTX_NAME = "rocprofv3"; -uint8_t gpu_context_allocate() { +uint8_t gpu_context_allocate(ToolData * data) { timespec ts; 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 = false; + bool is_calibrated = true; float timestamp_period = 1.0f; + data->previous_cpu_time = cpu_timestamp; // Allocate the process-unique GPU context ID. There's a max of 255 available; // if we are recreating devices a lot we may exceed that. Don't do that, or @@ -218,9 +222,12 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, rocprofiler_record_counter_t* record_data, size_t record_count, rocprofiler_user_data_t /*user_data*/ , - void* callback_data_args) + void* callback_data) { - if (!TracyIsStarted) return; + assert(callback_data != nullptr); + ToolData * data = static_cast(callback_data); + if (!data->init) return; + for(size_t i = 0; i < record_count; ++i) { int64_t profilerTime = Profiler::GetTime(); TracyLfqPrepare( QueueType::PlotDataDouble ); @@ -231,21 +238,6 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, } } -void delay_init(void *user_data) { - ToolData * data = static_cast(user_data); - if (data->init) return; - data->init = true; - data->context_id = gpu_context_allocate(); - - TracyLfqPrepare( QueueType::PlotConfig ); - MemWrite( &item->plotConfig.name, (uint64_t)PLOT_NAME); - MemWrite( &item->plotConfig.type, (uint8_t)PlotFormatType::Number ); - MemWrite( &item->plotConfig.step, (uint8_t)false ); - MemWrite( &item->plotConfig.fill, (uint8_t)true ); - MemWrite( &item->plotConfig.color, 0 ); - TracyLfqCommit; -} - /** * Callback from rocprofiler when an kernel dispatch is enqueued into the HSA queue. * rocprofiler_counter_config_id_t* is a return to specify what counters to collect @@ -256,10 +248,11 @@ void dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, rocprofiler_profile_config_id_t* config, rocprofiler_user_data_t* /*user_data*/, - void* callback_data_args) + void* callback_data) { - if (!TracyIsStarted) return; - delay_init(callback_data_args); + 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. @@ -348,10 +341,9 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, rocprofiler_user_data_t* user_data, void* callback_data) { - if (!TracyIsStarted) return; assert(callback_data != nullptr); ToolData * data = static_cast(callback_data); - delay_init(callback_data); + if (!data->init) return; if(record.kind == ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT && record.operation == ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER) @@ -409,13 +401,53 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, } } +void calibration_thread(void * ptr) { + while (!TracyIsStarted); + ToolData * data = static_cast(ptr); + data->context_id = gpu_context_allocate(data); + + TracyLfqPrepare( QueueType::PlotConfig ); + MemWrite( &item->plotConfig.name, (uint64_t)PLOT_NAME); + MemWrite( &item->plotConfig.type, (uint8_t)PlotFormatType::Number ); + MemWrite( &item->plotConfig.step, (uint8_t)false ); + MemWrite( &item->plotConfig.fill, (uint8_t)true ); + MemWrite( &item->plotConfig.color, 0 ); + TracyLfqCommit; + + data->init = true; + + 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. + 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); + tracy::MemWrite(&item->gpuCalibration.gpuTime, gpu_timestamp); + tracy::MemWrite(&item->gpuCalibration.cpuTime, cpu_timestamp); + tracy::MemWrite(&item->gpuCalibration.cpuDelta, cpu_timestamp - data->previous_cpu_time); + tracy::MemWrite(&item->gpuCalibration.context, data->context_id); + tracy::Profiler::QueueSerialFinish(); + data->previous_cpu_time = cpu_timestamp; + } + + sleep(1); + } +} + int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) { + ToolData * data = static_cast(user_data); + data->cal_thread = std::make_unique(calibration_thread, data); + ROCPROFILER_CALL( rocprofiler_create_context( &get_client_ctx() ), "context creation failed" ); - // ROCPROFILER_CALL( rocprofiler_configure_callback_dispatch_counting_service( get_client_ctx(), dispatch_callback, - // user_data, record_callback, user_data ), - // "Could not setup counting service" ); + ROCPROFILER_CALL( rocprofiler_configure_callback_dispatch_counting_service( get_client_ctx(), dispatch_callback, + user_data, record_callback, user_data ), + "Could not setup counting service" ); rocprofiler_tracing_operation_t ops[] = {ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER}; ROCPROFILER_CALL( @@ -453,6 +485,10 @@ 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(); } } @@ -468,7 +504,7 @@ extern "C" client_id->name = "Tracy"; // (optional) create configure data - static auto data = ToolData{ version, runtime_version, priority, *client_id, 0, false, 0, 0 }; + static ToolData data = ToolData{ version, runtime_version, priority, *client_id, 0, false, 0, 0 }; //std::cerr << "profile hello" << std::endl; From 2e49bdf4cbf6a605b42e9945cb081f14c275c899 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Tue, 1 Jul 2025 15:16:03 -0700 Subject: [PATCH 06/21] 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 ); From a754db16f8046d63030fe140bf5c809cd0ef7de5 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 2 Jul 2025 15:24:46 -0700 Subject: [PATCH 07/21] Show counter name in GUI --- profiler/src/profiler/TracyView_ZoneInfo.cpp | 14 +++++++-- public/client/TracyProfiler.cpp | 18 ++++++++++++ public/client/TracyRocprof.cpp | 14 ++++++++- public/common/TracyQueue.hpp | 16 +++++++++++ server/TracyEvent.hpp | 1 + server/TracyWorker.cpp | 30 ++++++++++++++++++++ server/TracyWorker.hpp | 1 + 7 files changed, 91 insertions(+), 3 deletions(-) diff --git a/profiler/src/profiler/TracyView_ZoneInfo.cpp b/profiler/src/profiler/TracyView_ZoneInfo.cpp index fd70b831..98af9e63 100644 --- a/profiler/src/profiler/TracyView_ZoneInfo.cpp +++ b/profiler/src/profiler/TracyView_ZoneInfo.cpp @@ -1581,7 +1581,12 @@ void View::DrawGpuInfoWindow() 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]) ); + auto id = ev.note_ids[i]; + if (ctx->notes.count(id)) { + TextFocused( m_worker.GetString( ctx->notes.at(id) ), RealToString(ev.note_vals[i]) ); + } else { + TextFocused( RealToString(ev.note_ids[i]), RealToString(ev.note_vals[i]) ); + } } ImGui::Separator(); @@ -2053,7 +2058,12 @@ void View::ZoneTooltip( const GpuEvent& ev ) 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]) ); + auto id = ev.note_ids[i]; + if (ctx->notes.count(id)) { + TextFocused( m_worker.GetString( ctx->notes.at(id) ), RealToString(ev.note_vals[i]) ); + } else { + TextFocused( RealToString(ev.note_ids[i]), RealToString(ev.note_vals[i]) ); + } } ImGui::EndTooltip(); diff --git a/public/client/TracyProfiler.cpp b/public/client/TracyProfiler.cpp index e2e0747b..9848a639 100644 --- a/public/client/TracyProfiler.cpp +++ b/public/client/TracyProfiler.cpp @@ -2358,6 +2358,10 @@ static void FreeAssociatedMemory( const QueueItem& item ) tracy_free( (void*)ptr ); break; #endif + case QueueType::GpuAnnotationName: + ptr = MemRead( &item.gpuAnnotationNameFat.ptr ); + tracy_free( (void*)ptr ); + break; #ifdef TRACY_ON_DEMAND case QueueType::MessageAppInfo: case QueueType::GpuContextName: @@ -2573,6 +2577,12 @@ Profiler::DequeueStatus Profiler::Dequeue( moodycamel::ConsumerToken& token ) tracy_free_fast( (void*)ptr ); #endif break; + case QueueType::GpuAnnotationName: + ptr = MemRead( &item->gpuAnnotationNameFat.ptr ); + size = MemRead( &item->gpuAnnotationNameFat.size ); + SendSingleString( (const char*)ptr, size ); + tracy_free_fast( (void*)ptr ); + break; case QueueType::PlotDataInt: case QueueType::PlotDataFloat: case QueueType::PlotDataDouble: @@ -2931,6 +2941,14 @@ Profiler::DequeueStatus Profiler::DequeueSerial() #endif break; } + case QueueType::GpuAnnotationName: + { + ptr = MemRead( &item->gpuAnnotationNameFat.ptr ); + uint16_t size = MemRead( &item->gpuAnnotationNameFat.size ); + SendSingleString( (const char*)ptr, size ); + tracy_free_fast( (void*)ptr ); + break; + } #ifdef TRACY_FIBERS case QueueType::ZoneBegin: case QueueType::ZoneBeginCallstack: diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index b225249c..6caf220b 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -263,7 +263,6 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, 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); @@ -351,6 +350,19 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, { std::clog << "Counter: " << counter.handle << " " << info.name << "\n"; collect_counters.push_back(counter); + + size_t name_length = strlen(info.name); + char* cloned_name = (char*)tracy::tracy_malloc(name_length); + memcpy(cloned_name, info.name, name_length); + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuAnnotationName); + tracy::MemWrite(&item->gpuAnnotationNameFat.context, data->context_id); + tracy::MemWrite(&item->gpuAnnotationNameFat.noteId, counter.handle); + tracy::MemWrite(&item->gpuAnnotationNameFat.ptr, (uint64_t)cloned_name); + tracy::MemWrite(&item->gpuAnnotationNameFat.size, name_length); + tracy::Profiler::QueueSerialFinish(); + } } } diff --git a/public/common/TracyQueue.hpp b/public/common/TracyQueue.hpp index 12ee4cf9..c8644053 100644 --- a/public/common/TracyQueue.hpp +++ b/public/common/TracyQueue.hpp @@ -61,6 +61,7 @@ enum class QueueType : uint8_t ThreadWakeup, GpuTime, GpuContextName, + GpuAnnotationName, CallstackFrameSize, SymbolInformation, ExternalNameMetadata, @@ -488,6 +489,18 @@ struct QueueGpuContextNameFat : public QueueGpuContextName uint16_t size; }; +struct QueueGpuAnnotationName +{ + int64_t noteId; + uint8_t context; +}; + +struct QueueGpuAnnotationNameFat : public QueueGpuAnnotationName +{ + uint64_t ptr; + uint16_t size; +}; + struct QueueMemNamePayload { uint64_t name; @@ -765,6 +778,8 @@ struct QueueItem QueueGpuTimeSync gpuTimeSync; QueueGpuContextName gpuContextName; QueueGpuContextNameFat gpuContextNameFat; + QueueGpuAnnotationName gpuAnnotationName; + QueueGpuAnnotationNameFat gpuAnnotationNameFat; QueueMemAlloc memAlloc; QueueMemFree memFree; QueueMemDiscard memDiscard; @@ -859,6 +874,7 @@ static constexpr size_t QueueDataSize[] = { sizeof( QueueHeader ) + sizeof( QueueThreadWakeup ), sizeof( QueueHeader ) + sizeof( QueueGpuTime ), sizeof( QueueHeader ) + sizeof( QueueGpuContextName ), + sizeof( QueueHeader ) + sizeof( QueueGpuAnnotationName ), sizeof( QueueHeader ) + sizeof( QueueCallstackFrameSize ), sizeof( QueueHeader ) + sizeof( QueueSymbolInformation ), sizeof( QueueHeader ), // ExternalNameMetadata - not for wire transfer diff --git a/server/TracyEvent.hpp b/server/TracyEvent.hpp index 6e2949a4..630124c0 100644 --- a/server/TracyEvent.hpp +++ b/server/TracyEvent.hpp @@ -778,6 +778,7 @@ struct GpuCtxData uint32_t overflowMul; StringIdx name; unordered_flat_map threadData; + unordered_flat_map notes; short_ptr query[64*1024]; }; diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index 94e50fad..72595ece 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -1105,6 +1105,15 @@ Worker::Worker( FileRead& f, EventType::Type eventMask, bool bgTasks, bool allow auto ctx = m_slab.AllocInit(); uint8_t calibration; f.Read7( ctx->thread, calibration, ctx->count, ctx->period, ctx->type, ctx->name, ctx->overflow ); + uint64_t notesz; + f.Read( notesz ); + for ( uint64_t i=0; inotes)::key_type key; + decltype(ctx->notes)::mapped_type value; + f.Read2( key, value ); + ctx->notes[key] = value; + } ctx->hasCalibration = calibration; ctx->hasPeriod = ctx->period != 1.f; m_data.gpuCnt += ctx->count; @@ -4622,6 +4631,9 @@ bool Worker::Process( const QueueItem& ev ) case QueueType::GpuContextName: ProcessGpuContextName( ev.gpuContextName ); break; + case QueueType::GpuAnnotationName: + ProcessGpuAnnotationName( ev.gpuAnnotationName ); + break; case QueueType::GpuZoneAnnotation: ProcessGpuZoneAnnotation( ev.zoneAnnotation ); break; @@ -6017,6 +6029,14 @@ void Worker::ProcessGpuContextName( const QueueGpuContextName& ev ) ctx->name = StringIdx( idx ); } +void Worker::ProcessGpuAnnotationName( const QueueGpuAnnotationName& ev ) +{ + auto ctx = m_gpuCtxMap[ev.context]; + assert( ctx ); + const auto idx = GetSingleStringIdx(); + ctx->notes[ev.noteId] = StringIdx( idx ); +} + void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) { auto ctx = m_gpuCtxMap[ev.context]; @@ -6031,6 +6051,9 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) zone->note_ids[zone->note_count] = ev.noteId; zone->note_vals[zone->note_count] = ev.value; zone->note_count++; + + if (ctx->notes.contains(ev.noteId)) + fprintf(stderr, "%s: %f\n", GetString(ctx->notes[ev.noteId]), ev.value); } MemEvent* Worker::ProcessMemAllocImpl( MemData& memdata, const QueueMemAlloc& ev ) @@ -8149,6 +8172,13 @@ void Worker::Write( FileWrite& f, bool fiDict ) f.Write( &ctx->type, sizeof( ctx->type ) ); f.Write( &ctx->name, sizeof( ctx->name ) ); f.Write( &ctx->overflow, sizeof( ctx->overflow ) ); + sz = ctx->notes.size(); + f.Write( &sz, sizeof( sz ) ); + for( auto& p : ctx->notes ) + { + f.Write( &p.first, sizeof( p.first ) ); + f.Write( &p.second, sizeof( p.second ) ); + } sz = ctx->threadData.size(); f.Write( &sz, sizeof( sz ) ); for( auto& td : ctx->threadData ) diff --git a/server/TracyWorker.hpp b/server/TracyWorker.hpp index fd1dc8ee..ff4b16af 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 ProcessGpuAnnotationName( const QueueGpuAnnotationName& 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 ); From e9e0404930cbd3e05ee59de3a88921375070a830 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 2 Jul 2025 15:42:05 -0700 Subject: [PATCH 08/21] Add support for multiple counters --- public/client/TracyRocprof.cpp | 36 +++++++++------------------------- 1 file changed, 9 insertions(+), 27 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 6caf220b..818cb88d 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -55,7 +55,6 @@ struct ToolData }; using namespace tracy; -const char * PLOT_NAME = "SQ_WAVES"; rocprofiler_context_id_t& get_client_ctx() @@ -233,16 +232,12 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, ToolData * data = static_cast(callback_data); if (!data->init) return; - double sum; + std::unordered_map sums; for(size_t i = 0; i < record_count; ++i) { - int64_t profilerTime = Profiler::GetTime(); - TracyLfqPrepare( QueueType::PlotDataDouble ); - MemWrite( &item->plotDataDouble.name, (uint64_t)PLOT_NAME ); - MemWrite( &item->plotDataDouble.time, profilerTime ); - MemWrite( &item->plotDataDouble.val, record_data[i].counter_value ); - TracyLfqCommit; - - sum += record_data[i].counter_value; + auto _counter_id = rocprofiler_counter_id_t{}; + ROCPROFILER_CALL(rocprofiler_query_record_counter_id(record_data[i].id, &_counter_id), + "query record counter id"); + sums[_counter_id.handle] += record_data[i].counter_value; } uint16_t query_id = 0; @@ -255,16 +250,12 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, } } - if (record_count > 0) { - //fprintf(stderr, "a %lu\n", dispatch_data.dispatch_info.dispatch_id); + for( auto& p: sums ) { 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); + tracy::MemWrite(&item->zoneAnnotation.noteId, p.first); tracy::MemWrite(&item->zoneAnnotation.queryId, query_id); - tracy::MemWrite(&item->zoneAnnotation.value, sum); + tracy::MemWrite(&item->zoneAnnotation.value, p.second); tracy::MemWrite(&item->zoneAnnotation.context, data->context_id); tracy::Profiler::QueueSerialFinish(); } @@ -315,7 +306,7 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, if(search_cache()) return; // Counters we want to collect (here its SQ_WAVES) - std::set counters_to_collect = {"SQ_WAVES"}; + std::set counters_to_collect = {"SQ_WAVES", "GL2C_MISS"}; // GPU Counter IDs std::vector gpu_counters; @@ -450,15 +441,6 @@ void calibration_thread(void * ptr) { while (!TracyIsStarted); ToolData * data = static_cast(ptr); data->context_id = gpu_context_allocate(data); - - TracyLfqPrepare( QueueType::PlotConfig ); - MemWrite( &item->plotConfig.name, (uint64_t)PLOT_NAME); - MemWrite( &item->plotConfig.type, (uint8_t)PlotFormatType::Number ); - MemWrite( &item->plotConfig.step, (uint8_t)false ); - MemWrite( &item->plotConfig.fill, (uint8_t)true ); - MemWrite( &item->plotConfig.color, 0 ); - TracyLfqCommit; - data->init = true; #if USE_CALIBRATION From d1f9df8058f9f2a8f922e671ebf280242f355146 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 2 Jul 2025 16:06:22 -0700 Subject: [PATCH 09/21] Get counter names from environment variable Allows user to customize the collected information with environment variable TRACY_ROCPROF_COUNTERS. --- public/client/TracyRocprof.cpp | 15 ++++++++++----- server/TracyWorker.cpp | 3 --- 2 files changed, 10 insertions(+), 8 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 818cb88d..32ad8376 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -50,6 +50,7 @@ struct ToolData std::unordered_map launch_start_times; std::unordered_map launch_end_times; std::unordered_map dispatch_query_id; + std::set counter_names = {"SQ_WAVES", "GL2C_MISS", "GL2C_HIT"}; std::unique_ptr cal_thread; std::mutex mut{}; }; @@ -305,8 +306,6 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, auto wlock = std::unique_lock{m_mutex}; if(search_cache()) return; - // Counters we want to collect (here its SQ_WAVES) - std::set counters_to_collect = {"SQ_WAVES", "GL2C_MISS"}; // GPU Counter IDs std::vector gpu_counters; @@ -337,7 +336,7 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, rocprofiler_query_counter_info( counter, ROCPROFILER_COUNTER_INFO_VERSION_0, static_cast(&info)), "Could not query info"); - if(counters_to_collect.count(std::string(info.name)) > 0) + if(data->counter_names.count(std::string(info.name)) > 0) { std::clog << "Counter: " << counter.handle << " " << info.name << "\n"; collect_counters.push_back(counter); @@ -441,6 +440,14 @@ void calibration_thread(void * ptr) { while (!TracyIsStarted); ToolData * data = static_cast(ptr); data->context_id = gpu_context_allocate(data); + const char* user_counters = GetEnvVar("TRACY_ROCPROF_COUNTERS"); + if (user_counters) { + data->counter_names.clear(); + std::stringstream ss(user_counters); + std::string counter; + while (std::getline(ss, counter, ',')) + data->counter_names.insert(counter); + } data->init = true; #if USE_CALIBRATION @@ -536,8 +543,6 @@ extern "C" // (optional) create configure data static ToolData data = ToolData{ version, runtime_version, priority, *client_id, 0, false, 0, 0 }; - //std::cerr << "profile hello" << std::endl; - // construct configure result static auto cfg = rocprofiler_tool_configure_result_t{ sizeof( rocprofiler_tool_configure_result_t ), &tool_init, &tool_fini, static_cast( &data ) }; diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index 72595ece..09e3cf8e 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -6051,9 +6051,6 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) zone->note_ids[zone->note_count] = ev.noteId; zone->note_vals[zone->note_count] = ev.value; zone->note_count++; - - if (ctx->notes.contains(ev.noteId)) - fprintf(stderr, "%s: %f\n", GetString(ctx->notes[ev.noteId]), ev.value); } MemEvent* Worker::ProcessMemAllocImpl( MemData& memdata, const QueueMemAlloc& ev ) From 9413436ba1f6a4205fe2560fc6dbd00cd80d4b0b Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Mon, 7 Jul 2025 17:55:50 -0700 Subject: [PATCH 10/21] Search backward for the correct zone Needed to make tracing more intense applications work. --- server/TracyWorker.cpp | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index 09e3cf8e..d438383d 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -6044,9 +6044,15 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) // 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 ); + auto & timeline = ctx->threadData.begin()->second.timeline; + assert( timeline.size() ); + ssize_t i = timeline.size() - 1; + for ( ; i >= 0 ; i--) { + if( timeline[i]->query_id == ev.queryId ) { + break; + } + } + auto& zone = timeline[i]; assert( zone->note_count < 10 ); zone->note_ids[zone->note_count] = ev.noteId; zone->note_vals[zone->note_count] = ev.value; From 7fc5b6c9771545e88df62f567e877c99c796abc7 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 9 Jul 2025 10:09:12 -0700 Subject: [PATCH 11/21] Increase protocol version --- public/common/TracyProtocol.hpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/public/common/TracyProtocol.hpp b/public/common/TracyProtocol.hpp index d23b1d08..ff38686f 100644 --- a/public/common/TracyProtocol.hpp +++ b/public/common/TracyProtocol.hpp @@ -9,7 +9,7 @@ namespace tracy constexpr unsigned Lz4CompressBound( unsigned isize ) { return isize + ( isize / 255 ) + 16; } -enum : uint32_t { ProtocolVersion = 75 }; +enum : uint32_t { ProtocolVersion = 76 }; enum : uint16_t { BroadcastVersion = 3 }; using lz4sz_t = uint32_t; From 1494fe56714e0d5b55dfdc07bdb9af986847d045 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 9 Jul 2025 10:27:49 -0700 Subject: [PATCH 12/21] Apply code style --- profiler/src/profiler/TracyView_ZoneInfo.cpp | 40 +- public/client/TracyRocprof.cpp | 549 ++++++++++--------- public/common/TracyQueue.hpp | 16 +- server/TracyWorker.cpp | 43 +- 4 files changed, 329 insertions(+), 319 deletions(-) diff --git a/profiler/src/profiler/TracyView_ZoneInfo.cpp b/profiler/src/profiler/TracyView_ZoneInfo.cpp index 98af9e63..3ea2d4fd 100644 --- a/profiler/src/profiler/TracyView_ZoneInfo.cpp +++ b/profiler/src/profiler/TracyView_ZoneInfo.cpp @@ -1579,14 +1579,18 @@ 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++ ) { - auto id = ev.note_ids[i]; - if (ctx->notes.count(id)) { - TextFocused( m_worker.GetString( ctx->notes.at(id) ), RealToString(ev.note_vals[i]) ); - } else { - TextFocused( RealToString(ev.note_ids[i]), RealToString(ev.note_vals[i]) ); - } + TextFocused( "Query ID:", RealToString( ev.query_id ) ); + for( int i = 0; i < ev.note_count; i++ ) + { + auto id = ev.note_ids[i]; + if( ctx->notes.count( id ) ) + { + TextFocused( m_worker.GetString( ctx->notes.at( id ) ), RealToString( ev.note_vals[i] ) ); + } + else + { + TextFocused( RealToString( ev.note_ids[i] ), RealToString( ev.note_vals[i] ) ); + } } ImGui::Separator(); @@ -2056,14 +2060,18 @@ 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++ ) { - auto id = ev.note_ids[i]; - if (ctx->notes.count(id)) { - TextFocused( m_worker.GetString( ctx->notes.at(id) ), RealToString(ev.note_vals[i]) ); - } else { - TextFocused( RealToString(ev.note_ids[i]), RealToString(ev.note_vals[i]) ); - } + TextFocused( "Query ID:", RealToString( ev.query_id ) ); + for( int i = 0; i < ev.note_count; i++ ) + { + auto id = ev.note_ids[i]; + if( ctx->notes.count( id ) ) + { + TextFocused( m_worker.GetString( ctx->notes.at( id ) ), RealToString( ev.note_vals[i] ) ); + } + else + { + 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 32ad8376..13bb7009 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -1,17 +1,17 @@ -#include -#include #include "TracyProfiler.hpp" #include "TracyThread.hpp" #include "tracy/TracyC.h" +#include +#include #include -#include -#include #include +#include #include #include -#include #include +#include +#include #define ROCPROFILER_CALL( result, msg ) \ { \ @@ -50,28 +50,28 @@ struct ToolData std::unordered_map launch_start_times; std::unordered_map launch_end_times; std::unordered_map dispatch_query_id; - std::set counter_names = {"SQ_WAVES", "GL2C_MISS", "GL2C_HIT"}; + std::set counter_names = { "SQ_WAVES", "GL2C_MISS", "GL2C_HIT" }; std::unique_ptr cal_thread; - std::mutex mut{}; + std::mutex mut{}; }; using namespace tracy; -rocprofiler_context_id_t& -get_client_ctx() +rocprofiler_context_id_t& get_client_ctx() { - static rocprofiler_context_id_t ctx{0}; + static rocprofiler_context_id_t ctx{ 0 }; return ctx; } -const char * CTX_NAME = "rocprofv3"; +const char* CTX_NAME = "rocprofv3"; -uint8_t gpu_context_allocate(ToolData * data) { +uint8_t gpu_context_allocate( ToolData* data ) +{ timespec ts; - clock_gettime(CLOCK_BOOTTIME, &ts); + clock_gettime( CLOCK_BOOTTIME, &ts ); uint64_t cpu_timestamp = Profiler::GetTime(); - uint64_t gpu_timestamp = ((uint64_t)ts.tv_sec * 1000000000) + ts.tv_nsec; + uint64_t gpu_timestamp = ( (uint64_t)ts.tv_sec * 1000000000 ) + ts.tv_nsec; bool is_calibrated = USE_CALIBRATION; float timestamp_period = 1.0f; data->previous_cpu_time = cpu_timestamp; @@ -79,186 +79,193 @@ uint8_t gpu_context_allocate(ToolData * data) { // Allocate the process-unique GPU context ID. There's a max of 255 available; // if we are recreating devices a lot we may exceed that. Don't do that, or // wrap around and get weird (but probably still usable) numbers. - uint8_t context_id = - tracy::GetGpuCtxCounter().fetch_add(1, std::memory_order_relaxed); - if (context_id >= 255) { - context_id %= 255; + uint8_t context_id = tracy::GetGpuCtxCounter().fetch_add( 1, std::memory_order_relaxed ); + if( context_id >= 255 ) + { + context_id %= 255; } uint8_t context_flags = 0; - if (is_calibrated) { - // Tell tracy we'll be passing calibrated timestamps and not to mess with - // the times. We'll periodically send GpuCalibration events in case the - // times drift. - context_flags |= tracy::GpuContextCalibration; + if( is_calibrated ) + { + // Tell tracy we'll be passing calibrated timestamps and not to mess with + // the times. We'll periodically send GpuCalibration events in case the + // times drift. + context_flags |= tracy::GpuContextCalibration; } { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuNewContext); - tracy::MemWrite(&item->gpuNewContext.cpuTime, cpu_timestamp); - tracy::MemWrite(&item->gpuNewContext.gpuTime, gpu_timestamp); - memset(&item->gpuNewContext.thread, 0, sizeof(item->gpuNewContext.thread)); - tracy::MemWrite(&item->gpuNewContext.period, timestamp_period); - tracy::MemWrite(&item->gpuNewContext.context, context_id); - tracy::MemWrite(&item->gpuNewContext.flags, context_flags); - tracy::MemWrite(&item->gpuNewContext.type, tracy::GpuContextType::Vulkan); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuNewContext ); + tracy::MemWrite( &item->gpuNewContext.cpuTime, cpu_timestamp ); + tracy::MemWrite( &item->gpuNewContext.gpuTime, gpu_timestamp ); + memset( &item->gpuNewContext.thread, 0, sizeof( item->gpuNewContext.thread ) ); + tracy::MemWrite( &item->gpuNewContext.period, timestamp_period ); + tracy::MemWrite( &item->gpuNewContext.context, context_id ); + tracy::MemWrite( &item->gpuNewContext.flags, context_flags ); + tracy::MemWrite( &item->gpuNewContext.type, tracy::GpuContextType::Vulkan ); + tracy::Profiler::QueueSerialFinish(); } // Send the name of the context along. // NOTE: Tracy will unconditionally free the name so we must clone it here. // Since internally Tracy will use its own rpmalloc implementation we must // make sure we allocate from the same source. - size_t name_length = strlen(CTX_NAME); - char* cloned_name = (char*)tracy::tracy_malloc(name_length); - memcpy(cloned_name, CTX_NAME, name_length); + size_t name_length = strlen( CTX_NAME ); + char* cloned_name = (char*)tracy::tracy_malloc( name_length ); + memcpy( cloned_name, CTX_NAME, name_length ); { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuContextName); - tracy::MemWrite(&item->gpuContextNameFat.context, context_id); - tracy::MemWrite(&item->gpuContextNameFat.ptr, (uint64_t)cloned_name); - tracy::MemWrite(&item->gpuContextNameFat.size, name_length); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuContextName ); + tracy::MemWrite( &item->gpuContextNameFat.context, context_id ); + tracy::MemWrite( &item->gpuContextNameFat.ptr, (uint64_t)cloned_name ); + tracy::MemWrite( &item->gpuContextNameFat.size, name_length ); + tracy::Profiler::QueueSerialFinish(); } return context_id; } -uint64_t kernel_src_loc(ToolData *data, uint64_t kernel_id) { +uint64_t kernel_src_loc( ToolData* data, uint64_t kernel_id ) +{ uint64_t src_loc = 0; - auto _lk = std::unique_lock{data->mut}; + auto _lk = std::unique_lock{ data->mut }; rocprofiler_kernel_id_t kid = kernel_id; - if (data->client_kernels.count(kid)) { - auto &sym_data = data->client_kernels[kid]; - const char * name = sym_data.kernel_name; - size_t name_len = strlen(name); + if( data->client_kernels.count( kid ) ) + { + auto& sym_data = data->client_kernels[kid]; + const char* name = sym_data.kernel_name; + size_t name_len = strlen( name ); uint32_t line = 0; - src_loc = tracy::Profiler::AllocSourceLocation( - line, NULL, 0, name, name_len, - NULL, 0); + src_loc = tracy::Profiler::AllocSourceLocation( line, NULL, 0, name, name_len, NULL, 0 ); } return src_loc; } -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) { +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}; + 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; + if( dispatch_id != UINT64_MAX ) data->dispatch_query_id[dispatch_id] = query_id; } uint64_t cpu_start_time = 0, cpu_end_time = 0; - if (dispatch_id == UINT64_MAX) { + if( dispatch_id == UINT64_MAX ) + { cpu_start_time = tracy::Profiler::GetTime(); cpu_end_time = tracy::Profiler::GetTime(); - } else { - auto _lk = std::unique_lock{data->mut}; - cpu_start_time = data->launch_start_times.at(dispatch_id); - cpu_end_time = data->launch_end_times.at(dispatch_id); - data->launch_start_times.erase(dispatch_id); - data->launch_end_times.erase(dispatch_id); + } + else + { + auto _lk = std::unique_lock{ data->mut }; + cpu_start_time = data->launch_start_times.at( dispatch_id ); + cpu_end_time = data->launch_end_times.at( dispatch_id ); + data->launch_start_times.erase( dispatch_id ); + data->launch_end_times.erase( dispatch_id ); } - if (src_loc != 0) { + if( src_loc != 0 ) + { { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, - tracy::QueueType::GpuZoneBeginAllocSrcLocSerial); - tracy::MemWrite(&item->gpuZoneBegin.cpuTime, cpu_start_time); - tracy::MemWrite(&item->gpuZoneBegin.srcloc, (uint64_t)src_loc); - tracy::MemWrite(&item->gpuZoneBegin.thread, tracy::GetThreadHandle()); - tracy::MemWrite(&item->gpuZoneBegin.queryId, query_id); - tracy::MemWrite(&item->gpuZoneBegin.context, context_id); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuZoneBeginAllocSrcLocSerial ); + tracy::MemWrite( &item->gpuZoneBegin.cpuTime, cpu_start_time ); + tracy::MemWrite( &item->gpuZoneBegin.srcloc, (uint64_t)src_loc ); + tracy::MemWrite( &item->gpuZoneBegin.thread, tracy::GetThreadHandle() ); + tracy::MemWrite( &item->gpuZoneBegin.queryId, query_id ); + tracy::MemWrite( &item->gpuZoneBegin.context, context_id ); + tracy::Profiler::QueueSerialFinish(); } - } else { - static const ___tracy_source_location_data src_loc = {NULL, NULL, NULL, 0, 0}; + } + else + { + static const ___tracy_source_location_data src_loc = { NULL, NULL, NULL, 0, 0 }; { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneBeginSerial); - tracy::MemWrite(&item->gpuZoneBegin.cpuTime, cpu_start_time); - tracy::MemWrite(&item->gpuZoneBegin.srcloc, (uint64_t)&src_loc); - tracy::MemWrite(&item->gpuZoneBegin.thread, tracy::GetThreadHandle()); - tracy::MemWrite(&item->gpuZoneBegin.queryId, query_id); - tracy::MemWrite(&item->gpuZoneBegin.context, context_id); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuZoneBeginSerial ); + tracy::MemWrite( &item->gpuZoneBegin.cpuTime, cpu_start_time ); + tracy::MemWrite( &item->gpuZoneBegin.srcloc, (uint64_t)&src_loc ); + tracy::MemWrite( &item->gpuZoneBegin.thread, tracy::GetThreadHandle() ); + tracy::MemWrite( &item->gpuZoneBegin.queryId, query_id ); + tracy::MemWrite( &item->gpuZoneBegin.context, context_id ); + tracy::Profiler::QueueSerialFinish(); } } { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuTime); - tracy::MemWrite(&item->gpuTime.gpuTime, start_timestamp); - tracy::MemWrite(&item->gpuTime.queryId, query_id); - tracy::MemWrite(&item->gpuTime.context, context_id); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuTime ); + tracy::MemWrite( &item->gpuTime.gpuTime, start_timestamp ); + tracy::MemWrite( &item->gpuTime.queryId, query_id ); + tracy::MemWrite( &item->gpuTime.context, context_id ); + tracy::Profiler::QueueSerialFinish(); } { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneEndSerial); - tracy::MemWrite(&item->gpuZoneEnd.cpuTime, cpu_end_time); - tracy::MemWrite(&item->gpuZoneEnd.thread, tracy::GetThreadHandle()); - tracy::MemWrite(&item->gpuZoneEnd.queryId, query_id); - tracy::MemWrite(&item->gpuZoneEnd.context, context_id); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuZoneEndSerial ); + tracy::MemWrite( &item->gpuZoneEnd.cpuTime, cpu_end_time ); + tracy::MemWrite( &item->gpuZoneEnd.thread, tracy::GetThreadHandle() ); + tracy::MemWrite( &item->gpuZoneEnd.queryId, query_id ); + tracy::MemWrite( &item->gpuZoneEnd.context, context_id ); + tracy::Profiler::QueueSerialFinish(); } { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuTime); - tracy::MemWrite(&item->gpuTime.gpuTime, end_timestamp); - tracy::MemWrite(&item->gpuTime.queryId, query_id); - tracy::MemWrite(&item->gpuTime.context, context_id); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuTime ); + tracy::MemWrite( &item->gpuTime.gpuTime, end_timestamp ); + tracy::MemWrite( &item->gpuTime.queryId, query_id ); + tracy::MemWrite( &item->gpuTime.context, context_id ); + tracy::Profiler::QueueSerialFinish(); } } -void -record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, - rocprofiler_record_counter_t* record_data, - size_t record_count, - rocprofiler_user_data_t /*user_data*/ , - void* callback_data) +void record_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data, + rocprofiler_record_counter_t* record_data, size_t record_count, + rocprofiler_user_data_t /*user_data*/, void* callback_data ) { - assert(callback_data != nullptr); - ToolData * data = static_cast(callback_data); - if (!data->init) return; + assert( callback_data != nullptr ); + ToolData* data = static_cast( callback_data ); + if( !data->init ) return; std::unordered_map sums; - for(size_t i = 0; i < record_count; ++i) { + for( size_t i = 0; i < record_count; ++i ) + { auto _counter_id = rocprofiler_counter_id_t{}; - ROCPROFILER_CALL(rocprofiler_query_record_counter_id(record_data[i].id, &_counter_id), - "query record counter id"); + ROCPROFILER_CALL( rocprofiler_query_record_counter_id( record_data[i].id, &_counter_id ), + "query record counter id" ); sums[_counter_id.handle] += 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"); - } + 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" ); + } } - for( auto& p: sums ) { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuZoneAnnotation); - tracy::MemWrite(&item->zoneAnnotation.noteId, p.first); - tracy::MemWrite(&item->zoneAnnotation.queryId, query_id); - tracy::MemWrite(&item->zoneAnnotation.value, p.second); - tracy::MemWrite(&item->zoneAnnotation.context, data->context_id); - tracy::Profiler::QueueSerialFinish(); + for( auto& p : sums ) + { + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuZoneAnnotation ); + tracy::MemWrite( &item->zoneAnnotation.noteId, p.first ); + tracy::MemWrite( &item->zoneAnnotation.queryId, query_id ); + tracy::MemWrite( &item->zoneAnnotation.value, p.second ); + tracy::MemWrite( &item->zoneAnnotation.context, data->context_id ); + tracy::Profiler::QueueSerialFinish(); } } @@ -268,15 +275,13 @@ record_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, * for this dispatch (dispatch_packet). This example function creates a profile * to collect the counter SQ_WAVES for all kernel dispatch packets. */ -void -dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, - rocprofiler_profile_config_id_t* config, - rocprofiler_user_data_t* /*user_data*/, - void* callback_data) +void dispatch_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data, + rocprofiler_profile_config_id_t* config, rocprofiler_user_data_t* /*user_data*/, + void* callback_data ) { - assert(callback_data != nullptr); - ToolData * data = static_cast(callback_data); - if (!data->init) return; + 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. @@ -285,12 +290,12 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, * set for the agent. If we have, return it. Otherwise, construct a new profile counter * set. */ - static std::shared_mutex m_mutex = {}; + static std::shared_mutex m_mutex = {}; static std::unordered_map profile_cache = {}; - auto search_cache = [&]() { - if(auto pos = profile_cache.find(dispatch_data.dispatch_info.agent_id.handle); - pos != profile_cache.end()) + auto search_cache = [&]() + { + if( auto pos = profile_cache.find( dispatch_data.dispatch_info.agent_id.handle ); pos != profile_cache.end() ) { *config = pos->second; return true; @@ -299,122 +304,127 @@ dispatch_callback(rocprofiler_dispatch_counting_service_data_t dispatch_data, }; { - auto rlock = std::shared_lock{m_mutex}; - if(search_cache()) return; + auto rlock = std::shared_lock{ m_mutex }; + if( search_cache() ) return; } - auto wlock = std::unique_lock{m_mutex}; - if(search_cache()) return; + auto wlock = std::unique_lock{ m_mutex }; + if( search_cache() ) return; // GPU Counter IDs std::vector gpu_counters; // Iterate through the agents and get the counters available on that agent - ROCPROFILER_CALL(rocprofiler_iterate_agent_supported_counters( - dispatch_data.dispatch_info.agent_id, - [](rocprofiler_agent_id_t, - rocprofiler_counter_id_t* counters, - size_t num_counters, - void* user_data) { - std::vector* vec = - static_cast*>(user_data); - for(size_t i = 0; i < num_counters; i++) - { - vec->push_back(counters[i]); - } - return ROCPROFILER_STATUS_SUCCESS; - }, - static_cast(&gpu_counters)), - "Could not fetch supported counters"); + ROCPROFILER_CALL( + rocprofiler_iterate_agent_supported_counters( + dispatch_data.dispatch_info.agent_id, + []( rocprofiler_agent_id_t, rocprofiler_counter_id_t* counters, size_t num_counters, void* user_data ) + { + std::vector* vec = + static_cast*>( user_data ); + for( size_t i = 0; i < num_counters; i++ ) + { + vec->push_back( counters[i] ); + } + return ROCPROFILER_STATUS_SUCCESS; + }, + static_cast( &gpu_counters ) ), + "Could not fetch supported counters" ); std::vector collect_counters; // Look for the counters contained in counters_to_collect in gpu_counters - for(auto& counter : gpu_counters) + for( auto& counter : gpu_counters ) { rocprofiler_counter_info_v0_t info; ROCPROFILER_CALL( - rocprofiler_query_counter_info( - counter, ROCPROFILER_COUNTER_INFO_VERSION_0, static_cast(&info)), - "Could not query info"); - if(data->counter_names.count(std::string(info.name)) > 0) + rocprofiler_query_counter_info( counter, ROCPROFILER_COUNTER_INFO_VERSION_0, static_cast( &info ) ), + "Could not query info" ); + if( data->counter_names.count( std::string( info.name ) ) > 0 ) { std::clog << "Counter: " << counter.handle << " " << info.name << "\n"; - collect_counters.push_back(counter); + collect_counters.push_back( counter ); - size_t name_length = strlen(info.name); - char* cloned_name = (char*)tracy::tracy_malloc(name_length); - memcpy(cloned_name, info.name, name_length); + size_t name_length = strlen( info.name ); + char* cloned_name = (char*)tracy::tracy_malloc( name_length ); + memcpy( cloned_name, info.name, name_length ); { - auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuAnnotationName); - tracy::MemWrite(&item->gpuAnnotationNameFat.context, data->context_id); - tracy::MemWrite(&item->gpuAnnotationNameFat.noteId, counter.handle); - tracy::MemWrite(&item->gpuAnnotationNameFat.ptr, (uint64_t)cloned_name); - tracy::MemWrite(&item->gpuAnnotationNameFat.size, name_length); - tracy::Profiler::QueueSerialFinish(); + auto* item = tracy::Profiler::QueueSerial(); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuAnnotationName ); + tracy::MemWrite( &item->gpuAnnotationNameFat.context, data->context_id ); + tracy::MemWrite( &item->gpuAnnotationNameFat.noteId, counter.handle ); + tracy::MemWrite( &item->gpuAnnotationNameFat.ptr, (uint64_t)cloned_name ); + tracy::MemWrite( &item->gpuAnnotationNameFat.size, name_length ); + tracy::Profiler::QueueSerialFinish(); } } } // Create a colleciton profile for the counters - rocprofiler_profile_config_id_t profile = {.handle = 0}; - ROCPROFILER_CALL(rocprofiler_create_profile_config(dispatch_data.dispatch_info.agent_id, - collect_counters.data(), - collect_counters.size(), - &profile), - "Could not construct profile cfg"); + rocprofiler_profile_config_id_t profile = { .handle = 0 }; + ROCPROFILER_CALL( rocprofiler_create_profile_config( dispatch_data.dispatch_info.agent_id, collect_counters.data(), + collect_counters.size(), &profile ), + "Could not construct profile cfg" ); - profile_cache.emplace(dispatch_data.dispatch_info.agent_id.handle, profile); + profile_cache.emplace( dispatch_data.dispatch_info.agent_id.handle, profile ); // Return the profile to collect those counters for this dispatch *config = profile; } using kernel_symbol_data_t = rocprofiler_callback_tracing_code_object_kernel_symbol_register_data_t; -void -tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, - rocprofiler_user_data_t* user_data, - void* callback_data) +void tool_callback_tracing_callback( rocprofiler_callback_tracing_record_t record, rocprofiler_user_data_t* user_data, + void* callback_data ) { - assert(callback_data != nullptr); - ToolData * data = static_cast(callback_data); - if (!data->init) return; + assert( callback_data != nullptr ); + ToolData* data = static_cast( callback_data ); + if( !data->init ) return; - if(record.kind == ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT && - record.operation == ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER) + if( record.kind == ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT && + record.operation == ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER ) { - auto* sym_data = static_cast(record.payload); + auto* sym_data = static_cast( record.payload ); - if(record.phase == ROCPROFILER_CALLBACK_PHASE_LOAD) + if( record.phase == ROCPROFILER_CALLBACK_PHASE_LOAD ) { - auto _lk = std::unique_lock{data->mut}; - data->client_kernels.emplace(sym_data->kernel_id, *sym_data); + auto _lk = std::unique_lock{ data->mut }; + data->client_kernels.emplace( sym_data->kernel_id, *sym_data ); } - else if(record.phase == ROCPROFILER_CALLBACK_PHASE_UNLOAD) + else if( record.phase == ROCPROFILER_CALLBACK_PHASE_UNLOAD ) { - auto _lk = std::unique_lock{data->mut}; - data->client_kernels.erase(sym_data->kernel_id); + auto _lk = std::unique_lock{ data->mut }; + data->client_kernels.erase( sym_data->kernel_id ); } - } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH) { - auto* rdata = static_cast(record.payload); - if (record.operation == ROCPROFILER_KERNEL_DISPATCH_ENQUEUE) { - if (record.phase == ROCPROFILER_CALLBACK_PHASE_ENTER) { - auto _lk = std::unique_lock{data->mut}; - data->launch_start_times.emplace(rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime()); - } else if (record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT) { - auto _lk = std::unique_lock{data->mut}; - data->launch_end_times.emplace(rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime()); + } + else if( record.kind == ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH ) + { + auto* rdata = static_cast( record.payload ); + if( record.operation == ROCPROFILER_KERNEL_DISPATCH_ENQUEUE ) + { + if( record.phase == ROCPROFILER_CALLBACK_PHASE_ENTER ) + { + auto _lk = std::unique_lock{ data->mut }; + data->launch_start_times.emplace( rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime() ); + } + else if( record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT ) + { + auto _lk = std::unique_lock{ data->mut }; + data->launch_end_times.emplace( rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime() ); } - } else if (record.operation == ROCPROFILER_KERNEL_DISPATCH_COMPLETE) { - uint64_t src_loc = kernel_src_loc(data, rdata->dispatch_info.kernel_id); - record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc, rdata->dispatch_info.dispatch_id); } - } else if (record.kind == ROCPROFILER_CALLBACK_TRACING_MEMORY_COPY && - record.operation != ROCPROFILER_MEMORY_COPY_NONE && - record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT) { - auto* rdata = static_cast(record.payload); - const char * name = nullptr; - switch(record.operation) { + else if( record.operation == ROCPROFILER_KERNEL_DISPATCH_COMPLETE ) + { + uint64_t src_loc = kernel_src_loc( data, rdata->dispatch_info.kernel_id ); + record_interval( data, rdata->start_timestamp, rdata->end_timestamp, src_loc, + rdata->dispatch_info.dispatch_id ); + } + } + else if( record.kind == ROCPROFILER_CALLBACK_TRACING_MEMORY_COPY && + record.operation != ROCPROFILER_MEMORY_COPY_NONE && record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT ) + { + auto* rdata = static_cast( record.payload ); + const char* name = nullptr; + switch( record.operation ) + { case ROCPROFILER_MEMORY_COPY_DEVICE_TO_DEVICE: name = "DeviceToDeviceCopy"; break; @@ -428,57 +438,59 @@ tool_callback_tracing_callback(rocprofiler_callback_tracing_record_t record, name = "HostToHostCopy"; break; } - size_t name_len = strlen(name); - uint64_t src_loc = tracy::Profiler::AllocSourceLocation( - 0, NULL, 0, name, name_len, - NULL, 0); - record_interval(data, rdata->start_timestamp, rdata->end_timestamp, src_loc, UINT64_MAX); + size_t name_len = strlen( name ); + uint64_t src_loc = tracy::Profiler::AllocSourceLocation( 0, NULL, 0, name, name_len, NULL, 0 ); + record_interval( data, rdata->start_timestamp, rdata->end_timestamp, src_loc, UINT64_MAX ); } } -void calibration_thread(void * ptr) { - while (!TracyIsStarted); - ToolData * data = static_cast(ptr); - data->context_id = gpu_context_allocate(data); - const char* user_counters = GetEnvVar("TRACY_ROCPROF_COUNTERS"); - if (user_counters) { - data->counter_names.clear(); - std::stringstream ss(user_counters); - std::string counter; - while (std::getline(ss, counter, ',')) - data->counter_names.insert(counter); +void calibration_thread( void* ptr ) +{ + while( !TracyIsStarted ) + ; + ToolData* data = static_cast( ptr ); + data->context_id = gpu_context_allocate( data ); + const char* user_counters = GetEnvVar( "TRACY_ROCPROF_COUNTERS" ); + if( user_counters ) + { + data->counter_names.clear(); + std::stringstream ss( user_counters ); + std::string counter; + while( std::getline( ss, counter, ',' ) ) data->counter_names.insert( counter ); } data->init = true; #if USE_CALIBRATION - while (data->init) { + 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. - clock_gettime(CLOCK_BOOTTIME, &ts); + 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) { + if( cpu_timestamp > data->previous_cpu_time ) + { auto* item = tracy::Profiler::QueueSerial(); - tracy::MemWrite(&item->hdr.type, tracy::QueueType::GpuCalibration); - tracy::MemWrite(&item->gpuCalibration.gpuTime, gpu_timestamp); - tracy::MemWrite(&item->gpuCalibration.cpuTime, cpu_timestamp); - tracy::MemWrite(&item->gpuCalibration.cpuDelta, cpu_timestamp - data->previous_cpu_time); - tracy::MemWrite(&item->gpuCalibration.context, data->context_id); + tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuCalibration ); + tracy::MemWrite( &item->gpuCalibration.gpuTime, gpu_timestamp ); + tracy::MemWrite( &item->gpuCalibration.cpuTime, cpu_timestamp ); + tracy::MemWrite( &item->gpuCalibration.cpuDelta, cpu_timestamp - data->previous_cpu_time ); + tracy::MemWrite( &item->gpuCalibration.context, data->context_id ); tracy::Profiler::QueueSerialFinish(); data->previous_cpu_time = cpu_timestamp; } - sleep(1); + sleep( 1 ); } #endif } int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) { - ToolData * data = static_cast(user_data); - data->cal_thread = std::make_unique(calibration_thread, data); + ToolData* data = static_cast( user_data ); + data->cal_thread = std::make_unique( calibration_thread, data ); ROCPROFILER_CALL( rocprofiler_create_context( &get_client_ctx() ), "context creation failed" ); @@ -486,44 +498,33 @@ int tool_init( rocprofiler_client_finalize_t fini_func, void* user_data ) user_data, record_callback, user_data ), "Could not setup counting service" ); - rocprofiler_tracing_operation_t ops[] = {ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER}; - ROCPROFILER_CALL( - rocprofiler_configure_callback_tracing_service(get_client_ctx(), - ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT, - ops, - 1, - tool_callback_tracing_callback, - user_data), - "callback tracing service failed to configure"); + rocprofiler_tracing_operation_t ops[] = { ROCPROFILER_CODE_OBJECT_DEVICE_KERNEL_SYMBOL_REGISTER }; + ROCPROFILER_CALL( rocprofiler_configure_callback_tracing_service( get_client_ctx(), + ROCPROFILER_CALLBACK_TRACING_CODE_OBJECT, ops, 1, + tool_callback_tracing_callback, user_data ), + "callback tracing service failed to configure" ); - rocprofiler_tracing_operation_t ops2[] = {ROCPROFILER_KERNEL_DISPATCH_COMPLETE, ROCPROFILER_KERNEL_DISPATCH_ENQUEUE}; + rocprofiler_tracing_operation_t ops2[] = { ROCPROFILER_KERNEL_DISPATCH_COMPLETE, + ROCPROFILER_KERNEL_DISPATCH_ENQUEUE }; ROCPROFILER_CALL( - rocprofiler_configure_callback_tracing_service(get_client_ctx(), - ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH, - ops2, - 2, - 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, - nullptr, - 0, - tool_callback_tracing_callback, - user_data), - "callback tracing service failed to configure"); + rocprofiler_configure_callback_tracing_service( get_client_ctx(), ROCPROFILER_CALLBACK_TRACING_KERNEL_DISPATCH, + ops2, 2, 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, nullptr, + 0, tool_callback_tracing_callback, user_data ), + "callback tracing service failed to configure" ); ROCPROFILER_CALL( rocprofiler_start_context( get_client_ctx() ), "start context" ); return 0; } -void tool_fini( void* tool_data_v ) { - rocprofiler_stop_context(get_client_ctx()); +void tool_fini( void* tool_data_v ) +{ + rocprofiler_stop_context( get_client_ctx() ); - ToolData * data = static_cast(tool_data_v); + ToolData* data = static_cast( tool_data_v ); data->init = false; data->cal_thread.reset(); } diff --git a/public/common/TracyQueue.hpp b/public/common/TracyQueue.hpp index c8644053..44b31921 100644 --- a/public/common/TracyQueue.hpp +++ b/public/common/TracyQueue.hpp @@ -450,10 +450,10 @@ struct QueueGpuZoneEnd struct QueueGpuZoneAnnotation { - int64_t noteId; - double value; - uint16_t queryId; - uint8_t context; + int64_t noteId; + double value; + uint16_t queryId; + uint8_t context; }; struct QueueGpuTime @@ -491,14 +491,14 @@ struct QueueGpuContextNameFat : public QueueGpuContextName struct QueueGpuAnnotationName { - int64_t noteId; - uint8_t context; + int64_t noteId; + uint8_t context; }; struct QueueGpuAnnotationNameFat : public QueueGpuAnnotationName { - uint64_t ptr; - uint16_t size; + uint64_t ptr; + uint16_t size; }; struct QueueMemNamePayload diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index d438383d..c8809120 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -1107,12 +1107,12 @@ Worker::Worker( FileRead& f, EventType::Type eventMask, bool bgTasks, bool allow f.Read7( ctx->thread, calibration, ctx->count, ctx->period, ctx->type, ctx->name, ctx->overflow ); uint64_t notesz; f.Read( notesz ); - for ( uint64_t i=0; inotes)::key_type key; - decltype(ctx->notes)::mapped_type value; - f.Read2( key, value ); - ctx->notes[key] = value; + decltype( ctx->notes )::key_type key; + decltype( ctx->notes )::mapped_type value; + f.Read2( key, value ); + ctx->notes[key] = value; } ctx->hasCalibration = calibration; ctx->hasPeriod = ctx->period != 1.f; @@ -6042,15 +6042,16 @@ 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() ); - auto & timeline = ctx->threadData.begin()->second.timeline; + auto& timeline = ctx->threadData.begin()->second.timeline; assert( timeline.size() ); ssize_t i = timeline.size() - 1; - for ( ; i >= 0 ; i--) { - if( timeline[i]->query_id == ev.queryId ) { - break; - } + for( ; i >= 0; i-- ) + { + if( timeline[i]->query_id == ev.queryId ) + { + break; + } } auto& zone = timeline[i]; assert( zone->note_count < 10 ); @@ -7834,10 +7835,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); + f.Read( zone->query_id ); + f.Read( zone->note_count ); + f.Read( zone->note_ids ); + f.Read( zone->note_vals ); } while( ++zone != end ); } @@ -8179,8 +8180,8 @@ void Worker::Write( FileWrite& f, bool fiDict ) f.Write( &sz, sizeof( sz ) ); for( auto& p : ctx->notes ) { - f.Write( &p.first, sizeof( p.first ) ); - f.Write( &p.second, sizeof( p.second ) ); + f.Write( &p.first, sizeof( p.first ) ); + f.Write( &p.second, sizeof( p.second ) ); } sz = ctx->threadData.size(); f.Write( &sz, sizeof( sz ) ); @@ -8568,10 +8569,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) ); + 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 ) ); } } From 6a5e4d8a6079231b6ef7072112c7b86ed7fb015f Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 9 Jul 2025 12:36:36 -0700 Subject: [PATCH 13/21] Use assert intead of a condition --- public/client/TracyRocprof.cpp | 12 ++++-------- 1 file changed, 4 insertions(+), 8 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 13bb7009..adbf30dc 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -247,14 +247,10 @@ void record_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data 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" ); - } + // An assumption is made here that the counter values are supplied after the dispatch + // complete callback. + assert( data->dispatch_query_id.count( dispatch_data.dispatch_info.dispatch_id ) ); + query_id = data->dispatch_query_id[dispatch_data.dispatch_info.dispatch_id]; } for( auto& p : sums ) From 3fce5c1280cda365789706833b3bbb8587cbcbd6 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 9 Jul 2025 23:08:58 -0700 Subject: [PATCH 14/21] Use a map to record counter values This removes the limitation of 10 counters. --- profiler/src/profiler/TracyView_ZoneInfo.cpp | 18 +++++------ public/client/TracyRocprof.cpp | 2 -- server/TracyEvent.hpp | 4 +-- server/TracyWorker.cpp | 32 ++++++++++++++------ 4 files changed, 31 insertions(+), 25 deletions(-) diff --git a/profiler/src/profiler/TracyView_ZoneInfo.cpp b/profiler/src/profiler/TracyView_ZoneInfo.cpp index 3ea2d4fd..adae1f94 100644 --- a/profiler/src/profiler/TracyView_ZoneInfo.cpp +++ b/profiler/src/profiler/TracyView_ZoneInfo.cpp @@ -1580,16 +1580,15 @@ void View::DrawGpuInfoWindow() } TextFocused( "Query ID:", RealToString( ev.query_id ) ); - for( int i = 0; i < ev.note_count; i++ ) + for( auto& p : ev.notes ) { - auto id = ev.note_ids[i]; - if( ctx->notes.count( id ) ) + if( ctx->notes.count( p.first ) ) { - TextFocused( m_worker.GetString( ctx->notes.at( id ) ), RealToString( ev.note_vals[i] ) ); + TextFocused( m_worker.GetString( ctx->notes.at( p.first ) ), RealToString( p.second ) ); } else { - TextFocused( RealToString( ev.note_ids[i] ), RealToString( ev.note_vals[i] ) ); + TextFocused( RealToString( p.first ), RealToString( p.second ) ); } } @@ -2061,16 +2060,15 @@ void View::ZoneTooltip( const GpuEvent& ev ) } TextFocused( "Query ID:", RealToString( ev.query_id ) ); - for( int i = 0; i < ev.note_count; i++ ) + for( auto& p : ev.notes ) { - auto id = ev.note_ids[i]; - if( ctx->notes.count( id ) ) + if( ctx->notes.count( p.first ) ) { - TextFocused( m_worker.GetString( ctx->notes.at( id ) ), RealToString( ev.note_vals[i] ) ); + TextFocused( m_worker.GetString( ctx->notes.at( p.first ) ), RealToString( p.second ) ); } else { - TextFocused( RealToString( ev.note_ids[i] ), RealToString( ev.note_vals[i] ) ); + TextFocused( RealToString( p.first ), RealToString( p.second ) ); } } diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index adbf30dc..d38b3bba 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -366,8 +366,6 @@ void dispatch_callback( rocprofiler_dispatch_counting_service_data_t dispatch_da *config = profile; } -using kernel_symbol_data_t = rocprofiler_callback_tracing_code_object_kernel_symbol_register_data_t; - void tool_callback_tracing_callback( rocprofiler_callback_tracing_record_t record, rocprofiler_user_data_t* user_data, void* callback_data ) { diff --git a/server/TracyEvent.hpp b/server/TracyEvent.hpp index 630124c0..6a323c42 100644 --- a/server/TracyEvent.hpp +++ b/server/TracyEvent.hpp @@ -413,9 +413,7 @@ struct GpuEvent uint64_t _gpuEnd_child2; Int24 callstack; uint16_t query_id; - int64_t note_ids[10]; - double note_vals[10]; - uint8_t note_count; + unordered_flat_map notes; }; enum { GpuEventSize = sizeof( GpuEvent ) }; diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index c8809120..7cb98f9a 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -5774,6 +5774,10 @@ void Worker::ProcessGpuZoneBeginImplCommon( GpuEvent* zone, const QueueGpuZoneBe zone->callstack.SetVal( 0 ); zone->SetChild( -1 ); zone->query_id = ev.queryId; + // tracy allocates slab memory without invoking the constructor + new( &zone->notes ) unordered_flat_map(); + // reserve space for all the counters we've been given a name for + zone->notes.reserve( ctx->notes.size() ); uint64_t ztid; if( ctx->thread == 0 ) @@ -6054,10 +6058,7 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) } } auto& zone = timeline[i]; - assert( zone->note_count < 10 ); - zone->note_ids[zone->note_count] = ev.noteId; - zone->note_vals[zone->note_count] = ev.value; - zone->note_count++; + zone->notes.insert_or_assign( ev.noteId, ev.value ); } MemEvent* Worker::ProcessMemAllocImpl( MemData& memdata, const QueueMemAlloc& ev ) @@ -7836,9 +7837,17 @@ void Worker::ReadTimeline( FileRead& f, Vector>& _vec, uint6 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 ); + uint64_t note_count; + f.Read( note_count ); + new( &zone->notes ) unordered_flat_map(); + zone->notes.reserve( note_count ); + for( uint64_t i = 0; i < note_count; i++ ) + { + int64_t id; + double value; + f.Read2( id, value ); + zone->notes[id] = value; + } } while( ++zone != end ); } @@ -8570,9 +8579,12 @@ 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 ) ); + uint64_t note_count = v.notes.size(); + f.Write( ¬e_count, sizeof( note_count ) ); + for ( auto& p : v.notes ) { + f.Write( &p.first, sizeof( p.first ) ); + f.Write( &p.second, sizeof( p.second ) ); + } } } From d4a35c5ab139071f6bc9f62fdfa2e46fe91ec62d Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Thu, 10 Jul 2025 14:29:23 -0700 Subject: [PATCH 15/21] Change rocprof context name --- profiler/src/profiler/TracyView.hpp | 3 ++- public/client/TracyRocprof.cpp | 2 +- public/common/TracyQueue.hpp | 3 ++- 3 files changed, 5 insertions(+), 3 deletions(-) diff --git a/profiler/src/profiler/TracyView.hpp b/profiler/src/profiler/TracyView.hpp index 95cc31ac..96e8e7ed 100644 --- a/profiler/src/profiler/TracyView.hpp +++ b/profiler/src/profiler/TracyView.hpp @@ -41,7 +41,8 @@ constexpr const char* GpuContextNames[] = { "Direct3D 11", "Metal", "Custom", - "CUDA" + "CUDA", + "Rocprof" }; struct MemoryPage; diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index d38b3bba..086b7aa4 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -102,7 +102,7 @@ uint8_t gpu_context_allocate( ToolData* data ) tracy::MemWrite( &item->gpuNewContext.period, timestamp_period ); tracy::MemWrite( &item->gpuNewContext.context, context_id ); tracy::MemWrite( &item->gpuNewContext.flags, context_flags ); - tracy::MemWrite( &item->gpuNewContext.type, tracy::GpuContextType::Vulkan ); + tracy::MemWrite( &item->gpuNewContext.type, tracy::GpuContextType::Rocprof ); tracy::Profiler::QueueSerialFinish(); } diff --git a/public/common/TracyQueue.hpp b/public/common/TracyQueue.hpp index 44b31921..8243f6d4 100644 --- a/public/common/TracyQueue.hpp +++ b/public/common/TracyQueue.hpp @@ -408,7 +408,8 @@ enum class GpuContextType : uint8_t Direct3D11, Metal, Custom, - CUDA + CUDA, + Rocprof }; enum GpuContextFlags : uint8_t From 3324b46dca53a6e4e6b611d66834a921c58163d1 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Thu, 10 Jul 2025 14:51:19 -0700 Subject: [PATCH 16/21] Make rocprof optional --- CMakeLists.txt | 7 +++++-- public/TracyClient.cpp | 3 +++ 2 files changed, 8 insertions(+), 2 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index ccf68101..679fda6e 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -33,7 +33,7 @@ else() endif() find_package(Threads REQUIRED) -find_package(rocprofiler-sdk REQUIRED PATHS "/opt/rocm/lib/cmake") +find_package(rocprofiler-sdk PATHS "/opt/rocm/lib/cmake") set(TRACY_PUBLIC_DIR ${CMAKE_CURRENT_SOURCE_DIR}/public) @@ -56,8 +56,11 @@ target_link_libraries( PUBLIC Threads::Threads ${CMAKE_DL_LIBS} - rocprofiler-sdk::rocprofiler-sdk ) +if(rocprofiler-sdk_FOUND) + target_compile_definitions(TracyClient PUBLIC TRACY_ROCPROF) + target_link_libraries(TracyClient PUBLIC rocprofiler-sdk::rocprofiler-sdk) +endif() if(TRACY_Fortran) add_library(TracyClientF90 ${TRACY_VISIBILITY} "${TRACY_PUBLIC_DIR}/TracyClient.F90") diff --git a/public/TracyClient.cpp b/public/TracyClient.cpp index 192f36e4..70bca515 100644 --- a/public/TracyClient.cpp +++ b/public/TracyClient.cpp @@ -31,7 +31,10 @@ #include "client/TracyAlloc.cpp" #include "client/TracyOverride.cpp" #include "client/TracyKCore.cpp" + +#ifdef TRACY_ROCPROF #include "client/TracyRocprof.cpp" +#endif #if defined(TRACY_HAS_CALLSTACK) # if TRACY_HAS_CALLSTACK == 2 || TRACY_HAS_CALLSTACK == 3 || TRACY_HAS_CALLSTACK == 4 || TRACY_HAS_CALLSTACK == 6 From 114f6ef09623b6bb638b04bfa0e4b3fd7ba9cae2 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Thu, 10 Jul 2025 17:25:56 -0700 Subject: [PATCH 17/21] Supply the correct thread ID for annotations --- public/client/TracyRocprof.cpp | 38 +++++++++++++++++++++++----------- public/common/TracyQueue.hpp | 1 + server/TracyWorker.cpp | 5 ++--- 3 files changed, 29 insertions(+), 15 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 086b7aa4..84207440 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -35,6 +35,14 @@ namespace using kernel_symbol_data_t = rocprofiler_callback_tracing_code_object_kernel_symbol_register_data_t; +struct DispatchData +{ + int64_t launch_start; + int64_t launch_end; + uint32_t thread_id; + uint16_t query_id; +}; + struct ToolData { uint32_t version; @@ -47,9 +55,7 @@ struct ToolData uint64_t query_id; int64_t previous_cpu_time; std::unordered_map client_kernels; - std::unordered_map launch_start_times; - std::unordered_map launch_end_times; - std::unordered_map dispatch_query_id; + std::unordered_map dispatch_data; std::set counter_names = { "SQ_WAVES", "GL2C_MISS", "GL2C_HIT" }; std::unique_ptr cal_thread; std::mutex mut{}; @@ -152,7 +158,12 @@ void record_interval( ToolData* data, rocprofiler_timestamp_t start_timestamp, r 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; + if( dispatch_id != UINT64_MAX ) + { + DispatchData& dispatch_data = data->dispatch_data[dispatch_id]; + dispatch_data.query_id = query_id; + dispatch_data.thread_id = tracy::GetThreadHandle(); + } } uint64_t cpu_start_time = 0, cpu_end_time = 0; @@ -164,10 +175,9 @@ void record_interval( ToolData* data, rocprofiler_timestamp_t start_timestamp, r else { auto _lk = std::unique_lock{ data->mut }; - cpu_start_time = data->launch_start_times.at( dispatch_id ); - cpu_end_time = data->launch_end_times.at( dispatch_id ); - data->launch_start_times.erase( dispatch_id ); - data->launch_end_times.erase( dispatch_id ); + DispatchData& dispatch_data = data->dispatch_data[dispatch_id]; + cpu_start_time = dispatch_data.launch_start; + cpu_end_time = dispatch_data.launch_end; } if( src_loc != 0 ) @@ -245,12 +255,15 @@ void record_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data } uint16_t query_id = 0; + uint32_t thread_id = 0; { auto _lk = std::unique_lock{ data->mut }; // An assumption is made here that the counter values are supplied after the dispatch // complete callback. - assert( data->dispatch_query_id.count( dispatch_data.dispatch_info.dispatch_id ) ); - query_id = data->dispatch_query_id[dispatch_data.dispatch_info.dispatch_id]; + assert( data->dispatch_data.count( dispatch_data.dispatch_info.dispatch_id ) ); + DispatchData& ddata = data->dispatch_data[dispatch_data.dispatch_info.dispatch_id]; + query_id = ddata.query_id; + thread_id = ddata.thread_id; } for( auto& p : sums ) @@ -259,6 +272,7 @@ void record_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuZoneAnnotation ); tracy::MemWrite( &item->zoneAnnotation.noteId, p.first ); tracy::MemWrite( &item->zoneAnnotation.queryId, query_id ); + tracy::MemWrite( &item->zoneAnnotation.thread, thread_id ); tracy::MemWrite( &item->zoneAnnotation.value, p.second ); tracy::MemWrite( &item->zoneAnnotation.context, data->context_id ); tracy::Profiler::QueueSerialFinish(); @@ -397,12 +411,12 @@ void tool_callback_tracing_callback( rocprofiler_callback_tracing_record_t recor if( record.phase == ROCPROFILER_CALLBACK_PHASE_ENTER ) { auto _lk = std::unique_lock{ data->mut }; - data->launch_start_times.emplace( rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime() ); + data->dispatch_data[rdata->dispatch_info.dispatch_id].launch_start = tracy::Profiler::GetTime(); } else if( record.phase == ROCPROFILER_CALLBACK_PHASE_EXIT ) { auto _lk = std::unique_lock{ data->mut }; - data->launch_end_times.emplace( rdata->dispatch_info.dispatch_id, tracy::Profiler::GetTime() ); + data->dispatch_data[rdata->dispatch_info.dispatch_id].launch_end = tracy::Profiler::GetTime(); } } else if( record.operation == ROCPROFILER_KERNEL_DISPATCH_COMPLETE ) diff --git a/public/common/TracyQueue.hpp b/public/common/TracyQueue.hpp index 8243f6d4..765c83c7 100644 --- a/public/common/TracyQueue.hpp +++ b/public/common/TracyQueue.hpp @@ -453,6 +453,7 @@ struct QueueGpuZoneAnnotation { int64_t noteId; double value; + uint32_t thread; uint16_t queryId; uint8_t context; }; diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index 7cb98f9a..c5e336dc 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -6045,9 +6045,8 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) { auto ctx = m_gpuCtxMap[ev.context]; assert( ctx ); - // TODO: Get thread ID properly - assert( ctx->threadData.size() ); - auto& timeline = ctx->threadData.begin()->second.timeline; + assert( ctx->threadData.contains( ev.thread ) ); + auto& timeline = ctx->threadData.at( ev.thread ).timeline; assert( timeline.size() ); ssize_t i = timeline.size() - 1; for( ; i >= 0; i-- ) From 0c77bfcbed3dbc5289e37df39f1f9d0aa009b6a4 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Fri, 11 Jul 2025 16:57:16 -0700 Subject: [PATCH 18/21] Use tracy data structures --- public/client/TracyRocprof.cpp | 13 ++++++------- 1 file changed, 6 insertions(+), 7 deletions(-) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 84207440..7d58d405 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -1,3 +1,4 @@ +#include "../server/tracy_robin_hood.h" #include "TracyProfiler.hpp" #include "TracyThread.hpp" #include "tracy/TracyC.h" @@ -51,12 +52,11 @@ struct ToolData rocprofiler_client_id_t client_id; uint8_t context_id; bool init; - uint64_t src_loc; uint64_t query_id; int64_t previous_cpu_time; - std::unordered_map client_kernels; - std::unordered_map dispatch_data; - std::set counter_names = { "SQ_WAVES", "GL2C_MISS", "GL2C_HIT" }; + tracy::unordered_map client_kernels; + tracy::unordered_map dispatch_data; + tracy::unordered_set counter_names = { "SQ_WAVES", "GL2C_MISS", "GL2C_HIT" }; std::unique_ptr cal_thread; std::mutex mut{}; }; @@ -282,8 +282,7 @@ void record_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data /** * Callback from rocprofiler when an kernel dispatch is enqueued into the HSA queue. * rocprofiler_counter_config_id_t* is a return to specify what counters to collect - * for this dispatch (dispatch_packet). This example function creates a profile - * to collect the counter SQ_WAVES for all kernel dispatch packets. + * for this dispatch (dispatch_packet). */ void dispatch_callback( rocprofiler_dispatch_counting_service_data_t dispatch_data, rocprofiler_profile_config_id_t* config, rocprofiler_user_data_t* /*user_data*/, @@ -342,6 +341,7 @@ void dispatch_callback( rocprofiler_dispatch_counting_service_data_t dispatch_da "Could not fetch supported counters" ); std::vector collect_counters; + collect_counters.reserve( data->counter_names.size() ); // Look for the counters contained in counters_to_collect in gpu_counters for( auto& counter : gpu_counters ) { @@ -351,7 +351,6 @@ void dispatch_callback( rocprofiler_dispatch_counting_service_data_t dispatch_da "Could not query info" ); if( data->counter_names.count( std::string( info.name ) ) > 0 ) { - std::clog << "Counter: " << counter.handle << " " << info.name << "\n"; collect_counters.push_back( counter ); size_t name_length = strlen( info.name ); From 21a34c5a386306d9f090375571dd518d177a90ca Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Mon, 14 Jul 2025 12:58:47 -0700 Subject: [PATCH 19/21] Fix windows build error --- server/TracyWorker.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index c5e336dc..f2c9c8d9 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -6048,7 +6048,7 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) assert( ctx->threadData.contains( ev.thread ) ); auto& timeline = ctx->threadData.at( ev.thread ).timeline; assert( timeline.size() ); - ssize_t i = timeline.size() - 1; + uint64_t i = timeline.size() - 1; for( ; i >= 0; i-- ) { if( timeline[i]->query_id == ev.queryId ) From 9caa91f06f02dfe8e11991c8f1609b6c866c6354 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Wed, 16 Jul 2025 16:02:54 -0700 Subject: [PATCH 20/21] Move the annotations data to the GPU context --- profiler/src/profiler/TracyView_ZoneInfo.cpp | 34 ++++---- server/TracyEvent.hpp | 4 +- server/TracyWorker.cpp | 81 +++++++++++--------- 3 files changed, 65 insertions(+), 54 deletions(-) diff --git a/profiler/src/profiler/TracyView_ZoneInfo.cpp b/profiler/src/profiler/TracyView_ZoneInfo.cpp index adae1f94..6d3b9d12 100644 --- a/profiler/src/profiler/TracyView_ZoneInfo.cpp +++ b/profiler/src/profiler/TracyView_ZoneInfo.cpp @@ -1580,15 +1580,18 @@ void View::DrawGpuInfoWindow() } TextFocused( "Query ID:", RealToString( ev.query_id ) ); - for( auto& p : ev.notes ) + if( ctx->notes.contains( ev.query_id ) ) { - if( ctx->notes.count( p.first ) ) + for( auto& p : ctx->notes.at( ev.query_id ) ) { - TextFocused( m_worker.GetString( ctx->notes.at( p.first ) ), RealToString( p.second ) ); - } - else - { - TextFocused( RealToString( p.first ), RealToString( p.second ) ); + if( ctx->noteNames.count( p.first ) ) + { + TextFocused( m_worker.GetString( ctx->noteNames.at( p.first ) ), RealToString( p.second ) ); + } + else + { + TextFocused( RealToString( p.first ), RealToString( p.second ) ); + } } } @@ -2060,15 +2063,18 @@ void View::ZoneTooltip( const GpuEvent& ev ) } TextFocused( "Query ID:", RealToString( ev.query_id ) ); - for( auto& p : ev.notes ) + if( ctx->notes.contains( ev.query_id ) ) { - if( ctx->notes.count( p.first ) ) + for( auto& p : ctx->notes.at( ev.query_id ) ) { - TextFocused( m_worker.GetString( ctx->notes.at( p.first ) ), RealToString( p.second ) ); - } - else - { - TextFocused( RealToString( p.first ), RealToString( p.second ) ); + if( ctx->noteNames.count( p.first ) ) + { + TextFocused( m_worker.GetString( ctx->noteNames.at( p.first ) ), RealToString( p.second ) ); + } + else + { + TextFocused( RealToString( p.first ), RealToString( p.second ) ); + } } } diff --git a/server/TracyEvent.hpp b/server/TracyEvent.hpp index 6a323c42..b2276dee 100644 --- a/server/TracyEvent.hpp +++ b/server/TracyEvent.hpp @@ -413,7 +413,6 @@ struct GpuEvent uint64_t _gpuEnd_child2; Int24 callstack; uint16_t query_id; - unordered_flat_map notes; }; enum { GpuEventSize = sizeof( GpuEvent ) }; @@ -776,7 +775,8 @@ struct GpuCtxData uint32_t overflowMul; StringIdx name; unordered_flat_map threadData; - unordered_flat_map notes; + unordered_flat_map noteNames; + unordered_flat_map> notes; short_ptr query[64*1024]; }; diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index f2c9c8d9..bb5cef45 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -1109,10 +1109,10 @@ Worker::Worker( FileRead& f, EventType::Type eventMask, bool bgTasks, bool allow f.Read( notesz ); for( uint64_t i = 0; i < notesz; i++ ) { - decltype( ctx->notes )::key_type key; - decltype( ctx->notes )::mapped_type value; + decltype( ctx->noteNames )::key_type key; + decltype( ctx->noteNames )::mapped_type value; f.Read2( key, value ); - ctx->notes[key] = value; + ctx->noteNames[key] = value; } ctx->hasCalibration = calibration; ctx->hasPeriod = ctx->period != 1.f; @@ -1131,6 +1131,26 @@ Worker::Worker( FileRead& f, EventType::Type eventMask, bool bgTasks, bool allow ReadTimeline( f, td->second.timeline, tsz, refTime, refGpuTime, childIdx ); } } + + f.Read( notesz ); + ctx->notes.reserve( notesz ); + for( uint64_t i = 0; i < notesz; i++ ) + { + uint16_t query_id; + f.Read( query_id ); + auto& notes = ctx->notes[query_id]; + uint64_t note_count; + f.Read( note_count ); + notes.reserve( note_count ); + for( uint64_t i = 0; i < note_count; i++ ) + { + int64_t id; + double value; + f.Read2( id, value ); + notes[id] = value; + } + } + m_data.gpuData[i] = ctx; } @@ -5774,10 +5794,6 @@ void Worker::ProcessGpuZoneBeginImplCommon( GpuEvent* zone, const QueueGpuZoneBe zone->callstack.SetVal( 0 ); zone->SetChild( -1 ); zone->query_id = ev.queryId; - // tracy allocates slab memory without invoking the constructor - new( &zone->notes ) unordered_flat_map(); - // reserve space for all the counters we've been given a name for - zone->notes.reserve( ctx->notes.size() ); uint64_t ztid; if( ctx->thread == 0 ) @@ -6038,26 +6054,18 @@ void Worker::ProcessGpuAnnotationName( const QueueGpuAnnotationName& ev ) auto ctx = m_gpuCtxMap[ev.context]; assert( ctx ); const auto idx = GetSingleStringIdx(); - ctx->notes[ev.noteId] = StringIdx( idx ); + ctx->noteNames[ev.noteId] = StringIdx( idx ); } void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) { auto ctx = m_gpuCtxMap[ev.context]; assert( ctx ); - assert( ctx->threadData.contains( ev.thread ) ); - auto& timeline = ctx->threadData.at( ev.thread ).timeline; - assert( timeline.size() ); - uint64_t i = timeline.size() - 1; - for( ; i >= 0; i-- ) + if( !ctx->notes.contains( ev.queryId ) ) { - if( timeline[i]->query_id == ev.queryId ) - { - break; - } + ctx->notes[ev.queryId].reserve( ctx->noteNames.size() ); } - auto& zone = timeline[i]; - zone->notes.insert_or_assign( ev.noteId, ev.value ); + ctx->notes.at( ev.queryId )[ev.noteId] = ev.value; } MemEvent* Worker::ProcessMemAllocImpl( MemData& memdata, const QueueMemAlloc& ev ) @@ -7836,17 +7844,6 @@ void Worker::ReadTimeline( FileRead& f, Vector>& _vec, uint6 zone->SetCpuEnd( refTime ); zone->SetGpuEnd( refGpuTime ); f.Read( zone->query_id ); - uint64_t note_count; - f.Read( note_count ); - new( &zone->notes ) unordered_flat_map(); - zone->notes.reserve( note_count ); - for( uint64_t i = 0; i < note_count; i++ ) - { - int64_t id; - double value; - f.Read2( id, value ); - zone->notes[id] = value; - } } while( ++zone != end ); } @@ -8184,9 +8181,9 @@ void Worker::Write( FileWrite& f, bool fiDict ) f.Write( &ctx->type, sizeof( ctx->type ) ); f.Write( &ctx->name, sizeof( ctx->name ) ); f.Write( &ctx->overflow, sizeof( ctx->overflow ) ); - sz = ctx->notes.size(); + sz = ctx->noteNames.size(); f.Write( &sz, sizeof( sz ) ); - for( auto& p : ctx->notes ) + for( auto& p : ctx->noteNames ) { f.Write( &p.first, sizeof( p.first ) ); f.Write( &p.second, sizeof( p.second ) ); @@ -8201,6 +8198,20 @@ void Worker::Write( FileWrite& f, bool fiDict ) f.Write( &tid, sizeof( tid ) ); WriteTimeline( f, td.second.timeline, refTime, refGpuTime ); } + + sz = ctx->notes.size(); + f.Write( &sz, sizeof( sz ) ); + for( auto& notes : ctx->notes ) + { + f.Write( ¬es.first, sizeof( notes.first ) ); + sz = notes.second.size(); + f.Write( &sz, sizeof( sz ) ); + for( auto& note : notes.second ) + { + f.Write( ¬e.first, sizeof( note.first ) ); + f.Write( ¬e.second, sizeof( note.second ) ); + } + } } sz = m_data.plots.Data().size(); @@ -8578,12 +8589,6 @@ 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 ) ); - uint64_t note_count = v.notes.size(); - f.Write( ¬e_count, sizeof( note_count ) ); - for ( auto& p : v.notes ) { - f.Write( &p.first, sizeof( p.first ) ); - f.Write( &p.second, sizeof( p.second ) ); - } } } From 1639598d621229b5d9f05f623e92a60ff84f5174 Mon Sep 17 00:00:00 2001 From: Eric Eaton Date: Mon, 21 Jul 2025 15:30:42 -0700 Subject: [PATCH 21/21] Update documentation This provides some instructions and tips for the manual. Also: * Made the calibration feature a CMake option * Cleaned up some minor code issues * Fixed an issue with the calibration * Incremented patch number --- CMakeLists.txt | 4 +++ manual/tracy.tex | 29 ++++++++++++++++++++ profiler/src/profiler/TracyView_ZoneInfo.cpp | 2 -- public/TracyClient.cpp | 2 +- public/client/TracyRocprof.cpp | 22 ++++++--------- public/common/TracyVersion.hpp | 2 +- server/TracyWorker.cpp | 9 +++--- 7 files changed, 49 insertions(+), 21 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 679fda6e..27dfce14 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -147,6 +147,10 @@ set_option(TRACY_VERBOSE "[advanced] Verbose output from the profiler" OFF) mark_as_advanced(TRACY_VERBOSE) set_option(TRACY_DEMANGLE "[advanced] Don't use default demangling function - You'll need to provide your own" OFF) mark_as_advanced(TRACY_DEMANGLE) +if(rocprofiler-sdk_FOUND) + set_option(TRACY_ROCPROF_CALIBRATION "[advanced] Use continuous calibration of the Rocprof GPU time." OFF) + mark_as_advanced(TRACY_ROCPROF_CALIBRATION) +endif() # handle incompatible combinations if(TRACY_MANUAL_LIFETIME AND NOT TRACY_DELAYED_INIT) diff --git a/manual/tracy.tex b/manual/tracy.tex index 90a9d3e7..5089f9a8 100644 --- a/manual/tracy.tex +++ b/manual/tracy.tex @@ -1706,6 +1706,35 @@ Unlike other GPU backends in Tracy, there is no need to call \texttt{TracyCUDACo To stop profiling, call the \texttt{TracyCUDAStopProfiling(ctx)} macro. +\subsubsection{ROCm} + +On Linux, if rocprofiler-sdk is installed, tracy can automatically trace GPU dispatches and collect +performance counter values. If CMake can't find rocprofiler-sdk, you can set the CMake variable +\texttt{rocprofiler-sdk\_DIR} to point it at the correct module directory. Use the +\texttt{TRACY\_ROCPROF\_COUNTERS} environment variable with the desired counters separated by commas +to control what values are collected. The results will appear for each dispatch in the tool tip and +zone detail window. Results are summed across dimensions. You can get a list of the counters +available for your hardware with this command: +\begin{lstlisting}[language=sh] +rocprofv3 -L +\end{lstlisting} + +\subparagraph{Troubleshooting} +\begin{itemize} +\item If you are taking very long captures, you may see drift between the GPU and + CPU timelines. This may be mitigated by setting the CMake variable + \texttt{TRACY\_ROCPROF\_CALIBRATION}, which will refresh the time synchronization about every + second. +\item The timeline drift may also be affected by network time synchronization, in which case the + drift will be reduced by disabling that, with the advantage that there is no application performance + cost. +\item On some GPUs, you will need to change the the performance level to see non-zero results from + some counters. Use this command: +\begin{lstlisting}[language=sh] +sudo amd-smi set -g 0 -l stable_std +\end{lstlisting} +\end{itemize} + \subsubsection{Multiple zones in one scope} Putting more than one GPU zone macro in a single scope features the same issue as with the \texttt{ZoneScoped} macros, described in section~\ref{multizone} (but this time the variable name is \texttt{\_\_\_tracy\_gpu\_zone}). diff --git a/profiler/src/profiler/TracyView_ZoneInfo.cpp b/profiler/src/profiler/TracyView_ZoneInfo.cpp index 6d3b9d12..14b7b28a 100644 --- a/profiler/src/profiler/TracyView_ZoneInfo.cpp +++ b/profiler/src/profiler/TracyView_ZoneInfo.cpp @@ -1579,7 +1579,6 @@ void View::DrawGpuInfoWindow() TextFocused( "Delay to execution:", TimeToString( AdjustGpuTime( ev.GpuStart(), begin, drift ) - ev.CpuStart() ) ); } - TextFocused( "Query ID:", RealToString( ev.query_id ) ); if( ctx->notes.contains( ev.query_id ) ) { for( auto& p : ctx->notes.at( ev.query_id ) ) @@ -2062,7 +2061,6 @@ 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 ) ); if( ctx->notes.contains( ev.query_id ) ) { for( auto& p : ctx->notes.at( ev.query_id ) ) diff --git a/public/TracyClient.cpp b/public/TracyClient.cpp index 70bca515..e9a01848 100644 --- a/public/TracyClient.cpp +++ b/public/TracyClient.cpp @@ -33,7 +33,7 @@ #include "client/TracyKCore.cpp" #ifdef TRACY_ROCPROF -#include "client/TracyRocprof.cpp" +# include "client/TracyRocprof.cpp" #endif #if defined(TRACY_HAS_CALLSTACK) diff --git a/public/client/TracyRocprof.cpp b/public/client/TracyRocprof.cpp index 7d58d405..370e42ec 100644 --- a/public/client/TracyRocprof.cpp +++ b/public/client/TracyRocprof.cpp @@ -29,8 +29,6 @@ } \ } -#define USE_CALIBRATION 0 - namespace { @@ -78,7 +76,6 @@ 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 = USE_CALIBRATION; float timestamp_period = 1.0f; data->previous_cpu_time = cpu_timestamp; @@ -92,13 +89,12 @@ uint8_t gpu_context_allocate( ToolData* data ) } uint8_t context_flags = 0; - if( is_calibrated ) - { - // Tell tracy we'll be passing calibrated timestamps and not to mess with - // the times. We'll periodically send GpuCalibration events in case the - // times drift. - context_flags |= tracy::GpuContextCalibration; - } +#ifdef TRACY_ROCPROF_CALIBRATION + // Tell tracy we'll be passing calibrated timestamps and not to mess with + // the times. We'll periodically send GpuCalibration events in case the + // times drift. + context_flags |= tracy::GpuContextCalibration; +#endif { auto* item = tracy::Profiler::QueueSerial(); tracy::MemWrite( &item->hdr.type, tracy::QueueType::GpuNewContext ); @@ -467,9 +463,11 @@ void calibration_thread( void* ptr ) } data->init = true; -#if USE_CALIBRATION +#ifdef TRACY_ROCPROF_CALIBRATION while( data->init ) { + sleep( 1 ); + 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. @@ -488,8 +486,6 @@ void calibration_thread( void* ptr ) tracy::Profiler::QueueSerialFinish(); data->previous_cpu_time = cpu_timestamp; } - - sleep( 1 ); } #endif } diff --git a/public/common/TracyVersion.hpp b/public/common/TracyVersion.hpp index 6da3a6f6..7d704c50 100644 --- a/public/common/TracyVersion.hpp +++ b/public/common/TracyVersion.hpp @@ -7,7 +7,7 @@ namespace Version { enum { Major = 0 }; enum { Minor = 12 }; -enum { Patch = 3 }; +enum { Patch = 4 }; } } diff --git a/server/TracyWorker.cpp b/server/TracyWorker.cpp index bb5cef45..88e87cd7 100644 --- a/server/TracyWorker.cpp +++ b/server/TracyWorker.cpp @@ -6061,11 +6061,12 @@ void Worker::ProcessGpuZoneAnnotation( const QueueGpuZoneAnnotation& ev ) { auto ctx = m_gpuCtxMap[ev.context]; assert( ctx ); - if( !ctx->notes.contains( ev.queryId ) ) - { - ctx->notes[ev.queryId].reserve( ctx->noteNames.size() ); + auto note = ctx->notes.find( ev.queryId ); + if( note == ctx->notes.end() ) { + note = ctx->notes.emplace( ev.queryId, decltype(ctx->notes)::mapped_type{} ).first; + note->second.reserve( ctx->noteNames.size() ); } - ctx->notes.at( ev.queryId )[ev.noteId] = ev.value; + note->second[ev.noteId] = ev.value; } MemEvent* Worker::ProcessMemAllocImpl( MemData& memdata, const QueueMemAlloc& ev )