From 5eb895fc7ddd5e3a46e6c3cdbb56227402a1955b Mon Sep 17 00:00:00 2001 From: "Jonathan R. Madsen" Date: Thu, 9 Feb 2023 09:47:48 -0600 Subject: [PATCH] Causal profiling fixes (#241) - corrections in the calculations for latency and throughput points in `validate-causal-json.py` - `omnitrace-causal` LD_PRELOAD libpthread - ensures omnitrace is always wrapping libpthread.so pthread symbols - minimal experiment delay - always sleep 10 milliseconds before starting experiments - ensures ~10 samples are taken to determine the sampling rate - fixes issue with deadlocks on condition variables - overhaul of `causal::component::blocking_gotcha` and `causal::component::unblocking_gotcha` components - these components enforce the processing/crediting of delays before/after a thread is suspended - these components wrap functions `pthread_cond_wait`, `pthread_cond_signal`, `pthread_mutex_lock`, etc. - Fully implemented correct handling of processing/crediting delays based on return values and arguments - E.g. skip crediting delay if `pthread_mutex_trylock` fail acquiring lock - E.g. `kill`, `sigwait`, etc. check to make sure they are only applied if the PID matches its PID ## Condition Variable Deadlock Fix In parallel applications using condition variables, it was found that the causal profiling was virtually guaranteed to deadlock. Although it was difficult to prove, evidence suggested that this was due to the work that was being done while taking a sample was causing notification to the condition variable to be lost. This was alleviated by the following updates: - Separate out the part of `causal::backtrace::sample(int)` which calculates the sampling rate into small `sample_rate` component - This component is essentially "always on" during sampling - Added bundle of components invoked by `causal_sampler_t` during sampling - Added two function calls to support disabling and re-enabling calls to `causal::backtrace::sample(int)` on a per-thread basis - `causal::sampling::block_backtrace_samples()` - `causal::sampling::unblock_backtrace_samples()` - These two function now surround the wrappee functions of `blocking_gotcha` and `unblocking_gotcha` **This solution was experimentally validated with a Geant4 application which uses a tasking model which makes _numerous_ calls to wait on a condition variables** (it was this application which exposed the bug) * Fix validate-causal-json.py - corrections in the calculations for latency and throughput points * Update timemory submodule - support for thread-local trait::runtime_enabled * omnitrace-causal: LD_PRELOAD pthread library - ensures omnitrace is always wrapping libpthread.so pthread symbols * initial experiment delay - always sleep 10 milliseconds before starting experiments - ensures ~10 samples are taken to determine the sampling rate * sample_rate component + block_backtrace_samples - separate out the part of backtrace::sample which calculates the sampling rate into small sample_rate component - add sample_rate component to causal_bundle_t used by causal_sampler_t - causal::sampling::block_backtrace_samples() disables backtrace samples from being taken on a thread - causal::sampling::unblock_backtrace_samples() enables backtrace samples from being taken on a thread - above two function surround calls to function wrapped by blocking_gotcha and unblocking_gotcha - the work happening in backtrace::sample when within these calls produced deadlocks for condition variables (notifications to condition variables were lost) * blocking/unblocking gotcha updates - overhaul of blocking_gotcha and unblocking_gotcha - added fast_gotcha trait: replace function calls instead of wrapping - when wrappees are called, backtrace samples are suppressed (thread-local) - properly handle kill, sigwait, sigwaitinfo, sigtimedwait - properly handle all instances of applying postblock based on return value * Fix calculation of OMNITRACE_MAX_THREADS * removed unnecessary checks in causal::delay * Updated timemory with internal compiler error fix [ROCm/rocprofiler-systems commit: 7c73d981258cc3a29477756a95c1f90c5f8897dd] --- projects/rocprofiler-systems/CMakeLists.txt | 28 ++- .../cmake/MacroUtilities.cmake | 30 +++ .../rocprofiler-systems/external/timemory | 2 +- .../source/bin/omnitrace-causal/impl.cpp | 5 +- .../library/causal/components/backtrace.cpp | 77 +++---- .../library/causal/components/backtrace.hpp | 8 + .../causal/components/blocking_gotcha.cpp | 217 +++++++++++++----- .../causal/components/blocking_gotcha.hpp | 27 ++- .../causal/components/unblocking_gotcha.cpp | 103 +++++---- .../causal/components/unblocking_gotcha.hpp | 16 +- .../lib/omnitrace/library/causal/data.cpp | 3 + .../lib/omnitrace/library/causal/delay.cpp | 12 - .../lib/omnitrace/library/causal/sampling.cpp | 17 +- .../lib/omnitrace/library/causal/sampling.hpp | 6 + .../tests/validate-causal-json.py | 94 +++++--- 15 files changed, 429 insertions(+), 216 deletions(-) diff --git a/projects/rocprofiler-systems/CMakeLists.txt b/projects/rocprofiler-systems/CMakeLists.txt index 26f16fe07a..21655f902c 100644 --- a/projects/rocprofiler-systems/CMakeLists.txt +++ b/projects/rocprofiler-systems/CMakeLists.txt @@ -233,10 +233,19 @@ endif() include(ProcessorCount) processorcount(OMNITRACE_PROCESSOR_COUNT) -math(EXPR OMNITRACE_THREAD_COUNT "16 * ${OMNITRACE_PROCESSOR_COUNT}") -if(OMNITRACE_THREAD_COUNT LESS 128) + +if(OMNITRACE_PROCESSOR_COUNT LESS 8) set(OMNITRACE_THREAD_COUNT 128) +else() + math(EXPR OMNITRACE_THREAD_COUNT "16 * ${OMNITRACE_PROCESSOR_COUNT}") + compute_pow2_ceil(OMNITRACE_THREAD_COUNT "16 * ${OMNITRACE_PROCESSOR_COUNT}") + + # set the default to 2048 if it could not be calculated + if(OMNITRACE_THREAD_COUNT LESS 2) + set(OMNITRACE_THREAD_COUNT 2048) + endif() endif() + set(OMNITRACE_MAX_THREADS "${OMNITRACE_THREAD_COUNT}" CACHE @@ -247,6 +256,21 @@ omnitrace_add_feature( OMNITRACE_MAX_THREADS "Maximum number of total threads supported in the host application (default: max of 128 or 16 * nproc)" ) + +compute_pow2_ceil(_MAX_THREADS "${OMNITRACE_MAX_THREADS}") + +if(_MAX_THREADS GREATER 0 AND NOT OMNITRACE_MAX_THREADS EQUAL _MAX_THREADS) + omnitrace_message( + FATAL_ERROR + "Error! OMNITRACE_MAX_THREADS must be a power of 2. Recommendation: ${_MAX_THREADS}" + ) +elseif(NOT OMNITRACE_MAX_THREADS EQUAL _MAX_THREADS) + omnitrace_message( + AUTHOR_WARNING + "OMNITRACE_MAX_THREADS (=${OMNITRACE_MAX_THREADS}) must be a power of 2. We were unable to verify it so we are emitting this warning instead. Estimate resulted in: ${_MAX_THREADS}" + ) +endif() + set(OMNITRACE_MAX_UNWIND_DEPTH "64" CACHE diff --git a/projects/rocprofiler-systems/cmake/MacroUtilities.cmake b/projects/rocprofiler-systems/cmake/MacroUtilities.cmake index e24e68478f..df6b0868d9 100644 --- a/projects/rocprofiler-systems/cmake/MacroUtilities.cmake +++ b/projects/rocprofiler-systems/cmake/MacroUtilities.cmake @@ -892,4 +892,34 @@ function(OMNITRACE_INSTALL_TPL _TPL_TARGET _NEW_NAME _BUILD_TREE_DIR _COMPONENT) endfunction() +function(COMPUTE_POW2_CEIL _OUTPUT _VALUE) + find_package(Python3 COMPONENTS Interpreter) + + if(Python3_FOUND) + execute_process( + COMMAND + ${Python3_EXECUTABLE} -c + "VALUE = ${_VALUE}; ispow2 = lambda x: x if (x and (not(x & (x - 1)))) else None; v = list(filter(ispow2, [x for x in range(VALUE, VALUE**2)])); print(v[0])" + RESULT_VARIABLE _POW2_RET + OUTPUT_VARIABLE _POW2_OUT + ERROR_VARIABLE _POW2_ERR + OUTPUT_STRIP_TRAILING_WHITESPACE) + + if(_POW2_RET EQUAL 0) + set(${_OUTPUT} + ${_POW2_OUT} + PARENT_SCOPE) + else() + set(${_OUTPUT} + "-1" + PARENT_SCOPE) + endif() + else() + set(${_OUTPUT} + "-1" + PARENT_SCOPE) + endif() + +endfunction() + cmake_policy(POP) diff --git a/projects/rocprofiler-systems/external/timemory b/projects/rocprofiler-systems/external/timemory index e4b06f9479..d290a33575 160000 --- a/projects/rocprofiler-systems/external/timemory +++ b/projects/rocprofiler-systems/external/timemory @@ -1 +1 @@ -Subproject commit e4b06f94790bf690e30c0c9c0ea26031b149c7f2 +Subproject commit d290a3357568507f60bf0da6f1248893874580bb diff --git a/projects/rocprofiler-systems/source/bin/omnitrace-causal/impl.cpp b/projects/rocprofiler-systems/source/bin/omnitrace-causal/impl.cpp index 66975dfabd..948216c54c 100644 --- a/projects/rocprofiler-systems/source/bin/omnitrace-causal/impl.cpp +++ b/projects/rocprofiler-systems/source/bin/omnitrace-causal/impl.cpp @@ -43,6 +43,7 @@ #include #include #include +#include #include #include #include @@ -340,7 +341,9 @@ prepare_environment_for_run(std::vector& _env) if(launcher.empty()) { update_env(_env, "LD_PRELOAD", - get_realpath(get_internal_libpath("libomnitrace-dl.so")), true); + join(":", LIBPTHREAD_SO, + get_realpath(get_internal_libpath("libomnitrace-dl.so"))), + true); } } diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.cpp index f53bd14453..ef50dd9c5b 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.cpp @@ -70,38 +70,6 @@ get_delay_statistics() static auto& _v = thread_data_t::instance(construct_on_init{}); return _v; } - -auto& -get_in_use() -{ - using thread_data_t = thread_data, category::sampling>; - - static_assert( - use_placement_new_when_generating_unique_ptr::value, - "sampling is_use thread data should use placement new to allocate unique_ptr"); - - static auto& _v = thread_data_t::instance(construct_on_init{}); - return _v; -} - -struct scoped_in_use -{ - scoped_in_use(int64_t _tid = utility::get_thread_index()) - : value{ get_in_use()->at(_tid) } - { - value = true; - } - ~scoped_in_use() { value = false; } - - bool& value; -}; - -auto -is_in_use(int64_t _tid = threading::get_id()) -{ - return get_in_use()->at(_tid); -} - } // namespace void @@ -111,13 +79,26 @@ backtrace::start() // before it is called in sampler or else a deadlock will occur when // the sample interrupts a malloc call (void) get_delay_statistics(); - (void) get_in_use(); } void backtrace::stop() {} +void +sample_rate::sample(int _sig) +{ + if(_sig != get_realtime_signal()) return; + + // update the last sample for backtrace signal(s) even when in use + static thread_local int64_t _last_sample = 0; + + auto _this_sample = tracing::now(); + auto& _period_stat = get_delay_statistics()->at(threading::get_id()); + if(_last_sample > 0) _period_stat += (_this_sample - _last_sample); + _last_sample = _this_sample; +} + void backtrace::sample(int _sig) { @@ -125,16 +106,17 @@ backtrace::sample(int _sig) constexpr int64_t ignore_depth = ::omnitrace::causal::unwind_offset; // update the last sample for backtrace signal(s) even when in use - static thread_local int64_t _last_sample = 0; + static thread_local size_t _protect_flag = 0; - if(is_in_use() || + // sampling_guard _guard{}; + + if((_protect_flag & 1) == 1 || OMNITRACE_UNLIKELY(!trait::runtime_enabled::get())) { - if(_sig == get_realtime_signal()) _last_sample = tracing::now(); return; } - scoped_in_use _in_use{}; + ++_protect_flag; m_index = causal::experiment::get_index(); m_stack = get_unw_signal_frame_stack_raw(); @@ -150,10 +132,8 @@ backtrace::sample(int _sig) } else if(_sig == get_realtime_signal()) { - auto _this_sample = tracing::now(); - auto& _period_stat = get_delay_statistics()->at(threading::get_id()); - if(_last_sample > 0) _period_stat += (_this_sample - _last_sample); - _last_sample = _this_sample; + static thread_local auto _tid = threading::get_id(); + auto& _period_stat = get_delay_statistics()->at(_tid); if(causal::experiment::is_active() && causal::experiment::is_selected(m_stack)) { @@ -173,6 +153,8 @@ backtrace::sample(int _sig) { OMNITRACE_THROW("unhandled signal %i\n", _sig); } + + ++_protect_flag; } template @@ -194,13 +176,10 @@ backtrace::get_period(uint64_t _units) tim::statistics backtrace::get_period_stats() { - scoped_in_use _in_use{}; - auto _data = tim::statistics{}; + auto _data = tim::statistics{}; if(!get_delay_statistics()) return _data; - for(size_t i = 0; i < get_delay_statistics()->size(); ++i) + for(auto itr : *get_delay_statistics()) { - scoped_in_use _thr_in_use{ static_cast(i) }; - const auto& itr = get_delay_statistics()->at(i); if(itr.get_count() > 1) _data += itr; } return _data; @@ -209,11 +188,9 @@ backtrace::get_period_stats() void backtrace::reset_period_stats() { - scoped_in_use _in_use{}; - for(size_t i = 0; i < get_delay_statistics()->size(); ++i) + for(auto& itr : *get_delay_statistics()) { - scoped_in_use _thr_in_use{ static_cast(i) }; - get_delay_statistics()->at(i).reset(); + itr.reset(); } } } // namespace component diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.hpp index 0e1a2d5160..eb85aa21a7 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/backtrace.hpp @@ -45,6 +45,14 @@ namespace causal { namespace component { +struct sample_rate +: tim::component::empty_base +, tim::concepts::component +{ + using value_type = void; + static void sample(int = -1); +}; + struct backtrace : tim::component::empty_base , tim::concepts::component diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.cpp index b96073aa8b..f0e8982a9e 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.cpp @@ -24,18 +24,41 @@ #include "core/config.hpp" #include "core/debug.hpp" #include "core/state.hpp" +#include "library/causal/components/causal_gotcha.hpp" #include "library/causal/delay.hpp" #include "library/causal/experiment.hpp" +#include "library/causal/sampling.hpp" #include "library/runtime.hpp" #include #include +#include +#include #include #include #include #include +#pragma weak pthread_join +#pragma weak pthread_mutex_lock +#pragma weak pthread_spin_lock +#pragma weak pthread_cond_wait +#pragma weak pthread_rwlock_rdlock +#pragma weak pthread_rwlock_wrlock +#pragma weak pthread_tryjoin_np +#pragma weak pthread_timedjoin_np +#pragma weak pthread_cond_timedwait +#pragma weak pthread_rwlock_timedrdlock +#pragma weak pthread_rwlock_timedwrlock +#pragma weak pthread_mutex_trylock +#pragma weak pthread_spin_trylock +#pragma weak pthread_rwlock_trywrlock +#pragma weak sigwait +#pragma weak sigwaitinfo +#pragma weak sigtimedwait +#pragma weak sigsuspend + namespace omnitrace { namespace causal @@ -67,48 +90,48 @@ blocking_gotcha::configure() blocking_gotcha_t::get_initializer() = []() { if(!config::get_use_causal()) return; - blocking_gotcha_t::configure( - comp::gotcha_config<0, int, pthread_mutex_t*>{ "pthread_mutex_lock" }); + // postblock(true) + // - pthread_join + // - pthread_mutex_lock + // - pthread_cond_wait + // - pthread_barrier_wait + // - pthread_rwlock_rdlock + // - pthread_rwlock_wrlock - blocking_gotcha_t::configure( - comp::gotcha_config<1, int, pthread_mutex_t*>{ "pthread_mutex_trylock" }); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 0, pthread_join); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 1, pthread_mutex_lock); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 2, pthread_spin_lock); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 3, pthread_cond_wait); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 4, pthread_rwlock_rdlock); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 5, pthread_rwlock_wrlock); - blocking_gotcha_t::configure( - comp::gotcha_config<2, int, pthread_rwlock_t*>{ "pthread_rwlock_wrlock" }); + // postblock(result == 0) + // - pthread_tryjoin_np + // - pthread_timedjoin_np + // - pthread_cond_timedwait + // - pthread_rwlock_timedrdlock + // - pthread_rwlock_timedwrlock - blocking_gotcha_t::configure( - comp::gotcha_config<3, int, pthread_rwlock_t*>{ "pthread_rwlock_trywrlock" }); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 6, pthread_tryjoin_np); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 7, pthread_timedjoin_np); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 8, pthread_cond_timedwait); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 9, pthread_rwlock_timedrdlock); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 10, pthread_rwlock_timedwrlock); - blocking_gotcha_t::configure( - comp::gotcha_config<4, int, pthread_spinlock_t*>{ "pthread_spin_lock" }); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 11, pthread_mutex_trylock); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 12, pthread_spin_trylock); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 13, pthread_rwlock_trywrlock); - blocking_gotcha_t::configure( - comp::gotcha_config<5, int, pthread_spinlock_t*>{ "pthread_spin_trylock" }); + // postblock(...) + // - sigwait + // - sigwaitinfo + // - sigtimedwait + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 14, sigwait); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 15, sigwaitinfo); + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 16, sigtimedwait); - blocking_gotcha_t::configure( - comp::gotcha_config<6, int, pthread_t, void**>{ "pthread_join" }); - - blocking_gotcha_t::configure( - comp::gotcha_config<7, int, pthread_cond_t*, pthread_mutex_t*>{ - "pthread_cond_wait" }); - - blocking_gotcha_t::configure( - comp::gotcha_config<8, int, pthread_cond_t*, pthread_mutex_t*, - const struct timespec*>{ "pthread_cond_timedwait" }); - - blocking_gotcha_t::configure( - comp::gotcha_config<9, int, const sigset_t*, int*>{ "sigwait" }); - - blocking_gotcha_t::configure( - comp::gotcha_config<10, int, const sigset_t*, int*, siginfo_t*>{ - "sigwaitinfo" }); - - blocking_gotcha_t::configure( - comp::gotcha_config<11, int, const sigset_t*, int*, siginfo_t*, - const struct timespec*>{ "sigtimedwait" }); - - blocking_gotcha_t::configure( - comp::gotcha_config<12, int, const sigset_t*>{ "sigsuspend" }); + // other + TIMEMORY_C_GOTCHA(blocking_gotcha_t, 17, sigsuspend); }; } @@ -118,34 +141,114 @@ blocking_gotcha::shutdown() blocking_gotcha_t::disable(); } -void -blocking_gotcha::start() +template +Ret +blocking_gotcha::operator()(const comp::gotcha_data& _data, Ret (*_func)(Args...), + Args... _args) const noexcept { - if(causal::experiment::is_active() && - get_thread_state() == ::omnitrace::ThreadState::Enabled && delay_value == 0) - delay_value = causal::delay::get_global().load(); + int64_t _delay_value = causal::delay::get_global().load(std::memory_order_relaxed); + + causal::sampling::block_backtrace_samples(); + auto _ret = (*_func)(_args...); + causal::sampling::unblock_backtrace_samples(); + + if(get_thread_state() < ::omnitrace::ThreadState::Internal) + { + if(_data.index <= 5) + causal::delay::postblock(_delay_value); + else if(_ret == 0 && _data.index >= 6 && _data.index <= 13) + causal::delay::postblock(_delay_value); + else + OMNITRACE_FAIL_F("Error! unexpected index %zu ('%s')\n", _data.index, + _data.tool_id.c_str()); + } + + return _ret; } -void -blocking_gotcha::audit(const comp::gotcha_data& _data, audit::outgoing, int _ret) +int +blocking_gotcha::operator()(const comp::gotcha_data&, int (*)(const sigset_t*, int*), + const sigset_t* _set_v, int* _sig) const noexcept { - // if one of the try/timed functions did not succeed, reset the delay value to zero - if(_ret != 0 && _ret != ETIMEDOUT && - std::set{ 1, 3, 5, 8, 11 }.count(_data.index) > 0) - { - delay_value = 0; - } + auto _active = get_thread_state() < ::omnitrace::ThreadState::Internal; + + sigset_t _set = *_set_v; + causal_gotcha::remove_signals(&_set); + siginfo_t _info; + + int64_t _delay_value = (_active) ? causal::delay::get_global().load() : 0; + + auto* _data = blocking_gotcha_t::at(16); + auto f_sigwaitinfo = reinterpret_cast(_data->wrappee); + + causal::sampling::block_backtrace_samples(); + auto _ret = (*f_sigwaitinfo)(&_set, &_info); + causal::sampling::unblock_backtrace_samples(); + + // Woken up by another thread if the call did not fail and this is waking process + if(_active && _ret != -1 && _info.si_pid == process::get_id()) + causal::delay::postblock(_delay_value); + + if(_ret == -1) + return errno; // If there was an error, return the error code + else + *_sig = _ret; // sig is declared as non-null so skip check + + return 0; } -void -blocking_gotcha::stop() +int +blocking_gotcha::operator()(const comp::gotcha_data&, + int (*_func)(const sigset_t*, siginfo_t*), + const sigset_t* _set_v, siginfo_t* _info_v) const noexcept { - if(delay_value > 0 && causal::experiment::is_active() && - get_thread_state() == ::omnitrace::ThreadState::Enabled) - { - causal::delay::postblock(delay_value); - delay_value = 0; - } + auto _active = get_thread_state() < ::omnitrace::ThreadState::Internal; + + sigset_t _set = *_set_v; + causal_gotcha::remove_signals(&_set); + siginfo_t _info; + + int64_t _delay_value = (_active) ? causal::delay::get_global().load() : 0; + + causal::sampling::block_backtrace_samples(); + auto _ret = (*_func)(&_set, &_info); + causal::sampling::unblock_backtrace_samples(); + + // Woken up by another thread if the call did not fail and this is waking process + if(_active && _ret > 0 && _info.si_pid == process::get_id()) + causal::delay::postblock(_delay_value); + + if(_ret > 0 && _info_v) *_info_v = _info; + + return _ret; +} + +int +blocking_gotcha::operator()(const comp::gotcha_data&, + int (*_func)(const sigset_t*, siginfo_t*, + const struct timespec*), + const sigset_t* _set_v, siginfo_t* _info_v, + const struct timespec* _wait_v) const noexcept +{ + auto _active = get_thread_state() < ::omnitrace::ThreadState::Internal; + + sigset_t _set = *_set_v; + causal_gotcha::remove_signals(&_set); + siginfo_t _info; + + int64_t _delay_value = (_active) ? causal::delay::get_global().load() : 0; + + causal::sampling::block_backtrace_samples(); + auto _ret = (*_func)(&_set, &_info, _wait_v); + causal::sampling::unblock_backtrace_samples(); + + // Woken up by another thread if the call did not fail and this is waking process + if(_active && _ret > 0 && _info.si_pid == process::get_id()) + causal::delay::postblock(_delay_value); + + if(_ret > 0 && _info_v) *_info_v = _info; + + return _ret; } } // namespace component } // namespace causal diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.hpp index 543701fe2b..0b590471cb 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/blocking_gotcha.hpp @@ -40,11 +40,9 @@ namespace causal { namespace component { -using timespec_t = struct timespec; -// this is used to wrap pthread_mutex() struct blocking_gotcha : comp::base { - static constexpr size_t gotcha_capacity = 13; + static constexpr size_t gotcha_capacity = 19; OMNITRACE_DEFAULT_OBJECT(blocking_gotcha) @@ -57,20 +55,29 @@ struct blocking_gotcha : comp::base static void configure(); static void shutdown(); - void start(); - void audit(const comp::gotcha_data&, audit::outgoing, int); - void stop(); + template + Ret operator()(const comp::gotcha_data&, Ret (*)(Args...), Args...) const noexcept; -private: - int64_t delay_value = 0; + int operator()(const comp::gotcha_data&, int (*)(const sigset_t*, int*), + const sigset_t*, int*) const noexcept; + + int operator()(const comp::gotcha_data&, int (*)(const sigset_t*, siginfo_t*), + const sigset_t*, siginfo_t*) const noexcept; + + int operator()(const comp::gotcha_data&, + int (*)(const sigset_t*, siginfo_t*, const struct timespec*), + const sigset_t*, siginfo_t*, const struct timespec*) const noexcept; }; using blocking_gotcha_t = - comp::gotcha, category::causal>; + comp::gotcha, blocking_gotcha>; } // namespace component } // namespace causal } // namespace omnitrace OMNITRACE_DEFINE_CONCRETE_TRAIT(prevent_reentry, causal::component::blocking_gotcha_t, false_type) +OMNITRACE_DEFINE_CONCRETE_TRAIT(static_data, causal::component::blocking_gotcha_t, + false_type) +OMNITRACE_DEFINE_CONCRETE_TRAIT(fast_gotcha, causal::component::blocking_gotcha_t, + true_type) diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.cpp index 5e0b7dbed0..437617d6ea 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.cpp @@ -23,18 +23,31 @@ #include "library/causal/components/unblocking_gotcha.hpp" #include "core/config.hpp" #include "core/debug.hpp" +#include "core/state.hpp" +#include "library/causal/components/causal_gotcha.hpp" #include "library/causal/delay.hpp" #include "library/causal/experiment.hpp" +#include "library/causal/sampling.hpp" #include "library/runtime.hpp" #include #include +#include #include #include #include #include +#pragma weak pthread_mutex_unlock +#pragma weak pthread_spin_unlock +#pragma weak pthread_cond_signal +#pragma weak pthread_cond_broadcast +#pragma weak pthread_kill +#pragma weak pthread_sigqueue +#pragma weak pthread_barrier_wait +#pragma weak kill + namespace omnitrace { namespace causal @@ -66,29 +79,15 @@ unblocking_gotcha::configure() unblocking_gotcha_t::get_initializer() = []() { if(!config::get_use_causal()) return; - unblocking_gotcha_t::configure( - comp::gotcha_config<0, int, pthread_mutex_t*>{ "pthread_mutex_unlock" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<1, int, pthread_rwlock_t*>{ "pthread_rwlock_unlock" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<2, int, pthread_spinlock_t*>{ "pthread_spin_unlock" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<3, int, pthread_barrier_t*>{ "pthread_barrier_wait" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<4, int, pthread_cond_t*>{ "pthread_cond_signal" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<5, int, pthread_cond_t*>{ "pthread_cond_broadcast" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<6, int, pthread_t, int>{ "pthread_kill" }); - - unblocking_gotcha_t::configure( - comp::gotcha_config<7, void, void*>{ "pthread_exit" }); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 0, pthread_mutex_unlock); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 1, pthread_spin_unlock); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 2, pthread_rwlock_unlock); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 3, pthread_cond_signal); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 4, pthread_cond_broadcast); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 5, pthread_kill); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 6, pthread_sigqueue); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 7, pthread_barrier_wait); + TIMEMORY_C_GOTCHA(unblocking_gotcha_t, 8, kill); }; } @@ -98,35 +97,45 @@ unblocking_gotcha::shutdown() unblocking_gotcha_t::disable(); } -void -unblocking_gotcha::start() +template +Ret +unblocking_gotcha::operator()(const comp::gotcha_data& _data, Ret (*_func)(Args...), + Args... _args) const noexcept { - if(causal::experiment::is_active() && - get_thread_state() == ::omnitrace::ThreadState::Enabled) - causal::delay::process(); + auto _active = get_thread_state() < ::omnitrace::ThreadState::Internal; + + if(_active) causal::delay::process(); + + if(_active && _data.index == 7) + { + int64_t _delay_value = (_active) ? causal::delay::get_global().load() : 0; + + causal::sampling::block_backtrace_samples(); + auto _ret = (*_func)(_args...); + causal::sampling::unblock_backtrace_samples(); + + causal::delay::postblock(_delay_value); + return _ret; + } + else + { + return (*_func)(_args...); + } } -void -unblocking_gotcha::stop() +int +unblocking_gotcha::operator()(const comp::gotcha_data&, int (*_func)(pid_t, int), + pid_t _pid, int _sig) const noexcept { - if(causal::experiment::is_active() && - get_thread_state() == ::omnitrace::ThreadState::Enabled) - causal::delay::credit(); -} + auto _active = get_thread_state() < ::omnitrace::ThreadState::Internal; -void -unblocking_gotcha::set_data(const comp::gotcha_data& _data) -{ - OMNITRACE_SCOPED_THREAD_STATE(ThreadState::Internal); - auto _hash = tim::add_hash_id(_data.tool_id); - auto&& _ident = tim::get_hash_identifier(_hash); - if(_ident != _data.tool_id) - throw ::omnitrace::exception( - JOIN("", "Error! resolving hash for \"", _data.tool_id, "\" (", _hash, - ") returns ", _ident.c_str())); -#if defined(OMNITRACE_CI) - OMNITRACE_VERBOSE_F(3, "data set for '%s'...\n", _data.tool_id.c_str()); -#endif + if(_active && _pid == process::get_id()) causal::delay::process(); + + causal::sampling::block_backtrace_samples(); + auto _ret = (*_func)(_pid, _sig); + causal::sampling::unblock_backtrace_samples(); + + return _ret; } } // namespace component } // namespace causal diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.hpp index 44a58728ef..f13a87e63a 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/components/unblocking_gotcha.hpp @@ -39,11 +39,9 @@ namespace causal { namespace component { -using timespec_t = struct timespec; -// this is used to wrap pthread_mutex() struct unblocking_gotcha : comp::base { - static constexpr size_t gotcha_capacity = 8; + static constexpr size_t gotcha_capacity = 9; OMNITRACE_DEFAULT_OBJECT(unblocking_gotcha) @@ -56,15 +54,15 @@ struct unblocking_gotcha : comp::base static void configure(); static void shutdown(); - static void start(); - static void stop(); + template + Ret operator()(const comp::gotcha_data&, Ret (*)(Args...), Args...) const noexcept; - static void set_data(const comp::gotcha_data&); + int operator()(const comp::gotcha_data&, int (*)(pid_t, int), pid_t, + int) const noexcept; }; using unblocking_gotcha_t = - comp::gotcha, category::causal>; + comp::gotcha, unblocking_gotcha>; } // namespace component } // namespace causal } // namespace omnitrace @@ -72,4 +70,6 @@ using unblocking_gotcha_t = OMNITRACE_DEFINE_CONCRETE_TRAIT(prevent_reentry, causal::component::unblocking_gotcha_t, false_type) OMNITRACE_DEFINE_CONCRETE_TRAIT(static_data, causal::component::unblocking_gotcha_t, + false_type) +OMNITRACE_DEFINE_CONCRETE_TRAIT(fast_gotcha, causal::component::unblocking_gotcha_t, true_type) diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/data.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/data.cpp index 798630f4fc..ca85f0249d 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/data.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/data.cpp @@ -467,6 +467,9 @@ perform_experiment_impl(std::shared_ptr> _started) // NOLINT } } + // allow ~10 samples to be collected + std::this_thread::sleep_for(std::chrono::milliseconds{ 10 }); + double _delay_sec = config::get_setting_value("OMNITRACE_CAUSAL_DELAY").second; double _duration_sec = diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/delay.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/delay.cpp index a9d932f7d7..7dacac43be 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/delay.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/delay.cpp @@ -97,9 +97,6 @@ int64_t sleep_for_overhead = compute_sleep_for_overhead(); void delay::process() { - if(!trait::runtime_enabled::get()) return; - if(get_state() >= ::omnitrace::State::Finalized) return; - if(causal::experiment::is_active()) { if(get_global() < get_local()) @@ -126,9 +123,6 @@ delay::process() void delay::credit() { - if(!trait::runtime_enabled::get()) return; - if(get_state() >= ::omnitrace::State::Finalized) return; - auto _diff = get_global() - get_local(); if(_diff > 0) { @@ -139,9 +133,6 @@ delay::credit() void delay::preblock() { - if(!trait::runtime_enabled::get()) return; - if(get_state() >= ::omnitrace::State::Finalized) return; - auto _diff = get_global() - get_local(); if(_diff > 0) { @@ -152,9 +143,6 @@ delay::preblock() void delay::postblock(int64_t _preblock_global_delay_value) { - if(!trait::runtime_enabled::get()) return; - if(get_state() >= ::omnitrace::State::Finalized) return; - get_local() += (get_global() - _preblock_global_delay_value); } diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.cpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.cpp index 501c162a30..10452b6115 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.cpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.cpp @@ -60,7 +60,8 @@ namespace sampling using ::tim::sampling::dynamic; using ::tim::sampling::timer; -using causal_bundle_t = tim::lightweight_tuple; +using causal_bundle_t = + tim::lightweight_tuple; using causal_sampler_t = tim::sampling::sampler; } // namespace sampling } // namespace causal @@ -307,6 +308,20 @@ unblock_samples() trait::runtime_enabled::set(true); } +void +block_backtrace_samples() +{ + trait::runtime_enabled::set(scope::thread_scope{}, + false); +} + +void +unblock_backtrace_samples() +{ + trait::runtime_enabled::set(scope::thread_scope{}, + true); +} + void block_signals(std::set _signals) { diff --git a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.hpp b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.hpp index 992a139c0e..5cc465bef5 100644 --- a/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.hpp +++ b/projects/rocprofiler-systems/source/lib/omnitrace/library/causal/sampling.hpp @@ -45,6 +45,12 @@ block_samples(); void unblock_samples(); +void +block_backtrace_samples(); + +void +unblock_backtrace_samples(); + void block_signals(std::set = {}); void unblock_signals(std::set = {}); diff --git a/projects/rocprofiler-systems/tests/validate-causal-json.py b/projects/rocprofiler-systems/tests/validate-causal-json.py index e9f0a781ca..b4acda0cdd 100755 --- a/projects/rocprofiler-systems/tests/validate-causal-json.py +++ b/projects/rocprofiler-systems/tests/validate-causal-json.py @@ -65,13 +65,15 @@ class validation(object): ) -class experiment_data(object): +class throughput_point(object): def __init__(self, _speedup): self.speedup = _speedup + self.delta = [] self.duration = [] - def __iadd__(self, _val): - self.duration += [float(_val)] + def __iadd__(self, _data): + self.delta += [float(_data[0])] + self.duration += [float(_data[1])] def __len__(self): return len(self.duration) @@ -85,11 +87,48 @@ class experiment_data(object): def __lt__(self, rhs): return self.speedup < rhs.speedup - def mean(self): - return mean(self.duration) + def get_data(self): + return [x / y for x, y in zip(self.duration, self.delta)] - def stddev(self): - return stddev(self.duration) + def mean(self): + return sum(self.duration) / sum(self.delta) + + +class latency_point(object): + def __init__(self, _speedup): + self.speedup = _speedup + self.arrivals = [] + self.departures = [] + self.duration = [] + + def __iadd__(self, _data): + self.arrivals += [float(_data[0])] + self.departures += [float(_data[1])] + self.duration += [float(_data[2])] + + def __len__(self): + return len(self.duration) + + def __eq__(self, rhs): + return self.speedup == rhs.speedup + + def __neq__(self, rhs): + return not self == rhs + + def __lt__(self, rhs): + return self.speedup < rhs.speedup + + def get_data(self): + _duration = sum(self.duration) + return [y / x for x, y in zip(self.arrivals, self.duration)] + + def get_difference(self): + _duration = sum(self.duration) + return [x / _duration for x in self.duration] + + def mean(self): + rate = sum(self.arrivals) / sum(self.duration) + return sum(self.get_difference()) / rate class line_speedup(object): @@ -114,7 +153,7 @@ class line_speedup(object): return 0.0 _data = [] _base = self.base.mean() - for ditr in self.data.duration: + for ditr in self.data.get_data(): _data += [((_base - ditr) / _base) * 100] return stddev(_data) @@ -164,19 +203,18 @@ class experiment_progress(object): self.data = _data def get_impact(self): - """ speedup_c = [x.compute_speedup() for x in self.data] speedup_v = [x.virtual_speedup() for x in self.data] impact = [] for i in range(len(self.data) - 1): x = speedup_v[i + 1] - speedup_v[i] - y_low = speedup_c[i] - y_upp = speedup_c[i + 1] - a_low = x * min([y_low, y_upp]) - a_high = 0.5 * x * (max([y_low, y_upp]) - min([y_low, y_upp])) - impact += [a_low + a_high] - """ - impact = [x.compute_speedup() for x in self.data] + y = [speedup_c[i], speedup_c[i + 1]] + y_min = min(y) + y_max = max(y) + a_low = x * y_min + a_upp = 0.5 * x * (y_max - y_min) + impact += [a_low + a_upp] + # impact = [x.compute_speedup() for x in self.data] return [sum(impact), mean(impact), stddev(impact)] def __len__(self): @@ -197,9 +235,12 @@ class experiment_progress(object): return self.get_impact()[0] < rhs.get_impact()[0] -def find_or_insert(_data, _value): +def find_or_insert(_data, _value, _type): if _value not in _data: - _data[_value] = experiment_data(_value) + if _type == "throughput": + _data[_value] = throughput_point(_value) + elif _type == "latency": + _data[_value] = latency_point(_value) return _data[_value] @@ -232,19 +273,18 @@ def process_data(data, _data, args): if "delta" in pts: _delt = pts["delta"] if _delt > 0: - itr = find_or_insert(data[_selected][_name], _speedup) - itr += float(_duration) / float(_delt) - else: - _diff = pts["arrival"] - pts["departure"] + 1 - _rate = pts["arrival"] / float(_duration) - if _rate > 0: - itr = find_or_insert(data[_selected][_name], _speedup) - itr += float(_diff) / float(_rate) + itr = find_or_insert( + data[_selected][_name], _speedup, "throughput" + ) + itr += [_delt, _duration] + elif "arrival" in pts and pts["arrival"] > 0: + itr = find_or_insert(data[_selected][_name], _speedup, "latency") + itr += [pts["arrival"], pts["departure"], _duration] else: _delt = pts["laps"] if _delt > 0: itr = find_or_insert(data[_selected][_name], _speedup) - itr += float(_duration) / float(_delt) + itr += [_delt, _duration] return data