diff --git a/src/vt/trace/trace.cc b/src/vt/trace/trace.cc index c4d2ed0f1c..217dd3a161 100644 --- a/src/vt/trace/trace.cc +++ b/src/vt/trace/trace.cc @@ -67,6 +67,8 @@ namespace vt { namespace trace { +std::unordered_map manual_timings; + using TraceContainersType = TraceContainers; using LogType = Trace::LogType; @@ -119,6 +121,13 @@ void Trace::finalize() /*override*/ { // Always end any between-loop event left open. endProcessing(between_sched_event_, timing::getCurrentTime()); between_sched_event_ = TraceProcessingTag{}; + + fmt::print("{}: ", theContext()->getNode()); + for (auto const& [name, time] : manual_timings) { + fmt::print("({},{}) ", name, time); + } + fmt::print("\n"); + fflush(stdout); } void Trace::loadAndBroadcastSpec() { diff --git a/src/vt/trace/trace.h b/src/vt/trace/trace.h index 232f36d4e5..225792efa7 100644 --- a/src/vt/trace/trace.h +++ b/src/vt/trace/trace.h @@ -64,6 +64,8 @@ namespace vt { namespace trace { +extern std::unordered_map manual_timings; + /// Tracking information for beginProcessing/endProcessing. struct TraceProcessingTag { diff --git a/src/vt/vrt/collection/balance/baselb/baselb.cc b/src/vt/vrt/collection/balance/baselb/baselb.cc index 219218d850..cddd52592a 100644 --- a/src/vt/vrt/collection/balance/baselb/baselb.cc +++ b/src/vt/vrt/collection/balance/baselb/baselb.cc @@ -77,9 +77,22 @@ std::shared_ptr BaseLB::startLB( importProcessorData(in_stats, in_comm_lb_data, in_data_map); runInEpochCollective("BaseLB::startLB -> runLB", [this,total_load]{ + + auto t1 = timing::getCurrentTime(); getArgs(phase_); + auto t2 = timing::getCurrentTime(); + trace::manual_timings["getArgs"] = t2-t1; + inputParams(config_entry_.get()); + + auto t3 = timing::getCurrentTime(); + trace::manual_timings["inputParams"] = t3-t2; + runLB(total_load); + + auto t4 = timing::getCurrentTime(); + trace::manual_timings["runLB"] = t4-t3; + }); return normalizeReassignments();