Expand reporting of timing information.
1. Add an ExecutionSummary object to record execution
information about Ceres objects.
2. Add an EventLogger object to log events in a function call.
3. Add a ScopedExecutionTimer object to log times in ExecutionSummary.
4. Instrument ProgramEvaluator and all the linear solvers
to report their timing statistics.
5. Connect the timing statistics to Summary::FullReport.
6. Add high precision timer on unix systems using
gettimeofday() call.
7. Various minor clean ups all around.
Change-Id: I5e09804b730b09535484124be7dbc1c58eccd1d4
diff --git a/internal/ceres/wall_time.cc b/internal/ceres/wall_time.cc
index 0dce19f..8dc4e1f 100644
--- a/internal/ceres/wall_time.cc
+++ b/internal/ceres/wall_time.cc
@@ -28,12 +28,20 @@
//
// Author: strandmark@google.com (Petter Strandmark)
+#include "ceres/wall_time.h"
+
#ifdef CERES_USE_OPENMP
#include <omp.h>
#else
#include <ctime>
#endif
+#ifdef _WIN32
+#include <windows.h>
+#else
+#include <sys/time.h>
+#endif
+
namespace ceres {
namespace internal {
@@ -41,8 +49,47 @@
#ifdef CERES_USE_OPENMP
return omp_get_wtime();
#else
+#ifdef _WIN32
return static_cast<double>(std::time(NULL));
+#else
+ timeval time_val;
+ gettimeofday(&time_val, NULL);
+ return (time_val.tv_sec + time_val.tv_usec * 1e-6);
#endif
+#endif
+}
+
+EventLogger::EventLogger(const string& logger_name)
+ : start_time_(WallTimeInSeconds()),
+ last_event_time_(start_time_),
+ events_("") {
+ StringAppendF(&events_,
+ "\n%s\n Delta Cumulative\n",
+ logger_name.c_str());
+}
+
+EventLogger::~EventLogger() {
+ if (VLOG_IS_ON(3)) {
+ AddEvent("Total");
+ VLOG(2) << "\n" << events_ << "\n";
+ }
+}
+
+void EventLogger::AddEvent(const string& event_name) {
+ if (!VLOG_IS_ON(3)) {
+ return;
+ }
+
+ const double current_time = WallTimeInSeconds();
+ const double relative_time_delta = current_time - last_event_time_;
+ const double absolute_time_delta = current_time - start_time_;
+ last_event_time_ = current_time;
+
+ StringAppendF(&events_,
+ " %25s : %5.3e %5.3e\n",
+ event_name.c_str(),
+ relative_time_delta,
+ absolute_time_delta);
}
} // namespace internal
