From c006e542a5c61007d636024fa68f23df0a225c76 Mon Sep 17 00:00:00 2001 From: "Jonathan R. Madsen" Date: Thu, 21 Jul 2022 11:15:26 -0500 Subject: [PATCH] Replaces OMNITRACE_CONDITIONAL_BASIC_PRINT with OMNITRACE_VERBOSE (#97) Replaces OMNITRACE_CONDITIONAL_BASIC_PRINT with OMNITRACE_VERBOSE and similar where possible --- .../critical-trace.cpp | 32 +++++-------- source/lib/omnitrace/library.cpp | 2 +- .../library/components/backtrace.cpp | 8 ++-- .../library/components/fork_gotcha.cpp | 3 +- .../components/pthread_create_gotcha.cpp | 4 +- .../omnitrace/library/components/rocm_smi.cpp | 3 +- source/lib/omnitrace/library/config.cpp | 48 +++++++++---------- .../lib/omnitrace/library/critical_trace.cpp | 11 ++--- .../lib/omnitrace/library/process_sampler.cpp | 5 +- source/lib/omnitrace/library/roctracer.cpp | 6 +-- source/lib/omnitrace/library/runtime.cpp | 3 +- 11 files changed, 55 insertions(+), 70 deletions(-) diff --git a/source/bin/omnitrace-critical-trace/critical-trace.cpp b/source/bin/omnitrace-critical-trace/critical-trace.cpp index 0f70561d27..7c73e51c3a 100644 --- a/source/bin/omnitrace-critical-trace/critical-trace.cpp +++ b/source/bin/omnitrace-critical-trace/critical-trace.cpp @@ -136,13 +136,11 @@ fini_perfetto() else { // Write the trace into a file. - OMNITRACE_CONDITIONAL_BASIC_PRINT_F( - config::get_verbose() >= 0, - "> Outputting '%s' (%.2f KB / %.2f MB / %.2f GB)... ", - config::get_perfetto_output_filename().c_str(), - static_cast(trace_data.size()) / tim::units::KB, - static_cast(trace_data.size()) / tim::units::MB, - static_cast(trace_data.size()) / tim::units::GB); + OMNITRACE_BASIC_VERBOSE(0, "> Outputting '%s' (%.2f KB / %.2f MB / %.2f GB)... ", + config::get_perfetto_output_filename().c_str(), + static_cast(trace_data.size()) / tim::units::KB, + static_cast(trace_data.size()) / tim::units::MB, + static_cast(trace_data.size()) / tim::units::GB); std::ofstream ofs{}; if(!tim::filepath::open(ofs, config::get_perfetto_output_filename(), @@ -220,9 +218,8 @@ save_call_graph(const std::string& _fname, const std::string& _label, if(_msg) { if(_func.empty()) _func = __FUNCTION__; - OMNITRACE_CONDITIONAL_BASIC_PRINT(get_verbose() >= 0, - "[%s] Outputting '%s'...\n", _func.c_str(), - _fname.c_str()); + OMNITRACE_BASIC_VERBOSE(0, "[%s] Outputting '%s'...\n", _func.c_str(), + _fname.c_str()); } ofs << oss.str() << std::endl; } @@ -266,9 +263,8 @@ save_critical_trace(const std::string& _fname, const std::string& _label, if(_msg) { if(_func.empty()) _func = __FUNCTION__; - OMNITRACE_CONDITIONAL_BASIC_PRINT(get_verbose() >= 0, - "[%s] Outputting '%s'...\n", _func.c_str(), - _fname.c_str()); + OMNITRACE_BASIC_VERBOSE(0, "[%s] Outputting '%s'...\n", _func.c_str(), + _fname.c_str()); } std::stringstream oss{}; if(_cchain.size() > 1000) @@ -306,9 +302,8 @@ save_call_chain_text(const std::string& _fname, const call_chain& _call_chain, if(_msg) { if(_func.empty()) _func = __FUNCTION__; - OMNITRACE_CONDITIONAL_BASIC_PRINT(get_verbose() >= 0, - "[%s] Outputting '%s'...\n", _func.c_str(), - _fname.c_str()); + OMNITRACE_BASIC_VERBOSE(0, "[%s] Outputting '%s'...\n", _func.c_str(), + _fname.c_str()); } ofs << _call_chain << "\n"; } @@ -352,9 +347,8 @@ save_call_chain_json(const std::string& _fname, const std::string& _label, if(_msg) { if(_func.empty()) _func = __FUNCTION__; - OMNITRACE_CONDITIONAL_BASIC_PRINT(get_verbose() >= 0, - "[%s] Outputting '%s'...\n", _func.c_str(), - _fname.c_str()); + OMNITRACE_BASIC_VERBOSE(0, "[%s] Outputting '%s'...\n", _func.c_str(), + _fname.c_str()); } std::stringstream oss{}; if(_call_chain.size() > 100000) diff --git a/source/lib/omnitrace/library.cpp b/source/lib/omnitrace/library.cpp index 0d88c89e80..e6cda0a209 100644 --- a/source/lib/omnitrace/library.cpp +++ b/source/lib/omnitrace/library.cpp @@ -930,7 +930,7 @@ omnitrace_finalize_hidden(void) std::string _msg = JOIN("", *itr); auto _pos = _msg.find(">>> "); if(_pos != std::string::npos) _msg = _msg.substr(_pos + 5); - OMNITRACE_CONDITIONAL_PRINT(get_verbose() >= 0, "%s\n", _msg.c_str()); + OMNITRACE_VERBOSE(0, "%s\n", _msg.c_str()); } } diff --git a/source/lib/omnitrace/library/components/backtrace.cpp b/source/lib/omnitrace/library/components/backtrace.cpp index e5d3fbb99f..88371ed1df 100644 --- a/source/lib/omnitrace/library/components/backtrace.cpp +++ b/source/lib/omnitrace/library/components/backtrace.cpp @@ -432,7 +432,7 @@ backtrace::post_process(int64_t _tid) { // this should be relatively common OMNITRACE_CONDITIONAL_PRINT( - get_debug() && get_verbose() > 1, + get_debug() && get_verbose() >= 2, "Post-processing sampling entries for thread %lu skipped (no sampler)\n", _tid); return; @@ -652,9 +652,9 @@ backtrace::post_process(int64_t _tid) if(_data.empty()) return; - OMNITRACE_CONDITIONAL_PRINT( - get_verbose() >= 0 || get_debug_sampling(), - "Post-processing %zu sampling entries for thread %lu...\n", _data.size(), _tid); + OMNITRACE_VERBOSE(0 || get_debug_sampling(), + "Post-processing %zu sampling entries for thread %lu...\n", + _data.size(), _tid); std::sort(_data.begin(), _data.end(), [](const sampling::bundle_t* _lhs, const sampling::bundle_t* _rhs) { diff --git a/source/lib/omnitrace/library/components/fork_gotcha.cpp b/source/lib/omnitrace/library/components/fork_gotcha.cpp index 1e61af50bd..1cfc6a0cbe 100644 --- a/source/lib/omnitrace/library/components/fork_gotcha.cpp +++ b/source/lib/omnitrace/library/components/fork_gotcha.cpp @@ -45,8 +45,7 @@ fork_gotcha::audit(const gotcha_data_t&, audit::incoming) { OMNITRACE_VERBOSE(1, "fork() called on PID %i (rank: %i), TID %li\n", process::get_id(), dmp::rank(), threading::get_id()); - OMNITRACE_CONDITIONAL_BASIC_PRINT( - get_debug_env(), + OMNITRACE_BASIC_DEBUG( "Warning! Calling fork() within an OpenMPI application using libfabric " "may result is segmentation fault\n"); TIMEMORY_CONDITIONAL_DEMANGLED_BACKTRACE(get_debug_env(), 16); diff --git a/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp b/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp index db69d0017b..e448abb130 100644 --- a/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp +++ b/source/lib/omnitrace/library/components/pthread_create_gotcha.cpp @@ -235,8 +235,8 @@ pthread_create_gotcha::shutdown() bundles->clear(); - OMNITRACE_CONDITIONAL_BASIC_PRINT( - (get_verbose_env() >= 2 || get_debug_env()) && _ndangling > 0, + OMNITRACE_BASIC_VERBOSE( + 2 && _ndangling > 0, "[pthread_create_gotcha::shutdown] cleaned up %lu dangling bundles\n", _ndangling); } diff --git a/source/lib/omnitrace/library/components/rocm_smi.cpp b/source/lib/omnitrace/library/components/rocm_smi.cpp index 6620d47e53..4aec80bfcc 100644 --- a/source/lib/omnitrace/library/components/rocm_smi.cpp +++ b/source/lib/omnitrace/library/components/rocm_smi.cpp @@ -211,8 +211,7 @@ data::shutdown() void data::post_process(uint32_t _dev_id) { - OMNITRACE_CONDITIONAL_PRINT(get_debug() || get_verbose() > 0, - "Post-processing rocm-smi data for device %u\n", _dev_id); + OMNITRACE_VERBOSE(1, "Post-processing rocm-smi data for device %u\n", _dev_id); using component::sampling_gpu_busy; using component::sampling_gpu_memory; diff --git a/source/lib/omnitrace/library/config.cpp b/source/lib/omnitrace/library/config.cpp index f9e4b6c520..3ad1278357 100644 --- a/source/lib/omnitrace/library/config.cpp +++ b/source/lib/omnitrace/library/config.cpp @@ -169,10 +169,9 @@ configure_settings(bool _init) if(get_state() < State::Init) { ::tim::print_demangled_backtrace<64>(); - OMNITRACE_CONDITIONAL_THROW(true, - "config::configure_settings() called before " - "omnitrace_init_library. state = %s", - std::to_string(get_state()).c_str()); + OMNITRACE_THROW("config::configure_settings() called before " + "omnitrace_init_library. state = %s", + std::to_string(get_state()).c_str()); } tim::manager::add_metadata("OMNITRACE_VERSION", OMNITRACE_VERSION_STRING); @@ -493,22 +492,20 @@ configure_settings(bool _init) if(_paranoid > 1) { - OMNITRACE_CONDITIONAL_BASIC_PRINT( - get_verbose_env() >= 0, - "/proc/sys/kernel/perf_event_paranoid has a value of %i. " - "Disabling PAPI (requires a value <= 1)...\n", - _paranoid); - OMNITRACE_CONDITIONAL_BASIC_PRINT( - get_verbose_env() >= 0, - "In order to enable PAPI support, run 'echo N | sudo tee " - "/proc/sys/kernel/perf_event_paranoid' where N is < 2\n"); + OMNITRACE_BASIC_VERBOSE(0, + "/proc/sys/kernel/perf_event_paranoid has a value of %i. " + "Disabling PAPI (requires a value <= 1)...\n", + _paranoid); + OMNITRACE_BASIC_VERBOSE(0, + "In order to enable PAPI support, run 'echo N | sudo tee " + "/proc/sys/kernel/perf_event_paranoid' where N is < 2\n"); tim::trait::runtime_enabled::set(false); tim::trait::runtime_enabled::set(false); tim::trait::runtime_enabled::set(false); tim::trait::runtime_enabled::set(false); tim::trait::runtime_enabled::set(false); tim::trait::runtime_enabled::set(false); - _config->get_papi_events() = ""; + _config->get_papi_events() = std::string{}; } else { @@ -558,6 +555,7 @@ configure_settings(bool _init) using argparser_t = tim::argparse::argument_parser; argparser_t _parser{ _exe }; tim::timemory_init(_cmd, _parser, "omnitrace-"); + _settings_are_configured() = true; } _config->get_global_components() = @@ -595,9 +593,7 @@ configure_settings(bool _init) configure_signal_handler(); configure_disabled_settings(); - _settings_are_configured() = true; - - OMNITRACE_CONDITIONAL_BASIC_PRINT(get_verbose_env() > 0, "configuration complete\n"); + OMNITRACE_VERBOSE(1, "configuration complete\n"); } void @@ -642,10 +638,10 @@ configure_mode_settings() if(gpu::device_count() == 0) { - OMNITRACE_VERBOSE_F( - 1, "No HIP devices were found: disabling roctracer and rocm_smi...\n"); - _set("OMNITRACE_USE_ROCTRACER", false); + OMNITRACE_VERBOSE(1, "No HIP devices were found: disabling roctracer, " + "rocprofiler, and rocm_smi...\n"); _set("OMNITRACE_USE_ROCPROFILER", false); + _set("OMNITRACE_USE_ROCTRACER", false); _set("OMNITRACE_USE_ROCM_SMI", false); } @@ -726,8 +722,8 @@ configure_signal_handler() { auto _info = ::tim::signal_settings::get_info(static_cast(_v)); - OMNITRACE_CONDITIONAL_BASIC_PRINT( - get_verbose_env() >= 2 || get_debug_env(), + OMNITRACE_VERBOSE( + 2, "signal %s (%i) ignored (OMNITRACE_IGNORE_DYNINST_TRAMPOLINE=ON)\n", std::get<0>(_info).c_str(), _v); if(get_verbose_env() > 1 || get_debug_env()) @@ -751,14 +747,14 @@ configure_disabled_settings() auto _disabled = _config->disable_category(_category); _config->enable(_opt); for(auto&& itr : _disabled) - OMNITRACE_BASIC_VERBOSE(3, "[%s=OFF] disabled option :: '%s'\n", - _opt.c_str(), itr.c_str()); + OMNITRACE_VERBOSE(3, "[%s=OFF] disabled option :: '%s'\n", + _opt.c_str(), itr.c_str()); return false; } auto _enabled = _config->enable_category(_category); for(auto&& itr : _enabled) - OMNITRACE_BASIC_VERBOSE(3, "[%s=ON] enabled option :: '%s'\n", - _opt.c_str(), itr.c_str()); + OMNITRACE_VERBOSE(3, "[%s=ON] enabled option :: '%s'\n", _opt.c_str(), + itr.c_str()); return true; }; diff --git a/source/lib/omnitrace/library/critical_trace.cpp b/source/lib/omnitrace/library/critical_trace.cpp index d3758a1a28..74eb46e737 100644 --- a/source/lib/omnitrace/library/critical_trace.cpp +++ b/source/lib/omnitrace/library/critical_trace.cpp @@ -173,10 +173,9 @@ entry::operator+=(const entry& rhs) } else { - OMNITRACE_CONDITIONAL_PRINT( - get_verbose() > 1, - "Warning! Incorrect phase. entry::operator+=(entry) is only valid for " - "Phase::BEGIN += Phase::END\n"); + OMNITRACE_VERBOSE( + 2, "Warning! Incorrect phase. entry::operator+=(entry) is only valid for " + "Phase::BEGIN += Phase::END\n"); } return *this; } @@ -647,8 +646,8 @@ save_call_chain_json(const std::string& _fname, const std::string& _label, if(_msg) { if(_func.empty()) _func = __FUNCTION__; - OMNITRACE_CONDITIONAL_PRINT(get_verbose() >= 0, "[%s] Outputting '%s'...\n", - _func.c_str(), _fname.c_str()); + OMNITRACE_VERBOSE(0, "[%s] Outputting '%s'...\n", _func.c_str(), + _fname.c_str()); } std::stringstream oss{}; if(_call_chain.size() > 100000) diff --git a/source/lib/omnitrace/library/process_sampler.cpp b/source/lib/omnitrace/library/process_sampler.cpp index e9c141e0fd..0d1e5a2271 100644 --- a/source/lib/omnitrace/library/process_sampler.cpp +++ b/source/lib/omnitrace/library/process_sampler.cpp @@ -82,9 +82,8 @@ sampler::poll(std::atomic* _state, nsec_t _interval, promise_t* _ready) for(auto& itr : instances) itr->config(); - OMNITRACE_CONDITIONAL_BASIC_PRINT( - get_verbose() > 0 || get_debug(), - "Thread sampler polling at an interval of %f seconds...\n", + OMNITRACE_VERBOSE( + 1, "Thread sampler polling at an interval of %f seconds...\n", std::chrono::duration_cast>(_interval).count()); auto _now = std::chrono::steady_clock::now(); diff --git a/source/lib/omnitrace/library/roctracer.cpp b/source/lib/omnitrace/library/roctracer.cpp index 9c55ec63e0..c90ca75b4d 100644 --- a/source/lib/omnitrace/library/roctracer.cpp +++ b/source/lib/omnitrace/library/roctracer.cpp @@ -242,7 +242,7 @@ 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_CONDITIONAL_PRINT_F( - get_debug() && get_verbose() > 1, "<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", + get_debug() && get_verbose() >= 2, "<%-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"); @@ -553,7 +553,7 @@ 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_CONDITIONAL_PRINT_F( - get_debug() && get_verbose() > 1, "<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", + get_debug() && get_verbose() >= 2, "<%-30s id(%u)\tcorrelation_id(%lu) %s>\n", op_name, cid, data->correlation_id, (data->phase == ACTIVITY_API_PHASE_ENTER) ? "on-enter" : "on-exit"); @@ -890,7 +890,7 @@ hip_activity_callback(const char* begin, const char* end, void*) { static size_t _n = 0; OMNITRACE_CONDITIONAL_PRINT_F( - get_debug() && get_verbose() > 1, + get_debug() && get_verbose() >= 2, "%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, diff --git a/source/lib/omnitrace/library/runtime.cpp b/source/lib/omnitrace/library/runtime.cpp index 9c06b3327d..0b20a71078 100644 --- a/source/lib/omnitrace/library/runtime.cpp +++ b/source/lib/omnitrace/library/runtime.cpp @@ -143,8 +143,7 @@ setup_gotchas() if(_initialized) return; _initialized = true; - OMNITRACE_CONDITIONAL_PRINT_F( - get_debug_env(), + OMNITRACE_BASIC_DEBUG( "Configuring gotcha wrapper around fork, MPI_Init, and MPI_Init_thread\n"); mpi_gotcha::configure();