trace.cpp File Reference

#include "timemory/trace.hpp"
#include "timemory/compat/library.h"
#include "timemory/library.h"
#include "timemory/runtime/configure.hpp"
#include "timemory/timemory.hpp"
#include "timemory/utility/bits/signals.hpp"
#include <cstdarg>
#include <cstdlib>
#include <deque>
#include <iostream>
#include <unordered_map>

Include dependency graph for trace.cpp:

Go to the source code of this file.

Macros
#define	TIMEMORY_LIBRARY_SOURCE   1

Typedefs
using	string_t = std::string
using	overhead_map_t = std::unordered_map< size_t, std::pair< wall_clock, size_t > >
using	throttle_set_t = std::set< size_t >
using	traceset_t = tim::component_bundle< TIMEMORY_API, user_trace_bundle >
using	trace_map_t = std::unordered_map< size_t, std::deque< traceset_t > >
using	mpi_trace_bundle_t = tim::component_tuple<>

Functions
std::array< bool, 2 > &	get_library_state ()
bool	setup_mpi_gotcha ()
bool	timemory_trace_is_initialized ()
bool	timemory_is_throttled (const char *name)
void	timemory_reset_throttle (const char *name)
void	timemory_add_hash_id (uint64_t id, const char *name)
void	timemory_add_hash_ids (uint64_t nentries, uint64_t *ids, const char **names)
void	timemory_copy_hash_ids ()
void	timemory_push_trace_hash (uint64_t id)
void	timemory_pop_trace_hash (uint64_t id)
void	timemory_push_trace (const char *name)
void	timemory_pop_trace (const char *name)
void	timemory_trace_set_env (const char *env_var, const char *env_val)
void	timemory_trace_init (const char *comps, bool read_command_line, const char *cmd)
void	timemory_trace_finalize (void)

Macro Definition Documentation

TIMEMORY_LIBRARY_SOURCE

#define TIMEMORY_LIBRARY_SOURCE   1

Definition at line 26 of file trace.cpp.

Typedef Documentation

mpi_trace_bundle_t

using mpi_trace_bundle_t = tim::component_tuple<>

Definition at line 335 of file trace.cpp.

overhead_map_t

using overhead_map_t = std::unordered_map<size_t, std::pair<wall_clock, size_t> >

Definition at line 50 of file trace.cpp.

string_t

using string_t = std::string

Definition at line 49 of file trace.cpp.

throttle_set_t

using throttle_set_t = std::set<size_t>

Definition at line 51 of file trace.cpp.

trace_map_t

using trace_map_t = std::unordered_map<size_t, std::deque<traceset_t> >

Definition at line 53 of file trace.cpp.

traceset_t

using traceset_t = tim::component_bundle<TIMEMORY_API, user_trace_bundle>

Definition at line 52 of file trace.cpp.

Function Documentation

get_library_state()

std::array< bool, 2 > & get_library_state

(

)

Definition at line 127 of file library.cpp.

{
    static auto _instance = std::array<bool, 2>({ { false, false } });
    return _instance;
}

Referenced by timemory_finalize_library(), timemory_init_library(), timemory_library_is_initialized(), timemory_pop_trace(), timemory_pop_trace_hash(), timemory_push_trace(), timemory_push_trace_hash(), timemory_trace_is_initialized(), and timemory_trace_set_env().

setup_mpi_gotcha()

bool setup_mpi_gotcha

(

)

Definition at line 340 of file trace.cpp.

{
    return false;
}

timemory_add_hash_id()

void timemory_add_hash_id	(	uint64_t	id,
		const char *	name
	)

Definition at line 392 of file trace.cpp.

    {
        tim::trace::lock<tim::trace::library> lk{};
        if(!lk)
        {
            if(tim::settings::debug())
                fprintf(stderr,
                        "[timemory-trace]> timemory_add_hash_id failed: locked...\n");
            return;
        }
        if(tim::settings::debug())
            fprintf(stderr, "[timemory-trace]> adding '%s' with hash %lu...\n", name,
                    (unsigned long) id);
        auto _id = tim::add_hash_id(name);
        if(_id != id)
            tim::add_hash_id(_id, id);
 
        // master thread adds the ids
        if(tim::threading::get_id() == 0)
        {
            master_hash_ids[id] = name;
            if(_id != id)
                master_hash_ids[_id] = name;
        }
    }

References tim::debug.

Referenced by timemory_add_hash_ids().

timemory_add_hash_ids()

void timemory_add_hash_ids	(	uint64_t	nentries,
		uint64_t *	ids,
		const char **	names
	)

Definition at line 420 of file trace.cpp.

    {
        if(tim::settings::debug())
            fprintf(stderr, "[timemory-trace]> adding %lu hash ids...\n",
                    (unsigned long) nentries);
        for(uint64_t i = 0; i < nentries; ++i)
            timemory_add_hash_id(ids[i], names[i]);
    }

References tim::debug, and timemory_add_hash_id().

timemory_copy_hash_ids()

void timemory_copy_hash_ids

(

)

Definition at line 431 of file trace.cpp.

    {
        tim::trace::lock<tim::trace::library> lk{};
        static thread_local bool              once_per_thread = false;
        if(!once_per_thread && tim::threading::get_id() > 0)
        {
            if(tim::settings::debug())
                fprintf(stderr, "[timemory-trace]> copying hash ids...\n");
            once_per_thread  = true;
            auto _master_ids = master_hash_ids;
            for(const auto& itr : _master_ids)
                timemory_add_hash_id(itr.first, itr.second.c_str());
        }
    }

References tim::debug.

Referenced by timemory_push_trace_hash().

timemory_is_throttled()

bool timemory_is_throttled

(

const char *

name

)

Definition at line 374 of file trace.cpp.

    {
        size_t _id = tim::get_hash_id(name);
        return (get_throttle()->count(_id) > 0);
    }

timemory_pop_trace()

void timemory_pop_trace

(

const char *

name

)

Definition at line 632 of file trace.cpp.

    {
        uint64_t _hash = std::numeric_limits<uint64_t>::max();
        {
            tim::trace::lock<tim::trace::library> lk{};
            if(!get_library_state()[0] || get_library_state()[1])
                return;
            _hash = tim::get_hash_id(name);
        }
        timemory_pop_trace_hash(_hash);
    }

References get_library_state(), std::max(), and timemory_pop_trace_hash().

timemory_pop_trace_hash()

void timemory_pop_trace_hash

(

uint64_t

id

)

Definition at line 514 of file trace.cpp.

    {
        tim::trace::lock<tim::trace::library> lk{};
        if(!get_library_state()[0] || get_library_state()[1])
            return;
 
        auto& _trace_map = get_trace_map();
        if(!tim::settings::enabled() && _trace_map.empty())
        {
            if(tim::settings::debug() && _trace_map.empty())
                fprintf(stderr,
                        "[timemory-trace]> timemory_pop_trace_hash(%lu) failed. "
                        "trace_map empty...\n",
                        (unsigned long) id);
            return;
        }
 
        int64_t ntotal = _trace_map[id].size();
        int64_t offset = ntotal - 1;
 
        if(tim::settings::debug())
        {
            auto     itr  = tim::get_hash_ids()->find(id);
            string_t name = (itr != tim::get_hash_ids()->end()) ? itr->second : "unknown";
            fprintf(stderr,
                    "ending trace for '%s' (id = %llu, offset = %lli, rank = %i, pid = "
                    "%i, thread = %i)...\n",
                    name.c_str(), (long long unsigned) id, (long long int) offset,
                    tim::dmp::rank(), (int) tim::process::get_id(),
                    (int) tim::threading::get_id());
        }
 
        (*get_overhead())[id].first.stop();
 
        // if there were no entries, return (pop called without a push)
        if(offset < 0)
            return;
 
        if(offset >= 0 && ntotal > 0)
        {
            _trace_map[id].back().stop();
            _trace_map[id].pop_back();
        }
 
        if(get_throttle() && get_throttle()->count(id) > 0)
            return;
 
        auto _count = ++(get_overhead()->at(id).second);
 
        if(_count % tim::settings::throttle_count() == 0)
        {
            auto _accum = get_overhead()->at(id).first.get_accum() / _count;
            if(_accum < tim::settings::throttle_value())
            {
                if(tim::settings::debug() || tim::settings::verbose() > 0)
                {
                    auto name = tim::get_hash_ids()->find(id)->second;
                    fprintf(
                        stderr,
                        "[timemory-trace]> Throttling all future calls to '%s' on rank = "
                        "%i, pid = "
                        "%i, thread = %i. avg runtime = %lu ns from %lu invocations... "
                        "Consider eliminating from instrumentation...\n",
                        name.c_str(), tim::dmp::rank(), (int) tim::process::get_id(),
                        (int) tim::threading::get_id(), (unsigned long) _accum,
                        (unsigned long) _count);
                }
                get_throttle()->insert(id);
            }
            else
            {
                if(_accum < (10 * tim::settings::throttle_value()) &&
                   (tim::settings::debug() || tim::settings::verbose() > 1))
                {
                    auto name = tim::get_hash_ids()->find(id)->second;
                    fprintf(
                        stderr,
                        "[timemory-trace]> Warning! function call '%s' within an order "
                        "of magnitude of threshold for throttling value on rank = %i, "
                        "pid = "
                        "%i, thread = %i. avg runtime = %lu ns from %lu invocations... "
                        "Consider eliminating from instrumentation...\n",
                        name.c_str(), tim::dmp::rank(), (int) tim::process::get_id(),
                        (int) tim::threading::get_id(), (unsigned long) _accum,
                        (unsigned long) _count);
                }
            }
            get_overhead()->at(id).first.reset();
            get_overhead()->at(id).second = 0;
        }
    }

References get_library_state().

Referenced by timemory_pop_trace().

timemory_push_trace()

void timemory_push_trace

(

const char *

name

)

Definition at line 608 of file trace.cpp.

    {
        if(!timemory_trace_is_initialized())
            timemory_trace_init("", true, "");
 
        uint64_t _hash = std::numeric_limits<uint64_t>::max();
        {
            tim::trace::lock<tim::trace::library> lk{};
            if(tim::settings::debug())
                PRINT_HERE("rank = %i, pid = %i, thread = %i, name = %s",
                           tim::dmp::rank(), (int) tim::process::get_id(),
                           (int) tim::threading::get_id(), name);
 
            if(!get_library_state()[0] || get_library_state()[1] ||
               !tim::settings::enabled())
                return;
 
            _hash = tim::add_hash_id(name);
        }
        timemory_push_trace_hash(_hash);
    }

References tim::debug, tim::enabled, get_library_state(), std::max(), PRINT_HERE, timemory_push_trace_hash(), timemory_trace_init(), and timemory_trace_is_initialized().

timemory_push_trace_hash()

void timemory_push_trace_hash

(

uint64_t

id

)

Definition at line 448 of file trace.cpp.

    {
        if(!timemory_trace_is_initialized())
            timemory_trace_init("", true, "");
 
        static thread_local auto _copied = (timemory_copy_hash_ids(), true);
        tim::consume_parameters(_copied);
 
        tim::trace::lock<tim::trace::library> lk{};
 
        if(!lk)
        {
#if defined(DEBUG) || !defined(NDEBUG)
            if(tim::settings::debug())
                PRINT_HERE("Tracing is locked: %s", (lk) ? "Y" : "N");
#endif
            return;
        }
 
        if(!get_library_state()[0] || get_library_state()[1] || !tim::settings::enabled())
        {
#if defined(DEBUG) || !defined(NDEBUG)
            if(tim::settings::debug())
                PRINT_HERE("Invalid library state: init = %s, fini = %s, enabled = %s",
                           (get_library_state()[0]) ? "Y" : "N",
                           (get_library_state()[1]) ? "Y" : "N",
                           (tim::settings::enabled()) ? "Y" : "N");
#endif
            return;
        }
 
        if(get_throttle()->count(id) > 0)
        {
#if defined(DEBUG) || !defined(NDEBUG)
            if(tim::settings::debug())
                PRINT_HERE("trace %llu is throttled", (unsigned long long) id);
#endif
            return;
        }
 
        auto& _trace_map = get_trace_map();
        auto& _overh_map = *get_overhead();
 
        if(tim::get_hash_ids()->find(id) == tim::get_hash_ids()->end())
            return;
 
        if(tim::settings::debug())
        {
            int64_t  n    = _trace_map[id].size();
            auto     itr  = tim::get_hash_ids()->find(id);
            string_t name = (itr != tim::get_hash_ids()->end()) ? itr->second : "unknown";
            fprintf(stderr,
                    "beginning trace for '%s' (id = %llu, offset = %lli, rank = %i, pid "
                    "= %i, thread = %i)...\n",
                    name.c_str(), (long long unsigned) id, (long long int) n,
                    tim::dmp::rank(), (int) tim::process::get_id(),
                    (int) tim::threading::get_id());
        }
 
        _trace_map[id].emplace_back(traceset_t{ id });
        _trace_map[id].back().start();
        _overh_map[id].first.start();
    }

References tim::consume_parameters(), tim::debug, tim::enabled, get_library_state(), PRINT_HERE, timemory_copy_hash_ids(), timemory_trace_init(), and timemory_trace_is_initialized().

Referenced by timemory_push_trace().

timemory_reset_throttle()

void timemory_reset_throttle

(

const char *

name

)

Definition at line 382 of file trace.cpp.

    {
        size_t _id = tim::get_hash_id(name);
        auto   itr = get_throttle()->find(_id);
        if(itr != get_throttle()->end())
            get_throttle()->erase(itr);
    }

timemory_trace_finalize()

void timemory_trace_finalize

(

void

)

Definition at line 808 of file trace.cpp.

    {
        tim::trace::lock<tim::trace::library> lk{};
        if(library_trace_count.load() == 0)
            return;
 
        auto  _manager  = tim::manager::master_instance();
        auto* _settings = tim::settings::instance();
        if(!_manager || !_settings)
            return;
 
        auto _debug = _settings->get_debug();
        if(_settings->get_verbose() > 1 || _settings->get_debug())
            PRINT_HERE("rank = %i, pid = %i, thread = %i", tim::dmp::rank(),
                       (int) tim::process::get_id(), (int) tim::threading::get_id());
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "getting count");
        // do the finalization
        auto _count = --library_trace_count;
 
        if(_count > 0)
        {
            CONDITIONAL_PRINT_HERE(_debug, "%s", "positive count");
            // have the manager finalize
            if(tim::manager::instance())
                tim::manager::instance()->finalize();
            CONDITIONAL_PRINT_HERE(_debug, "%s", "returning");
            return;
        }
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "secondary lock");
        tim::auto_lock_t lock(tim::type_mutex<TIMEMORY_API>());
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "setting state");
        // tim::settings::enabled() = false;
        get_library_state()[1] = true;
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "barrier");
        tim::mpi::barrier();
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "resetting");
        // reset traces just in case
        user_trace_bundle::reset();
 
        // if already finalized
        bool _skip_stop = false;
        if(!_manager || _manager->is_finalized())
            _skip_stop = true;
 
        // clean up any remaining entries
        if(!_skip_stop)
        {
            CONDITIONAL_PRINT_HERE(_debug, "%s", "cleaning trace map");
            for(auto& itr : get_trace_map())
            {
                for(auto& eitr : itr.second)
                    eitr.stop();
                // delete all the records
                itr.second.clear();
            }
            CONDITIONAL_PRINT_HERE(_debug, "%s", "clearing trace map");
            // delete all the records
            get_trace_map().clear();
        }
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "resetting mpi gotcha");
        // deactivate the gotcha wrappers
        if(use_mpi_gotcha)
            mpi_gotcha_handle.reset();
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "finalizing library");
        // finalize the library
        timemory_finalize_library();
 
        CONDITIONAL_PRINT_HERE(_debug, "%s", "finalized trace");
    }

timemory_trace_init()

void timemory_trace_init	(	const char *	comps,
		bool	read_command_line,
		const char *	cmd
	)

Definition at line 671 of file trace.cpp.

    {
        tim::trace::lock<tim::trace::library> lk{};
        if(!tim::manager::instance() || tim::manager::instance()->is_finalized())
            return;
 
        // configures the output path
        auto _configure_output_path = [&]() {
            static bool _performed_explicit = false;
            if(_performed_explicit || tim::settings::output_path() != "timemory-output")
                return;
            if(read_command_line)
            {
                auto _init = [](int _ac, char** _av) { timemory_init_library(_ac, _av); };
                tim::config::read_command_line(_init);
            }
            else
            {
                std::string exe_name = (cmd) ? cmd : "";
                if(!exe_name.empty())
                    _performed_explicit = true;
 
                while(exe_name.find('\\') != std::string::npos)
                    exe_name = exe_name.substr(exe_name.find_last_of('\\') + 1);
                while(exe_name.find('/') != std::string::npos)
                    exe_name = exe_name.substr(exe_name.find_last_of('/') + 1);
 
                static const std::vector<std::string> _exe_suffixes = { ".py", ".exe" };
                for(const auto& ext : _exe_suffixes)
                {
                    if(exe_name.find(ext) != std::string::npos)
                        exe_name.erase(exe_name.find(ext), ext.length() + 1);
                }
 
                exe_name = std::string("timemory-") + exe_name + "-output";
                for(auto& itr : exe_name)
                {
                    if(itr == '_')
                        itr = '-';
                }
 
                tim::settings::output_path() = exe_name;
            }
            if(tim::manager::instance())
                tim::manager::instance()->update_metadata_prefix();
        };
 
        // write the info about the rank/pid/thread/command
        auto _write_info = [&]() {
            std::stringstream _info;
            _info << "[timemory_trace_init]> ";
            if(tim::dmp::is_initialized())
                _info << "rank = " << tim::dmp::rank() << ", ";
            _info << "pid = " << tim::process::get_id() << ", ";
            _info << "tid = " << tim::threading::get_id();
            if(cmd && strlen(cmd) > 0)
                _info << ", command: " << cmd;
            if(comps && strlen(comps) > 0)
                _info << ", default components: " << comps;
            fprintf(stderr, "%s\n", _info.str().c_str());
        };
 
        // configures the tracing components
        auto _configure_components = [&]() {
            if(comps && strlen(comps) > 0)
            {
                _write_info();
                tim::set_env<std::string>("TIMEMORY_TRACE_COMPONENTS", comps, 0);
                if(tim::settings::trace_components().empty())
                    tim::settings::trace_components() = comps;
            }
 
            tim::settings::parse();
 
            // configure bundle
            user_trace_bundle::global_init(true);
            // tim::operation::init<user_trace_bundle>(
            //    tim::operation::mode_constant<tim::operation::init_mode::global>{});
        };
 
        if(!get_library_state()[0] && library_trace_count++ == 0)
        {
            _configure_components();
            _configure_output_path();
 
            tim::manager::use_exit_hook(false);
            get_library_state()[0] = true;
 
            auto _exit_action = [](int nsig) {
                auto _manager = tim::manager::master_instance();
                if(_manager && !_manager->is_finalized() && !_manager->is_finalizing())
                {
                    std::cout << "Finalizing after signal: " << nsig << " :: "
                              << tim::signal_settings::str(
                                     static_cast<tim::sys_signal>(nsig))
                              << std::endl;
                    timemory_trace_finalize();
                }
            };
            tim::signal_settings::set_exit_action(_exit_action);
            std::atexit(&timemory_trace_finalize);
#if !defined(TIMEMORY_MACOS)
            // Apple clang version 11.0.3 (clang-1103.0.32.62) doesn't seem to have this
            // function
            std::at_quick_exit(&tim::timemory_finalize);
#endif
 
#if defined(TIMEMORY_MPI_GOTCHA)
            if(!mpi_gotcha_handle.get())
            {
                mpi_gotcha_handle =
                    std::make_shared<mpi_trace_bundle_t>("timemory_trace_mpi_gotcha");
                mpi_trace_gotcha::get_trace_components() = comps;
                mpi_trace_gotcha::read_command_line()    = read_command_line;
                mpi_trace_gotcha::get_command()          = (cmd) ? cmd : "";
                if(mpi_is_attached)
                    mpi_trace_gotcha::set_attr();
                mpi_gotcha_handle->start();
            }
            else if(mpi_gotcha_handle.get())
            {
                tim::manager::instance()->update_metadata_prefix();
            }
#endif
        }
        else
        {
            if(tim::settings::debug())
                PRINT_HERE("trace already initialized: %s",
                           (get_library_state()[0]) ? "Y" : "N");
 
            _configure_components();
        }
    }

References tim::plotting::cmd, tim::exe_name, tim::manager::instance(), tim::output_path, tim::config::read_command_line(), and timemory_init_library().

Referenced by timemory_push_trace(), and timemory_push_trace_hash().

timemory_trace_is_initialized()

bool timemory_trace_is_initialized

(

void

)

Definition at line 366 of file trace.cpp.

    {
        return (get_library_state()[0] &&
                library_trace_count.load(std::memory_order_relaxed) > 0);
    }

References get_library_state().

Referenced by timemory_push_trace(), and timemory_push_trace_hash().

timemory_trace_set_env()

void timemory_trace_set_env	(	const char *	env_var,
		const char *	env_val
	)

Definition at line 658 of file trace.cpp.

    {
        tim::trace::lock<tim::trace::library> lk{};
        tim::set_env<std::string>(env_var, env_val, 0);
        if(get_library_state()[0])
        {
            tim::settings::parse();
            user_trace_bundle::global_init(true);
        }
    }

References get_library_state(), and tim::settings::parse().