/*+ ARES/HADES/BORG Package -- ./libLSS/tools/console.cpp Copyright (C) 2014-2020 Guilhem Lavaux Copyright (C) 2009-2020 Jens Jasche Additional contributions from: Guilhem Lavaux (2023) +*/ #include "libLSS/cconfig.h" #include #include #include #include #include "libLSS/tools/string_tools.hpp" #include #include #include #include "libLSS/tools/static_init.hpp" #include "console.hpp" #include #include "libLSS/tools/hdf5_type.hpp" #include "libLSS/tools/timing_db.hpp" using boost::format; using boost::str; using boost::chrono::duration; using boost::chrono::duration_cast; using boost::chrono::system_clock; using LibLSS::Console; using LibLSS::details::ProgressBase; static std::string format_duration(duration &d) { typedef boost::chrono::hours hours; typedef boost::chrono::minutes minutes; typedef boost::chrono::seconds seconds; duration d_int = duration_cast>(d); return str( format("%02d:%02d:%02d") % duration_cast(d_int).count() % duration_cast(d_int % hours(1)).count() % duration_cast(d_int % minutes(1)).count()); } #ifndef NDEBUG void boost::assertion_failed( char const *expr, char const *function, char const *file, long line) { auto &cons = Console::instance(); std::string msg = "ASSERTION FAILED: " + std::string(expr) + " in " + std::string(function) + " (" + std::string(file) + ")"; cons.print(msg); ::abort(); LibLSS::MPI_Communication::instance()->abort(); } void boost::assertion_failed_msg( char const *expr, char const *msg, char const *function, char const *file, long line) { auto &cons = Console::instance(); std::string m = "ASSERTION FAILED: " + std::string(expr) + ", msg = " + std::string(msg) + " in " + std::string(function) + " (" + std::string(file) + ")"; cons.print(m); ::abort(); LibLSS::MPI_Communication::instance()->abort(); } #endif void Console::print_stack_trace() { std::string s = boost::stacktrace::to_string(boost::stacktrace::stacktrace()); print(LibLSS::tokenize(s, "\n")); } ProgressBase::ProgressBase(Console *c, const std::string &m, int num, int step) : numElements(num), percent(0), iLevel(c->indentLevel), step(step), msg(m), start(system_clock::now()), console(c) {} void ProgressBase::destroy() { update(numElements); console->cleanProgress(this); } void ProgressBase::update(int i) { int new_percent; if (numElements == 0) return; current = i; new_percent = current * 100L / numElements; if (new_percent > (percent + step - 1)) { duration elapsed = system_clock::now() - start, sec; int oldLevel = console->indentLevel; sec = elapsed * (100. - new_percent) / new_percent; percent = new_percent; console->setIndentLevel(iLevel); print( str(format("%s %d %% (ETA %s, elapsed %s)") % msg % new_percent % format_duration(sec) % format_duration(elapsed))); console->setIndentLevel(oldLevel); } } struct StatInfo { size_t count; double total_time; StatInfo() : count(0), total_time(0) {} }; struct TimingInfoStore { CosmoTool::CosmoString name; StatInfo info; }; CTOOL_STRUCT_TYPE( StatInfo, HDF5T_StatInfo, ((size_t, count))((double, total_time))); CTOOL_STRUCT_TYPE( TimingInfoStore, HDF5T_TimingInfoStore, ((CosmoTool::CosmoString, name))((StatInfo, info))); static std::map timing_stats; static bool report_timing_done = true; namespace LibLSS { namespace timings { void record(std::string const &n, double t) { #ifdef LIBLSS_TIMED_CONTEXT if (report_timing_done) return; auto &info = timing_stats[n]; info.count++; info.total_time += t; #endif } } // namespace timings } // namespace LibLSS #include "libLSS/ares_version.hpp" namespace LibLSS { namespace details { namespace { ConsoleContextBase baseContext; } thread_local ConsoleContextBase *currentContext = &baseContext; } // namespace details } // namespace LibLSS namespace { using namespace LibLSS; static std::string g_time_file_pattern = "timing_stats_%d.txt"; static void record_init() { Console::instance().print( "libLSS version " + ARES_GIT_VERSION + " built-in modules " + ARES_BUILTIN_MODULES); report_timing_done = false; } static void dump_time_records(bool close) { if (report_timing_done) return; report_timing_done = close; std::string s = str(format(g_time_file_pattern) % LibLSS::MPI_Communication::instance()->rank()); std::ofstream f(s); f << "ARES version " << ARES_GIT_VERSION << " modules " << ARES_BUILTIN_MODULES << std::endl << std::endl; f << "Cumulative timing spent in different context" << std::endl << "--------------------------------------------" << std::endl << "Context, Total time (seconds)" << std::endl << std::endl; std::vector> sorted_timings; std::copy( timing_stats.begin(), timing_stats.end(), std::back_inserter(sorted_timings)); std::sort( sorted_timings.begin(), sorted_timings.end(), [](std::pair const &p1, std::pair const &p2) { return p1.second.total_time > p2.second.total_time; }); for (auto &n : sorted_timings) { f << format("% 40s\t%d\t%g") % n.first % n.second.count % n.second.total_time << std::endl; } } static void record_fini() { dump_time_records(true); } // Highest priority after console. LibLSS::RegisterStaticInit reg_record_init(record_init, record_fini, 1, "Timing database"); } // namespace namespace LibLSS { namespace timings { void set_file_pattern(std::string const &pattern) { g_time_file_pattern = pattern; } void trigger_dump() { dump_time_records(false); } void reset() { timing_stats.clear(); } void load(H5_CommonFileGroup &g) { boost::multi_array store; try { CosmoTool::hdf5_read_array(g, "timings", store, true); for (size_t i = 0; i < store.num_elements(); i++) { TimingInfoStore const &t = store[i]; auto &entry = timing_stats[std::string(t.name.s)]; entry.count += t.info.count; entry.total_time += t.info.total_time; } } catch (H5::FileIException const &e) { Console::instance().print( "No timing database in this file."); } } void save(H5_CommonFileGroup &g) { boost::multi_array store; ssize_t idx = 0; store.resize(boost::extents[timing_stats.size()]); for (auto &n : timing_stats) { store[idx].name.s = n.first.c_str(); store[idx].info = n.second; idx++; } CosmoTool::hdf5_write_array(g, "timings", store); } } // namespace timings } // namespace LibLSS AUTO_REGISTRATOR_IMPL(console_timing);