X-Git-Url: https://git.lyx.org/gitweb/?a=blobdiff_plain;f=src%2Fsupport%2Fpmprof.h;h=fb926708f87af07d78f2dfc24378b916e2b6a623;hb=7b0f9d95248820bc70b820dd6b558de4a6713bae;hp=7cd2efcbfbfc1a349c5473d41992edee68f053c3;hpb=7d698b43a808b0951537a8d115e0a0c83b233ce2;p=lyx.git

diff --git a/src/support/pmprof.h b/src/support/pmprof.h
index 7cd2efcbfb..fb926708f8 100644
--- a/src/support/pmprof.h
+++ b/src/support/pmprof.h
@@ -8,13 +8,8 @@
  * Full author contact details are available in file CREDITS.
  */
 
-#ifndef PMPROF_H
-#define PMPROF_H
-
-#include <sys/time.h>
-#include <iostream>
-
-/** How to use this trivial profiler:
+/**
+ * ==== HOW TO USE THIS TRIVIAL PROFILER:
  *
  * * at the beginning of the interesting block, just add:
  *   PROFILE_THIS_BLOCK(some_identifier)
@@ -23,7 +18,21 @@
  *
  * * when the program ends, statistics will be sent to standard error, like:
  *
- *   ##### some_identifier: 6.48475usec, count=25405
+ *   #pmprof# some_identifier: 6.51usec, count=7120, total=46.33msec
+ *
+ * * It is also possible to profile caching schemes. All it takes is an additional
+ *   PROFILE_CACHE_MISS(some_identifier)
+ *   in the place that takes care of cache misses. Then the output at the end will change to
+ *
+ *   #pmprof# some_identifier: 6.51usec, count=7120, total=46.33msec
+ *      hit: 96%, 4.36usec, count=6849, total=29.89msec
+ *     miss: 3%, 60.65usec, count=271, total=16.43msec
+ *
+ * * if DISABLE_PMPROF is defined before including pmprof.h, the
+ *   profiler is replaced by empty macros. This is useful for quickly
+ *   checking the overhead.
+ *
+ * ==== ABOUT PROFILING SCOPE:
  *
  * The code measured by the profiler corresponds to the lifetime of a
  * local variable declared by the PROFILE_THIS_BLOCK macro.
@@ -92,33 +101,92 @@
 
  */
 
+#ifndef PMPROF_H
+#define PMPROF_H
+
+#if defined(DISABLE_PMPROF)
+
+// Make pmprof an empty shell
+#define PROFILE_THIS_BLOCK(a)
+#define PROFILE_CACHE_MISS(a)
+
+#else
+
+#include <chrono>
+#include <iomanip>
+#include <iostream>
+
+
+//#if defined(__GNUG__) && defined(_GLIBCXX_DEBUG)
+//#error Profiling is not usable when run-time debugging is in effect
+//#endif
+
+namespace {
+
+void dumpTime(std::chrono::duration<double> value)
+{
+	double const val = value.count();
+	std::cerr << std::fixed << std::setprecision(2);
+	if (val >= 1.0)
+	 	std::cerr << val << " s";
+	else if (val >= 0.001)
+		std::cerr << val * 1000 << " ms";
+	else
+	 	std::cerr << val * 1000000 << " us";
+}
+
+void dump(std::chrono::duration<double> total, unsigned long long count) {
+	dumpTime(total / count);
+	std::cerr << ", count=" << count
+			  << ", total=";
+	dumpTime(total);
+	std::cerr << std::endl;
+}
+
+} // namespace
+
 
 /* Helper class for gathering data. Instantiate this as a static
  * variable, so that its destructor will be executed when the program
  * ends.
  */
+
+
 class PMProfStat {
 public:
-	PMProfStat(char const * name)
-	  : name_(name), sec_(0), usec_(0), count_(0) {};
+	PMProfStat(char const * name) : name_(name), count_(0), miss_count_(0) {}
 
 	~PMProfStat() {
-		if (count_>0)
-		  std::cerr << "##### " << name_ << ": "
-			    << 1.0 * (sec_ * 1000000 + usec_)/ count_
-			    << "usec, count=" << count_ << std::endl;
+		if (count_>0) {
+			if (miss_count_ == 0) {
+				std::cerr << "#pmprof# " << name_ << ": ";
+				dump(dur_, count_);
+			}
+			else {
+				std::cerr << "#pmprof# " << name_ << ": ";
+				dump(dur_ + miss_dur_, count_ + miss_count_);
+				std::cerr << "   hit: " << 100 * count_ / (count_ + miss_count_) << "%, ";
+				dump(dur_, count_);
+				std::cerr << "  miss: " << 100 * miss_count_ / (count_ + miss_count_) << "%, ";
+				dump(miss_dur_, miss_count_);
+			}
+		}
 	}
 
-	void add(const long long s, const long long u) {
-		sec_ += s;
-		usec_ += u;
-		count_++;
+	void add(std::chrono::duration<double> d, const bool hit) {
+		if (hit) {
+			dur_ += d;
+			count_++;
+		} else {
+			miss_dur_ += d;
+			miss_count_++;
+		}
 	}
 
 private:
 	char const * name_;
-	long long sec_, usec_;
-	unsigned long long count_;
+	std::chrono::duration<double> dur_, miss_dur_;
+	unsigned long long count_, miss_count_;
 };
 
 
@@ -129,19 +197,19 @@ private:
  */
 class PMProfInstance {
 public:
-	PMProfInstance(PMProfStat * stat) : stat_(stat)
+	PMProfInstance(PMProfStat * stat) : hit(true), stat_(stat)
 	{
-		gettimeofday(&before_, 0);
+		before_ = std::chrono::system_clock::now();
 	}
 
 	~PMProfInstance() {
-		gettimeofday(&after_, 0);
-		stat_->add(after_.tv_sec - before_.tv_sec,
-			   after_.tv_usec - before_.tv_usec);
+		stat_->add(std::chrono::system_clock::now() - before_, hit);
 	}
 
+	bool hit;
+
 private:
-	timeval before_, after_;
+	std::chrono::system_clock::time_point before_;
 	PMProfStat * stat_;
 };
 
@@ -150,5 +218,9 @@ private:
 	static PMProfStat PMPS_##a(#a);\
 	PMProfInstance PMPI_##a(&PMPS_##a);
 
+#define PROFILE_CACHE_MISS(a) \
+	PMPI_##a.hit = false;
+
+#endif // !defined(DISABLE_PMPROF)
 
 #endif