From 77703ef4f1ca7ff24b87c706d01446209d26a28a Mon Sep 17 00:00:00 2001 From: "Jonathan R. Madsen" Date: Thu, 21 Apr 2022 22:59:50 -0500 Subject: [PATCH] Miscellaneous fixes (#44) * Miscellaneous fixes - handle HSA OnLoad called during omnitrace-avail - disable setting HSA_ENABLE_INTERRUPT when roctracer not used - sampler max verbose - fix roctracer get_clock_skew - cleanup roctracer debug output - update timemory submodule with fence - simplify min-instructions vs. min-address-range specification - exclude cxx regex updates - disable HSA_TOOLS_LIB and HSA_ENABLE_INTERRUPT when no roctracer * git safe.directory --- .../workflows/ubuntu-focal-external-rocm.yml | 1 + .github/workflows/ubuntu-focal-external.yml | 1 + external/timemory | 2 +- source/bin/omnitrace-avail/avail.cpp | 1 + source/bin/omnitrace/fwd.hpp | 1 + source/bin/omnitrace/omnitrace.cpp | 72 +++++++++++++- source/lib/omnitrace-dl/dl.cpp | 8 +- .../lib/omnitrace/include/library/config.hpp | 3 + .../lib/omnitrace/include/library/debug.hpp | 54 +++++++---- .../omnitrace/include/library/thread_data.hpp | 8 ++ source/lib/omnitrace/src/library.cpp | 8 ++ .../src/library/components/backtrace.cpp | 1 + .../components/roctracer_callbacks.cpp | 95 +++++++++++++------ source/lib/omnitrace/src/library/config.cpp | 21 ++++ 14 files changed, 221 insertions(+), 55 deletions(-) diff --git a/.github/workflows/ubuntu-focal-external-rocm.yml b/.github/workflows/ubuntu-focal-external-rocm.yml index 3b1b73555f..47f1f5380b 100644 --- a/.github/workflows/ubuntu-focal-external-rocm.yml +++ b/.github/workflows/ubuntu-focal-external-rocm.yml @@ -50,6 +50,7 @@ jobs: - name: Configure CMake timeout-minutes: 5 run: + git config --global --add safe.directory ${PWD} && cmake --version && cmake -B build -DCMAKE_C_COMPILER=${CC} diff --git a/.github/workflows/ubuntu-focal-external.yml b/.github/workflows/ubuntu-focal-external.yml index 6a59dd656b..39cd3ee347 100644 --- a/.github/workflows/ubuntu-focal-external.yml +++ b/.github/workflows/ubuntu-focal-external.yml @@ -44,6 +44,7 @@ jobs: - name: Configure CMake timeout-minutes: 5 run: + git config --global --add safe.directory ${PWD} && cmake --version && cmake -B build -DCMAKE_C_COMPILER=$(echo '${{ matrix.compiler }}' | sed 's/+/c/g') diff --git a/external/timemory b/external/timemory index 8be4a75c71..3dbe0d4d74 160000 --- a/external/timemory +++ b/external/timemory @@ -1 +1 @@ -Subproject commit 8be4a75c714a0866e01591436160caa82fb51cae +Subproject commit 3dbe0d4d746f923330df9d506ab51e72ab5d38a5 diff --git a/source/bin/omnitrace-avail/avail.cpp b/source/bin/omnitrace-avail/avail.cpp index 72d559ab24..2d5c1478a4 100644 --- a/source/bin/omnitrace-avail/avail.cpp +++ b/source/bin/omnitrace-avail/avail.cpp @@ -345,6 +345,7 @@ struct component_categories int main(int argc, char** argv) { + tim::set_env("OMNITRACE_INIT_TOOLING", "OFF", 1); omnitrace_init_library(); std::set _category_options = component_categories{}(); diff --git a/source/bin/omnitrace/fwd.hpp b/source/bin/omnitrace/fwd.hpp index d67b2cb079..533d0ff032 100644 --- a/source/bin/omnitrace/fwd.hpp +++ b/source/bin/omnitrace/fwd.hpp @@ -148,6 +148,7 @@ extern bool instr_loop_traps; extern size_t min_address_range; extern size_t min_loop_address_range; extern size_t min_instructions; +extern size_t min_loop_instructions; // // debug settings // diff --git a/source/bin/omnitrace/omnitrace.cpp b/source/bin/omnitrace/omnitrace.cpp index 603e4c742d..c6ed6c2340 100644 --- a/source/bin/omnitrace/omnitrace.cpp +++ b/source/bin/omnitrace/omnitrace.cpp @@ -49,6 +49,7 @@ bool instr_loop_traps = false; size_t min_address_range = (1 << 8); // 256 size_t min_loop_address_range = (1 << 8); // 256 size_t min_instructions = (1 << 6); // 64 +size_t min_loop_instructions = (1 << 6); // 64 bool werror = false; bool debug_print = false; bool instr_print = false; @@ -597,16 +598,23 @@ main(int argc, char** argv) "value, exclude it from instrumentation") .count(1) .dtype("int") - .set_default(min_instructions) .action( [](parser_t& p) { min_instructions = p.get("min-instructions"); }); + parser + .add_argument({ "--min-instructions-loop" }, + "If the number of instructions in a function containing a loop is " + "less than this value, exclude it from instrumentation") + .count(1) + .dtype("int") + .action([](parser_t& p) { + min_loop_instructions = p.get("min-instructions-loop"); + }); parser .add_argument({ "-r", "--min-address-range" }, "If the address range of a function is less than this value, " "exclude it from instrumentation") .count(1) .dtype("int") - .set_default(min_address_range) .action( [](parser_t& p) { min_address_range = p.get("min-address-range"); }); parser @@ -615,7 +623,6 @@ main(int argc, char** argv) "this value, exclude it from instrumentation") .count(1) .dtype("int") - .set_default(min_loop_address_range) .action([](parser_t& p) { min_loop_address_range = p.get("min-address-range-loop"); }); @@ -696,6 +703,56 @@ main(int argc, char** argv) return -1; } + auto _handle_heuristics = [&parser](std::string&& _exists, std::string&& _not_exists, + auto& _field, auto _value, std::string&& _msg, + bool _cond) { + // if first is specified but second is not, to reduce verbosity of command-line + // and increase simplicity, set _field to specified value + if(parser.exists(_exists) && !parser.exists(_not_exists) && _cond) + { + verbprintf(3, + "Option '--%s' specified but '--%s ' was not specified. " + "Setting %s to %s...\n", + _exists.c_str(), _not_exists.c_str(), _msg.c_str(), + TIMEMORY_JOIN("", _value).c_str()); + _field = _value; + } + }; + + // if instructions was specified and address range was not + _handle_heuristics("min-instructions", "min-address-range", min_address_range, 0, + "minimum address range", true); + _handle_heuristics("min-instructions-loop", "min-address-range-loop", + min_loop_address_range, 0, "minimum address range for loops", + true); + + // if address range was specified but instructions was not + _handle_heuristics("min-address-range", "min-instructions", min_instructions, 0, + "minimum instructions", true); + _handle_heuristics("min-address-range-loop", "min-instructions-loop", + min_loop_instructions, 0, "minimum instructions for loops", true); + + // if non-loop value was specified but loop value was not + _handle_heuristics("min-instructions", "min-instructions-loop", min_loop_instructions, + min_instructions, "minimum instructions for loops", true); + _handle_heuristics("min-address-range", "min-address-range-loop", + min_loop_address_range, min_address_range, + "minimum address range for loops", true); + + // if non-loop instructions was specified and loop address range was not specified + // as long as non-loop address range and loop instructions were not specified + _handle_heuristics("min-instructions", "min-address-range-loop", + min_loop_address_range, 0, "minimum address range for loops", + !parser.exists("min-address-range") && + !parser.exists("min-instructions-loop")); + + // if non-loop address range was specified and loop instructions was not specified + // as long as non-loop instructions and loop address range were not specified + _handle_heuristics("min-address-range", "min-instructions-loop", + min_loop_instructions, 0, "minimum instructions for loops", + !parser.exists("min-instructions") && + !parser.exists("min-address-range-loop")); + if(binary_rewrite && outfile.empty()) { auto _is_local = (get_realpath(cmdv0) == @@ -857,7 +914,9 @@ main(int argc, char** argv) // for runtime instrumentation, we need to set this before the process gets created if(!binary_rewrite) { +#if defined(OMNITRACE_USE_ROCTRACER) tim::set_env("HSA_ENABLE_INTERRUPT", "0", 0); +#endif if(_pid >= 0) { verbprintf(-10, "#-------------------------------------------------------" @@ -1394,8 +1453,10 @@ main(int argc, char** argv) // prioritize the user environment arguments auto env_vars = parser.get("env"); env_vars.emplace_back(TIMEMORY_JOIN('=', "OMNITRACE_MODE", instr_mode)); +#if defined(OMNITRACE_USE_ROCTRACER) env_vars.emplace_back(TIMEMORY_JOIN('=', "HSA_ENABLE_INTERRUPT", "0")); env_vars.emplace_back(TIMEMORY_JOIN('=', "HSA_TOOLS_LIB", _libname)); +#endif env_vars.emplace_back(TIMEMORY_JOIN('=', "OMNITRACE_MPI_INIT", "OFF")); env_vars.emplace_back(TIMEMORY_JOIN('=', "OMNITRACE_MPI_FINALIZE", "OFF")); env_vars.emplace_back( @@ -1459,7 +1520,7 @@ main(int argc, char** argv) // //----------------------------------------------------------------------------------// - if(instr_mode == "trace") + if(instr_mode != "sampling") { for(const auto& itr : available_module_functions) { @@ -1959,7 +2020,8 @@ instrument_entity(const string_t& function_name) "(omnitrace|tim::|N3tim|MPI_Init|MPI_Finalize|dyninst|tm_clones)", regex_opts); static std::regex exclude_cxx( "(std::_Sp_counted_base|std::(use|has)_facet|std::locale|::sentry|^std::_|::_(M|" - "S)_|::basic_string[a-zA-Z,<>: ]+::_M_create)", + "S)_|::basic_string[a-zA-Z,<>: ]+::_M_create|::__|::_(Alloc|State)|" + "std::(basic_|)(ifstream|ios|istream|ostream|stream))", regex_opts); static std::regex leading("^(_|\\.|frame_dummy|transaction clone|virtual " "thunk|non-virtual thunk|\\(|targ|kmp_threadprivate_)", diff --git a/source/lib/omnitrace-dl/dl.cpp b/source/lib/omnitrace-dl/dl.cpp index c92c45e499..1d60fdc749 100644 --- a/source/lib/omnitrace-dl/dl.cpp +++ b/source/lib/omnitrace-dl/dl.cpp @@ -129,10 +129,10 @@ struct OMNITRACE_HIDDEN_API indirect fprintf(stderr, "[omnitrace][dl][pid=%i] libomnitrace.so resolved to '%s'\n", getpid(), m_omnilib.c_str()); } - auto _omni_hsa_lib = m_omnilib; - const char* _hsa_lib = getenv("HSA_TOOLS_LIB"); - if(_hsa_lib) _omni_hsa_lib.append(":").append(_hsa_lib); - setenv("HSA_TOOLS_LIB", _omni_hsa_lib.c_str(), 1); +#if defined(OMNITRACE_USE_ROCTRACER) && OMNITRACE_USE_ROCTRACER > 0 + auto _omni_hsa_lib = m_omnilib; + setenv("HSA_TOOLS_LIB", _omni_hsa_lib.c_str(), 0); +#endif m_omnihandle = open(m_omnilib); m_userhandle = open(m_userlib); init(); diff --git a/source/lib/omnitrace/include/library/config.hpp b/source/lib/omnitrace/include/library/config.hpp index 11b4ad63f9..913ad9ebb7 100644 --- a/source/lib/omnitrace/include/library/config.hpp +++ b/source/lib/omnitrace/include/library/config.hpp @@ -42,6 +42,9 @@ namespace omnitrace // inline namespace config { +bool +settings_are_configured(); + void configure_settings(bool _init = true); diff --git a/source/lib/omnitrace/include/library/debug.hpp b/source/lib/omnitrace/include/library/debug.hpp index e64e8155b3..bb7a25ada3 100644 --- a/source/lib/omnitrace/include/library/debug.hpp +++ b/source/lib/omnitrace/include/library/debug.hpp @@ -45,6 +45,12 @@ get_debug(); int get_verbose(); +bool +get_debug_env(); + +int +get_verbose_env(); + bool get_is_continuous_integration(); @@ -77,14 +83,24 @@ get_chars(T&& _c, std::index_sequence) #define OMNITRACE_LINESTR TIMEMORY_STRINGIZE(__LINE__) #define OMNITRACE_VARIABLE(LABEL) OMNITRACE_VAR_NAME_COMBINE(_omni_var_, LABEL) -#if defined(TIMEMORY_USE_MPI) -# define OMNITRACE_PROCESS_IDENTIFIER static_cast(::tim::dmp::rank()) -#elif defined(TIMEMORY_USE_MPI_HEADERS) -# define OMNITRACE_PROCESS_IDENTIFIER \ - (::tim::dmp::is_initialized()) ? static_cast(::tim::dmp::rank()) \ - : static_cast(::tim::process::get_id()) -#else -# define OMNITRACE_PROCESS_IDENTIFIER static_cast(::tim::process::get_id()) +#if !defined(OMNITRACE_DEBUG_BUFFER_LEN) +# define OMNITRACE_DEBUG_BUFFER_LEN 2048 +#endif + +#if !defined(OMNITRACE_PROCESS_IDENTIFIER) +# if defined(TIMEMORY_USE_MPI) +# define OMNITRACE_PROCESS_IDENTIFIER static_cast(::tim::dmp::rank()) +# elif defined(TIMEMORY_USE_MPI_HEADERS) +# define OMNITRACE_PROCESS_IDENTIFIER \ + (::tim::dmp::is_initialized()) ? static_cast(::tim::dmp::rank()) \ + : static_cast(::tim::process::get_id()) +# else +# define OMNITRACE_PROCESS_IDENTIFIER static_cast(::tim::process::get_id()) +# endif +#endif + +#if !defined(OMNITRACE_THREAD_IDENTIFIER) +# define OMNITRACE_THREAD_IDENTIFIER ::tim::threading::get_id() #endif #if defined(__clang__) || (__GNUC__ < 9) @@ -120,7 +136,7 @@ get_chars(T&& _c, std::index_sequence) fflush(stderr); \ tim::auto_lock_t _lk{ tim::type_mutex() }; \ fprintf(stderr, "[omnitrace][%i][%li] ", OMNITRACE_PROCESS_IDENTIFIER, \ - tim::threading::get_id()); \ + OMNITRACE_THREAD_IDENTIFIER); \ fprintf(stderr, __VA_ARGS__); \ fflush(stderr); \ } @@ -143,7 +159,7 @@ get_chars(T&& _c, std::index_sequence) fflush(stderr); \ tim::auto_lock_t _lk{ tim::type_mutex() }; \ fprintf(stderr, "[omnitrace][%i][%li][%s] ", OMNITRACE_PROCESS_IDENTIFIER, \ - tim::threading::get_id(), OMNITRACE_FUNCTION); \ + OMNITRACE_THREAD_IDENTIFIER, OMNITRACE_FUNCTION); \ fprintf(stderr, __VA_ARGS__); \ fflush(stderr); \ } @@ -162,22 +178,23 @@ get_chars(T&& _c, std::index_sequence) #define OMNITRACE_CONDITIONAL_THROW(COND, ...) \ if(COND) \ { \ - char _msg_buffer[2048]; \ - snprintf(_msg_buffer, 2048, "[omnitrace][%i][%li][%s] ", \ - OMNITRACE_PROCESS_IDENTIFIER, tim::threading::get_id(), \ + char _msg_buffer[OMNITRACE_DEBUG_BUFFER_LEN]; \ + snprintf(_msg_buffer, OMNITRACE_DEBUG_BUFFER_LEN, "[omnitrace][%i][%li][%s] ", \ + OMNITRACE_PROCESS_IDENTIFIER, OMNITRACE_THREAD_IDENTIFIER, \ OMNITRACE_FUNCTION); \ auto len = strlen(_msg_buffer); \ - snprintf(_msg_buffer + len, 2048 - len, __VA_ARGS__); \ + snprintf(_msg_buffer + len, OMNITRACE_DEBUG_BUFFER_LEN - len, __VA_ARGS__); \ throw std::runtime_error(_msg_buffer); \ } #define OMNITRACE_CONDITIONAL_BASIC_THROW(COND, ...) \ if(COND) \ { \ - char _msg_buffer[2048]; \ - snprintf(_msg_buffer, 2048, "[omnitrace][%s] ", OMNITRACE_FUNCTION); \ + char _msg_buffer[OMNITRACE_DEBUG_BUFFER_LEN]; \ + snprintf(_msg_buffer, OMNITRACE_DEBUG_BUFFER_LEN, "[omnitrace][%s] ", \ + OMNITRACE_FUNCTION); \ auto len = strlen(_msg_buffer); \ - snprintf(_msg_buffer + len, 2048 - len, __VA_ARGS__); \ + snprintf(_msg_buffer + len, OMNITRACE_DEBUG_BUFFER_LEN - len, __VA_ARGS__); \ throw std::runtime_error(_msg_buffer); \ } @@ -247,7 +264,8 @@ get_chars(T&& _c, std::index_sequence) #define OMNITRACE_BASIC_PRINT(...) OMNITRACE_CONDITIONAL_BASIC_PRINT(true, __VA_ARGS__) -#define OMNITRACE_BASIC_PRINT_F(...) OMNITRACE_CONDITIONAL_BASIC_PRINT(true, __VA_ARGS__) +#define OMNITRACE_BASIC_PRINT_F(...) \ + OMNITRACE_CONDITIONAL_BASIC_PRINT_F(true, __VA_ARGS__) //--------------------------------------------------------------------------------------// // diff --git a/source/lib/omnitrace/include/library/thread_data.hpp b/source/lib/omnitrace/include/library/thread_data.hpp index 954a6e93c1..d0c7833bff 100644 --- a/source/lib/omnitrace/include/library/thread_data.hpp +++ b/source/lib/omnitrace/include/library/thread_data.hpp @@ -53,6 +53,14 @@ struct thread_data static std::unique_ptr& instance(construct_on_init, Args&&...); template static instance_array_t& instances(construct_on_init, Args&&...); + + static constexpr size_t size() { return MaxThreads; } + + decltype(auto) begin() { return instances().begin(); } + decltype(auto) end() { return instances().end(); } + + decltype(auto) begin() const { return instances().begin(); } + decltype(auto) end() const { return instances().end(); } }; template diff --git a/source/lib/omnitrace/src/library.cpp b/source/lib/omnitrace/src/library.cpp index 2e6b8b668c..7e35cbe7c8 100644 --- a/source/lib/omnitrace/src/library.cpp +++ b/source/lib/omnitrace/src/library.cpp @@ -114,7 +114,9 @@ ensure_finalization(bool _static_init = false) // // see: // https://github.com/ROCm-Developer-Tools/roctracer/issues/22#issuecomment-572814465 +#if defined(OMNITRACE_USE_ROCTRACER) tim::set_env("HSA_ENABLE_INTERRUPT", "0", 0); +#endif } return scope::destructor{ []() { omnitrace_finalize_hidden(); } }; } @@ -502,6 +504,12 @@ omnitrace_init_library_hidden() extern "C" bool omnitrace_init_tooling_hidden() { + if(!tim::get_env("OMNITRACE_INIT_TOOLING", true)) + { + omnitrace_init_library_hidden(); + return false; + } + static bool _once = false; static auto _debug_init = get_debug_init(); diff --git a/source/lib/omnitrace/src/library/components/backtrace.cpp b/source/lib/omnitrace/src/library/components/backtrace.cpp index c045f461c6..e552248d11 100644 --- a/source/lib/omnitrace/src/library/components/backtrace.cpp +++ b/source/lib/omnitrace/src/library/components/backtrace.cpp @@ -345,6 +345,7 @@ backtrace::configure(bool _setup, int64_t _tid) _sampler->set_signals(*_signal_types); _sampler->set_flags(SA_RESTART); _sampler->set_delay(_delay); + _sampler->set_verbose(std::min(_sampler->get_verbose(), 1)); _sampler->set_frequency(_prof_freq, { SIGPROF }); _sampler->set_frequency(_alrm_freq, { SIGALRM }); diff --git a/source/lib/omnitrace/src/library/components/roctracer_callbacks.cpp b/source/lib/omnitrace/src/library/components/roctracer_callbacks.cpp index 636b8d930a..4d8c9a1fb6 100644 --- a/source/lib/omnitrace/src/library/components/roctracer_callbacks.cpp +++ b/source/lib/omnitrace/src/library/components/roctracer_callbacks.cpp @@ -28,8 +28,10 @@ #include "library/sampling.hpp" #include "library/thread_data.hpp" +#include #include +#include #include #include @@ -48,30 +50,60 @@ namespace api = tim::api; int64_t get_clock_skew() { - static auto _v = []() { + static auto _use = tim::get_env("OMNITRACE_USE_ROCTRACER_CLOCK_SKEW", true); + static auto _v = []() { + namespace cpu = tim::cpu; // synchronize timestamps // We'll take a CPU timestamp before and after taking a GPU timestmp, then // take the average of those two, hoping that it's roughly at the same time // as the GPU timestamp. - auto _now = []() { - return std::chrono::duration_cast( - std::chrono::steady_clock::now().time_since_epoch()) - .count(); + static auto _cpu_now = []() { + cpu::fence(); + return comp::wall_clock::record(); }; - uint64_t _cpu_ts = _now(); - uint64_t _gpu_ts; - roctracer_get_timestamp(&_gpu_ts); - _cpu_ts += _now(); - _cpu_ts /= 2; - // assume CPU timestamp is greater than GPU - OMNITRACE_BASIC_VERBOSE_F(2, "CPU timestamp: %lu\n", _cpu_ts); - OMNITRACE_BASIC_VERBOSE_F(2, "HIP timestamp: %lu\n", _gpu_ts); - auto _diff = static_cast(_cpu_ts) - static_cast(_gpu_ts); - OMNITRACE_BASIC_VERBOSE_F(2, "CPU/HIP timestamp skew: %li\n", _diff); + static auto _gpu_now = []() { + cpu::fence(); + uint64_t _v = 0; + ROCTRACER_CALL(roctracer_get_timestamp(&_v)); + return _v; + }; + + do + { + // warm up cache and allow for any static initialization + (void) _cpu_now(); + (void) _gpu_now(); + } while(false); + + auto _compute = [](volatile uint64_t& _cpu_ts, volatile uint64_t& _gpu_ts) { + _cpu_ts = 0; + _gpu_ts = 0; + _cpu_ts += _cpu_now() / 2; + _gpu_ts += _gpu_now() / 1; + _cpu_ts += _cpu_now() / 2; + return static_cast(_cpu_ts) - static_cast(_gpu_ts); + }; + constexpr int64_t _n = 10; + int64_t _cpu_ave = 0; + int64_t _gpu_ave = 0; + int64_t _diff = 0; + for(int64_t i = 0; i < _n; ++i) + { + volatile uint64_t _cpu_ts = 0; + volatile uint64_t _gpu_ts = 0; + _diff += _compute(_cpu_ts, _gpu_ts); + _cpu_ave += _cpu_ts / _n; + _gpu_ave += _gpu_ts / _n; + } + OMNITRACE_BASIC_VERBOSE(1, "CPU timestamp: %li\n", _cpu_ave); + OMNITRACE_BASIC_VERBOSE(1, "HIP timestamp: %li\n", _gpu_ave); + OMNITRACE_BASIC_VERBOSE(0, "CPU/HIP timestamp skew: %li (used: %s)\n", _diff, + _use ? "yes" : "no"); + _diff /= _n; return _diff; }(); - return _v; + return (_use) ? _v : 0; } std::unordered_set& @@ -141,9 +173,10 @@ hsa_api_callback(uint32_t domain, uint32_t cid, const void* callback_data, void* (void) arg; const hsa_api_data_t* data = reinterpret_cast(callback_data); - OMNITRACE_DEBUG("<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", - roctracer_op_string(domain, cid, 0), cid, data->correlation_id, - (data->phase == ACTIVITY_API_PHASE_ENTER) ? "on-enter" : "on-exit"); + OMNITRACE_CONDITIONAL_PRINT_F( + get_debug() && get_verbose() > 1, "<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", + roctracer_op_string(domain, cid, 0), cid, data->correlation_id, + (data->phase == ACTIVITY_API_PHASE_ENTER) ? "on-enter" : "on-exit"); static thread_local int64_t begin_timestamp = 0; static auto _scope = []() { @@ -246,6 +279,8 @@ hsa_activity_callback(uint32_t op, activity_record_t* record, void* arg) if(get_state() != State::Active || !trait::runtime_enabled::get()) return; + sampling::block_signals(); + static const char* copy_op_name = "hsa_async_copy"; static const char* dispatch_op_name = "hsa_dispatch"; static const char* barrier_op_name = "hsa_barrier"; @@ -321,8 +356,6 @@ hip_api_callback(uint32_t domain, uint32_t cid, const void* callback_data, void* if(get_state() != State::Active || !trait::runtime_enabled::get()) return; - (void) get_clock_skew(); - using Device = critical_trace::Device; using Phase = critical_trace::Phase; @@ -347,9 +380,10 @@ hip_api_callback(uint32_t domain, uint32_t cid, const void* callback_data, void* } const hip_api_data_t* data = reinterpret_cast(callback_data); - OMNITRACE_DEBUG("<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", op_name, cid, - data->correlation_id, - (data->phase == ACTIVITY_API_PHASE_ENTER) ? "on-enter" : "on-exit"); + OMNITRACE_CONDITIONAL_PRINT_F( + get_debug() && get_verbose() > 1, "<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", + op_name, cid, data->correlation_id, + (data->phase == ACTIVITY_API_PHASE_ENTER) ? "on-enter" : "on-exit"); int64_t _ts = comp::wall_clock::record(); auto _tid = threading::get_id(); @@ -579,8 +613,8 @@ hip_activity_callback(const char* begin, const char* end, void*) { static size_t _n = 0; - OMNITRACE_VERBOSE_F( - 2, + OMNITRACE_CONDITIONAL_PRINT_F( + get_debug() && get_verbose() > 1, "%4zu :: %-20s :: %-20s :: correlation_id(%6lu) time_ns(%12lu:%12lu) " "delta_ns(%12lu) device_id(%d) stream_id(%lu) proc_id(%u) thr_id(%lu)\n", _n++, op_name, _name, record->correlation_id, _beg_ns, _end_ns, @@ -604,6 +638,8 @@ hip_activity_callback(const char* begin, const char* end, void*) record->correlation_id, "device", record->device_id, "queue", record->queue_id, "op", _op_id_names.at(record->op)); TRACE_EVENT_END("device", _end_ns); + // for some reason, this is necessary to make sure very last one ends + TRACE_EVENT_END("device", _end_ns); } auto _func = [_critical_trace, _depth, _tid, _cid, _laps, _beg_ns, _end_ns, @@ -687,13 +723,16 @@ extern "C" bool OnLoad(HsaApiTable* table, uint64_t runtime_version, uint64_t failed_tool_count, const char* const* failed_tool_names) { + if(!tim::get_env("OMNITRACE_INIT_TOOLING", true)) return true; + pthread_gotcha::push_enable_sampling_on_child_threads(false); OMNITRACE_CONDITIONAL_BASIC_PRINT_F(get_debug_env() || get_verbose_env() > 0, "\n"); tim::consume_parameters(table, runtime_version, failed_tool_count, failed_tool_names); - if(get_state() < State::Active) omnitrace_init_tooling_hidden(); + if(!config::settings_are_configured() && get_state() < State::Active) + omnitrace_init_tooling_hidden(); auto _setup = [=]() { try @@ -775,6 +814,8 @@ extern "C" roctracer_disable_op_activity(ACTIVITY_DOMAIN_HSA_OPS, HSA_OP_ID_COPY)); }; + (void) get_clock_skew(); + comp::roctracer::add_setup("hsa", std::move(_setup)); comp::roctracer::add_shutdown("hsa", std::move(_shutdown)); diff --git a/source/lib/omnitrace/src/library/config.cpp b/source/lib/omnitrace/src/library/config.cpp index d927484d1c..27b8102430 100644 --- a/source/lib/omnitrace/src/library/config.cpp +++ b/source/lib/omnitrace/src/library/config.cpp @@ -84,9 +84,30 @@ get_setting_name(std::string _v) inline namespace config { +namespace +{ +TIMEMORY_NOINLINE bool& +_settings_are_configured() +{ + static bool _v = false; + return _v; +} +} // namespace + +bool +settings_are_configured() +{ + volatile bool _v = _settings_are_configured(); + return _v; +} + void configure_settings(bool _init) { + volatile bool _v = _settings_are_configured(); + if(_v) return; + _settings_are_configured() = true; + static bool _once = false; if(_once) return; _once = true;