Test execution stats improvements

--stats can have optional values:
  --stats=out prints all test timings to standard output,
  --stats=<filename> prints all test timings to a file in tab-separated format.

Stats are now kept in vector to allow duplicated values.

test/Stats.cpp

@@ -19,6 +19,7 @@
 
 #include <iterator>
 #include <numeric>
+#include <fstream>
 
 namespace dev
 {
@@ -31,6 +32,11 @@ Stats& Stats::get()
 	return instance;
 }
 
+void Stats::suiteStarted(std::string const& _name)
+{
+	m_currentSuite = _name;
+}
+
 void Stats::testStarted(std::string const& _name)
 {
 	m_currentTest = _name;
@@ -39,7 +45,7 @@ void Stats::testStarted(std::string const& _name)
 
 void Stats::testFinished()
 {
-	m_stats[clock::now() - m_tp] = std::move(m_currentTest);
+	m_stats.push_back({clock::now() - m_tp, m_currentSuite + "/" + m_currentTest});
 }
 
 std::ostream& operator<<(std::ostream& out, Stats::clock::duration const& d)
@@ -52,31 +58,42 @@ Stats::~Stats()
 	if (m_stats.empty())
 		return;
 
+	std::sort(m_stats.begin(), m_stats.end(), [](Stats::Item const& a, Stats::Item const& b){
+		return a.duration < b.duration;
+	});
+
 	auto& out = std::cout;
 	auto itr = m_stats.begin();
 	auto min = *itr;
 	auto max = *m_stats.rbegin();
 	std::advance(itr, m_stats.size() / 2);
 	auto med = *itr;
-	auto tot = std::accumulate(m_stats.begin(), m_stats.end(), clock::duration{}, [](clock::duration const& a, stats_t::value_type const& v)
+	auto tot = std::accumulate(m_stats.begin(), m_stats.end(), clock::duration{}, [](clock::duration const& a, Stats::Item const& v)
 	{
-		return a + v.first;
+		return a + v.duration;
 	});
 
 	out << "\nSTATS:\n\n" << std::setfill(' ');
 
-	if (Options::get().statsFull)
+	if (Options::get().statsOutFile == "out")
 	{
 		for (auto&& s: m_stats)
-			out << "  " << std::setw(40) << std::left << s.second.substr(0, 40) << s.first << " \n";
+			out << "  " << std::setw(40) << std::left << s.name.substr(0, 40) << s.duration << " \n";
 		out << "\n";
 	}
+	else if (!Options::get().statsOutFile.empty())
+	{
+		// Output stats to file
+		std::ofstream file{Options::get().statsOutFile};
+		for (auto&& s: m_stats)
+			file << s.name << "\t" << std::chrono::duration_cast<std::chrono::microseconds>(s.duration).count() << "\n";
+	}
 
 	out	<< "  tot: " << tot << "\n"
 		<< "  avg: " << (tot / m_stats.size()) << "\n\n"
-		<< "  min: " << min.first << " (" << min.second << ")\n"
-		<< "  med: " << med.first << " (" << med.second << ")\n"
-		<< "  max: " << max.first << " (" << max.second << ")\n";
+		<< "  min: " << min.duration << " (" << min.name << ")\n"
+		<< "  med: " << med.duration << " (" << med.name << ")\n"
+		<< "  max: " << max.duration << " (" << max.name << ")\n";
 }
 
 }

test/Stats.h

@@ -18,7 +18,7 @@
 #pragma once
 
 #include <chrono>
-#include <map>
+#include <vector>
 
 #include "TestHelper.h"
 
@@ -31,19 +31,26 @@ class Stats: public Listener
 {
 public:
 	using clock = std::chrono::high_resolution_clock;
-	using stats_t = std::map<clock::duration, std::string>;
+
+	struct Item
+	{
+		clock::duration duration;
+		std::string 	name;
+	};
 
 	static Stats& get();
 
 	~Stats();
 
+	void suiteStarted(std::string const& _name) override;
 	void testStarted(std::string const& _name) override;
 	void testFinished() override;
 
 private:
 	clock::time_point m_tp;
+	std::string m_currentSuite;
 	std::string m_currentTest;
-	stats_t m_stats;
+	std::vector<Item> m_stats;
 };
 
 }

test/TestHelper.cpp

@@ -29,6 +29,7 @@
 #include <libethereum/Client.h>
 #include <liblll/Compiler.h>
 #include <libevm/VMFactory.h>
+#include "Stats.h"
 
 using namespace std;
 using namespace dev::eth;
@@ -447,6 +448,9 @@ void executeTests(const string& _name, const string& _testPathAppendix, std::fun
 	string testPath = getTestPath();
 	testPath += _testPathAppendix;
 
+	if (Options::get().stats)
+		Listener::registerListener(Stats::get());
+
 	if (Options::get().fillTests)
 	{
 		try
@@ -478,6 +482,7 @@ void executeTests(const string& _name, const string& _testPathAppendix, std::fun
 		string s = asString(dev::contents(testPath + "/" + _name + ".json"));
 		BOOST_REQUIRE_MESSAGE(s.length() > 0, "Contents of " + testPath + "/" + _name + ".json is empty. Have you cloned the 'tests' repo branch develop and set ETHEREUM_TEST_PATH to its path?");
 		json_spirit::read_string(s, v);
+		Listener::notifySuiteStarted(_name);
 		doTests(v, false);
 	}
 	catch (Exception const& _e)
@@ -551,10 +556,12 @@ Options::Options()
 			vmtrace = true;
 		else if (arg == "--filltests")
 			fillTests = true;
-		else if (arg == "--stats")
+		else if (arg.compare(0, 7, "--stats") == 0)
+		{
 			stats = true;
-		else if (arg == "--stats=full")
-			stats = statsFull = true;
+			if (arg.size() > 7)
+				statsOutFile = arg.substr(8); // skip '=' char
+		}
 		else if (arg == "--performance")
 			performance = true;
 		else if (arg == "--quadratic")
@@ -602,6 +609,12 @@ void Listener::registerListener(Listener& _listener)
 	g_listener = &_listener;
 }
 
+void Listener::notifySuiteStarted(std::string const& _name)
+{
+	if (g_listener)
+		g_listener->suiteStarted(_name);
+}
+
 void Listener::notifyTestStarted(std::string const& _name)
 {
 	if (g_listener)

test/TestHelper.h

@@ -164,7 +164,7 @@ public:
 	bool vmtrace = false;	///< Create EVM execution tracer // TODO: Link with log verbosity?
 	bool fillTests = false; ///< Create JSON test files from execution results
 	bool stats = false;		///< Execution time stats
-	bool statsFull = false; ///< Output full stats - execution times for every test
+	std::string statsOutFile; ///< Stats output file. "out" for standard output
 
 	/// Test selection
 	/// @{
@@ -191,10 +191,12 @@ class Listener
 public:
 	virtual ~Listener() = default;
 
+	virtual void suiteStarted(std::string const&) {}
 	virtual void testStarted(std::string const& _name) = 0;
 	virtual void testFinished() = 0;
 
 	static void registerListener(Listener& _listener);
+	static void notifySuiteStarted(std::string const& _name);
 	static void notifyTestStarted(std::string const& _name);
 	static void notifyTestFinished();
 

test/state.cpp

@@ -31,7 +31,6 @@
 #include <libethereum/Defaults.h>
 #include <libevm/VM.h>
 #include "TestHelper.h"
-#include "Stats.h"
 
 using namespace std;
 using namespace json_spirit;
@@ -42,9 +41,6 @@ namespace dev {  namespace test {
 
 void doStateTests(json_spirit::mValue& v, bool _fillin)
 {
-	if (Options::get().stats)
-		Listener::registerListener(Stats::get());
-
 	for (auto& i: v.get_obj())
 	{
 		std::cout << "  " << i.first << "\n";
@@ -255,6 +251,7 @@ BOOST_AUTO_TEST_CASE(stRandom)
 			string s = asString(dev::contents(path.string()));
 			BOOST_REQUIRE_MESSAGE(s.length() > 0, "Content of " + path.string() + " is empty. Have you cloned the 'tests' repo branch develop and set ETHEREUM_TEST_PATH to its path?");
 			json_spirit::read_string(s, v);
+			test::Listener::notifySuiteStarted(path.filename().string());
 			dev::test::doStateTests(v, false);
 		}
 		catch (Exception const& _e)

test/vm.cpp

@@ -25,7 +25,6 @@
 #include <libethereum/Executive.h>
 #include <libevm/VMFactory.h>
 #include "vm.h"
-#include "Stats.h"
 
 using namespace std;
 using namespace json_spirit;
@@ -311,9 +310,6 @@ namespace dev { namespace test {
 
 void doVMTests(json_spirit::mValue& v, bool _fillin)
 {
-	if (Options::get().stats)
-		Listener::registerListener(Stats::get());
-
 	for (auto& i: v.get_obj())
 	{
 		std::cout << "  " << i.first << "\n";
@@ -549,6 +545,7 @@ BOOST_AUTO_TEST_CASE(vmRandom)
 			string s = asString(dev::contents(path.string()));
 			BOOST_REQUIRE_MESSAGE(s.length() > 0, "Content of " + path.string() + " is empty. Have you cloned the 'tests' repo branch develop and set ETHEREUM_TEST_PATH to its path?");
 			json_spirit::read_string(s, v);
+			test::Listener::notifySuiteStarted(path.filename().string());
 			doVMTests(v, false);
 		}
 		catch (Exception const& _e)