blob: cdbf9ac7a6cec99f91e6a3c241b528c9b1c66113 [file] [log] [blame]
fischman@chromium.org998561e2012-01-24 07:56:41 +09001// Copyright (c) 2012 The Chromium Authors. All rights reserved.
license.botf003cfe2008-08-24 09:55:55 +09002// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
initial.commit3f4a7322008-07-27 06:49:38 +09004
5// Test of classes in the tracked_objects.h classes.
6
7#include "base/tracked_objects.h"
phajdan.jr@chromium.org6dce3c22009-06-04 00:01:29 +09008
mostynb@opera.comf29dd612013-09-04 08:29:12 +09009#include <stddef.h>
10
jar@chromium.org666ef9c2011-10-25 03:55:16 +090011#include "base/memory/scoped_ptr.h"
rsesek@chromium.org687756f2013-07-26 06:38:23 +090012#include "base/process/process_handle.h"
avi@chromium.orgb45ec932013-06-29 00:14:18 +090013#include "base/time/time.h"
mostynb@opera.comf29dd612013-09-04 08:29:12 +090014#include "base/tracking_info.h"
initial.commit3f4a7322008-07-27 06:49:38 +090015#include "testing/gtest/include/gtest/gtest.h"
16
isherman@chromium.org98c10d22012-04-13 09:39:26 +090017const int kLineNumber = 1776;
18const char kFile[] = "FixedUnitTestFileName";
19const char kWorkerThreadName[] = "WorkerThread-1";
20const char kMainThreadName[] = "SomeMainThreadName";
21const char kStillAlive[] = "Still_Alive";
22
initial.commit3f4a7322008-07-27 06:49:38 +090023namespace tracked_objects {
24
25class TrackedObjectsTest : public testing::Test {
jar@chromium.org7ad4a622011-11-07 04:14:48 +090026 protected:
jar@chromium.org4be2cb02011-11-01 07:36:21 +090027 TrackedObjectsTest() {
28 // On entry, leak any database structures in case they are still in use by
29 // prior threads.
30 ThreadData::ShutdownSingleThreadedCleanup(true);
vadimt29787df2014-09-16 04:19:38 +090031
32 test_time_ = 0;
33 ThreadData::SetAlternateTimeSource(&TrackedObjectsTest::GetTestTime);
34 ThreadData::now_function_is_time_ = true;
jar@chromium.org4be2cb02011-11-01 07:36:21 +090035 }
jar@chromium.org666ef9c2011-10-25 03:55:16 +090036
dchengca87abb2014-12-23 11:56:47 +090037 ~TrackedObjectsTest() override {
jar@chromium.org4be2cb02011-11-01 07:36:21 +090038 // We should not need to leak any structures we create, since we are
39 // single threaded, and carefully accounting for items.
40 ThreadData::ShutdownSingleThreadedCleanup(false);
41 }
jar@chromium.org7ad4a622011-11-07 04:14:48 +090042
isherman@chromium.org98c10d22012-04-13 09:39:26 +090043 // Reset the profiler state.
44 void Reset() {
45 ThreadData::ShutdownSingleThreadedCleanup(false);
vadimt29787df2014-09-16 04:19:38 +090046 test_time_ = 0;
isherman@chromium.org98c10d22012-04-13 09:39:26 +090047 }
48
49 // Simulate a birth on the thread named |thread_name|, at the given
50 // |location|.
51 void TallyABirth(const Location& location, const std::string& thread_name) {
52 // If the |thread_name| is empty, we don't initialize system with a thread
53 // name, so we're viewed as a worker thread.
54 if (!thread_name.empty())
55 ThreadData::InitializeThreadContext(kMainThreadName);
56
57 // Do not delete |birth|. We don't own it.
58 Births* birth = ThreadData::TallyABirthIfActive(location);
59
60 if (ThreadData::status() == ThreadData::DEACTIVATED)
61 EXPECT_EQ(reinterpret_cast<Births*>(NULL), birth);
62 else
63 EXPECT_NE(reinterpret_cast<Births*>(NULL), birth);
64 }
65
66 // Helper function to verify the most common test expectations.
67 void ExpectSimpleProcessData(const ProcessDataSnapshot& process_data,
68 const std::string& function_name,
69 const std::string& birth_thread,
70 const std::string& death_thread,
71 int count,
72 int run_ms,
73 int queue_ms) {
vadimtbba3ed92015-04-28 06:43:02 +090074 ASSERT_EQ(1u, process_data.phased_snapshots.size());
75 auto it = process_data.phased_snapshots.find(0);
76 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +090077 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
isherman@chromium.org98c10d22012-04-13 09:39:26 +090078
vadimt33dba1d2015-04-01 09:09:35 +090079 ASSERT_EQ(1u, process_data_phase.tasks.size());
80
81 EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name);
isherman@chromium.org98c10d22012-04-13 09:39:26 +090082 EXPECT_EQ(function_name,
vadimt33dba1d2015-04-01 09:09:35 +090083 process_data_phase.tasks[0].birth.location.function_name);
84 EXPECT_EQ(kLineNumber,
85 process_data_phase.tasks[0].birth.location.line_number);
isherman@chromium.org98c10d22012-04-13 09:39:26 +090086
vadimt33dba1d2015-04-01 09:09:35 +090087 EXPECT_EQ(birth_thread, process_data_phase.tasks[0].birth.thread_name);
isherman@chromium.org98c10d22012-04-13 09:39:26 +090088
vadimt33dba1d2015-04-01 09:09:35 +090089 EXPECT_EQ(count, process_data_phase.tasks[0].death_data.count);
isherman@chromium.org98c10d22012-04-13 09:39:26 +090090 EXPECT_EQ(count * run_ms,
vadimt33dba1d2015-04-01 09:09:35 +090091 process_data_phase.tasks[0].death_data.run_duration_sum);
92 EXPECT_EQ(run_ms, process_data_phase.tasks[0].death_data.run_duration_max);
93 EXPECT_EQ(run_ms,
94 process_data_phase.tasks[0].death_data.run_duration_sample);
isherman@chromium.org98c10d22012-04-13 09:39:26 +090095 EXPECT_EQ(count * queue_ms,
vadimt33dba1d2015-04-01 09:09:35 +090096 process_data_phase.tasks[0].death_data.queue_duration_sum);
97 EXPECT_EQ(queue_ms,
98 process_data_phase.tasks[0].death_data.queue_duration_max);
99 EXPECT_EQ(queue_ms,
100 process_data_phase.tasks[0].death_data.queue_duration_sample);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900101
vadimt33dba1d2015-04-01 09:09:35 +0900102 EXPECT_EQ(death_thread, process_data_phase.tasks[0].death_thread_name);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900103
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900104 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
jar@chromium.org7ad4a622011-11-07 04:14:48 +0900105 }
vadimt29787df2014-09-16 04:19:38 +0900106
107 // Sets time that will be returned by ThreadData::Now().
108 static void SetTestTime(unsigned int test_time) { test_time_ = test_time; }
109
110 private:
111 // Returns test time in milliseconds.
112 static unsigned int GetTestTime() { return test_time_; }
113
114 // Test time in milliseconds.
115 static unsigned int test_time_;
initial.commit3f4a7322008-07-27 06:49:38 +0900116};
117
vadimt29787df2014-09-16 04:19:38 +0900118// static
119unsigned int TrackedObjectsTest::test_time_;
120
vadimt6c709f02014-10-29 05:14:20 +0900121TEST_F(TrackedObjectsTest, TaskStopwatchNoStartStop) {
asvitkineac5567d2015-05-08 01:27:17 +0900122 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimt6c709f02014-10-29 05:14:20 +0900123
124 // Check that creating and destroying a stopwatch without starting it doesn't
125 // crash.
126 TaskStopwatch stopwatch;
127}
vadimt29787df2014-09-16 04:19:38 +0900128
darin@google.comaca48f52008-08-26 15:44:38 +0900129TEST_F(TrackedObjectsTest, MinimalStartupShutdown) {
initial.commit3f4a7322008-07-27 06:49:38 +0900130 // Minimal test doesn't even create any tasks.
asvitkineac5567d2015-05-08 01:27:17 +0900131 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
initial.commit3f4a7322008-07-27 06:49:38 +0900132
133 EXPECT_FALSE(ThreadData::first()); // No activity even on this thread.
jar@chromium.org79a58c32011-10-16 08:52:45 +0900134 ThreadData* data = ThreadData::Get();
initial.commit3f4a7322008-07-27 06:49:38 +0900135 EXPECT_TRUE(ThreadData::first()); // Now class was constructed.
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900136 ASSERT_TRUE(data);
137 EXPECT_FALSE(data->next());
jar@chromium.org79a58c32011-10-16 08:52:45 +0900138 EXPECT_EQ(data, ThreadData::Get());
initial.commit3f4a7322008-07-27 06:49:38 +0900139 ThreadData::BirthMap birth_map;
vadimtbba3ed92015-04-28 06:43:02 +0900140 ThreadData::DeathsSnapshot deaths;
vadimt498a6372015-05-02 04:13:01 +0900141 data->SnapshotMaps(0, &birth_map, &deaths);
jar@chromium.orga0260412011-12-04 16:19:10 +0900142 EXPECT_EQ(0u, birth_map.size());
vadimtbba3ed92015-04-28 06:43:02 +0900143 EXPECT_EQ(0u, deaths.size());
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900144
145 // Clean up with no leaking.
146 Reset();
initial.commit3f4a7322008-07-27 06:49:38 +0900147
148 // Do it again, just to be sure we reset state completely.
asvitkineac5567d2015-05-08 01:27:17 +0900149 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
initial.commit3f4a7322008-07-27 06:49:38 +0900150 EXPECT_FALSE(ThreadData::first()); // No activity even on this thread.
jar@chromium.org79a58c32011-10-16 08:52:45 +0900151 data = ThreadData::Get();
initial.commit3f4a7322008-07-27 06:49:38 +0900152 EXPECT_TRUE(ThreadData::first()); // Now class was constructed.
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900153 ASSERT_TRUE(data);
154 EXPECT_FALSE(data->next());
jar@chromium.org79a58c32011-10-16 08:52:45 +0900155 EXPECT_EQ(data, ThreadData::Get());
initial.commit3f4a7322008-07-27 06:49:38 +0900156 birth_map.clear();
vadimtbba3ed92015-04-28 06:43:02 +0900157 deaths.clear();
vadimt498a6372015-05-02 04:13:01 +0900158 data->SnapshotMaps(0, &birth_map, &deaths);
jar@chromium.orga0260412011-12-04 16:19:10 +0900159 EXPECT_EQ(0u, birth_map.size());
vadimtbba3ed92015-04-28 06:43:02 +0900160 EXPECT_EQ(0u, deaths.size());
initial.commit3f4a7322008-07-27 06:49:38 +0900161}
162
darin@google.comaca48f52008-08-26 15:44:38 +0900163TEST_F(TrackedObjectsTest, TinyStartupShutdown) {
asvitkineac5567d2015-05-08 01:27:17 +0900164 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
initial.commit3f4a7322008-07-27 06:49:38 +0900165
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900166 // Instigate tracking on a single tracked object, on our thread.
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900167 const char kFunction[] = "TinyStartupShutdown";
168 Location location(kFunction, kFile, kLineNumber, NULL);
vadimt498a6372015-05-02 04:13:01 +0900169 ThreadData::TallyABirthIfActive(location);
initial.commit3f4a7322008-07-27 06:49:38 +0900170
jar@chromium.orga0260412011-12-04 16:19:10 +0900171 ThreadData* data = ThreadData::first();
ajwong@chromium.org7211f7d2011-06-24 08:20:39 +0900172 ASSERT_TRUE(data);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900173 EXPECT_FALSE(data->next());
jar@chromium.org79a58c32011-10-16 08:52:45 +0900174 EXPECT_EQ(data, ThreadData::Get());
initial.commit3f4a7322008-07-27 06:49:38 +0900175 ThreadData::BirthMap birth_map;
vadimtbba3ed92015-04-28 06:43:02 +0900176 ThreadData::DeathsSnapshot deaths;
vadimt498a6372015-05-02 04:13:01 +0900177 data->SnapshotMaps(0, &birth_map, &deaths);
initial.commit3f4a7322008-07-27 06:49:38 +0900178 EXPECT_EQ(1u, birth_map.size()); // 1 birth location.
179 EXPECT_EQ(1, birth_map.begin()->second->birth_count()); // 1 birth.
vadimtbba3ed92015-04-28 06:43:02 +0900180 EXPECT_EQ(0u, deaths.size()); // No deaths.
initial.commit3f4a7322008-07-27 06:49:38 +0900181
182
jar@chromium.orgb5c974b2011-12-14 10:36:48 +0900183 // Now instigate another birth, while we are timing the run of the first
184 // execution.
jar@chromium.orgb5c974b2011-12-14 10:36:48 +0900185 // Create a child (using the same birth location).
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900186 // TrackingInfo will call TallyABirth() during construction.
vadimt29787df2014-09-16 04:19:38 +0900187 const int32 start_time = 1;
188 base::TimeTicks kBogusBirthTime = base::TimeTicks() +
189 base::TimeDelta::FromMilliseconds(start_time);
jar@chromium.orgb5c974b2011-12-14 10:36:48 +0900190 base::TrackingInfo pending_task(location, kBogusBirthTime);
vadimt29787df2014-09-16 04:19:38 +0900191 SetTestTime(1);
192 TaskStopwatch stopwatch;
vadimt6c709f02014-10-29 05:14:20 +0900193 stopwatch.Start();
jar@chromium.orgb5c974b2011-12-14 10:36:48 +0900194 // Finally conclude the outer run.
vadimt29787df2014-09-16 04:19:38 +0900195 const int32 time_elapsed = 1000;
196 SetTestTime(start_time + time_elapsed);
197 stopwatch.Stop();
198
199 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
initial.commit3f4a7322008-07-27 06:49:38 +0900200
201 birth_map.clear();
vadimtbba3ed92015-04-28 06:43:02 +0900202 deaths.clear();
vadimt498a6372015-05-02 04:13:01 +0900203 data->SnapshotMaps(0, &birth_map, &deaths);
initial.commit3f4a7322008-07-27 06:49:38 +0900204 EXPECT_EQ(1u, birth_map.size()); // 1 birth location.
205 EXPECT_EQ(2, birth_map.begin()->second->birth_count()); // 2 births.
vadimtbba3ed92015-04-28 06:43:02 +0900206 EXPECT_EQ(1u, deaths.size()); // 1 location.
207 EXPECT_EQ(1, deaths.begin()->second.death_data.count); // 1 death.
initial.commit3f4a7322008-07-27 06:49:38 +0900208
209 // The births were at the same location as the one known death.
vadimtbba3ed92015-04-28 06:43:02 +0900210 EXPECT_EQ(birth_map.begin()->second, deaths.begin()->first);
initial.commit3f4a7322008-07-27 06:49:38 +0900211
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900212 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900213 ThreadData::Snapshot(0, &process_data);
jar@chromium.orgb5c974b2011-12-14 10:36:48 +0900214
vadimtbba3ed92015-04-28 06:43:02 +0900215 ASSERT_EQ(1u, process_data.phased_snapshots.size());
216 auto it = process_data.phased_snapshots.find(0);
217 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +0900218 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
219 ASSERT_EQ(1u, process_data_phase.tasks.size());
220 EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name);
221 EXPECT_EQ(kFunction,
222 process_data_phase.tasks[0].birth.location.function_name);
223 EXPECT_EQ(kLineNumber,
224 process_data_phase.tasks[0].birth.location.line_number);
225 EXPECT_EQ(kWorkerThreadName, process_data_phase.tasks[0].birth.thread_name);
226 EXPECT_EQ(1, process_data_phase.tasks[0].death_data.count);
227 EXPECT_EQ(time_elapsed,
228 process_data_phase.tasks[0].death_data.run_duration_sum);
229 EXPECT_EQ(time_elapsed,
230 process_data_phase.tasks[0].death_data.run_duration_max);
231 EXPECT_EQ(time_elapsed,
232 process_data_phase.tasks[0].death_data.run_duration_sample);
233 EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_sum);
234 EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_max);
235 EXPECT_EQ(0, process_data_phase.tasks[0].death_data.queue_duration_sample);
236 EXPECT_EQ(kWorkerThreadName, process_data_phase.tasks[0].death_thread_name);
jar@chromium.orgb5c974b2011-12-14 10:36:48 +0900237}
238
vadimtbba3ed92015-04-28 06:43:02 +0900239TEST_F(TrackedObjectsTest, DeathDataTestRecordDeath) {
asvitkineac5567d2015-05-08 01:27:17 +0900240 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900241
242 scoped_ptr<DeathData> data(new DeathData());
243 ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
jar@chromium.orga0260412011-12-04 16:19:10 +0900244 EXPECT_EQ(data->run_duration_sum(), 0);
vadimtbba3ed92015-04-28 06:43:02 +0900245 EXPECT_EQ(data->run_duration_max(), 0);
jar@chromium.orga0260412011-12-04 16:19:10 +0900246 EXPECT_EQ(data->run_duration_sample(), 0);
247 EXPECT_EQ(data->queue_duration_sum(), 0);
vadimtbba3ed92015-04-28 06:43:02 +0900248 EXPECT_EQ(data->queue_duration_max(), 0);
jar@chromium.orga0260412011-12-04 16:19:10 +0900249 EXPECT_EQ(data->queue_duration_sample(), 0);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900250 EXPECT_EQ(data->count(), 0);
vadimtbba3ed92015-04-28 06:43:02 +0900251 EXPECT_EQ(nullptr, data->last_phase_snapshot());
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900252
isherman@chromium.org3306fc02012-03-25 07:17:18 +0900253 int32 run_ms = 42;
254 int32 queue_ms = 8;
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900255
jar@chromium.orga0260412011-12-04 16:19:10 +0900256 const int kUnrandomInt = 0; // Fake random int that ensure we sample data.
257 data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
258 EXPECT_EQ(data->run_duration_sum(), run_ms);
vadimtbba3ed92015-04-28 06:43:02 +0900259 EXPECT_EQ(data->run_duration_max(), run_ms);
jar@chromium.orga0260412011-12-04 16:19:10 +0900260 EXPECT_EQ(data->run_duration_sample(), run_ms);
261 EXPECT_EQ(data->queue_duration_sum(), queue_ms);
vadimtbba3ed92015-04-28 06:43:02 +0900262 EXPECT_EQ(data->queue_duration_max(), queue_ms);
jar@chromium.orga0260412011-12-04 16:19:10 +0900263 EXPECT_EQ(data->queue_duration_sample(), queue_ms);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900264 EXPECT_EQ(data->count(), 1);
vadimtbba3ed92015-04-28 06:43:02 +0900265 EXPECT_EQ(nullptr, data->last_phase_snapshot());
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900266
jar@chromium.orga0260412011-12-04 16:19:10 +0900267 data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
268 EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms);
vadimtbba3ed92015-04-28 06:43:02 +0900269 EXPECT_EQ(data->run_duration_max(), run_ms);
jar@chromium.orga0260412011-12-04 16:19:10 +0900270 EXPECT_EQ(data->run_duration_sample(), run_ms);
271 EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms);
vadimtbba3ed92015-04-28 06:43:02 +0900272 EXPECT_EQ(data->queue_duration_max(), queue_ms);
jar@chromium.orga0260412011-12-04 16:19:10 +0900273 EXPECT_EQ(data->queue_duration_sample(), queue_ms);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900274 EXPECT_EQ(data->count(), 2);
vadimtbba3ed92015-04-28 06:43:02 +0900275 EXPECT_EQ(nullptr, data->last_phase_snapshot());
276}
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900277
vadimtbba3ed92015-04-28 06:43:02 +0900278TEST_F(TrackedObjectsTest, DeathDataTest2Phases) {
asvitkineac5567d2015-05-08 01:27:17 +0900279 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimtbba3ed92015-04-28 06:43:02 +0900280
281 scoped_ptr<DeathData> data(new DeathData());
282 ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL));
283
284 int32 run_ms = 42;
285 int32 queue_ms = 8;
286
287 const int kUnrandomInt = 0; // Fake random int that ensure we sample data.
288 data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
289 data->RecordDeath(queue_ms, run_ms, kUnrandomInt);
290
291 data->OnProfilingPhaseCompleted(123);
292 EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms);
293 EXPECT_EQ(data->run_duration_max(), 0);
294 EXPECT_EQ(data->run_duration_sample(), run_ms);
295 EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms);
296 EXPECT_EQ(data->queue_duration_max(), 0);
297 EXPECT_EQ(data->queue_duration_sample(), queue_ms);
298 EXPECT_EQ(data->count(), 2);
299 ASSERT_NE(nullptr, data->last_phase_snapshot());
300 EXPECT_EQ(123, data->last_phase_snapshot()->profiling_phase);
301 EXPECT_EQ(2, data->last_phase_snapshot()->death_data.count);
302 EXPECT_EQ(2 * run_ms,
303 data->last_phase_snapshot()->death_data.run_duration_sum);
304 EXPECT_EQ(run_ms, data->last_phase_snapshot()->death_data.run_duration_max);
305 EXPECT_EQ(run_ms,
306 data->last_phase_snapshot()->death_data.run_duration_sample);
307 EXPECT_EQ(2 * queue_ms,
308 data->last_phase_snapshot()->death_data.queue_duration_sum);
309 EXPECT_EQ(queue_ms,
310 data->last_phase_snapshot()->death_data.queue_duration_max);
311 EXPECT_EQ(queue_ms,
312 data->last_phase_snapshot()->death_data.queue_duration_sample);
313 EXPECT_EQ(nullptr, data->last_phase_snapshot()->prev);
314
315 int32 run_ms1 = 21;
316 int32 queue_ms1 = 4;
317
318 data->RecordDeath(queue_ms1, run_ms1, kUnrandomInt);
319 EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms + run_ms1);
320 EXPECT_EQ(data->run_duration_max(), run_ms1);
321 EXPECT_EQ(data->run_duration_sample(), run_ms1);
322 EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms + queue_ms1);
323 EXPECT_EQ(data->queue_duration_max(), queue_ms1);
324 EXPECT_EQ(data->queue_duration_sample(), queue_ms1);
325 EXPECT_EQ(data->count(), 3);
326 ASSERT_NE(nullptr, data->last_phase_snapshot());
327 EXPECT_EQ(123, data->last_phase_snapshot()->profiling_phase);
328 EXPECT_EQ(2, data->last_phase_snapshot()->death_data.count);
329 EXPECT_EQ(2 * run_ms,
330 data->last_phase_snapshot()->death_data.run_duration_sum);
331 EXPECT_EQ(run_ms, data->last_phase_snapshot()->death_data.run_duration_max);
332 EXPECT_EQ(run_ms,
333 data->last_phase_snapshot()->death_data.run_duration_sample);
334 EXPECT_EQ(2 * queue_ms,
335 data->last_phase_snapshot()->death_data.queue_duration_sum);
336 EXPECT_EQ(queue_ms,
337 data->last_phase_snapshot()->death_data.queue_duration_max);
338 EXPECT_EQ(queue_ms,
339 data->last_phase_snapshot()->death_data.queue_duration_sample);
340 EXPECT_EQ(nullptr, data->last_phase_snapshot()->prev);
341}
342
343TEST_F(TrackedObjectsTest, Delta) {
asvitkineac5567d2015-05-08 01:27:17 +0900344 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimtbba3ed92015-04-28 06:43:02 +0900345
346 DeathDataSnapshot snapshot;
347 snapshot.count = 10;
348 snapshot.run_duration_sum = 100;
349 snapshot.run_duration_max = 50;
350 snapshot.run_duration_sample = 25;
351 snapshot.queue_duration_sum = 200;
352 snapshot.queue_duration_max = 101;
353 snapshot.queue_duration_sample = 26;
354
355 DeathDataSnapshot older_snapshot;
356 older_snapshot.count = 2;
357 older_snapshot.run_duration_sum = 95;
358 older_snapshot.run_duration_max = 48;
359 older_snapshot.run_duration_sample = 22;
360 older_snapshot.queue_duration_sum = 190;
361 older_snapshot.queue_duration_max = 99;
362 older_snapshot.queue_duration_sample = 21;
363
364 const DeathDataSnapshot& delta = snapshot.Delta(older_snapshot);
365 EXPECT_EQ(8, delta.count);
366 EXPECT_EQ(5, delta.run_duration_sum);
367 EXPECT_EQ(50, delta.run_duration_max);
368 EXPECT_EQ(25, delta.run_duration_sample);
369 EXPECT_EQ(10, delta.queue_duration_sum);
370 EXPECT_EQ(101, delta.queue_duration_max);
371 EXPECT_EQ(26, delta.queue_duration_sample);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900372}
373
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900374TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) {
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900375 // Start in the deactivated state.
asvitkineac5567d2015-05-08 01:27:17 +0900376 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900377
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900378 const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread";
379 Location location(kFunction, kFile, kLineNumber, NULL);
380 TallyABirth(location, std::string());
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900381
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900382 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900383 ThreadData::Snapshot(0, &process_data);
vadimt33dba1d2015-04-01 09:09:35 +0900384
vadimtbba3ed92015-04-28 06:43:02 +0900385 ASSERT_EQ(1u, process_data.phased_snapshots.size());
386
387 auto it = process_data.phased_snapshots.find(0);
388 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +0900389 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
390
vadimtbba3ed92015-04-28 06:43:02 +0900391 ASSERT_EQ(0u, process_data_phase.tasks.size());
392
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900393 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900394}
395
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900396TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) {
397 // Start in the deactivated state.
asvitkineac5567d2015-05-08 01:27:17 +0900398 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900399
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900400 const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread";
401 Location location(kFunction, kFile, kLineNumber, NULL);
402 TallyABirth(location, kMainThreadName);
403
404 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900405 ThreadData::Snapshot(0, &process_data);
vadimt33dba1d2015-04-01 09:09:35 +0900406
vadimtbba3ed92015-04-28 06:43:02 +0900407 ASSERT_EQ(1u, process_data.phased_snapshots.size());
408
409 auto it = process_data.phased_snapshots.find(0);
410 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +0900411 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
412
vadimtbba3ed92015-04-28 06:43:02 +0900413 ASSERT_EQ(0u, process_data_phase.tasks.size());
414
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900415 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900416}
417
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900418TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) {
asvitkineac5567d2015-05-08 01:27:17 +0900419 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900420
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900421 const char kFunction[] = "BirthOnlyToSnapshotWorkerThread";
422 Location location(kFunction, kFile, kLineNumber, NULL);
423 TallyABirth(location, std::string());
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900424
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900425 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900426 ThreadData::Snapshot(0, &process_data);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900427 ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName,
428 kStillAlive, 1, 0, 0);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900429}
430
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900431TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) {
asvitkineac5567d2015-05-08 01:27:17 +0900432 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900433
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900434 const char kFunction[] = "BirthOnlyToSnapshotMainThread";
435 Location location(kFunction, kFile, kLineNumber, NULL);
436 TallyABirth(location, kMainThreadName);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900437
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900438 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900439 ThreadData::Snapshot(0, &process_data);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900440 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kStillAlive,
441 1, 0, 0);
442}
443
444TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) {
asvitkineac5567d2015-05-08 01:27:17 +0900445 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900446
447 const char kFunction[] = "LifeCycleToSnapshotMainThread";
448 Location location(kFunction, kFile, kLineNumber, NULL);
449 TallyABirth(location, kMainThreadName);
450
jdduke49481fa2015-01-10 06:01:38 +0900451 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900452 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
453 // TrackingInfo will call TallyABirth() during construction.
454 base::TrackingInfo pending_task(location, kDelayedStartTime);
455 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900456
vadimt29787df2014-09-16 04:19:38 +0900457 const unsigned int kStartOfRun = 5;
458 const unsigned int kEndOfRun = 7;
459 SetTestTime(kStartOfRun);
460 TaskStopwatch stopwatch;
vadimt6c709f02014-10-29 05:14:20 +0900461 stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +0900462 SetTestTime(kEndOfRun);
463 stopwatch.Stop();
464
465 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900466
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900467 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900468 ThreadData::Snapshot(0, &process_data);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900469 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
470 kMainThreadName, 1, 2, 4);
jar@chromium.org173e3862011-10-30 12:44:25 +0900471}
472
vadimtbba3ed92015-04-28 06:43:02 +0900473TEST_F(TrackedObjectsTest, TwoPhases) {
asvitkineac5567d2015-05-08 01:27:17 +0900474 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimtbba3ed92015-04-28 06:43:02 +0900475
476 const char kFunction[] = "TwoPhases";
477 Location location(kFunction, kFile, kLineNumber, NULL);
478 TallyABirth(location, kMainThreadName);
479
480 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
481 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
482 // TrackingInfo will call TallyABirth() during construction.
483 base::TrackingInfo pending_task(location, kDelayedStartTime);
484 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
485
486 const unsigned int kStartOfRun = 5;
487 const unsigned int kEndOfRun = 7;
488 SetTestTime(kStartOfRun);
489 TaskStopwatch stopwatch;
490 stopwatch.Start();
491 SetTestTime(kEndOfRun);
492 stopwatch.Stop();
493
494 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
495
496 ThreadData::OnProfilingPhaseCompleted(0);
497
498 TallyABirth(location, kMainThreadName);
499
500 const TrackedTime kTimePosted1 = TrackedTime::FromMilliseconds(9);
501 const base::TimeTicks kDelayedStartTime1 = base::TimeTicks();
502 // TrackingInfo will call TallyABirth() during construction.
503 base::TrackingInfo pending_task1(location, kDelayedStartTime1);
504 pending_task1.time_posted = kTimePosted1; // Overwrite implied Now().
505
506 const unsigned int kStartOfRun1 = 11;
507 const unsigned int kEndOfRun1 = 21;
508 SetTestTime(kStartOfRun1);
509 TaskStopwatch stopwatch1;
510 stopwatch1.Start();
511 SetTestTime(kEndOfRun1);
512 stopwatch1.Stop();
513
514 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task1, stopwatch1);
515
516 ProcessDataSnapshot process_data;
517 ThreadData::Snapshot(1, &process_data);
518
519 ASSERT_EQ(2u, process_data.phased_snapshots.size());
520
521 auto it0 = process_data.phased_snapshots.find(0);
522 ASSERT_TRUE(it0 != process_data.phased_snapshots.end());
523 const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second;
524
525 ASSERT_EQ(1u, process_data_phase0.tasks.size());
526
527 EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name);
528 EXPECT_EQ(kFunction,
529 process_data_phase0.tasks[0].birth.location.function_name);
530 EXPECT_EQ(kLineNumber,
531 process_data_phase0.tasks[0].birth.location.line_number);
532
533 EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name);
534
535 EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count);
536 EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sum);
537 EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_max);
538 EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sample);
539 EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sum);
540 EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_max);
541 EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sample);
542
543 EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name);
544
vadimtbba3ed92015-04-28 06:43:02 +0900545 auto it1 = process_data.phased_snapshots.find(1);
546 ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
547 const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
548
549 ASSERT_EQ(1u, process_data_phase1.tasks.size());
550
551 EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name);
552 EXPECT_EQ(kFunction,
553 process_data_phase1.tasks[0].birth.location.function_name);
554 EXPECT_EQ(kLineNumber,
555 process_data_phase1.tasks[0].birth.location.line_number);
556
557 EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name);
558
559 EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count);
560 EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_sum);
561 EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_max);
562 EXPECT_EQ(10, process_data_phase1.tasks[0].death_data.run_duration_sample);
563 EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_sum);
564 EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_max);
565 EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.queue_duration_sample);
566
567 EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name);
568
vadimtbba3ed92015-04-28 06:43:02 +0900569 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
570}
571
572TEST_F(TrackedObjectsTest, ThreePhases) {
asvitkineac5567d2015-05-08 01:27:17 +0900573 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimtbba3ed92015-04-28 06:43:02 +0900574
575 const char kFunction[] = "ThreePhases";
576 Location location(kFunction, kFile, kLineNumber, NULL);
577
578 // Phase 0
579 {
580 TallyABirth(location, kMainThreadName);
581
582 // TrackingInfo will call TallyABirth() during construction.
583 SetTestTime(10);
584 base::TrackingInfo pending_task(location, base::TimeTicks());
585
586 SetTestTime(17);
587 TaskStopwatch stopwatch;
588 stopwatch.Start();
589 SetTestTime(23);
590 stopwatch.Stop();
591
592 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
593 }
594
595 ThreadData::OnProfilingPhaseCompleted(0);
596
597 // Phase 1
598 {
599 TallyABirth(location, kMainThreadName);
600
601 SetTestTime(30);
602 base::TrackingInfo pending_task(location, base::TimeTicks());
603
604 SetTestTime(35);
605 TaskStopwatch stopwatch;
606 stopwatch.Start();
607 SetTestTime(39);
608 stopwatch.Stop();
609
610 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
611 }
612
613 ThreadData::OnProfilingPhaseCompleted(1);
614
615 // Phase 2
616 {
617 TallyABirth(location, kMainThreadName);
618
619 // TrackingInfo will call TallyABirth() during construction.
620 SetTestTime(40);
621 base::TrackingInfo pending_task(location, base::TimeTicks());
622
623 SetTestTime(43);
624 TaskStopwatch stopwatch;
625 stopwatch.Start();
626 SetTestTime(45);
627 stopwatch.Stop();
628
629 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
630 }
631
632 // Snapshot and check results.
633 ProcessDataSnapshot process_data;
634 ThreadData::Snapshot(2, &process_data);
635
636 ASSERT_EQ(3u, process_data.phased_snapshots.size());
637
638 auto it0 = process_data.phased_snapshots.find(0);
639 ASSERT_TRUE(it0 != process_data.phased_snapshots.end());
640 const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second;
641
642 ASSERT_EQ(1u, process_data_phase0.tasks.size());
643
644 EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name);
645 EXPECT_EQ(kFunction,
646 process_data_phase0.tasks[0].birth.location.function_name);
647 EXPECT_EQ(kLineNumber,
648 process_data_phase0.tasks[0].birth.location.line_number);
649
650 EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name);
651
652 EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count);
653 EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_sum);
654 EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_max);
655 EXPECT_EQ(6, process_data_phase0.tasks[0].death_data.run_duration_sample);
656 EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_sum);
657 EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_max);
658 EXPECT_EQ(7, process_data_phase0.tasks[0].death_data.queue_duration_sample);
659
660 EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name);
661
vadimtbba3ed92015-04-28 06:43:02 +0900662 auto it1 = process_data.phased_snapshots.find(1);
663 ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
664 const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
665
666 ASSERT_EQ(1u, process_data_phase1.tasks.size());
667
668 EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name);
669 EXPECT_EQ(kFunction,
670 process_data_phase1.tasks[0].birth.location.function_name);
671 EXPECT_EQ(kLineNumber,
672 process_data_phase1.tasks[0].birth.location.line_number);
673
674 EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name);
675
676 EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count);
677 EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_sum);
678 EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_max);
679 EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.run_duration_sample);
680 EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_sum);
681 EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_max);
682 EXPECT_EQ(5, process_data_phase1.tasks[0].death_data.queue_duration_sample);
683
684 EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name);
685
vadimtbba3ed92015-04-28 06:43:02 +0900686 auto it2 = process_data.phased_snapshots.find(2);
687 ASSERT_TRUE(it2 != process_data.phased_snapshots.end());
688 const ProcessDataPhaseSnapshot& process_data_phase2 = it2->second;
689
690 ASSERT_EQ(1u, process_data_phase2.tasks.size());
691
692 EXPECT_EQ(kFile, process_data_phase2.tasks[0].birth.location.file_name);
693 EXPECT_EQ(kFunction,
694 process_data_phase2.tasks[0].birth.location.function_name);
695 EXPECT_EQ(kLineNumber,
696 process_data_phase2.tasks[0].birth.location.line_number);
697
698 EXPECT_EQ(kMainThreadName, process_data_phase2.tasks[0].birth.thread_name);
699
700 EXPECT_EQ(1, process_data_phase2.tasks[0].death_data.count);
701 EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_sum);
702 EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_max);
703 EXPECT_EQ(2, process_data_phase2.tasks[0].death_data.run_duration_sample);
704 EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_sum);
705 EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_max);
706 EXPECT_EQ(3, process_data_phase2.tasks[0].death_data.queue_duration_sample);
707
708 EXPECT_EQ(kMainThreadName, process_data_phase2.tasks[0].death_thread_name);
709
vadimtbba3ed92015-04-28 06:43:02 +0900710 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
711}
712
713TEST_F(TrackedObjectsTest, TwoPhasesSecondEmpty) {
asvitkineac5567d2015-05-08 01:27:17 +0900714 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimtbba3ed92015-04-28 06:43:02 +0900715
716 const char kFunction[] = "TwoPhasesSecondEmpty";
717 Location location(kFunction, kFile, kLineNumber, NULL);
718 ThreadData::InitializeThreadContext(kMainThreadName);
719
720 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
721 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
722 // TrackingInfo will call TallyABirth() during construction.
723 base::TrackingInfo pending_task(location, kDelayedStartTime);
724 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
725
726 const unsigned int kStartOfRun = 5;
727 const unsigned int kEndOfRun = 7;
728 SetTestTime(kStartOfRun);
729 TaskStopwatch stopwatch;
730 stopwatch.Start();
731 SetTestTime(kEndOfRun);
732 stopwatch.Stop();
733
734 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
735
736 ThreadData::OnProfilingPhaseCompleted(0);
737
738 ProcessDataSnapshot process_data;
739 ThreadData::Snapshot(1, &process_data);
740
741 ASSERT_EQ(2u, process_data.phased_snapshots.size());
742
743 auto it0 = process_data.phased_snapshots.find(0);
744 ASSERT_TRUE(it0 != process_data.phased_snapshots.end());
745 const ProcessDataPhaseSnapshot& process_data_phase0 = it0->second;
746
747 ASSERT_EQ(1u, process_data_phase0.tasks.size());
748
749 EXPECT_EQ(kFile, process_data_phase0.tasks[0].birth.location.file_name);
750 EXPECT_EQ(kFunction,
751 process_data_phase0.tasks[0].birth.location.function_name);
752 EXPECT_EQ(kLineNumber,
753 process_data_phase0.tasks[0].birth.location.line_number);
754
755 EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].birth.thread_name);
756
757 EXPECT_EQ(1, process_data_phase0.tasks[0].death_data.count);
758 EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sum);
759 EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_max);
760 EXPECT_EQ(2, process_data_phase0.tasks[0].death_data.run_duration_sample);
761 EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sum);
762 EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_max);
763 EXPECT_EQ(4, process_data_phase0.tasks[0].death_data.queue_duration_sample);
764
765 EXPECT_EQ(kMainThreadName, process_data_phase0.tasks[0].death_thread_name);
766
767 auto it1 = process_data.phased_snapshots.find(1);
768 ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
769 const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
770
771 ASSERT_EQ(0u, process_data_phase1.tasks.size());
772
vadimtbba3ed92015-04-28 06:43:02 +0900773 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
774}
775
776TEST_F(TrackedObjectsTest, TwoPhasesFirstEmpty) {
asvitkineac5567d2015-05-08 01:27:17 +0900777 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimtbba3ed92015-04-28 06:43:02 +0900778
779 ThreadData::OnProfilingPhaseCompleted(0);
780
781 const char kFunction[] = "TwoPhasesSecondEmpty";
782 Location location(kFunction, kFile, kLineNumber, NULL);
783 ThreadData::InitializeThreadContext(kMainThreadName);
784
785 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
786 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
787 // TrackingInfo will call TallyABirth() during construction.
788 base::TrackingInfo pending_task(location, kDelayedStartTime);
789 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
790
791 const unsigned int kStartOfRun = 5;
792 const unsigned int kEndOfRun = 7;
793 SetTestTime(kStartOfRun);
794 TaskStopwatch stopwatch;
795 stopwatch.Start();
796 SetTestTime(kEndOfRun);
797 stopwatch.Stop();
798
799 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
800
801 ProcessDataSnapshot process_data;
802 ThreadData::Snapshot(1, &process_data);
803
804 ASSERT_EQ(1u, process_data.phased_snapshots.size());
805
806 auto it1 = process_data.phased_snapshots.find(1);
807 ASSERT_TRUE(it1 != process_data.phased_snapshots.end());
808 const ProcessDataPhaseSnapshot& process_data_phase1 = it1->second;
809
810 ASSERT_EQ(1u, process_data_phase1.tasks.size());
811
812 EXPECT_EQ(kFile, process_data_phase1.tasks[0].birth.location.file_name);
813 EXPECT_EQ(kFunction,
814 process_data_phase1.tasks[0].birth.location.function_name);
815 EXPECT_EQ(kLineNumber,
816 process_data_phase1.tasks[0].birth.location.line_number);
817
818 EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].birth.thread_name);
819
820 EXPECT_EQ(1, process_data_phase1.tasks[0].death_data.count);
821 EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_sum);
822 EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_max);
823 EXPECT_EQ(2, process_data_phase1.tasks[0].death_data.run_duration_sample);
824 EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_sum);
825 EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_max);
826 EXPECT_EQ(4, process_data_phase1.tasks[0].death_data.queue_duration_sample);
827
828 EXPECT_EQ(kMainThreadName, process_data_phase1.tasks[0].death_thread_name);
829
830 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
831}
832
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900833// We will deactivate tracking after the birth, and before the death, and
834// demonstrate that the lifecycle is completely tallied. This ensures that
835// our tallied births are matched by tallied deaths (except for when the
836// task is still running, or is queued).
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900837TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) {
asvitkineac5567d2015-05-08 01:27:17 +0900838 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
jar@chromium.org173e3862011-10-30 12:44:25 +0900839
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900840 const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread";
841 Location location(kFunction, kFile, kLineNumber, NULL);
842 TallyABirth(location, kMainThreadName);
jar@chromium.org173e3862011-10-30 12:44:25 +0900843
jdduke49481fa2015-01-10 06:01:38 +0900844 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900845 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
846 // TrackingInfo will call TallyABirth() during construction.
847 base::TrackingInfo pending_task(location, kDelayedStartTime);
848 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
jar@chromium.org173e3862011-10-30 12:44:25 +0900849
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900850 // Turn off tracking now that we have births.
asvitkineac5567d2015-05-08 01:27:17 +0900851 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED);
jar@chromium.org173e3862011-10-30 12:44:25 +0900852
vadimt29787df2014-09-16 04:19:38 +0900853 const unsigned int kStartOfRun = 5;
854 const unsigned int kEndOfRun = 7;
855 SetTestTime(kStartOfRun);
856 TaskStopwatch stopwatch;
vadimt6c709f02014-10-29 05:14:20 +0900857 stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +0900858 SetTestTime(kEndOfRun);
859 stopwatch.Stop();
860
861 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900862
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900863 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900864 ThreadData::Snapshot(0, &process_data);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900865 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
866 kMainThreadName, 1, 2, 4);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900867}
868
869// We will deactivate tracking before starting a life cycle, and neither
870// the birth nor the death will be recorded.
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900871TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) {
872 // Start in the deactivated state.
asvitkineac5567d2015-05-08 01:27:17 +0900873 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900874
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900875 const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread";
876 Location location(kFunction, kFile, kLineNumber, NULL);
877 TallyABirth(location, kMainThreadName);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900878
jdduke49481fa2015-01-10 06:01:38 +0900879 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900880 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
881 // TrackingInfo will call TallyABirth() during construction.
882 base::TrackingInfo pending_task(location, kDelayedStartTime);
883 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
884
vadimt29787df2014-09-16 04:19:38 +0900885 const unsigned int kStartOfRun = 5;
886 const unsigned int kEndOfRun = 7;
887 SetTestTime(kStartOfRun);
888 TaskStopwatch stopwatch;
vadimt6c709f02014-10-29 05:14:20 +0900889 stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +0900890 SetTestTime(kEndOfRun);
891 stopwatch.Stop();
892
893 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900894
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900895 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900896 ThreadData::Snapshot(0, &process_data);
vadimt33dba1d2015-04-01 09:09:35 +0900897
vadimtbba3ed92015-04-28 06:43:02 +0900898 ASSERT_EQ(1u, process_data.phased_snapshots.size());
899
900 auto it = process_data.phased_snapshots.find(0);
901 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +0900902 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
903
vadimtbba3ed92015-04-28 06:43:02 +0900904 ASSERT_EQ(0u, process_data_phase.tasks.size());
905
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900906 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900907}
908
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900909TEST_F(TrackedObjectsTest, TwoLives) {
asvitkineac5567d2015-05-08 01:27:17 +0900910 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900911
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900912 const char kFunction[] = "TwoLives";
913 Location location(kFunction, kFile, kLineNumber, NULL);
914 TallyABirth(location, kMainThreadName);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900915
jdduke49481fa2015-01-10 06:01:38 +0900916 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900917 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
918 // TrackingInfo will call TallyABirth() during construction.
919 base::TrackingInfo pending_task(location, kDelayedStartTime);
920 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
921
vadimt29787df2014-09-16 04:19:38 +0900922 const unsigned int kStartOfRun = 5;
923 const unsigned int kEndOfRun = 7;
924 SetTestTime(kStartOfRun);
925 TaskStopwatch stopwatch;
vadimt6c709f02014-10-29 05:14:20 +0900926 stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +0900927 SetTestTime(kEndOfRun);
928 stopwatch.Stop();
929
930 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900931
932 // TrackingInfo will call TallyABirth() during construction.
933 base::TrackingInfo pending_task2(location, kDelayedStartTime);
934 pending_task2.time_posted = kTimePosted; // Overwrite implied Now().
vadimt29787df2014-09-16 04:19:38 +0900935 SetTestTime(kStartOfRun);
936 TaskStopwatch stopwatch2;
vadimt6c709f02014-10-29 05:14:20 +0900937 stopwatch2.Start();
vadimt29787df2014-09-16 04:19:38 +0900938 SetTestTime(kEndOfRun);
939 stopwatch2.Stop();
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900940
vadimt29787df2014-09-16 04:19:38 +0900941 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900942
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900943 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900944 ThreadData::Snapshot(0, &process_data);
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900945 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
946 kMainThreadName, 2, 2, 4);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900947}
948
949TEST_F(TrackedObjectsTest, DifferentLives) {
asvitkineac5567d2015-05-08 01:27:17 +0900950 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900951
952 // Use a well named thread.
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900953 ThreadData::InitializeThreadContext(kMainThreadName);
954 const char kFunction[] = "DifferentLives";
955 Location location(kFunction, kFile, kLineNumber, NULL);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900956
jdduke49481fa2015-01-10 06:01:38 +0900957 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900958 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
959 // TrackingInfo will call TallyABirth() during construction.
960 base::TrackingInfo pending_task(location, kDelayedStartTime);
961 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900962
vadimt29787df2014-09-16 04:19:38 +0900963 const unsigned int kStartOfRun = 5;
964 const unsigned int kEndOfRun = 7;
965 SetTestTime(kStartOfRun);
966 TaskStopwatch stopwatch;
vadimt6c709f02014-10-29 05:14:20 +0900967 stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +0900968 SetTestTime(kEndOfRun);
969 stopwatch.Stop();
970
971 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch);
jar@chromium.org666ef9c2011-10-25 03:55:16 +0900972
jar@chromium.org4be2cb02011-11-01 07:36:21 +0900973 const int kSecondFakeLineNumber = 999;
974 Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
975
976 // TrackingInfo will call TallyABirth() during construction.
977 base::TrackingInfo pending_task2(second_location, kDelayedStartTime);
978 pending_task2.time_posted = kTimePosted; // Overwrite implied Now().
979
isherman@chromium.org98c10d22012-04-13 09:39:26 +0900980 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +0900981 ThreadData::Snapshot(0, &process_data);
vadimt29787df2014-09-16 04:19:38 +0900982
vadimtbba3ed92015-04-28 06:43:02 +0900983 ASSERT_EQ(1u, process_data.phased_snapshots.size());
984 auto it = process_data.phased_snapshots.find(0);
985 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +0900986 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
987
988 ASSERT_EQ(2u, process_data_phase.tasks.size());
989
990 EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name);
991 EXPECT_EQ(kFunction,
992 process_data_phase.tasks[0].birth.location.function_name);
993 EXPECT_EQ(kLineNumber,
994 process_data_phase.tasks[0].birth.location.line_number);
995 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[0].birth.thread_name);
996 EXPECT_EQ(1, process_data_phase.tasks[0].death_data.count);
997 EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_sum);
998 EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_max);
999 EXPECT_EQ(2, process_data_phase.tasks[0].death_data.run_duration_sample);
1000 EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_sum);
1001 EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_max);
1002 EXPECT_EQ(4, process_data_phase.tasks[0].death_data.queue_duration_sample);
1003 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[0].death_thread_name);
1004 EXPECT_EQ(kFile, process_data_phase.tasks[1].birth.location.file_name);
1005 EXPECT_EQ(kFunction,
1006 process_data_phase.tasks[1].birth.location.function_name);
isherman@chromium.org98c10d22012-04-13 09:39:26 +09001007 EXPECT_EQ(kSecondFakeLineNumber,
vadimt33dba1d2015-04-01 09:09:35 +09001008 process_data_phase.tasks[1].birth.location.line_number);
1009 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[1].birth.thread_name);
1010 EXPECT_EQ(1, process_data_phase.tasks[1].death_data.count);
1011 EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_sum);
1012 EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_max);
1013 EXPECT_EQ(0, process_data_phase.tasks[1].death_data.run_duration_sample);
1014 EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_sum);
1015 EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_max);
1016 EXPECT_EQ(0, process_data_phase.tasks[1].death_data.queue_duration_sample);
1017 EXPECT_EQ(kStillAlive, process_data_phase.tasks[1].death_thread_name);
isherman@chromium.org98c10d22012-04-13 09:39:26 +09001018 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
initial.commit3f4a7322008-07-27 06:49:38 +09001019}
1020
vadimt29787df2014-09-16 04:19:38 +09001021TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) {
asvitkineac5567d2015-05-08 01:27:17 +09001022 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimt29787df2014-09-16 04:19:38 +09001023
1024 const char kFunction[] = "TaskWithNestedExclusion";
1025 Location location(kFunction, kFile, kLineNumber, NULL);
1026 TallyABirth(location, kMainThreadName);
1027
jdduke49481fa2015-01-10 06:01:38 +09001028 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
vadimt29787df2014-09-16 04:19:38 +09001029 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1030 // TrackingInfo will call TallyABirth() during construction.
1031 base::TrackingInfo pending_task(location, kDelayedStartTime);
1032 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
1033
1034 SetTestTime(5);
1035 TaskStopwatch task_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001036 task_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001037 {
1038 SetTestTime(8);
1039 TaskStopwatch exclusion_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001040 exclusion_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001041 SetTestTime(12);
1042 exclusion_stopwatch.Stop();
1043 }
1044 SetTestTime(15);
1045 task_stopwatch.Stop();
1046
1047 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
1048
1049 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +09001050 ThreadData::Snapshot(0, &process_data);
vadimt29787df2014-09-16 04:19:38 +09001051 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
1052 kMainThreadName, 1, 6, 4);
1053}
1054
1055TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) {
asvitkineac5567d2015-05-08 01:27:17 +09001056 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimt29787df2014-09-16 04:19:38 +09001057
1058 const char kFunction[] = "TaskWith2NestedExclusions";
1059 Location location(kFunction, kFile, kLineNumber, NULL);
1060 TallyABirth(location, kMainThreadName);
1061
jdduke49481fa2015-01-10 06:01:38 +09001062 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
vadimt29787df2014-09-16 04:19:38 +09001063 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1064 // TrackingInfo will call TallyABirth() during construction.
1065 base::TrackingInfo pending_task(location, kDelayedStartTime);
1066 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
1067
1068 SetTestTime(5);
1069 TaskStopwatch task_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001070 task_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001071 {
1072 SetTestTime(8);
1073 TaskStopwatch exclusion_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001074 exclusion_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001075 SetTestTime(12);
1076 exclusion_stopwatch.Stop();
1077
1078 SetTestTime(15);
1079 TaskStopwatch exclusion_stopwatch2;
vadimt6c709f02014-10-29 05:14:20 +09001080 exclusion_stopwatch2.Start();
vadimt29787df2014-09-16 04:19:38 +09001081 SetTestTime(18);
1082 exclusion_stopwatch2.Stop();
1083 }
1084 SetTestTime(25);
1085 task_stopwatch.Stop();
1086
1087 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
1088
1089 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +09001090 ThreadData::Snapshot(0, &process_data);
vadimt29787df2014-09-16 04:19:38 +09001091 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName,
1092 kMainThreadName, 1, 13, 4);
1093}
1094
1095TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) {
asvitkineac5567d2015-05-08 01:27:17 +09001096 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE);
vadimt29787df2014-09-16 04:19:38 +09001097
1098 const char kFunction[] = "TaskWithNestedExclusionWithNestedTask";
1099 Location location(kFunction, kFile, kLineNumber, NULL);
1100
1101 const int kSecondFakeLineNumber = 999;
1102
1103 TallyABirth(location, kMainThreadName);
1104
jdduke49481fa2015-01-10 06:01:38 +09001105 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1);
vadimt29787df2014-09-16 04:19:38 +09001106 const base::TimeTicks kDelayedStartTime = base::TimeTicks();
1107 // TrackingInfo will call TallyABirth() during construction.
1108 base::TrackingInfo pending_task(location, kDelayedStartTime);
1109 pending_task.time_posted = kTimePosted; // Overwrite implied Now().
1110
1111 SetTestTime(5);
1112 TaskStopwatch task_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001113 task_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001114 {
1115 SetTestTime(8);
1116 TaskStopwatch exclusion_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001117 exclusion_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001118 {
1119 Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL);
1120 base::TrackingInfo nested_task(second_location, kDelayedStartTime);
1121 // Overwrite implied Now().
jdduke49481fa2015-01-10 06:01:38 +09001122 nested_task.time_posted = TrackedTime::FromMilliseconds(8);
vadimt29787df2014-09-16 04:19:38 +09001123 SetTestTime(9);
1124 TaskStopwatch nested_task_stopwatch;
vadimt6c709f02014-10-29 05:14:20 +09001125 nested_task_stopwatch.Start();
vadimt29787df2014-09-16 04:19:38 +09001126 SetTestTime(11);
1127 nested_task_stopwatch.Stop();
1128 ThreadData::TallyRunOnNamedThreadIfTracking(
1129 nested_task, nested_task_stopwatch);
1130 }
1131 SetTestTime(12);
1132 exclusion_stopwatch.Stop();
1133 }
1134 SetTestTime(15);
1135 task_stopwatch.Stop();
1136
1137 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, task_stopwatch);
1138
1139 ProcessDataSnapshot process_data;
vadimtbba3ed92015-04-28 06:43:02 +09001140 ThreadData::Snapshot(0, &process_data);
vadimt29787df2014-09-16 04:19:38 +09001141
vadimtbba3ed92015-04-28 06:43:02 +09001142 ASSERT_EQ(1u, process_data.phased_snapshots.size());
1143 auto it = process_data.phased_snapshots.find(0);
1144 ASSERT_TRUE(it != process_data.phased_snapshots.end());
vadimt33dba1d2015-04-01 09:09:35 +09001145 const ProcessDataPhaseSnapshot& process_data_phase = it->second;
1146
vadimt29787df2014-09-16 04:19:38 +09001147 // The order in which the two task follow is platform-dependent.
vadimt33dba1d2015-04-01 09:09:35 +09001148 int t0 =
1149 (process_data_phase.tasks[0].birth.location.line_number == kLineNumber)
1150 ? 0
1151 : 1;
vadimt29787df2014-09-16 04:19:38 +09001152 int t1 = 1 - t0;
1153
vadimt33dba1d2015-04-01 09:09:35 +09001154 ASSERT_EQ(2u, process_data_phase.tasks.size());
1155 EXPECT_EQ(kFile, process_data_phase.tasks[t0].birth.location.file_name);
1156 EXPECT_EQ(kFunction,
1157 process_data_phase.tasks[t0].birth.location.function_name);
1158 EXPECT_EQ(kLineNumber,
1159 process_data_phase.tasks[t0].birth.location.line_number);
1160 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t0].birth.thread_name);
1161 EXPECT_EQ(1, process_data_phase.tasks[t0].death_data.count);
1162 EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_sum);
1163 EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_max);
1164 EXPECT_EQ(6, process_data_phase.tasks[t0].death_data.run_duration_sample);
1165 EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_sum);
1166 EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_max);
1167 EXPECT_EQ(4, process_data_phase.tasks[t0].death_data.queue_duration_sample);
1168 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t0].death_thread_name);
1169 EXPECT_EQ(kFile, process_data_phase.tasks[t1].birth.location.file_name);
1170 EXPECT_EQ(kFunction,
1171 process_data_phase.tasks[t1].birth.location.function_name);
vadimt29787df2014-09-16 04:19:38 +09001172 EXPECT_EQ(kSecondFakeLineNumber,
vadimt33dba1d2015-04-01 09:09:35 +09001173 process_data_phase.tasks[t1].birth.location.line_number);
1174 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t1].birth.thread_name);
1175 EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.count);
1176 EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_sum);
1177 EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_max);
1178 EXPECT_EQ(2, process_data_phase.tasks[t1].death_data.run_duration_sample);
1179 EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_sum);
1180 EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_max);
1181 EXPECT_EQ(1, process_data_phase.tasks[t1].death_data.queue_duration_sample);
1182 EXPECT_EQ(kMainThreadName, process_data_phase.tasks[t1].death_thread_name);
vadimt29787df2014-09-16 04:19:38 +09001183 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id);
1184}
1185
deanm@google.com11f192a2008-08-26 20:29:01 +09001186} // namespace tracked_objects