Home | History | Annotate | Download | only in base
      1 /*
      2  * Copyright (C) 2012 The Android Open Source Project
      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 
     17 #include "timing_logger.h"
     18 
     19 #include "common_runtime_test.h"
     20 
     21 namespace art {
     22 
     23 class TimingLoggerTest : public CommonRuntimeTest {};
     24 
     25 // TODO: Negative test cases (improper pairing of EndSplit, etc.)
     26 
     27 TEST_F(TimingLoggerTest, StartEnd) {
     28   const char* split1name = "First Split";
     29   TimingLogger logger("StartEnd", true, false);
     30   logger.StartTiming(split1name);
     31   logger.EndTiming();  // Ends split1.
     32   const auto& timings = logger.GetTimings();
     33   EXPECT_EQ(2U, timings.size());  // Start, End splits
     34   EXPECT_TRUE(timings[0].IsStartTiming());
     35   EXPECT_STREQ(timings[0].GetName(), split1name);
     36   EXPECT_TRUE(timings[1].IsEndTiming());
     37 }
     38 
     39 
     40 TEST_F(TimingLoggerTest, StartNewEnd) {
     41   const char* split1name = "First Split";
     42   const char* split2name = "Second Split";
     43   const char* split3name = "Third Split";
     44   TimingLogger logger("StartNewEnd", true, false);
     45   logger.StartTiming(split1name);
     46   logger.NewTiming(split2name);
     47   logger.NewTiming(split3name);
     48   logger.EndTiming();
     49   // Get the timings and verify that they are sane.
     50   const auto& timings = logger.GetTimings();
     51   // 6 timings in the timing logger at this point.
     52   EXPECT_EQ(6U, timings.size());
     53   EXPECT_TRUE(timings[0].IsStartTiming());
     54   EXPECT_STREQ(timings[0].GetName(), split1name);
     55   EXPECT_TRUE(timings[1].IsEndTiming());
     56   EXPECT_TRUE(timings[2].IsStartTiming());
     57   EXPECT_STREQ(timings[2].GetName(), split2name);
     58   EXPECT_TRUE(timings[3].IsEndTiming());
     59   EXPECT_TRUE(timings[4].IsStartTiming());
     60   EXPECT_STREQ(timings[4].GetName(), split3name);
     61   EXPECT_TRUE(timings[5].IsEndTiming());
     62 }
     63 
     64 TEST_F(TimingLoggerTest, StartNewEndNested) {
     65   const char* name1 = "First Split";
     66   const char* name2 = "Second Split";
     67   const char* name3 = "Third Split";
     68   const char* name4 = "Fourth Split";
     69   const char* name5 = "Fifth Split";
     70   TimingLogger logger("StartNewEndNested", true, false);
     71   logger.StartTiming(name1);
     72   logger.NewTiming(name2);  // Ends timing1.
     73   logger.StartTiming(name3);
     74   logger.StartTiming(name4);
     75   logger.NewTiming(name5);  // Ends timing4.
     76   logger.EndTiming();  // Ends timing5.
     77   logger.EndTiming();  // Ends timing3.
     78   logger.EndTiming();  // Ends timing2.
     79   const auto& timings = logger.GetTimings();
     80   EXPECT_EQ(10U, timings.size());
     81   size_t idx_1 = logger.FindTimingIndex(name1, 0);
     82   size_t idx_2 = logger.FindTimingIndex(name2, 0);
     83   size_t idx_3 = logger.FindTimingIndex(name3, 0);
     84   size_t idx_4 = logger.FindTimingIndex(name4, 0);
     85   size_t idx_5 = logger.FindTimingIndex(name5, 0);
     86   size_t idx_6 = logger.FindTimingIndex("Not found", 0);
     87   EXPECT_NE(idx_1, TimingLogger::kIndexNotFound);
     88   EXPECT_NE(idx_2, TimingLogger::kIndexNotFound);
     89   EXPECT_NE(idx_3, TimingLogger::kIndexNotFound);
     90   EXPECT_NE(idx_4, TimingLogger::kIndexNotFound);
     91   EXPECT_NE(idx_5, TimingLogger::kIndexNotFound);
     92   EXPECT_EQ(idx_6, TimingLogger::kIndexNotFound);
     93   TimingLogger::TimingData data = logger.CalculateTimingData();
     94   EXPECT_STREQ(timings[idx_1].GetName(), name1);
     95   EXPECT_STREQ(timings[idx_2].GetName(), name2);
     96   EXPECT_STREQ(timings[idx_3].GetName(), name3);
     97   EXPECT_STREQ(timings[idx_4].GetName(), name4);
     98   EXPECT_STREQ(timings[idx_5].GetName(), name5);
     99 }
    100 
    101 
    102 TEST_F(TimingLoggerTest, Scoped) {
    103   const char* outersplit = "Outer Split";
    104   const char* innersplit1 = "Inner Split 1";
    105   const char* innerinnersplit1 = "Inner Inner Split 1";
    106   const char* innersplit2 = "Inner Split 2";
    107   TimingLogger logger("Scoped", true, false);
    108   {
    109     TimingLogger::ScopedTiming outer(outersplit, &logger);
    110     {
    111       TimingLogger::ScopedTiming inner1(innersplit1, &logger);
    112       {
    113         TimingLogger::ScopedTiming innerinner1(innerinnersplit1, &logger);
    114       }  // Ends innerinnersplit1.
    115     }  // Ends innersplit1.
    116     {
    117       TimingLogger::ScopedTiming inner2(innersplit2, &logger);
    118     }  // Ends innersplit2.
    119   }  // Ends outersplit.
    120   const size_t idx_outersplit = logger.FindTimingIndex(outersplit, 0);
    121   const size_t idx_innersplit1 = logger.FindTimingIndex(innersplit1, 0);
    122   const size_t idx_innerinnersplit1 = logger.FindTimingIndex(innerinnersplit1, 0);
    123   const size_t idx_innersplit2 = logger.FindTimingIndex(innersplit2, 0);
    124   const auto& timings = logger.GetTimings();
    125   EXPECT_EQ(8U, timings.size());  // 4 start timings and 4 end timings.
    126   EXPECT_GE(timings[idx_innerinnersplit1].GetTime(), timings[idx_innersplit1].GetTime());
    127   EXPECT_GE(timings[idx_innersplit2].GetTime(), timings[idx_innersplit1].GetTime());
    128   TimingLogger::TimingData data(logger.CalculateTimingData());
    129   EXPECT_GE(data.GetTotalTime(idx_outersplit), data.GetTotalTime(idx_innerinnersplit1));
    130   EXPECT_GE(data.GetTotalTime(idx_outersplit),
    131             data.GetTotalTime(idx_innersplit1) + data.GetTotalTime(idx_innersplit2));
    132   EXPECT_GE(data.GetTotalTime(idx_innersplit1), data.GetTotalTime(idx_innerinnersplit1));
    133 }
    134 
    135 
    136 TEST_F(TimingLoggerTest, ScopedAndExplicit) {
    137   const char* outersplit = "Outer Split";
    138   const char* innersplit = "Inner Split";
    139   const char* innerinnersplit1 = "Inner Inner Split 1";
    140   const char* innerinnersplit2 = "Inner Inner Split 2";
    141   TimingLogger logger("Scoped", true, false);
    142   logger.StartTiming(outersplit);
    143   {
    144     TimingLogger::ScopedTiming inner(innersplit, &logger);
    145     logger.StartTiming(innerinnersplit1);
    146     logger.NewTiming(innerinnersplit2);  // Ends innerinnersplit1.
    147     logger.EndTiming();
    148   }  // Ends innerinnersplit2, then innersplit.
    149   logger.EndTiming();  // Ends outersplit.
    150   const size_t idx_outersplit = logger.FindTimingIndex(outersplit, 0);
    151   const size_t idx_innersplit = logger.FindTimingIndex(innersplit, 0);
    152   const size_t idx_innerinnersplit1 = logger.FindTimingIndex(innerinnersplit1, 0);
    153   const size_t idx_innerinnersplit2 = logger.FindTimingIndex(innerinnersplit2, 0);
    154   const auto& timings = logger.GetTimings();
    155   EXPECT_EQ(8U, timings.size());
    156   EXPECT_LE(timings[idx_outersplit].GetTime(), timings[idx_innersplit].GetTime());
    157   EXPECT_LE(timings[idx_innersplit].GetTime(), timings[idx_innerinnersplit1].GetTime());
    158   EXPECT_LE(timings[idx_innerinnersplit1].GetTime(), timings[idx_innerinnersplit2].GetTime());
    159 }
    160 
    161 }  // namespace art
    162