folly/experimental/test/AutoTimerTest.cpp

   1 /*
   2  * Copyright 2016 Facebook, Inc.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *   http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16 #include <gtest/gtest.h>
  17
  18 #include <folly/experimental/AutoTimer.h>
  19
  20 using namespace folly;
  21 using namespace std;
  22
  23 struct StubLogger {
  24   void operator()(StringPiece msg, double sec) {
  25     m = msg.str();
  26     t = sec;
  27   }
  28   static std::string m;
  29   static double t;
  30 };
  31
  32 std::string StubLogger::m = "";
  33 double StubLogger::t = 0;
  34
  35 struct StubClock {
  36   typedef std::chrono::seconds duration;
  37
  38   static std::chrono::time_point<StubClock> now() {
  39     return std::chrono::time_point<StubClock>(std::chrono::duration<int>(t));
  40   }
  41   static int t;
  42 };
  43
  44 int StubClock::t = 0;
  45
  46 TEST(TestAutoTimer, HandleBasicClosure) {
  47   auto logger = [](StringPiece msg, double sec) {
  48     return StubLogger()(msg, sec);
  49   };
  50   StubClock::t = 1;
  51   // Here decltype is needed. But since most users are expected to use this
  52   // method with the default clock, template specification won't be needed even
  53   // when they use a closure. See test case HandleRealTimerClosure
  54   auto timer =
  55       makeAutoTimer<decltype(logger), StubClock>("", 0.0, std::move(logger));
  56   StubClock::t = 3;
  57   timer.log("foo");
  58   ASSERT_EQ("foo", StubLogger::m);
  59   ASSERT_EQ(2, StubLogger::t);
  60   timer.logFormat("bar {}", 5e-2);
  61   ASSERT_EQ("bar 0.05", StubLogger::m);
  62   ASSERT_EQ(0, StubLogger::t);
  63 }
  64
  65 TEST(TestAutoTimer, HandleBasic) {
  66   StubClock::t = 1;
  67   AutoTimer<StubLogger, StubClock> timer;
  68   StubClock::t = 3;
  69   timer.log("foo");
  70   ASSERT_EQ("foo", StubLogger::m);
  71   ASSERT_EQ(2, StubLogger::t);
  72   timer.logFormat("bar {}", 5e-2);
  73   ASSERT_EQ("bar 0.05", StubLogger::m);
  74   ASSERT_EQ(0, StubLogger::t);
  75 }
  76
  77 TEST(TestAutoTimer, HandleLogOnDestruct) {
  78   {
  79     StubClock::t = 0;
  80     AutoTimer<StubLogger, StubClock> timer("message");
  81     StubClock::t = 3;
  82     timer.log("foo");
  83     EXPECT_EQ("foo", StubLogger::m);
  84     EXPECT_EQ(3, StubLogger::t);
  85     StubClock::t = 5;
  86   }
  87   ASSERT_EQ("message", StubLogger::m);
  88   ASSERT_EQ(2, StubLogger::t);
  89 }
  90
  91 TEST(TestAutoTimer, HandleRealTimerClosure) {
  92   auto t = makeAutoTimer(
  93       "Third message on destruction", 0.0, [](StringPiece msg, double sec) {
  94         GoogleLogger<GoogleLoggerStyle::PRETTY>()(msg, sec);
  95       });
  96   t.log("First message");
  97   t.log("Second message");
  98 }
  99
 100 TEST(TestAutoTimer, HandleRealTimer) {
 101   AutoTimer<> t("Third message on destruction");
 102   t.log("First message");
 103   t.log("Second message");
 104 }
 105
 106 TEST(TestAutoTimer, HandleMinLogTime) {
 107   StubClock::t = 1;
 108   AutoTimer<StubLogger, StubClock> timer("", 3);
 109   StubClock::t = 3;
 110   // only 2 "seconds" have passed, so this shouldn't log
 111   StubLogger::t = 0;
 112   ASSERT_EQ(2.0, timer.log("foo"));
 113   ASSERT_EQ(0, StubLogger::t);
 114 }