From df20526aac7fe5294a39a446c0fc2a8e17c3b429 Mon Sep 17 00:00:00 2001 From: "Jonathan R. Madsen" Date: Fri, 22 Jul 2022 14:17:27 -0500 Subject: [PATCH] Sampling use SIGRTMIN + N signals (#104) * Use SIGRTMIN instead of SIGALRM for sampling * Config options + fully working SIGRTMIN sampling - OMNITRACE_SAMPLING_KEEP_INTERNAL config option - OMNITRACE_PROCESS_SAMPLING_FREQ config option - OMNITRACE_SAMPLING_REALTIME config option - OMNITRACE_SAMPLING_CPUTIME config option - OMNITRACE_SAMPLING_REALTIME_OFFSET config option * Fix omnitrace-avail-regex-negation test - OMNITRACE_PROCESS_SAMPLING_FREQ was causing failure [ROCm/rocprofiler-systems commit: d27f22ea3746502a260d0cc9012f5ac0a8832ddf] --- .../rocprofiler-systems/external/timemory | 2 +- .../source/bin/tests/CMakeLists.txt | 1 + .../library/components/backtrace.cpp | 82 ++++++++++++------- .../library/components/backtrace.hpp | 1 - .../components/pthread_create_gotcha.cpp | 6 +- .../source/lib/omnitrace/library/config.cpp | 82 +++++++++++++++++-- .../source/lib/omnitrace/library/config.hpp | 16 +++- .../source/lib/omnitrace/library/runtime.cpp | 37 +++++++++ .../source/lib/omnitrace/library/runtime.hpp | 10 +++ .../source/lib/omnitrace/library/sampling.cpp | 6 +- 10 files changed, 198 insertions(+), 45 deletions(-) diff --git a/projects/rocprofiler-systems/external/timemory b/projects/rocprofiler-systems/external/timemory index 768d6cfdd3..2e8cf9f409 160000 --- a/projects/rocprofiler-systems/external/timemory +++ b/projects/rocprofiler-systems/external/timemory @@ -1 +1 @@ -Subproject commit 768d6cfdd33f3bfb503b91f0dda202e7a2da765b +Subproject commit 2e8cf9f40906e1cffc4110ca0ce75ed001c30417 diff --git a/projects/rocprofiler-systems/source/bin/tests/CMakeLists.txt b/projects/rocprofiler-systems/source/bin/tests/CMakeLists.txt index 24555e3348..0a02db0e1c 100644 --- a/projects/rocprofiler-systems/source/bin/tests/CMakeLists.txt +++ b/projects/rocprofiler-systems/source/bin/tests/CMakeLists.txt @@ -252,6 +252,7 @@ omnitrace_add_bin_test( -r _P ~PERFETTO + ~PROCESS_SAMPLING --csv --brief LABELS "omnitrace-avail" diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.cpp index 88371ed1df..a870ae6f64 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.cpp @@ -28,6 +28,7 @@ #include "library/debug.hpp" #include "library/perfetto.hpp" #include "library/ptl.hpp" +#include "library/runtime.hpp" #include "library/sampling.hpp" #include "library/tracing.hpp" @@ -67,6 +68,7 @@ #include #include #include +#include #include #include @@ -117,12 +119,21 @@ using signal_type_instances = thread_data, api::sampling>; using backtrace_init_instances = thread_data; using sampler_running_instances = thread_data; using papi_vector_instances = thread_data; +using papi_label_instances = thread_data, api::sampling>; namespace { struct perfetto_rusage {}; +unique_ptr_t>& +get_papi_labels(int64_t _tid) +{ + static auto& _v = + papi_label_instances::instances(papi_label_instances::construct_on_init{}); + return _v.at(_tid); +} + unique_ptr_t& get_papi_vector(int64_t _tid) { @@ -167,6 +178,8 @@ backtrace::get() const if(strlen(itr) > 0) _v.emplace_back(itr); } std::reverse(_v.begin(), _v.end()); + while(!_v.empty() && _v.back() == "funlockfile") + _v.pop_back(); return _v; } @@ -298,7 +311,7 @@ backtrace::sample(int signum) m_ctx_swch = _cache.get_num_priority_context_switch() + _cache.get_num_voluntary_context_switch(); m_page_flt = _cache.get_num_major_page_faults() + _cache.get_num_minor_page_faults(); - m_data = tim::get_unw_backtrace(); + m_data = tim::get_unw_backtrace(); m_size = m_data.size(); if constexpr(tim::trait::is_available::value) @@ -332,23 +345,32 @@ backtrace::configure(bool _setup, int64_t _tid) { perfetto_counter_track::init(); OMNITRACE_DEBUG("HW COUNTER: starting...\n"); - if(get_papi_vector(_tid)) get_papi_vector(_tid)->start(); + if(get_papi_vector(_tid)) + { + using common_type_t = typename hw_counters::common_type; + get_papi_vector(_tid)->start(); + *get_papi_labels(_tid) = comp::papi_common::get_events(); + } } - auto _alrm_freq = 1.0 / std::min(get_sampling_freq(), 20.0); - auto _prof_freq = 1.0 / get_sampling_freq(); + auto _alrm_freq = std::min(get_sampling_freq(), 20.0); + auto _prof_freq = get_sampling_freq(); auto _delay = std::max(1.0e-3, get_sampling_delay()); + auto _verbose = std::min(get_verbose() - 2, 2); + if(get_debug_sampling()) _verbose = 2; OMNITRACE_DEBUG("Configuring sampler for thread %lu...\n", _tid); sampling::sampler_instances::construct("omnitrace", _tid, *_signal_types); + _sampler->set_signals(*_signal_types); _sampler->set_flags(SA_RESTART); - _sampler->set_delay(_delay); - _sampler->set_verbose(std::min(_sampler->get_verbose(), 2)); - if(_signal_types->count(SIGALRM) > 0) - _sampler->set_frequency(_alrm_freq, { SIGALRM }); - if(_signal_types->count(SIGPROF) > 0) - _sampler->set_frequency(_prof_freq, { SIGPROF }); + _sampler->set_delay(_delay, *_signal_types, (_verbose > 1)); + _sampler->set_verbose(_verbose); + if(_signal_types->count(get_realtime_signal()) > 0) + _sampler->set_frequency(_alrm_freq, { get_realtime_signal() }, + (_verbose > 1)); + if(_signal_types->count(get_cputime_signal()) > 0) + _sampler->set_frequency(_prof_freq, { get_cputime_signal() }, (_verbose > 1)); static_assert(tim::trait::buffer_size::value > 0, "Error! Zero buffer size"); @@ -358,10 +380,15 @@ backtrace::configure(bool _setup, int64_t _tid) "dynamic sampler requires a positive buffer size: %zu", _sampler->get_buffer_size()); - OMNITRACE_DEBUG("Sampler for thread %lu will be triggered %5.1fx per second " - "(every %5.2e seconds)...\n", - _tid, _sampler->get_frequency(units::sec), - _sampler->get_rate(units::sec)); + for(auto itr : *_signal_types) + { + const char* _type = (itr == get_realtime_signal()) ? "wall" : "CPU"; + OMNITRACE_VERBOSE(1, + "[%i] Sampler for thread %lu will be triggered %.1fx per " + "second of %s-time (every %.3f milliseconds)...\n", + itr, _tid, _sampler->get_frequency(units::sec, itr), _type, + _sampler->get_period(units::msec, itr)); + } *_running = true; backtrace_init_instances::construct(); @@ -454,26 +481,28 @@ backtrace::post_process(int64_t _tid) // check whether the call-stack entry should be used. -1 means break, 0 means continue auto _use_label = [](std::string_view _lbl) -> short { // debugging feature - static bool _keep_internal = - tim::get_env("OMNITRACE_SAMPLING_KEEP_INTERNAL", get_debug_sampling()); - const auto _npos = std::string::npos; + bool _keep_internal = get_sampling_keep_internal(); + const auto _npos = std::string::npos; if(_keep_internal) return 1; - if(_lbl.find("omnitrace::common::") != _npos) return -1; - if(_lbl.find("omnitrace_") != _npos) return -1; - if(_lbl.find("roctracer_") != _npos) return -1; - if(_lbl.find("perfetto::") != _npos) return -1; + if(_lbl.find("omnitrace::common::") != _npos) return 0; if(_lbl.find("omnitrace::") != _npos) return 0; if(_lbl.find("tim::") != _npos) return 0; + if(_lbl.find("DYNINST_") != _npos) return 0; + if(_lbl.find("omnitrace_") != _npos) return -1; + if(_lbl.find("rocprofiler_") != _npos) return -1; + if(_lbl.find("roctracer_") != _npos) return -1; + if(_lbl.find("perfetto::") != _npos) return -1; if(_lbl == "funlockfile") return 0; return 1; }; + bool _keep_suffix = tim::get_env("OMNITRACE_SAMPLING_KEEP_DYNINST_SUFFIX", + get_debug_sampling()); + // in the dyninst binary rewrite runtime, instrumented functions are appended with // "_dyninst", i.e. "main" will show up as "main_dyninst" in the backtrace. - auto _patch_label = [](std::string_view _lbl) -> std::string { + auto _patch_label = [_keep_suffix](std::string_view _lbl) -> std::string { // debugging feature - static bool _keep_suffix = tim::get_env( - "OMNITRACE_SAMPLING_KEEP_DYNINST_SUFFIX", get_debug_sampling()); if(_keep_suffix) return std::string{ _lbl }; const std::string _dyninst{ "_dyninst" }; auto _pos = _lbl.find(_dyninst); @@ -481,10 +510,7 @@ backtrace::post_process(int64_t _tid) return std::string{ _lbl }.replace(_pos, _dyninst.length(), ""); }; - using common_type_t = typename hw_counters::common_type; - auto _hw_cnt_labels = (get_papi_vector(_tid)) - ? comp::papi_common::get_events() - : std::vector{}; + auto _hw_cnt_labels = *get_papi_labels(_tid); auto _process_perfetto_counters = [&](const std::vector& _data) { auto _tid_name = JOIN("", '[', _tid, ']'); diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.hpp index ad9175387b..1465919071 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/components/backtrace.hpp @@ -33,7 +33,6 @@ #include #include #include -#include #include #include diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp index e448abb130..40d0c28e6f 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp @@ -295,8 +295,8 @@ pthread_create_gotcha::operator()(pthread_t* thread, const pthread_attr_t* attr, // block the signals in entire process OMNITRACE_DEBUG("blocking signals...\n"); - tim::sampling::block_signals({ SIGALRM, SIGPROF }, - tim::sampling::sigmask_scope::process); + auto _blocked_signals = get_sampling_signals(); + tim::sampling::block_signals(_blocked_signals, tim::sampling::sigmask_scope::process); start_bundle(_bundle); @@ -316,7 +316,7 @@ pthread_create_gotcha::operator()(pthread_t* thread, const pthread_attr_t* attr, // unblock the signals in the entire process OMNITRACE_DEBUG("unblocking signals...\n"); - tim::sampling::unblock_signals({ SIGALRM, SIGPROF }, + tim::sampling::unblock_signals(_blocked_signals, tim::sampling::sigmask_scope::process); OMNITRACE_DEBUG("returning success...\n"); diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/config.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/config.cpp index 3ad1278357..dbd62228df 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/config.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/config.cpp @@ -25,6 +25,7 @@ #include "library/defines.hpp" #include "library/gpu.hpp" #include "library/perfetto.hpp" +#include "library/runtime.hpp" #include #include @@ -40,10 +41,12 @@ #include #include +#include #include #include #include #include +#include #include #include #include @@ -291,10 +294,16 @@ configure_settings(bool _init) OMNITRACE_CONFIG_SETTING( double, "OMNITRACE_SAMPLING_DELAY", - "Number of seconds to wait before the first sampling signal is delivered, " + "Time (in seconds) to wait before the first sampling signal is delivered, " "increasing this value can fix deadlocks during init", 0.5, "sampling", "process_sampling"); + OMNITRACE_CONFIG_SETTING( + double, "OMNITRACE_PROCESS_SAMPLING_FREQ", + "Number of measurements per second when OMNITTRACE_USE_PROCESS_SAMPLING=ON. If " + "set to zero, uses OMNITRACE_SAMPLING_FREQ value", + 0.0, "process_sampling"); + OMNITRACE_CONFIG_SETTING( std::string, "OMNITRACE_SAMPLING_CPUS", "CPUs to collect frequency information for. Values should be separated by commas " @@ -341,6 +350,35 @@ configure_settings(bool _init) "cause deadlocks with ROCm-enabled OpenMPI.", false, "backend", "parallelism", "gotcha"); + OMNITRACE_CONFIG_SETTING(bool, "OMNITRACE_SAMPLING_KEEP_INTERNAL", + "If disabled, omnitrace will attempt to filter out internal " + "routines from the sampling call-stacks", + true, "sampling", "data"); + + OMNITRACE_CONFIG_SETTING( + bool, "OMNITRACE_SAMPLING_REALTIME", + "Enable sampling frequency via a wall-clock timer on child threads. This may " + "result in typically idle child threads consuming an unnecessary large amount of " + "CPU time. The main thread always has this enabled.", + false, "sampling"); + + OMNITRACE_CONFIG_SETTING(bool, "OMNITRACE_SAMPLING_CPUTIME", + "Enable sampling frequency via a timer that measures both " + "CPU time used by the current process, " + "and CPU time expended on behalf of the process by the " + "system. This is recommended.", + true, "timemory", "sampling"); + + auto _sigrt_range = SIGRTMAX - SIGRTMIN; + + OMNITRACE_CONFIG_SETTING( + int, "OMNITRACE_SAMPLING_REALTIME_OFFSET", + std::string{ + "Modify this value only if the target process is also using SIGRTMIN. E.g. " + "the signal used is SIGRTMIN + . Value must be <= " } + + std::to_string(_sigrt_range), + 0, "sampling"); + OMNITRACE_CONFIG_SETTING(bool, "OMNITRACE_FLAT_SAMPLING", "Ignore hierarchy in all statistical sampling entries", _config->get_flat_profile(), "timemory", "sampling", @@ -443,6 +481,7 @@ configure_settings(bool _init) OMNITRACE_CONFIG_SETTING(std::string, "OMNITRACE_OUTPUT_FILE", "[DEPRECATED] See OMNITRACE_PERFETTO_FILE", std::string{}, "perfetto", "io", "filename", "deprecated"); + OMNITRACE_CONFIG_SETTING(std::string, "OMNITRACE_PERFETTO_FILE", "Perfetto filename", std::string{ "perfetto-trace.proto" }, "perfetto", "io", "filename"); @@ -694,7 +733,7 @@ configure_signal_handler() using sys_signal = tim::sys_signal; tim::disable_signal_detection(); auto _exit_action = [](int nsig) { - tim::sampling::block_signals({ SIGPROF, SIGALRM }, + tim::sampling::block_signals(get_sampling_signals(), tim::sampling::sigmask_scope::process); OMNITRACE_BASIC_PRINT( "Finalizing afer signal %i :: %s\n", nsig, @@ -1314,6 +1353,34 @@ get_critical_trace_serialize_names() return static_cast&>(*_v->second).get(); } +bool +get_sampling_keep_internal() +{ + static auto _v = get_config()->find("OMNITRACE_SAMPLING_KEEP_INTERNAL"); + return static_cast&>(*_v->second).get(); +} + +bool +get_use_sampling_realtime() +{ + static auto _v = get_config()->find("OMNITRACE_SAMPLING_REALTIME"); + return static_cast&>(*_v->second).get(); +} + +bool +get_use_sampling_cputime() +{ + static auto _v = get_config()->find("OMNITRACE_SAMPLING_CPUTIME"); + return static_cast&>(*_v->second).get(); +} + +int +get_sampling_rtoffset() +{ + static auto _v = get_config()->find("OMNITRACE_SAMPLING_REALTIME_OFFSET"); + return static_cast&>(*_v->second).get(); +} + bool get_timeline_sampling() { @@ -1475,7 +1542,7 @@ get_instrumentation_interval() return static_cast&>(*_v->second).get(); } -double& +double get_sampling_freq() { static auto _v = get_config()->find("OMNITRACE_SAMPLING_FREQ"); @@ -1503,11 +1570,14 @@ get_critical_trace_count() return static_cast&>(*_v->second).get(); } -double& +double get_process_sampling_freq() { - static auto _v = std::min(get_sampling_freq(), 1000.0); - return _v; + static auto _v = get_config()->find("OMNITRACE_PROCESS_SAMPLING_FREQ"); + auto _val = + std::min(static_cast&>(*_v->second).get(), 1000.0); + if(_val < 1.0e-9) return get_sampling_freq(); + return _val; } std::string diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/config.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/config.hpp index 9389533c6f..3b0d2bbe20 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/config.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/config.hpp @@ -204,6 +204,18 @@ get_use_ompt(); bool get_use_code_coverage(); +bool +get_sampling_keep_internal(); + +bool +get_use_sampling_realtime(); + +bool +get_use_sampling_cputime(); + +int +get_sampling_rtoffset(); + bool get_timeline_sampling(); @@ -265,7 +277,7 @@ get_critical_trace_count(); size_t& get_instrumentation_interval(); -double& +double get_sampling_freq(); double& @@ -274,7 +286,7 @@ get_sampling_delay(); std::string get_sampling_cpus(); -double& +double get_process_sampling_freq(); std::string diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.cpp index 0b20a71078..0fec09cdf8 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.cpp @@ -51,6 +51,43 @@ namespace omnitrace { +int +get_realtime_signal() +{ + return SIGRTMIN + config::get_sampling_rtoffset(); +} + +int +get_cputime_signal() +{ + return SIGPROF; +} + +std::set +get_sampling_signals(int64_t _tid) +{ + auto _sigreal = get_realtime_signal(); + auto _sigprof = get_cputime_signal(); + + // on the main thread, typically use both real-time and cpu-time + // on secondary threads, typically use only cpu-time. + + if(_tid < 1) + { + if(config::get_use_sampling_cputime()) return std::set{ _sigreal, _sigprof }; + return std::set{ _sigreal }; + } + + if(config::get_use_sampling_realtime() && config::get_use_sampling_cputime()) + return std::set{ _sigreal, _sigprof }; + else if(config::get_use_sampling_realtime()) + return std::set{ _sigreal }; + else if(config::get_use_sampling_cputime()) + return std::set{ _sigprof }; + + return std::set{}; +} + std::atomic& get_cpu_cid() { diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.hpp index 91a8b310da..7af71c2400 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/runtime.hpp @@ -34,6 +34,7 @@ #include "library/timemory.hpp" #include +#include #include #include @@ -67,6 +68,15 @@ get_main_bundle(); std::unique_ptr& get_gotcha_bundle(); +int +get_realtime_signal(); + +int +get_cputime_signal(); + +std::set +get_sampling_signals(int64_t _tid = 0); + std::atomic& get_cpu_cid() TIMEMORY_HOT; diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/sampling.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/sampling.cpp index 0a4b5d6d12..6a31a6cca8 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/sampling.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/sampling.cpp @@ -25,6 +25,7 @@ #include "library/config.hpp" #include "library/debug.hpp" #include "library/ptl.hpp" +#include "library/runtime.hpp" #include #include @@ -124,10 +125,7 @@ unique_ptr_t>& get_signal_types(int64_t _tid) { static auto& _v = signal_type_instances::instances(); - // on the main thread, use both SIGALRM and SIGPROF. - // on secondary threads, only use SIGPROF. - signal_type_instances::construct((_tid == 0) ? std::set{ SIGALRM, SIGPROF } - : std::set{ SIGPROF }); + signal_type_instances::construct(omnitrace::get_sampling_signals(_tid)); return _v.at(_tid); }