| OLD | NEW |
|---|
| (Empty) |
| 1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | |
| 2 // Use of this source code is governed by a BSD-style license that can be | |
| 3 // found in the LICENSE file. | |
| 4 | |
| 5 // Test of classes in the tracked_objects.h classes. | |
| 6 | |
| 7 #include "base/tracked_objects.h" | |
| 8 | |
| 9 #include <stddef.h> | |
| 10 | |
| 11 #include "base/memory/scoped_ptr.h" | |
| 12 #include "base/process/process_handle.h" | |
| 13 #include "base/time/time.h" | |
| 14 #include "base/tracking_info.h" | |
| 15 #include "testing/gtest/include/gtest/gtest.h" | |
| 16 | |
| 17 const int kLineNumber = 1776; | |
| 18 const char kFile[] = "FixedUnitTestFileName"; | |
| 19 const char kWorkerThreadName[] = "WorkerThread-1"; | |
| 20 const char kMainThreadName[] = "SomeMainThreadName"; | |
| 21 const char kStillAlive[] = "Still_Alive"; | |
| 22 | |
| 23 namespace tracked_objects { | |
| 24 | |
| 25 class TrackedObjectsTest : public testing::Test { | |
| 26 protected: | |
| 27 TrackedObjectsTest() { | |
| 28 // On entry, leak any database structures in case they are still in use by | |
| 29 // prior threads. | |
| 30 ThreadData::ShutdownSingleThreadedCleanup(true); | |
| 31 | |
| 32 test_time_ = 0; | |
| 33 ThreadData::SetAlternateTimeSource(&TrackedObjectsTest::GetTestTime); | |
| 34 ThreadData::now_function_is_time_ = true; | |
| 35 } | |
| 36 | |
| 37 ~TrackedObjectsTest() override { | |
| 38 // 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 } | |
| 42 | |
| 43 // Reset the profiler state. | |
| 44 void Reset() { | |
| 45 ThreadData::ShutdownSingleThreadedCleanup(false); | |
| 46 test_time_ = 0; | |
| 47 } | |
| 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) { | |
| 74 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()); | |
| 77 const ProcessDataPhaseSnapshot& process_data_phase = it->second; | |
| 78 | |
| 79 ASSERT_EQ(1u, process_data_phase.tasks.size()); | |
| 80 | |
| 81 EXPECT_EQ(kFile, process_data_phase.tasks[0].birth.location.file_name); | |
| 82 EXPECT_EQ(function_name, | |
| 83 process_data_phase.tasks[0].birth.location.function_name); | |
| 84 EXPECT_EQ(kLineNumber, | |
| 85 process_data_phase.tasks[0].birth.location.line_number); | |
| 86 | |
| 87 EXPECT_EQ(birth_thread, process_data_phase.tasks[0].birth.thread_name); | |
| 88 | |
| 89 EXPECT_EQ(count, process_data_phase.tasks[0].death_data.count); | |
| 90 EXPECT_EQ(count * run_ms, | |
| 91 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); | |
| 95 EXPECT_EQ(count * queue_ms, | |
| 96 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); | |
| 101 | |
| 102 EXPECT_EQ(death_thread, process_data_phase.tasks[0].death_thread_name); | |
| 103 | |
| 104 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 105 } | |
| 106 | |
| 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_; | |
| 116 }; | |
| 117 | |
| 118 // static | |
| 119 unsigned int TrackedObjectsTest::test_time_; | |
| 120 | |
| 121 TEST_F(TrackedObjectsTest, TaskStopwatchNoStartStop) { | |
| 122 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 123 | |
| 124 // Check that creating and destroying a stopwatch without starting it doesn't | |
| 125 // crash. | |
| 126 TaskStopwatch stopwatch; | |
| 127 } | |
| 128 | |
| 129 TEST_F(TrackedObjectsTest, MinimalStartupShutdown) { | |
| 130 // Minimal test doesn't even create any tasks. | |
| 131 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 132 | |
| 133 EXPECT_FALSE(ThreadData::first()); // No activity even on this thread. | |
| 134 ThreadData* data = ThreadData::Get(); | |
| 135 EXPECT_TRUE(ThreadData::first()); // Now class was constructed. | |
| 136 ASSERT_TRUE(data); | |
| 137 EXPECT_FALSE(data->next()); | |
| 138 EXPECT_EQ(data, ThreadData::Get()); | |
| 139 ThreadData::BirthMap birth_map; | |
| 140 ThreadData::DeathsSnapshot deaths; | |
| 141 data->SnapshotMaps(0, &birth_map, &deaths); | |
| 142 EXPECT_EQ(0u, birth_map.size()); | |
| 143 EXPECT_EQ(0u, deaths.size()); | |
| 144 | |
| 145 // Clean up with no leaking. | |
| 146 Reset(); | |
| 147 | |
| 148 // Do it again, just to be sure we reset state completely. | |
| 149 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 150 EXPECT_FALSE(ThreadData::first()); // No activity even on this thread. | |
| 151 data = ThreadData::Get(); | |
| 152 EXPECT_TRUE(ThreadData::first()); // Now class was constructed. | |
| 153 ASSERT_TRUE(data); | |
| 154 EXPECT_FALSE(data->next()); | |
| 155 EXPECT_EQ(data, ThreadData::Get()); | |
| 156 birth_map.clear(); | |
| 157 deaths.clear(); | |
| 158 data->SnapshotMaps(0, &birth_map, &deaths); | |
| 159 EXPECT_EQ(0u, birth_map.size()); | |
| 160 EXPECT_EQ(0u, deaths.size()); | |
| 161 } | |
| 162 | |
| 163 TEST_F(TrackedObjectsTest, TinyStartupShutdown) { | |
| 164 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 165 | |
| 166 // Instigate tracking on a single tracked object, on our thread. | |
| 167 const char kFunction[] = "TinyStartupShutdown"; | |
| 168 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 169 ThreadData::TallyABirthIfActive(location); | |
| 170 | |
| 171 ThreadData* data = ThreadData::first(); | |
| 172 ASSERT_TRUE(data); | |
| 173 EXPECT_FALSE(data->next()); | |
| 174 EXPECT_EQ(data, ThreadData::Get()); | |
| 175 ThreadData::BirthMap birth_map; | |
| 176 ThreadData::DeathsSnapshot deaths; | |
| 177 data->SnapshotMaps(0, &birth_map, &deaths); | |
| 178 EXPECT_EQ(1u, birth_map.size()); // 1 birth location. | |
| 179 EXPECT_EQ(1, birth_map.begin()->second->birth_count()); // 1 birth. | |
| 180 EXPECT_EQ(0u, deaths.size()); // No deaths. | |
| 181 | |
| 182 | |
| 183 // Now instigate another birth, while we are timing the run of the first | |
| 184 // execution. | |
| 185 // Create a child (using the same birth location). | |
| 186 // TrackingInfo will call TallyABirth() during construction. | |
| 187 const int32 start_time = 1; | |
| 188 base::TimeTicks kBogusBirthTime = base::TimeTicks() + | |
| 189 base::TimeDelta::FromMilliseconds(start_time); | |
| 190 base::TrackingInfo pending_task(location, kBogusBirthTime); | |
| 191 SetTestTime(1); | |
| 192 TaskStopwatch stopwatch; | |
| 193 stopwatch.Start(); | |
| 194 // Finally conclude the outer run. | |
| 195 const int32 time_elapsed = 1000; | |
| 196 SetTestTime(start_time + time_elapsed); | |
| 197 stopwatch.Stop(); | |
| 198 | |
| 199 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); | |
| 200 | |
| 201 birth_map.clear(); | |
| 202 deaths.clear(); | |
| 203 data->SnapshotMaps(0, &birth_map, &deaths); | |
| 204 EXPECT_EQ(1u, birth_map.size()); // 1 birth location. | |
| 205 EXPECT_EQ(2, birth_map.begin()->second->birth_count()); // 2 births. | |
| 206 EXPECT_EQ(1u, deaths.size()); // 1 location. | |
| 207 EXPECT_EQ(1, deaths.begin()->second.death_data.count); // 1 death. | |
| 208 | |
| 209 // The births were at the same location as the one known death. | |
| 210 EXPECT_EQ(birth_map.begin()->second, deaths.begin()->first); | |
| 211 | |
| 212 ProcessDataSnapshot process_data; | |
| 213 ThreadData::Snapshot(0, &process_data); | |
| 214 | |
| 215 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()); | |
| 218 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); | |
| 237 } | |
| 238 | |
| 239 TEST_F(TrackedObjectsTest, DeathDataTestRecordDeath) { | |
| 240 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 241 | |
| 242 scoped_ptr<DeathData> data(new DeathData()); | |
| 243 ASSERT_NE(data, reinterpret_cast<DeathData*>(NULL)); | |
| 244 EXPECT_EQ(data->run_duration_sum(), 0); | |
| 245 EXPECT_EQ(data->run_duration_max(), 0); | |
| 246 EXPECT_EQ(data->run_duration_sample(), 0); | |
| 247 EXPECT_EQ(data->queue_duration_sum(), 0); | |
| 248 EXPECT_EQ(data->queue_duration_max(), 0); | |
| 249 EXPECT_EQ(data->queue_duration_sample(), 0); | |
| 250 EXPECT_EQ(data->count(), 0); | |
| 251 EXPECT_EQ(nullptr, data->last_phase_snapshot()); | |
| 252 | |
| 253 int32 run_ms = 42; | |
| 254 int32 queue_ms = 8; | |
| 255 | |
| 256 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); | |
| 259 EXPECT_EQ(data->run_duration_max(), run_ms); | |
| 260 EXPECT_EQ(data->run_duration_sample(), run_ms); | |
| 261 EXPECT_EQ(data->queue_duration_sum(), queue_ms); | |
| 262 EXPECT_EQ(data->queue_duration_max(), queue_ms); | |
| 263 EXPECT_EQ(data->queue_duration_sample(), queue_ms); | |
| 264 EXPECT_EQ(data->count(), 1); | |
| 265 EXPECT_EQ(nullptr, data->last_phase_snapshot()); | |
| 266 | |
| 267 data->RecordDeath(queue_ms, run_ms, kUnrandomInt); | |
| 268 EXPECT_EQ(data->run_duration_sum(), run_ms + run_ms); | |
| 269 EXPECT_EQ(data->run_duration_max(), run_ms); | |
| 270 EXPECT_EQ(data->run_duration_sample(), run_ms); | |
| 271 EXPECT_EQ(data->queue_duration_sum(), queue_ms + queue_ms); | |
| 272 EXPECT_EQ(data->queue_duration_max(), queue_ms); | |
| 273 EXPECT_EQ(data->queue_duration_sample(), queue_ms); | |
| 274 EXPECT_EQ(data->count(), 2); | |
| 275 EXPECT_EQ(nullptr, data->last_phase_snapshot()); | |
| 276 } | |
| 277 | |
| 278 TEST_F(TrackedObjectsTest, DeathDataTest2Phases) { | |
| 279 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 280 | |
| 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 | |
| 343 TEST_F(TrackedObjectsTest, Delta) { | |
| 344 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 345 | |
| 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); | |
| 372 } | |
| 373 | |
| 374 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotWorkerThread) { | |
| 375 // Start in the deactivated state. | |
| 376 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); | |
| 377 | |
| 378 const char kFunction[] = "DeactivatedBirthOnlyToSnapshotWorkerThread"; | |
| 379 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 380 TallyABirth(location, std::string()); | |
| 381 | |
| 382 ProcessDataSnapshot process_data; | |
| 383 ThreadData::Snapshot(0, &process_data); | |
| 384 | |
| 385 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()); | |
| 389 const ProcessDataPhaseSnapshot& process_data_phase = it->second; | |
| 390 | |
| 391 ASSERT_EQ(0u, process_data_phase.tasks.size()); | |
| 392 | |
| 393 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 394 } | |
| 395 | |
| 396 TEST_F(TrackedObjectsTest, DeactivatedBirthOnlyToSnapshotMainThread) { | |
| 397 // Start in the deactivated state. | |
| 398 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); | |
| 399 | |
| 400 const char kFunction[] = "DeactivatedBirthOnlyToSnapshotMainThread"; | |
| 401 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 402 TallyABirth(location, kMainThreadName); | |
| 403 | |
| 404 ProcessDataSnapshot process_data; | |
| 405 ThreadData::Snapshot(0, &process_data); | |
| 406 | |
| 407 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()); | |
| 411 const ProcessDataPhaseSnapshot& process_data_phase = it->second; | |
| 412 | |
| 413 ASSERT_EQ(0u, process_data_phase.tasks.size()); | |
| 414 | |
| 415 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 416 } | |
| 417 | |
| 418 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotWorkerThread) { | |
| 419 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 420 | |
| 421 const char kFunction[] = "BirthOnlyToSnapshotWorkerThread"; | |
| 422 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 423 TallyABirth(location, std::string()); | |
| 424 | |
| 425 ProcessDataSnapshot process_data; | |
| 426 ThreadData::Snapshot(0, &process_data); | |
| 427 ExpectSimpleProcessData(process_data, kFunction, kWorkerThreadName, | |
| 428 kStillAlive, 1, 0, 0); | |
| 429 } | |
| 430 | |
| 431 TEST_F(TrackedObjectsTest, BirthOnlyToSnapshotMainThread) { | |
| 432 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 433 | |
| 434 const char kFunction[] = "BirthOnlyToSnapshotMainThread"; | |
| 435 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 436 TallyABirth(location, kMainThreadName); | |
| 437 | |
| 438 ProcessDataSnapshot process_data; | |
| 439 ThreadData::Snapshot(0, &process_data); | |
| 440 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, kStillAlive, | |
| 441 1, 0, 0); | |
| 442 } | |
| 443 | |
| 444 TEST_F(TrackedObjectsTest, LifeCycleToSnapshotMainThread) { | |
| 445 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 446 | |
| 447 const char kFunction[] = "LifeCycleToSnapshotMainThread"; | |
| 448 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 449 TallyABirth(location, kMainThreadName); | |
| 450 | |
| 451 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 452 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(). | |
| 456 | |
| 457 const unsigned int kStartOfRun = 5; | |
| 458 const unsigned int kEndOfRun = 7; | |
| 459 SetTestTime(kStartOfRun); | |
| 460 TaskStopwatch stopwatch; | |
| 461 stopwatch.Start(); | |
| 462 SetTestTime(kEndOfRun); | |
| 463 stopwatch.Stop(); | |
| 464 | |
| 465 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); | |
| 466 | |
| 467 ProcessDataSnapshot process_data; | |
| 468 ThreadData::Snapshot(0, &process_data); | |
| 469 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, | |
| 470 kMainThreadName, 1, 2, 4); | |
| 471 } | |
| 472 | |
| 473 TEST_F(TrackedObjectsTest, TwoPhases) { | |
| 474 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 475 | |
| 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 | |
| 545 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 | |
| 569 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 570 } | |
| 571 | |
| 572 TEST_F(TrackedObjectsTest, ThreePhases) { | |
| 573 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 574 | |
| 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 | |
| 662 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 | |
| 686 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 | |
| 710 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 711 } | |
| 712 | |
| 713 TEST_F(TrackedObjectsTest, TwoPhasesSecondEmpty) { | |
| 714 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 715 | |
| 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 | |
| 773 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 774 } | |
| 775 | |
| 776 TEST_F(TrackedObjectsTest, TwoPhasesFirstEmpty) { | |
| 777 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 778 | |
| 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 | |
| 833 // 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). | |
| 837 TEST_F(TrackedObjectsTest, LifeCycleMidDeactivatedToSnapshotMainThread) { | |
| 838 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 839 | |
| 840 const char kFunction[] = "LifeCycleMidDeactivatedToSnapshotMainThread"; | |
| 841 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 842 TallyABirth(location, kMainThreadName); | |
| 843 | |
| 844 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 845 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(). | |
| 849 | |
| 850 // Turn off tracking now that we have births. | |
| 851 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); | |
| 852 | |
| 853 const unsigned int kStartOfRun = 5; | |
| 854 const unsigned int kEndOfRun = 7; | |
| 855 SetTestTime(kStartOfRun); | |
| 856 TaskStopwatch stopwatch; | |
| 857 stopwatch.Start(); | |
| 858 SetTestTime(kEndOfRun); | |
| 859 stopwatch.Stop(); | |
| 860 | |
| 861 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); | |
| 862 | |
| 863 ProcessDataSnapshot process_data; | |
| 864 ThreadData::Snapshot(0, &process_data); | |
| 865 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, | |
| 866 kMainThreadName, 1, 2, 4); | |
| 867 } | |
| 868 | |
| 869 // We will deactivate tracking before starting a life cycle, and neither | |
| 870 // the birth nor the death will be recorded. | |
| 871 TEST_F(TrackedObjectsTest, LifeCyclePreDeactivatedToSnapshotMainThread) { | |
| 872 // Start in the deactivated state. | |
| 873 ThreadData::InitializeAndSetTrackingStatus(ThreadData::DEACTIVATED); | |
| 874 | |
| 875 const char kFunction[] = "LifeCyclePreDeactivatedToSnapshotMainThread"; | |
| 876 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 877 TallyABirth(location, kMainThreadName); | |
| 878 | |
| 879 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 880 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 | |
| 885 const unsigned int kStartOfRun = 5; | |
| 886 const unsigned int kEndOfRun = 7; | |
| 887 SetTestTime(kStartOfRun); | |
| 888 TaskStopwatch stopwatch; | |
| 889 stopwatch.Start(); | |
| 890 SetTestTime(kEndOfRun); | |
| 891 stopwatch.Stop(); | |
| 892 | |
| 893 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); | |
| 894 | |
| 895 ProcessDataSnapshot process_data; | |
| 896 ThreadData::Snapshot(0, &process_data); | |
| 897 | |
| 898 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()); | |
| 902 const ProcessDataPhaseSnapshot& process_data_phase = it->second; | |
| 903 | |
| 904 ASSERT_EQ(0u, process_data_phase.tasks.size()); | |
| 905 | |
| 906 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 907 } | |
| 908 | |
| 909 TEST_F(TrackedObjectsTest, TwoLives) { | |
| 910 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 911 | |
| 912 const char kFunction[] = "TwoLives"; | |
| 913 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 914 TallyABirth(location, kMainThreadName); | |
| 915 | |
| 916 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 917 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 | |
| 922 const unsigned int kStartOfRun = 5; | |
| 923 const unsigned int kEndOfRun = 7; | |
| 924 SetTestTime(kStartOfRun); | |
| 925 TaskStopwatch stopwatch; | |
| 926 stopwatch.Start(); | |
| 927 SetTestTime(kEndOfRun); | |
| 928 stopwatch.Stop(); | |
| 929 | |
| 930 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); | |
| 931 | |
| 932 // TrackingInfo will call TallyABirth() during construction. | |
| 933 base::TrackingInfo pending_task2(location, kDelayedStartTime); | |
| 934 pending_task2.time_posted = kTimePosted; // Overwrite implied Now(). | |
| 935 SetTestTime(kStartOfRun); | |
| 936 TaskStopwatch stopwatch2; | |
| 937 stopwatch2.Start(); | |
| 938 SetTestTime(kEndOfRun); | |
| 939 stopwatch2.Stop(); | |
| 940 | |
| 941 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task2, stopwatch2); | |
| 942 | |
| 943 ProcessDataSnapshot process_data; | |
| 944 ThreadData::Snapshot(0, &process_data); | |
| 945 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, | |
| 946 kMainThreadName, 2, 2, 4); | |
| 947 } | |
| 948 | |
| 949 TEST_F(TrackedObjectsTest, DifferentLives) { | |
| 950 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 951 | |
| 952 // Use a well named thread. | |
| 953 ThreadData::InitializeThreadContext(kMainThreadName); | |
| 954 const char kFunction[] = "DifferentLives"; | |
| 955 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 956 | |
| 957 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 958 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(). | |
| 962 | |
| 963 const unsigned int kStartOfRun = 5; | |
| 964 const unsigned int kEndOfRun = 7; | |
| 965 SetTestTime(kStartOfRun); | |
| 966 TaskStopwatch stopwatch; | |
| 967 stopwatch.Start(); | |
| 968 SetTestTime(kEndOfRun); | |
| 969 stopwatch.Stop(); | |
| 970 | |
| 971 ThreadData::TallyRunOnNamedThreadIfTracking(pending_task, stopwatch); | |
| 972 | |
| 973 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 | |
| 980 ProcessDataSnapshot process_data; | |
| 981 ThreadData::Snapshot(0, &process_data); | |
| 982 | |
| 983 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()); | |
| 986 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); | |
| 1007 EXPECT_EQ(kSecondFakeLineNumber, | |
| 1008 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); | |
| 1018 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 1019 } | |
| 1020 | |
| 1021 TEST_F(TrackedObjectsTest, TaskWithNestedExclusion) { | |
| 1022 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 1023 | |
| 1024 const char kFunction[] = "TaskWithNestedExclusion"; | |
| 1025 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 1026 TallyABirth(location, kMainThreadName); | |
| 1027 | |
| 1028 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 1029 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; | |
| 1036 task_stopwatch.Start(); | |
| 1037 { | |
| 1038 SetTestTime(8); | |
| 1039 TaskStopwatch exclusion_stopwatch; | |
| 1040 exclusion_stopwatch.Start(); | |
| 1041 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; | |
| 1050 ThreadData::Snapshot(0, &process_data); | |
| 1051 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, | |
| 1052 kMainThreadName, 1, 6, 4); | |
| 1053 } | |
| 1054 | |
| 1055 TEST_F(TrackedObjectsTest, TaskWith2NestedExclusions) { | |
| 1056 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 1057 | |
| 1058 const char kFunction[] = "TaskWith2NestedExclusions"; | |
| 1059 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 1060 TallyABirth(location, kMainThreadName); | |
| 1061 | |
| 1062 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 1063 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; | |
| 1070 task_stopwatch.Start(); | |
| 1071 { | |
| 1072 SetTestTime(8); | |
| 1073 TaskStopwatch exclusion_stopwatch; | |
| 1074 exclusion_stopwatch.Start(); | |
| 1075 SetTestTime(12); | |
| 1076 exclusion_stopwatch.Stop(); | |
| 1077 | |
| 1078 SetTestTime(15); | |
| 1079 TaskStopwatch exclusion_stopwatch2; | |
| 1080 exclusion_stopwatch2.Start(); | |
| 1081 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; | |
| 1090 ThreadData::Snapshot(0, &process_data); | |
| 1091 ExpectSimpleProcessData(process_data, kFunction, kMainThreadName, | |
| 1092 kMainThreadName, 1, 13, 4); | |
| 1093 } | |
| 1094 | |
| 1095 TEST_F(TrackedObjectsTest, TaskWithNestedExclusionWithNestedTask) { | |
| 1096 ThreadData::InitializeAndSetTrackingStatus(ThreadData::PROFILING_ACTIVE); | |
| 1097 | |
| 1098 const char kFunction[] = "TaskWithNestedExclusionWithNestedTask"; | |
| 1099 Location location(kFunction, kFile, kLineNumber, NULL); | |
| 1100 | |
| 1101 const int kSecondFakeLineNumber = 999; | |
| 1102 | |
| 1103 TallyABirth(location, kMainThreadName); | |
| 1104 | |
| 1105 const TrackedTime kTimePosted = TrackedTime::FromMilliseconds(1); | |
| 1106 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; | |
| 1113 task_stopwatch.Start(); | |
| 1114 { | |
| 1115 SetTestTime(8); | |
| 1116 TaskStopwatch exclusion_stopwatch; | |
| 1117 exclusion_stopwatch.Start(); | |
| 1118 { | |
| 1119 Location second_location(kFunction, kFile, kSecondFakeLineNumber, NULL); | |
| 1120 base::TrackingInfo nested_task(second_location, kDelayedStartTime); | |
| 1121 // Overwrite implied Now(). | |
| 1122 nested_task.time_posted = TrackedTime::FromMilliseconds(8); | |
| 1123 SetTestTime(9); | |
| 1124 TaskStopwatch nested_task_stopwatch; | |
| 1125 nested_task_stopwatch.Start(); | |
| 1126 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; | |
| 1140 ThreadData::Snapshot(0, &process_data); | |
| 1141 | |
| 1142 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()); | |
| 1145 const ProcessDataPhaseSnapshot& process_data_phase = it->second; | |
| 1146 | |
| 1147 // The order in which the two task follow is platform-dependent. | |
| 1148 int t0 = | |
| 1149 (process_data_phase.tasks[0].birth.location.line_number == kLineNumber) | |
| 1150 ? 0 | |
| 1151 : 1; | |
| 1152 int t1 = 1 - t0; | |
| 1153 | |
| 1154 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); | |
| 1172 EXPECT_EQ(kSecondFakeLineNumber, | |
| 1173 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); | |
| 1183 EXPECT_EQ(base::GetCurrentProcId(), process_data.process_id); | |
| 1184 } | |
| 1185 | |
| 1186 } // namespace tracked_objects | |
| OLD | NEW |
|---|
Chromium Code Reviews
