Start of stats collector

libevmjit/ExecStats.cpp

@@ -0,0 +1,22 @@
+#include "ExecStats.h"
+
+namespace dev
+{
+namespace eth
+{
+namespace jit
+{
+
+void ExecStats::execStarted()
+{
+	m_tp = std::chrono::high_resolution_clock::now();
+}
+
+void ExecStats::execEnded()
+{
+	execTime = std::chrono::high_resolution_clock::now() - m_tp;
+}
+
+}
+}
+}

libevmjit/ExecStats.h

@@ -0,0 +1,32 @@
+#pragma once
+
+#include <string>
+#include <chrono>
+
+namespace dev
+{
+namespace eth
+{
+namespace jit
+{
+
+class ExecStats
+{
+public:
+	std::string id;
+	std::chrono::high_resolution_clock::duration compileTime;
+	std::chrono::high_resolution_clock::duration codegenTime;
+	std::chrono::high_resolution_clock::duration cacheLoadTime;
+	std::chrono::high_resolution_clock::duration execTime;
+
+	void execStarted();
+	void execEnded();
+
+private:
+	std::chrono::high_resolution_clock::time_point m_tp;
+
+};
+
+}
+}
+}

libevmjit/ExecutionEngine.cpp

@@ -83,6 +83,50 @@ bool showInfo()
 	return show;
 }
 
+class StatsCollector
+{
+public:
+	std::vector<std::unique_ptr<ExecStats>> stats;
+
+	~StatsCollector()
+	{
+		if (stats.empty())
+			return;
+
+		using d = decltype(ExecStats{}.execTime);
+		d total = d::zero();
+		d max = d::zero();
+		d min = d::max();
+
+		for (auto&& s : stats)
+		{
+			auto t = s->execTime;
+			total += t;
+			if (t < min)
+				min = t;
+			if (t > max)
+				max = t;
+		}
+
+		using u = std::chrono::microseconds;
+		auto nTotal = std::chrono::duration_cast<u>(total).count();
+		auto nAverage = std::chrono::duration_cast<u>(total / stats.size()).count();
+		auto nMax = std::chrono::duration_cast<u>(max).count();
+		auto nMin = std::chrono::duration_cast<u>(min).count();
+
+		std::cout << "Total  exec time: " << nTotal << " us" << std::endl
+				  << "Averge exec time: " << nAverage << " us" << std::endl
+				  << "Min    exec time: " << nMin << " us" << std::endl
+				  << "Max    exec time: " << nMax << " us" << std::endl;
+	}
+};
+
+}
+
+void ExecutionEngine::collectStats()
+{
+	if (!m_stats)
+		m_stats.reset(new ExecStats);
 }
 
 ReturnCode ExecutionEngine::run(RuntimeData* _data, Env* _env)
@@ -90,9 +134,15 @@ ReturnCode ExecutionEngine::run(RuntimeData* _data, Env* _env)
 	static std::unique_ptr<llvm::ExecutionEngine> ee;  // TODO: Use Managed Objects from LLVM?
 	static auto debugDumpModule = getEnvOption("EVMJIT_DUMP", false);
 	static auto objectCacheEnabled = getEnvOption("EVMJIT_CACHE", true);
+	static auto statsCollectingEnabled = getEnvOption("EVMJIT_STATS", false);
 	static auto infoShown = showInfo();
 	(void) infoShown;
 
+	static StatsCollector statsCollector;
+
+	if (statsCollectingEnabled)
+		collectStats();
+
 	auto codeBegin = _data->code;
 	auto codeEnd = codeBegin + _data->codeSize;
 	assert(codeBegin || !codeEnd); //TODO: Is it good idea to execute empty code?
@@ -153,17 +203,22 @@ ReturnCode ExecutionEngine::run(RuntimeData* _data, Env* _env)
 	}
 	assert(entryFuncPtr);
 
-	auto executionStartTime = std::chrono::high_resolution_clock::now();
+	if (m_stats)
+		m_stats->execStarted();
 
 	auto returnCode = runEntryFunc(entryFuncPtr, &runtime);
+
+	if (m_stats)
+		m_stats->execEnded();
+
 	if (returnCode == ReturnCode::Return)
 	{
 		returnData = runtime.getReturnData();     // Save reference to return data
 		std::swap(m_memory, runtime.getMemory()); // Take ownership of memory
 	}
 
-	auto executionEndTime = std::chrono::high_resolution_clock::now();
-	clog(JIT) << " + " << std::chrono::duration_cast<std::chrono::milliseconds>(executionEndTime - executionStartTime).count() << " ms\n";
+	if (statsCollectingEnabled)
+		statsCollector.stats.push_back(std::move(m_stats));
 
 	return returnCode;
 }

libevmjit/ExecutionEngine.h

@@ -1,6 +1,8 @@
 #pragma once
 
+#include <memory>
 #include "RuntimeData.h"
+#include "ExecStats.h"
 
 namespace dev
 {
@@ -18,6 +20,10 @@ public:
 
 	EXPORT ReturnCode run(RuntimeData* _data, Env* _env);
 
+	void collectStats();
+
+	std::unique_ptr<ExecStats> getStats();
+
 	/// Reference to returned data (RETURN opcode used)
 	bytes_ref returnData;
 
@@ -25,6 +31,8 @@ private:
 	/// After execution, if RETURN used, memory is moved there
 	/// to allow client copy the returned data
 	bytes m_memory;
+
+	std::unique_ptr<ExecStats> m_stats;
 };
 
 }