Merge pull request #136 from kloudkl/cuda_timing

Add Timer class unifying CPU and GPU timer and use it in net_speed_benchmark

2 files changed, 249 insertions, 0 deletions

diff --git a/src/caffe/test/test_benchmark.cpp b/src/caffe/test/test_benchmark.cpp
new file mode 100644
index 00000000..e8e3a116
--- /dev/null
+++ b/src/caffe/test/test_benchmark.cpp
@@ -0,0 +1,169 @@
+// Copyright 2014 kloud@github
+
+#include <unistd.h>  // for usleep
+#include <cuda_runtime.h>
+#include <gtest/gtest.h>
+
+#include "caffe/common.hpp"
+#include "caffe/util/benchmark.hpp"
+#include "caffe/test/test_caffe_main.hpp"
+
+namespace caffe {
+
+extern cudaDeviceProp CAFFE_TEST_CUDA_PROP;
+
+class BenchmarkTest : public ::testing::Test {};
+
+TEST_F(BenchmarkTest, TestTimerConstructorCPU) {
+  Caffe::set_mode(Caffe::CPU);
+  Timer timer;
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerConstructorGPU) {
+  Caffe::set_mode(Caffe::GPU);
+  Timer timer;
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerStartCPU) {
+  Caffe::set_mode(Caffe::CPU);
+  Timer timer;
+  timer.Start();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_TRUE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+  timer.Start();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_TRUE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+  timer.Stop();
+  timer.Start();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_TRUE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerStartGPU) {
+  Caffe::set_mode(Caffe::GPU);
+  Timer timer;
+  timer.Start();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_TRUE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+  timer.Stop();
+  timer.Start();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_TRUE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+  timer.Start();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_TRUE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerStopCPU) {
+  Caffe::set_mode(Caffe::CPU);
+  Timer timer;
+  timer.Stop();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+  timer.Start();
+  timer.Stop();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+  timer.Stop();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerStopGPU) {
+  Caffe::set_mode(Caffe::GPU);
+  Timer timer;
+  timer.Stop();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+  timer.Start();
+  timer.Stop();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+  timer.Stop();
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerMilliSecondsCPU) {
+  Caffe::set_mode(Caffe::CPU);
+  Timer timer;
+  CHECK_EQ(timer.MilliSeconds(), 0);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+  timer.Start();
+  usleep(300 * 1000);
+  CHECK_GE(timer.MilliSeconds(), 299);
+  CHECK_LE(timer.MilliSeconds(), 301);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerMilliSecondsGPU) {
+  Caffe::set_mode(Caffe::GPU);
+  Timer timer;
+  CHECK_EQ(timer.MilliSeconds(), 0);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+  timer.Start();
+  usleep(300 * 1000);
+  CHECK_GE(timer.MilliSeconds(), 299);
+  CHECK_LE(timer.MilliSeconds(), 301);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerSecondsCPU) {
+  Caffe::set_mode(Caffe::CPU);
+  Timer timer;
+  CHECK_EQ(timer.Seconds(), 0);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+  timer.Start();
+  usleep(300 * 1000);
+  CHECK_GE(timer.Seconds(), 0.299);
+  CHECK_LE(timer.Seconds(), 0.301);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+TEST_F(BenchmarkTest, TestTimerSecondsGPU) {
+  Caffe::set_mode(Caffe::GPU);
+  Timer timer;
+  CHECK_EQ(timer.Seconds(), 0);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_FALSE(timer.has_run_at_least_once());
+  timer.Start();
+  usleep(300 * 1000);
+  CHECK_GE(timer.Seconds(), 0.299);
+  CHECK_LE(timer.Seconds(), 0.301);
+  EXPECT_TRUE(timer.initted());
+  EXPECT_FALSE(timer.running());
+  EXPECT_TRUE(timer.has_run_at_least_once());
+}
+
+}  // namespace caffe
diff --git a/src/caffe/util/benchmark.cpp b/src/caffe/util/benchmark.cpp
new file mode 100644
index 00000000..21c38ad3
--- /dev/null
+++ b/src/caffe/util/benchmark.cpp
@@ -0,0 +1,80 @@
+// Copyright 2014 kloud@github
+
+#include <boost/date_time/posix_time/posix_time.hpp>
+#include <cuda_runtime.h>
+
+#include "caffe/common.hpp"
+#include "caffe/util/benchmark.hpp"
+
+namespace caffe {
+
+Timer::Timer()
+    : initted_(false),
+      running_(false),
+      has_run_at_least_once_(false) {
+  Init();
+}
+
+Timer::~Timer() {
+  if (Caffe::mode() == Caffe::GPU) {
+    CUDA_CHECK(cudaEventDestroy(start_gpu_));
+    CUDA_CHECK(cudaEventDestroy(stop_gpu_));
+  }
+}
+
+void Timer::Start() {
+  if (!running()) {
+    if (Caffe::mode() == Caffe::GPU) {
+      CUDA_CHECK(cudaEventRecord(start_gpu_, 0));
+    } else {
+      start_cpu_ = boost::posix_time::microsec_clock::local_time();
+    }
+    running_ = true;
+    has_run_at_least_once_ = true;
+  }
+}
+
+void Timer::Stop() {
+  if (running()) {
+    if (Caffe::mode() == Caffe::GPU) {
+      CUDA_CHECK(cudaEventRecord(stop_gpu_, 0));
+      CUDA_CHECK(cudaEventSynchronize(stop_gpu_));
+    } else {
+      stop_cpu_ = boost::posix_time::microsec_clock::local_time();
+    }
+    running_ = false;
+  }
+}
+
+float Timer::MilliSeconds() {
+  if (!has_run_at_least_once()) {
+    LOG(WARNING) << "Timer has never been run before reading time.";
+    return 0;
+  }
+  if (running()) {
+    Stop();
+  }
+  if (Caffe::mode() == Caffe::GPU) {
+    CUDA_CHECK(cudaEventElapsedTime(&elapsed_milliseconds_, start_gpu_,
+                                    stop_gpu_));
+  } else {
+    elapsed_milliseconds_ = (stop_cpu_ - start_cpu_).total_milliseconds();
+  }
+  return elapsed_milliseconds_;
+}
+
+float Timer::Seconds() {
+  return MilliSeconds() / 1000.;
+}
+
+void Timer::Init() {
+  if (!initted()) {
+    if (Caffe::mode() == Caffe::GPU) {
+      CUDA_CHECK(cudaEventCreate(&start_gpu_));
+      CUDA_CHECK(cudaEventCreate(&stop_gpu_));
+    }
+    initted_ = true;
+  }
+}
+
+}  // namespace caffe