From 47c3b558f2fc399f27b9e9c478b413e1f073645b Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Kamil=20=C5=9Aliwak?= <kamil.sliwak@codepoets.it>
Date: Thu, 27 Feb 2020 02:08:40 +0100
Subject: [PATCH] [yul-phaser] AlgorithmRunner: Print elapsed time after each
 round

---
 test/yulPhaser/AlgorithmRunner.cpp  |  2 +-
 tools/yulPhaser/AlgorithmRunner.cpp | 14 ++++++++++++--
 tools/yulPhaser/AlgorithmRunner.h   |  4 +++-
 3 files changed, 16 insertions(+), 4 deletions(-)

diff --git a/test/yulPhaser/AlgorithmRunner.cpp b/test/yulPhaser/AlgorithmRunner.cpp
index b3379d661..831cb360a 100644
--- a/test/yulPhaser/AlgorithmRunner.cpp
+++ b/test/yulPhaser/AlgorithmRunner.cpp
@@ -69,7 +69,7 @@ class AlgorithmRunnerFixture
 {
 protected:
 	// NOTE: Regexes here should not contain spaces because we strip them before matching
-	regex RoundSummaryRegex{R"(-+ROUND\d+-+)"};
+	regex RoundSummaryRegex{R"(-+ROUND\d+\[round:[0-9.]+s,total:[0-9.]+s\]-+)"};
 	regex InitialPopulationHeaderRegex{"-+INITIALPOPULATION-+"};
 
 	string individualPattern(Individual const& individual) const
diff --git a/tools/yulPhaser/AlgorithmRunner.cpp b/tools/yulPhaser/AlgorithmRunner.cpp
index 90440e120..9ddce41bc 100644
--- a/tools/yulPhaser/AlgorithmRunner.cpp
+++ b/tools/yulPhaser/AlgorithmRunner.cpp
@@ -34,27 +34,37 @@ void AlgorithmRunner::run(GeneticAlgorithm& _algorithm)
 	printInitialPopulation();
 	cacheClear();
 
+	chrono::steady_clock::time_point totalTimeStart = std::chrono::steady_clock::now();
 	for (size_t round = 0; !m_options.maxRounds.has_value() || round < m_options.maxRounds.value(); ++round)
 	{
+		chrono::steady_clock::time_point roundTimeStart = std::chrono::steady_clock::now();
 		cacheStartRound(round + 1);
 
 		m_population = _algorithm.runNextRound(m_population);
 		randomiseDuplicates();
 
-		printRoundSummary(round);
+		printRoundSummary(round, roundTimeStart, totalTimeStart);
 		populationAutosave();
 	}
 }
 
 void AlgorithmRunner::printRoundSummary(
-	size_t _round
+	size_t _round,
+	chrono::steady_clock::time_point _roundTimeStart,
+	chrono::steady_clock::time_point _totalTimeStart
 ) const
 {
 	if (!m_options.showOnlyTopChromosome)
 	{
 		if (m_options.showRoundInfo)
 		{
+			chrono::steady_clock::time_point now = std::chrono::steady_clock::now();
+			auto roundTime = chrono::duration_cast<chrono::milliseconds>(now - _roundTimeStart).count();
+			auto totalTime = chrono::duration_cast<chrono::milliseconds>(now - _totalTimeStart).count();
+
 			m_outputStream << "---------- ROUND " << _round + 1;
+			m_outputStream << " [round: " << fixed << setprecision(1) << roundTime / 1000.0 << " s,";
+			m_outputStream << " total: " << fixed << setprecision(1) << totalTime / 1000.0 << " s]";
 			m_outputStream << " ----------" << endl;
 		}
 		else if (m_population.individuals().size() > 0)
diff --git a/tools/yulPhaser/AlgorithmRunner.h b/tools/yulPhaser/AlgorithmRunner.h
index abef48869..7c6946391 100644
--- a/tools/yulPhaser/AlgorithmRunner.h
+++ b/tools/yulPhaser/AlgorithmRunner.h
@@ -71,7 +71,9 @@ public:
 
 private:
 	void printRoundSummary(
-		size_t _round
+		size_t _round,
+		std::chrono::steady_clock::time_point _roundTimeStart,
+		std::chrono::steady_clock::time_point _totalTimeStart
 	) const;
 	void printInitialPopulation() const;
 	void populationAutosave() const;