OLD | NEW |
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 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 | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "base/debug/trace_event_unittest.h" | 5 #include "base/debug/trace_event_unittest.h" |
6 | 6 |
7 #include <math.h> | 7 #include <math.h> |
8 #include <cstdlib> | 8 #include <cstdlib> |
9 | 9 |
10 #include "base/bind.h" | 10 #include "base/bind.h" |
(...skipping 234 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
245 continue; | 245 continue; |
246 DictionaryValue* dict = static_cast<DictionaryValue*>(value); | 246 DictionaryValue* dict = static_cast<DictionaryValue*>(value); |
247 | 247 |
248 if (IsAllKeyValueInDict(key_values, dict)) | 248 if (IsAllKeyValueInDict(key_values, dict)) |
249 return dict; | 249 return dict; |
250 } | 250 } |
251 return NULL; | 251 return NULL; |
252 } | 252 } |
253 | 253 |
254 void TraceEventTestFixture::DropTracedMetadataRecords() { | 254 void TraceEventTestFixture::DropTracedMetadataRecords() { |
255 | |
256 scoped_ptr<ListValue> old_trace_parsed(trace_parsed_.DeepCopy()); | 255 scoped_ptr<ListValue> old_trace_parsed(trace_parsed_.DeepCopy()); |
257 size_t old_trace_parsed_size = old_trace_parsed->GetSize(); | 256 size_t old_trace_parsed_size = old_trace_parsed->GetSize(); |
258 trace_parsed_.Clear(); | 257 trace_parsed_.Clear(); |
259 | 258 |
260 for (size_t i = 0; i < old_trace_parsed_size; i++) { | 259 for (size_t i = 0; i < old_trace_parsed_size; i++) { |
261 Value* value = NULL; | 260 Value* value = NULL; |
262 old_trace_parsed->Get(i, &value); | 261 old_trace_parsed->Get(i, &value); |
263 if (!value || value->GetType() != Value::TYPE_DICTIONARY) { | 262 if (!value || value->GetType() != Value::TYPE_DICTIONARY) { |
264 trace_parsed_.Append(value->DeepCopy()); | 263 trace_parsed_.Append(value->DeepCopy()); |
265 continue; | 264 continue; |
266 } | 265 } |
267 DictionaryValue* dict = static_cast<DictionaryValue*>(value); | 266 DictionaryValue* dict = static_cast<DictionaryValue*>(value); |
268 std::string tmp; | 267 std::string tmp; |
269 if(dict->GetString("ph", &tmp) && tmp == "M") | 268 if (dict->GetString("ph", &tmp) && tmp == "M") |
270 continue; | 269 continue; |
271 | 270 |
272 trace_parsed_.Append(value->DeepCopy()); | 271 trace_parsed_.Append(value->DeepCopy()); |
273 } | 272 } |
274 } | 273 } |
275 | 274 |
276 DictionaryValue* TraceEventTestFixture::FindNamePhase(const char* name, | 275 DictionaryValue* TraceEventTestFixture::FindNamePhase(const char* name, |
277 const char* phase) { | 276 const char* phase) { |
278 JsonKeyValue key_values[] = { | 277 JsonKeyValue key_values[] = { |
279 {"name", name, IS_EQUAL}, | 278 {"name", name, IS_EQUAL}, |
(...skipping 90 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
370 if (!value || value->GetType() != Value::TYPE_DICTIONARY) | 369 if (!value || value->GetType() != Value::TYPE_DICTIONARY) |
371 continue; | 370 continue; |
372 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value); | 371 const DictionaryValue* dict = static_cast<const DictionaryValue*>(value); |
373 | 372 |
374 if (IsStringInDict(string_to_match, dict)) | 373 if (IsStringInDict(string_to_match, dict)) |
375 hits.push_back(dict); | 374 hits.push_back(dict); |
376 } | 375 } |
377 return hits; | 376 return hits; |
378 } | 377 } |
379 | 378 |
380 const char* kControlCharacters = "\001\002\003\n\r"; | 379 const char kControlCharacters[] = "\001\002\003\n\r"; |
381 | 380 |
382 void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) { | 381 void TraceWithAllMacroVariants(WaitableEvent* task_complete_event) { |
383 { | 382 { |
384 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 0x1122, "extrastring1"); | 383 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 0x1122, "extrastring1"); |
385 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 0x3344, "extrastring2"); | 384 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 0x3344, "extrastring2"); |
386 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call", | 385 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call", |
387 0x5566, "extrastring3"); | 386 0x5566, "extrastring3"); |
388 | 387 |
389 TRACE_EVENT0("all", "TRACE_EVENT0 call"); | 388 TRACE_EVENT0("all", "TRACE_EVENT0 call"); |
390 TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1"); | 389 TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1"); |
(...skipping 80 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
471 TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID( | 470 TRACE_EVENT_OBJECT_SNAPSHOT_WITH_ID( |
472 "all", "tracked object 1", 0x42, "hello"); | 471 "all", "tracked object 1", 0x42, "hello"); |
473 TRACE_EVENT_OBJECT_DELETED_WITH_ID("all", "tracked object 1", 0x42); | 472 TRACE_EVENT_OBJECT_DELETED_WITH_ID("all", "tracked object 1", 0x42); |
474 | 473 |
475 TraceScopedTrackableObject<int> trackable("all", "tracked object 2", | 474 TraceScopedTrackableObject<int> trackable("all", "tracked object 2", |
476 0x2128506); | 475 0x2128506); |
477 trackable.snapshot("world"); | 476 trackable.snapshot("world"); |
478 | 477 |
479 TRACE_EVENT1(kControlCharacters, kControlCharacters, | 478 TRACE_EVENT1(kControlCharacters, kControlCharacters, |
480 kControlCharacters, kControlCharacters); | 479 kControlCharacters, kControlCharacters); |
481 } // Scope close causes TRACE_EVENT0 etc to send their END events. | 480 } // Scope close causes TRACE_EVENT0 etc to send their END events. |
482 | 481 |
483 if (task_complete_event) | 482 if (task_complete_event) |
484 task_complete_event->Signal(); | 483 task_complete_event->Signal(); |
485 } | 484 } |
486 | 485 |
487 void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) { | 486 void ValidateAllTraceMacrosCreatedData(const ListValue& trace_parsed) { |
488 const DictionaryValue* item = NULL; | 487 const DictionaryValue* item = NULL; |
489 | 488 |
490 #define EXPECT_FIND_(string) \ | 489 #define EXPECT_FIND_(string) \ |
491 item = FindTraceEntry(trace_parsed, string); \ | 490 item = FindTraceEntry(trace_parsed, string); \ |
(...skipping 801 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1293 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); | 1292 TRACE_EVENT_INSTANT0("cat", "event", TRACE_EVENT_SCOPE_THREAD); |
1294 EndTraceAndFlush(); | 1293 EndTraceAndFlush(); |
1295 EXPECT_EQ(event_watch_notification_, 0); | 1294 EXPECT_EQ(event_watch_notification_, 0); |
1296 } | 1295 } |
1297 | 1296 |
1298 // Test ASYNC_BEGIN/END events | 1297 // Test ASYNC_BEGIN/END events |
1299 TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) { | 1298 TEST_F(TraceEventTestFixture, AsyncBeginEndEvents) { |
1300 BeginTrace(); | 1299 BeginTrace(); |
1301 | 1300 |
1302 unsigned long long id = 0xfeedbeeffeedbeefull; | 1301 unsigned long long id = 0xfeedbeeffeedbeefull; |
1303 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", id); | 1302 TRACE_EVENT_ASYNC_BEGIN0("cat", "name1", id); |
1304 TRACE_EVENT_ASYNC_STEP_INTO0( "cat", "name1", id, "step1"); | 1303 TRACE_EVENT_ASYNC_STEP_INTO0("cat", "name1", id, "step1"); |
1305 TRACE_EVENT_ASYNC_END0("cat", "name1", id); | 1304 TRACE_EVENT_ASYNC_END0("cat", "name1", id); |
1306 TRACE_EVENT_BEGIN0( "cat", "name2"); | 1305 TRACE_EVENT_BEGIN0("cat", "name2"); |
1307 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name3", 0); | 1306 TRACE_EVENT_ASYNC_BEGIN0("cat", "name3", 0); |
1308 TRACE_EVENT_ASYNC_STEP_PAST0( "cat", "name3", 0, "step2"); | 1307 TRACE_EVENT_ASYNC_STEP_PAST0("cat", "name3", 0, "step2"); |
1309 | 1308 |
1310 EndTraceAndFlush(); | 1309 EndTraceAndFlush(); |
1311 | 1310 |
1312 EXPECT_TRUE(FindNamePhase("name1", "S")); | 1311 EXPECT_TRUE(FindNamePhase("name1", "S")); |
1313 EXPECT_TRUE(FindNamePhase("name1", "T")); | 1312 EXPECT_TRUE(FindNamePhase("name1", "T")); |
1314 EXPECT_TRUE(FindNamePhase("name1", "F")); | 1313 EXPECT_TRUE(FindNamePhase("name1", "F")); |
1315 | 1314 |
1316 std::string id_str; | 1315 std::string id_str; |
1317 StringAppendF(&id_str, "0x%llx", id); | 1316 StringAppendF(&id_str, "0x%llx", id); |
1318 | 1317 |
1319 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "S", "id", id_str.c_str())); | 1318 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "S", "id", id_str.c_str())); |
1320 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "T", "id", id_str.c_str())); | 1319 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "T", "id", id_str.c_str())); |
1321 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "F", "id", id_str.c_str())); | 1320 EXPECT_TRUE(FindNamePhaseKeyValue("name1", "F", "id", id_str.c_str())); |
1322 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "S", "id", "0x0")); | 1321 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "S", "id", "0x0")); |
1323 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "p", "id", "0x0")); | 1322 EXPECT_TRUE(FindNamePhaseKeyValue("name3", "p", "id", "0x0")); |
1324 | 1323 |
1325 // BEGIN events should not have id | 1324 // BEGIN events should not have id |
1326 EXPECT_FALSE(FindNamePhaseKeyValue("name2", "B", "id", "0")); | 1325 EXPECT_FALSE(FindNamePhaseKeyValue("name2", "B", "id", "0")); |
1327 } | 1326 } |
1328 | 1327 |
1329 // Test ASYNC_BEGIN/END events | 1328 // Test ASYNC_BEGIN/END events |
1330 TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) { | 1329 TEST_F(TraceEventTestFixture, AsyncBeginEndPointerMangling) { |
1331 void* ptr = this; | 1330 void* ptr = this; |
1332 | 1331 |
1333 TraceLog::GetInstance()->SetProcessID(100); | 1332 TraceLog::GetInstance()->SetProcessID(100); |
1334 BeginTrace(); | 1333 BeginTrace(); |
1335 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name1", ptr); | 1334 TRACE_EVENT_ASYNC_BEGIN0("cat", "name1", ptr); |
1336 TRACE_EVENT_ASYNC_BEGIN0( "cat", "name2", ptr); | 1335 TRACE_EVENT_ASYNC_BEGIN0("cat", "name2", ptr); |
1337 EndTraceAndFlush(); | 1336 EndTraceAndFlush(); |
1338 | 1337 |
1339 TraceLog::GetInstance()->SetProcessID(200); | 1338 TraceLog::GetInstance()->SetProcessID(200); |
1340 BeginTrace(); | 1339 BeginTrace(); |
1341 TRACE_EVENT_ASYNC_END0( "cat", "name1", ptr); | 1340 TRACE_EVENT_ASYNC_END0("cat", "name1", ptr); |
1342 EndTraceAndFlush(); | 1341 EndTraceAndFlush(); |
1343 | 1342 |
1344 DictionaryValue* async_begin = FindNamePhase("name1", "S"); | 1343 DictionaryValue* async_begin = FindNamePhase("name1", "S"); |
1345 DictionaryValue* async_begin2 = FindNamePhase("name2", "S"); | 1344 DictionaryValue* async_begin2 = FindNamePhase("name2", "S"); |
1346 DictionaryValue* async_end = FindNamePhase("name1", "F"); | 1345 DictionaryValue* async_end = FindNamePhase("name1", "F"); |
1347 EXPECT_TRUE(async_begin); | 1346 EXPECT_TRUE(async_begin); |
1348 EXPECT_TRUE(async_begin2); | 1347 EXPECT_TRUE(async_begin2); |
1349 EXPECT_TRUE(async_end); | 1348 EXPECT_TRUE(async_end); |
1350 | 1349 |
1351 Value* value = NULL; | 1350 Value* value = NULL; |
(...skipping 131 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1483 threads[i]->Stop(); | 1482 threads[i]->Stop(); |
1484 delete threads[i]; | 1483 delete threads[i]; |
1485 delete task_complete_events[i]; | 1484 delete task_complete_events[i]; |
1486 } | 1485 } |
1487 } | 1486 } |
1488 | 1487 |
1489 // Test that thread and process names show up in the trace | 1488 // Test that thread and process names show up in the trace |
1490 TEST_F(TraceEventTestFixture, ThreadNames) { | 1489 TEST_F(TraceEventTestFixture, ThreadNames) { |
1491 // Create threads before we enable tracing to make sure | 1490 // Create threads before we enable tracing to make sure |
1492 // that tracelog still captures them. | 1491 // that tracelog still captures them. |
1493 const int num_threads = 4; | 1492 const int kNumThreads = 4; |
1494 const int num_events = 10; | 1493 const int kNumEvents = 10; |
1495 Thread* threads[num_threads]; | 1494 Thread* threads[kNumThreads]; |
1496 PlatformThreadId thread_ids[num_threads]; | 1495 PlatformThreadId thread_ids[kNumThreads]; |
1497 for (int i = 0; i < num_threads; i++) | 1496 for (int i = 0; i < kNumThreads; i++) |
1498 threads[i] = new Thread(StringPrintf("Thread %d", i)); | 1497 threads[i] = new Thread(StringPrintf("Thread %d", i)); |
1499 | 1498 |
1500 // Enable tracing. | 1499 // Enable tracing. |
1501 BeginTrace(); | 1500 BeginTrace(); |
1502 | 1501 |
1503 // Now run some trace code on these threads. | 1502 // Now run some trace code on these threads. |
1504 WaitableEvent* task_complete_events[num_threads]; | 1503 WaitableEvent* task_complete_events[kNumThreads]; |
1505 for (int i = 0; i < num_threads; i++) { | 1504 for (int i = 0; i < kNumThreads; i++) { |
1506 task_complete_events[i] = new WaitableEvent(false, false); | 1505 task_complete_events[i] = new WaitableEvent(false, false); |
1507 threads[i]->Start(); | 1506 threads[i]->Start(); |
1508 thread_ids[i] = threads[i]->thread_id(); | 1507 thread_ids[i] = threads[i]->thread_id(); |
1509 threads[i]->message_loop()->PostTask( | 1508 threads[i]->message_loop()->PostTask( |
1510 FROM_HERE, base::Bind(&TraceManyInstantEvents, | 1509 FROM_HERE, base::Bind(&TraceManyInstantEvents, |
1511 i, num_events, task_complete_events[i])); | 1510 i, kNumEvents, task_complete_events[i])); |
1512 } | 1511 } |
1513 for (int i = 0; i < num_threads; i++) { | 1512 for (int i = 0; i < kNumThreads; i++) { |
1514 task_complete_events[i]->Wait(); | 1513 task_complete_events[i]->Wait(); |
1515 } | 1514 } |
1516 | 1515 |
1517 // Shut things down. | 1516 // Shut things down. |
1518 for (int i = 0; i < num_threads; i++) { | 1517 for (int i = 0; i < kNumThreads; i++) { |
1519 threads[i]->Stop(); | 1518 threads[i]->Stop(); |
1520 delete threads[i]; | 1519 delete threads[i]; |
1521 delete task_complete_events[i]; | 1520 delete task_complete_events[i]; |
1522 } | 1521 } |
1523 | 1522 |
1524 EndTraceAndFlush(); | 1523 EndTraceAndFlush(); |
1525 | 1524 |
1526 std::string tmp; | 1525 std::string tmp; |
1527 int tmp_int; | 1526 int tmp_int; |
1528 const DictionaryValue* item; | 1527 const DictionaryValue* item; |
1529 | 1528 |
1530 // Make sure we get thread name metadata. | 1529 // Make sure we get thread name metadata. |
1531 // Note, the test suite may have created a ton of threads. | 1530 // Note, the test suite may have created a ton of threads. |
1532 // So, we'll have thread names for threads we didn't create. | 1531 // So, we'll have thread names for threads we didn't create. |
1533 std::vector<const DictionaryValue*> items = | 1532 std::vector<const DictionaryValue*> items = |
1534 FindTraceEntries(trace_parsed_, "thread_name"); | 1533 FindTraceEntries(trace_parsed_, "thread_name"); |
1535 for (int i = 0; i < static_cast<int>(items.size()); i++) { | 1534 for (int i = 0; i < static_cast<int>(items.size()); i++) { |
1536 item = items[i]; | 1535 item = items[i]; |
1537 ASSERT_TRUE(item); | 1536 ASSERT_TRUE(item); |
1538 EXPECT_TRUE(item->GetInteger("tid", &tmp_int)); | 1537 EXPECT_TRUE(item->GetInteger("tid", &tmp_int)); |
1539 | 1538 |
1540 // See if this thread name is one of the threads we just created | 1539 // See if this thread name is one of the threads we just created |
1541 for (int j = 0; j < num_threads; j++) { | 1540 for (int j = 0; j < kNumThreads; j++) { |
1542 if(static_cast<int>(thread_ids[j]) != tmp_int) | 1541 if(static_cast<int>(thread_ids[j]) != tmp_int) |
1543 continue; | 1542 continue; |
1544 | 1543 |
1545 std::string expected_name = StringPrintf("Thread %d", j); | 1544 std::string expected_name = StringPrintf("Thread %d", j); |
1546 EXPECT_TRUE(item->GetString("ph", &tmp) && tmp == "M"); | 1545 EXPECT_TRUE(item->GetString("ph", &tmp) && tmp == "M"); |
1547 EXPECT_TRUE(item->GetInteger("pid", &tmp_int) && | 1546 EXPECT_TRUE(item->GetInteger("pid", &tmp_int) && |
1548 tmp_int == static_cast<int>(base::GetCurrentProcId())); | 1547 tmp_int == static_cast<int>(base::GetCurrentProcId())); |
1549 // If the thread name changes or the tid gets reused, the name will be | 1548 // If the thread name changes or the tid gets reused, the name will be |
1550 // a comma-separated list of thread names, so look for a substring. | 1549 // a comma-separated list of thread names, so look for a substring. |
1551 EXPECT_TRUE(item->GetString("args.name", &tmp) && | 1550 EXPECT_TRUE(item->GetString("args.name", &tmp) && |
(...skipping 1410 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
2962 { | 2961 { |
2963 TRACE_EVENT_SYNTHETIC_DELAY("test.Delay"); | 2962 TRACE_EVENT_SYNTHETIC_DELAY("test.Delay"); |
2964 } | 2963 } |
2965 base::TimeDelta duration = base::TimeTicks::Now() - start; | 2964 base::TimeDelta duration = base::TimeTicks::Now() - start; |
2966 EXPECT_GE(duration.InMilliseconds(), 50); | 2965 EXPECT_GE(duration.InMilliseconds(), 50); |
2967 | 2966 |
2968 EndTraceAndFlush(); | 2967 EndTraceAndFlush(); |
2969 } | 2968 } |
2970 | 2969 |
2971 TEST_F(TraceEventTestFixture, BadSyntheticDelayConfigurations) { | 2970 TEST_F(TraceEventTestFixture, BadSyntheticDelayConfigurations) { |
2972 const char* configs[] = { | 2971 const char* const configs[] = { |
2973 "", | 2972 "", |
2974 "DELAY(", | 2973 "DELAY(", |
2975 "DELAY(;", | 2974 "DELAY(;", |
2976 "DELAY(;)", | 2975 "DELAY(;)", |
2977 "DELAY(test.Delay)", | 2976 "DELAY(test.Delay)", |
2978 "DELAY(test.Delay;)" | 2977 "DELAY(test.Delay;)" |
2979 }; | 2978 }; |
2980 for (size_t i = 0; i < arraysize(configs); i++) { | 2979 for (size_t i = 0; i < arraysize(configs); i++) { |
2981 BeginSpecificTrace(configs[i]); | 2980 BeginSpecificTrace(configs[i]); |
2982 EndTraceAndFlush(); | 2981 EndTraceAndFlush(); |
(...skipping 89 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
3072 EXPECT_EQ(original_option.enable_sampling, new_options.enable_sampling); | 3071 EXPECT_EQ(original_option.enable_sampling, new_options.enable_sampling); |
3073 EXPECT_EQ(original_option.enable_systrace, new_options.enable_systrace); | 3072 EXPECT_EQ(original_option.enable_systrace, new_options.enable_systrace); |
3074 } | 3073 } |
3075 } | 3074 } |
3076 } | 3075 } |
3077 } | 3076 } |
3078 | 3077 |
3079 | 3078 |
3080 } // namespace debug | 3079 } // namespace debug |
3081 } // namespace base | 3080 } // namespace base |
OLD | NEW |