From a92020ac1e8a6eef9c60150a559a46ff89f10f04 Mon Sep 17 00:00:00 2001
From: VaclavT <vaclavt@gmail.com>
Date: Sun, 28 Mar 2021 23:52:33 +0200
Subject: [PATCH] added runtime in ms to -p option

---
 debug.lsp       |  2 +-
 ml.cpp          |  6 +++---
 ml_profiler.cpp | 27 +++++++++++++++++++++------
 ml_profiler.h   |  5 +++++
 4 files changed, 30 insertions(+), 10 deletions(-)

diff --git a/debug.lsp b/debug.lsp
index 1115117..e2610db 100644
--- a/debug.lsp
+++ b/debug.lsp
@@ -46,4 +46,4 @@
 
 (print (and (print "xx") (= 1 0) (print "yy")))
 
-(sleep 1.5)
\ No newline at end of file
+; (sleep 1.5)
\ No newline at end of file
diff --git a/ml.cpp b/ml.cpp
index e42e051..80bb2f7 100644
--- a/ml.cpp
+++ b/ml.cpp
@@ -1922,6 +1922,9 @@ int main(int argc, char *argv[]) {
 
 	srand(time(NULL));
 	try {
+		// performance monitor on
+		if (cmdOptionExists(argv, argv + argc, "-p")) 
+            MlPerfMon::instance().turnOn();
 		// skip loading std lib
 		if (!cmdOptionExists(argv, argv + argc, "-b")) {
 			load_std_lib(env);
@@ -1936,9 +1939,6 @@ int main(int argc, char *argv[]) {
 			std::cout << VERSION << std::endl;
 			return 0;
 		}
-		// performance monitor on
-		if (cmdOptionExists(argv, argv + argc, "-p"))
-            MlPerfMon::instance().turnOn();
 		// passed code
 		if (cmdOptionExists(argv, argv + argc, "-c")) {
 			std::vector<std::string> codes = getCmdOption(argv, argc, "-c");
diff --git a/ml_profiler.cpp b/ml_profiler.cpp
index 85fe5ac..e987d9c 100644
--- a/ml_profiler.cpp
+++ b/ml_profiler.cpp
@@ -3,10 +3,14 @@
 
 #include <iostream>
 #include <iomanip>
+#include <numeric>
+
+
+using namespace std::chrono;
 
 void MlPerfMon::turnOn() {
     perfOn = true;
-
+    start_time = std::chrono::high_resolution_clock::now();
 }
 
 void MlPerfMon::add_method_call(const std::string &method) {
@@ -22,21 +26,32 @@ void MlPerfMon::add_method_call(const std::string &method) {
 
 void MlPerfMon::print_results() {
     if (perfOn) {
-         std::cerr << std::endl << std::endl << "Call Frequency" << std::endl;
+        std::chrono::time_point<std::chrono::high_resolution_clock> end_time = std::chrono::high_resolution_clock::now();
 
         using callcount = std::pair<std::string, long>;
-
         std::vector<callcount> v(begin(calls_counter), end(calls_counter));
         std::sort(std::begin(v), std::end(v), [](const callcount& a, const callcount& b) { return a.second > b.second; });
+        long total_calls = 0;
+        for(auto const& c : v) { total_calls += c.second; }
+
+        std::cerr << std::endl << std::endl;
+        std::cerr << "perf stats" << std::endl;
+        std::cerr << "run time       : " << duration_cast<milliseconds>(end_time - start_time).count() << " ms " << std::endl;
+        std::cerr << "total calls    : " << total_calls << std::endl;
+        std::cerr << "methods called : " << calls_counter.size() << std::endl;
+        std::cerr << std::endl;
 
         int i {0};
         for(auto &p : v) {
-            // TODO when method name longer than 15 chars, here it crashes
-            p.first.insert(p.first.end(), 15 - p.first.size(), ' ');
+            if (p.first.size() >= method_name_print_len)
+                p.first.erase(method_name_print_len, std::string::npos);
+             else
+                p.first.insert(p.first.end(), method_name_print_len - p.first.size(), ' ');
+
             std::cerr << p.first << " " << p.second << std::endl;
 
             i++;
-            if (i > 10) break;
+            if (i > print_top_methods) break;
         }
 
         std::cerr << std::endl;
diff --git a/ml_profiler.h b/ml_profiler.h
index 505422a..042c780 100644
--- a/ml_profiler.h
+++ b/ml_profiler.h
@@ -3,6 +3,10 @@
 #include "ml.h"
 
 #include <unordered_map>
+#include <chrono>
+
+static const int method_name_print_len = 15;
+static const int print_top_methods = 15;
 
 class MlPerfMon {
 
@@ -25,4 +29,5 @@ public:
 private:
     bool perfOn;
     std::unordered_map<std::string, long> calls_counter;
+    std::chrono::time_point<std::chrono::high_resolution_clock> start_time;
 };