14446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum/* 24446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * Copyright (C) 2012 The Android Open Source Project 34446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * 44446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * Licensed under the Apache License, Version 2.0 (the "License"); 54446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * you may not use this file except in compliance with the License. 64446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * You may obtain a copy of the License at 74446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * 84446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * http://www.apache.org/licenses/LICENSE-2.0 94446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * 104446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * Unless required by applicable law or agreed to in writing, software 114446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * distributed under the License is distributed on an "AS IS" BASIS, 124446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 134446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * See the License for the specific language governing permissions and 144446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum * limitations under the License. 154446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum */ 164446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 174446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum#include "timing_logger.h" 184446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 19a1ce1fef2d49d1d537776a5308ace7102a815fe5Brian Carlstrom#include "common_runtime_test.h" 204446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 214446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloumnamespace art { 224446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 23a1ce1fef2d49d1d537776a5308ace7102a815fe5Brian Carlstromclass TimingLoggerTest : public CommonRuntimeTest {}; 244446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 254446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum// TODO: Negative test cases (improper pairing of EndSplit, etc.) 264446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 274446ab9e70dde779d97f451c4904f6b8770232bdAnwar GhuloumTEST_F(TimingLoggerTest, StartEnd) { 284446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* split1name = "First Split"; 29f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger logger("StartEnd", true, false); 30f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(split1name); 31f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); // Ends split1. 32f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const auto& timings = logger.GetTimings(); 33f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_EQ(2U, timings.size()); // Start, End splits 34f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[0].IsStartTiming()); 35f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[0].GetName(), split1name); 36f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[1].IsEndTiming()); 374446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum} 384446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 394446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 404446ab9e70dde779d97f451c4904f6b8770232bdAnwar GhuloumTEST_F(TimingLoggerTest, StartNewEnd) { 414446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* split1name = "First Split"; 424446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* split2name = "Second Split"; 434446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* split3name = "Third Split"; 44f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger logger("StartNewEnd", true, false); 45f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(split1name); 46f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.NewTiming(split2name); 47f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.NewTiming(split3name); 48f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); 49f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier // Get the timings and verify that they are sane. 50f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const auto& timings = logger.GetTimings(); 51f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier // 6 timings in the timing logger at this point. 52f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_EQ(6U, timings.size()); 53f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[0].IsStartTiming()); 54f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[0].GetName(), split1name); 55f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[1].IsEndTiming()); 56f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[2].IsStartTiming()); 57f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[2].GetName(), split2name); 58f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[3].IsEndTiming()); 59f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[4].IsStartTiming()); 60f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[4].GetName(), split3name); 61f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_TRUE(timings[5].IsEndTiming()); 624446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum} 634446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 644446ab9e70dde779d97f451c4904f6b8770232bdAnwar GhuloumTEST_F(TimingLoggerTest, StartNewEndNested) { 65f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const char* name1 = "First Split"; 66f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const char* name2 = "Second Split"; 67f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const char* name3 = "Third Split"; 68f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const char* name4 = "Fourth Split"; 69f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const char* name5 = "Fifth Split"; 70f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger logger("StartNewEndNested", true, false); 71f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(name1); 72f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.NewTiming(name2); // Ends timing1. 73f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(name3); 74f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(name4); 75f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.NewTiming(name5); // Ends timing4. 76f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); // Ends timing5. 77f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); // Ends timing3. 78f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); // Ends timing2. 79f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const auto& timings = logger.GetTimings(); 80f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_EQ(10U, timings.size()); 81f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier size_t idx_1 = logger.FindTimingIndex(name1, 0); 82f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier size_t idx_2 = logger.FindTimingIndex(name2, 0); 83f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier size_t idx_3 = logger.FindTimingIndex(name3, 0); 84f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier size_t idx_4 = logger.FindTimingIndex(name4, 0); 85f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier size_t idx_5 = logger.FindTimingIndex(name5, 0); 86f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier size_t idx_6 = logger.FindTimingIndex("Not found", 0); 87f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_NE(idx_1, TimingLogger::kIndexNotFound); 88f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_NE(idx_2, TimingLogger::kIndexNotFound); 89f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_NE(idx_3, TimingLogger::kIndexNotFound); 90f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_NE(idx_4, TimingLogger::kIndexNotFound); 91f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_NE(idx_5, TimingLogger::kIndexNotFound); 92f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_EQ(idx_6, TimingLogger::kIndexNotFound); 93f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::TimingData data = logger.CalculateTimingData(); 94f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[idx_1].GetName(), name1); 95f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[idx_2].GetName(), name2); 96f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[idx_3].GetName(), name3); 97f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[idx_4].GetName(), name4); 98f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_STREQ(timings[idx_5].GetName(), name5); 994446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum} 1004446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 1014446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 1024446ab9e70dde779d97f451c4904f6b8770232bdAnwar GhuloumTEST_F(TimingLoggerTest, Scoped) { 1034446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* outersplit = "Outer Split"; 1044446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* innersplit1 = "Inner Split 1"; 1054446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* innerinnersplit1 = "Inner Inner Split 1"; 1064446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* innersplit2 = "Inner Split 2"; 107f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger logger("Scoped", true, false); 1084446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum { 109f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::ScopedTiming outer(outersplit, &logger); 110f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier { 111f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::ScopedTiming inner1(innersplit1, &logger); 1124446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum { 113f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::ScopedTiming innerinner1(innerinnersplit1, &logger); 114f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier } // Ends innerinnersplit1. 115f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier } // Ends innersplit1. 116f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier { 117f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::ScopedTiming inner2(innersplit2, &logger); 118f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier } // Ends innersplit2. 1194446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum } // Ends outersplit. 120f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_outersplit = logger.FindTimingIndex(outersplit, 0); 121f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_innersplit1 = logger.FindTimingIndex(innersplit1, 0); 122f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_innerinnersplit1 = logger.FindTimingIndex(innerinnersplit1, 0); 123f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_innersplit2 = logger.FindTimingIndex(innersplit2, 0); 124f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const auto& timings = logger.GetTimings(); 125f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_EQ(8U, timings.size()); // 4 start timings and 4 end timings. 126f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_GE(timings[idx_innerinnersplit1].GetTime(), timings[idx_innersplit1].GetTime()); 127f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_GE(timings[idx_innersplit2].GetTime(), timings[idx_innersplit1].GetTime()); 128f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::TimingData data(logger.CalculateTimingData()); 129f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_GE(data.GetTotalTime(idx_outersplit), data.GetTotalTime(idx_innerinnersplit1)); 130f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_GE(data.GetTotalTime(idx_outersplit), 131f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier data.GetTotalTime(idx_innersplit1) + data.GetTotalTime(idx_innersplit2)); 132f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_GE(data.GetTotalTime(idx_innersplit1), data.GetTotalTime(idx_innerinnersplit1)); 1334446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum} 1344446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 1354446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 1364446ab9e70dde779d97f451c4904f6b8770232bdAnwar GhuloumTEST_F(TimingLoggerTest, ScopedAndExplicit) { 1374446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* outersplit = "Outer Split"; 1384446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* innersplit = "Inner Split"; 1394446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* innerinnersplit1 = "Inner Inner Split 1"; 1404446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum const char* innerinnersplit2 = "Inner Inner Split 2"; 141f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger logger("Scoped", true, false); 142f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(outersplit); 1434446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum { 144f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier TimingLogger::ScopedTiming inner(innersplit, &logger); 145f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.StartTiming(innerinnersplit1); 146f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.NewTiming(innerinnersplit2); // Ends innerinnersplit1. 147f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); 1484446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum } // Ends innerinnersplit2, then innersplit. 149f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier logger.EndTiming(); // Ends outersplit. 150f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_outersplit = logger.FindTimingIndex(outersplit, 0); 151f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_innersplit = logger.FindTimingIndex(innersplit, 0); 152f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_innerinnersplit1 = logger.FindTimingIndex(innerinnersplit1, 0); 153f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const size_t idx_innerinnersplit2 = logger.FindTimingIndex(innerinnersplit2, 0); 154f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier const auto& timings = logger.GetTimings(); 155f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_EQ(8U, timings.size()); 156f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_LE(timings[idx_outersplit].GetTime(), timings[idx_innersplit].GetTime()); 157f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_LE(timings[idx_innersplit].GetTime(), timings[idx_innerinnersplit1].GetTime()); 158f5997b4d3f889569d5a2b724d83d764bfbb8d106Mathieu Chartier EXPECT_LE(timings[idx_innerinnersplit1].GetTime(), timings[idx_innerinnersplit2].GetTime()); 1594446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum} 1604446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum 1614446ab9e70dde779d97f451c4904f6b8770232bdAnwar Ghuloum} // namespace art 162