X-Git-Url: https://main.carlh.net/gitweb/?a=blobdiff_plain;f=src%2Flib%2Ftimer.cc;h=e4e7bdfdc391a412f4ef0d4c25f5c1ada4e7404c;hb=fa5f3a8bf77209da27acc33cf144e2e4500a2600;hp=7afdc394df3cfc370e824a47a218a5f34ffcabde;hpb=3828baf56467224f5d44049bf1e7a7ed11f43a05;p=dcpomatic.git

diff --git a/src/lib/timer.cc b/src/lib/timer.cc
index 7afdc394d..e4e7bdfdc 100644
--- a/src/lib/timer.cc
+++ b/src/lib/timer.cc
@@ -1,5 +1,5 @@
 /*
-    Copyright (C) 2012 Carl Hetherington <cth@carlh.net>
+    Copyright (C) 2012-2019 Carl Hetherington <cth@carlh.net>
 
     This file is part of DCP-o-matic.
 
@@ -22,14 +22,16 @@
  *  @brief Some timing classes for debugging and profiling.
  */
 
-#include <iostream>
-#include <sys/time.h>
 #include "timer.h"
 #include "util.h"
+#include "compose.hpp"
+#include <iostream>
+#include <sys/time.h>
 
 #include "i18n.h"
 
 using namespace std;
+using boost::optional;
 
 /** @param n Name to use when giving output */
 PeriodTimer::PeriodTimer (string n)
@@ -58,35 +60,77 @@ StateTimer::StateTimer (string n, string s)
 	_state = s;
 }
 
+StateTimer::StateTimer (string n)
+	: _name (n)
+{
+
+}
+
+void
+StateTimer::set (string s)
+{
+	set_internal (s);
+}
+
 /** @param s New state that the caller is in */
 void
-StateTimer::set_state (string s)
+StateTimer::set_internal (optional<string> s)
 {
 	double const last = _time;
 	struct timeval t;
 	gettimeofday (&t, 0);
 	_time = seconds (t);
 
-	if (_totals.find (s) == _totals.end ()) {
-		_totals[s] = 0;
+	if (s && _counts.find(*s) == _counts.end()) {
+		_counts[*s] = Counts();
 	}
 
-	_totals[_state] += _time - last;
+	if (_state) {
+		_counts[*_state].total_time += _time - last;
+		_counts[*_state].number++;
+	}
 	_state = s;
 }
 
+void
+StateTimer::unset ()
+{
+	set_internal (optional<string>());
+}
+
+bool compare (pair<double, string> a, pair<double, string> b)
+{
+	return a.first > b.first;
+}
+
 /** Destroy StateTimer and generate a summary of the state timings on cout */
 StateTimer::~StateTimer ()
 {
-	if (_state.empty ()) {
+	if (!_state) {
 		return;
 	}
 
+	unset ();
+
+	int longest = 0;
+	for (map<string, Counts>::iterator i = _counts.begin(); i != _counts.end(); ++i) {
+		longest = max (longest, int(i->first.length()));
+	}
+
+	list<pair<double, string> > sorted;
+
+	for (map<string, Counts>::iterator i = _counts.begin(); i != _counts.end(); ++i) {
+		string name = i->first + string(longest + 1 - i->first.size(), ' ');
+		char buffer[64];
+		snprintf (buffer, 64, "%.4f", i->second.total_time);
+		string total_time (buffer);
+		sorted.push_back (make_pair(i->second.total_time, String::compose("\t%1%2 %3 %4", name, total_time, i->second.number, (i->second.total_time / i->second.number))));
+	}
 
-	set_state (N_(""));
+	sorted.sort (compare);
 
 	cout << _name << N_(":\n");
-	for (map<string, double>::iterator i = _totals.begin(); i != _totals.end(); ++i) {
-		cout << N_("\t") << i->first << " " << i->second << N_("\n");
+	for (list<pair<double, string> >::iterator i = sorted.begin(); i != sorted.end(); ++i) {
+		cout << N_("\t") << i->second << "\n";
 	}
 }