OLD | NEW |
1 // Copyright (c) 2011 The Chromium Authors. All rights reserved. | 1 // Copyright (c) 2011 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.h" | 5 #include "base/debug/trace_event.h" |
6 | 6 |
7 #include "base/bind.h" | 7 #include "base/bind.h" |
8 #include "base/command_line.h" | 8 #include "base/command_line.h" |
9 #include "base/json/json_reader.h" | 9 #include "base/json/json_reader.h" |
10 #include "base/json/json_writer.h" | 10 #include "base/json/json_writer.h" |
11 #include "base/memory/scoped_ptr.h" | 11 #include "base/memory/scoped_ptr.h" |
| 12 #include "base/process_util.h" |
12 #include "base/stringprintf.h" | 13 #include "base/stringprintf.h" |
13 #include "base/synchronization/waitable_event.h" | 14 #include "base/synchronization/waitable_event.h" |
14 #include "base/threading/thread.h" | 15 #include "base/threading/thread.h" |
15 #include "base/values.h" | 16 #include "base/values.h" |
16 #include "testing/gmock/include/gmock/gmock.h" | 17 #include "testing/gmock/include/gmock/gmock.h" |
17 #include "testing/gtest/include/gtest/gtest.h" | 18 #include "testing/gtest/include/gtest/gtest.h" |
18 | 19 |
19 namespace base { | 20 namespace base { |
20 namespace debug { | 21 namespace debug { |
21 | 22 |
(...skipping 125 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
147 // Recurse to test arguments | 148 // Recurse to test arguments |
148 DictionaryValue* args_dict = NULL; | 149 DictionaryValue* args_dict = NULL; |
149 dict->GetDictionary("args", &args_dict); | 150 dict->GetDictionary("args", &args_dict); |
150 if (args_dict) | 151 if (args_dict) |
151 return IsStringInDict(string_to_match, args_dict); | 152 return IsStringInDict(string_to_match, args_dict); |
152 | 153 |
153 return false; | 154 return false; |
154 } | 155 } |
155 | 156 |
156 DictionaryValue* FindTraceEntry(const ListValue& trace_parsed, | 157 DictionaryValue* FindTraceEntry(const ListValue& trace_parsed, |
157 const char *string_to_match, | 158 const char* string_to_match, |
158 DictionaryValue* match_after_this_item = NULL) { | 159 DictionaryValue* match_after_this_item = NULL) { |
159 // Scan all items | 160 // Scan all items |
160 size_t trace_parsed_count = trace_parsed.GetSize(); | 161 size_t trace_parsed_count = trace_parsed.GetSize(); |
161 for (size_t i = 0; i < trace_parsed_count; i++) { | 162 for (size_t i = 0; i < trace_parsed_count; i++) { |
162 Value* value = NULL; | 163 Value* value = NULL; |
163 trace_parsed.Get(i, &value); | 164 trace_parsed.Get(i, &value); |
164 if (match_after_this_item) { | 165 if (match_after_this_item) { |
165 if (value == match_after_this_item) | 166 if (value == match_after_this_item) |
166 match_after_this_item = NULL; | 167 match_after_this_item = NULL; |
167 continue; | 168 continue; |
168 } | 169 } |
169 if (!value || value->GetType() != Value::TYPE_DICTIONARY) | 170 if (!value || value->GetType() != Value::TYPE_DICTIONARY) |
170 continue; | 171 continue; |
171 DictionaryValue* dict = static_cast<DictionaryValue*>(value); | 172 DictionaryValue* dict = static_cast<DictionaryValue*>(value); |
172 | 173 |
173 if (IsStringInDict(string_to_match, dict)) | 174 if (IsStringInDict(string_to_match, dict)) |
174 return dict; | 175 return dict; |
175 } | 176 } |
176 return NULL; | 177 return NULL; |
177 } | 178 } |
178 | 179 |
| 180 std::vector<DictionaryValue*> FindTraceEntries( |
| 181 const ListValue& trace_parsed, |
| 182 const char* string_to_match) { |
| 183 std::vector<DictionaryValue*> hits; |
| 184 size_t trace_parsed_count = trace_parsed.GetSize(); |
| 185 for (size_t i = 0; i < trace_parsed_count; i++) { |
| 186 Value* value = NULL; |
| 187 trace_parsed.Get(i, &value); |
| 188 if (!value || value->GetType() != Value::TYPE_DICTIONARY) |
| 189 continue; |
| 190 DictionaryValue* dict = static_cast<DictionaryValue*>(value); |
| 191 |
| 192 if (IsStringInDict(string_to_match, dict)) |
| 193 hits.push_back(dict); |
| 194 } |
| 195 return hits; |
| 196 } |
| 197 |
179 void DataCapturedCallTraces(WaitableEvent* task_complete_event) { | 198 void DataCapturedCallTraces(WaitableEvent* task_complete_event) { |
180 { | 199 { |
181 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 1122, "extrastring1"); | 200 TRACE_EVENT_BEGIN_ETW("TRACE_EVENT_BEGIN_ETW call", 1122, "extrastring1"); |
182 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 3344, "extrastring2"); | 201 TRACE_EVENT_END_ETW("TRACE_EVENT_END_ETW call", 3344, "extrastring2"); |
183 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call", | 202 TRACE_EVENT_INSTANT_ETW("TRACE_EVENT_INSTANT_ETW call", |
184 5566, "extrastring3"); | 203 5566, "extrastring3"); |
185 | 204 |
186 TRACE_EVENT0("all", "TRACE_EVENT0 call"); | 205 TRACE_EVENT0("all", "TRACE_EVENT0 call"); |
187 TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1"); | 206 TRACE_EVENT1("all", "TRACE_EVENT1 call", "name1", "value1"); |
188 TRACE_EVENT2("all", "TRACE_EVENT2 call", | 207 TRACE_EVENT2("all", "TRACE_EVENT2 call", |
(...skipping 297 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
486 for (int i = 0; i < num_threads; i++) { | 505 for (int i = 0; i < num_threads; i++) { |
487 threads[i]->Stop(); | 506 threads[i]->Stop(); |
488 delete threads[i]; | 507 delete threads[i]; |
489 delete task_complete_events[i]; | 508 delete task_complete_events[i]; |
490 } | 509 } |
491 | 510 |
492 DataCapturedValidateManyTraces(trace_parsed_, trace_string_, | 511 DataCapturedValidateManyTraces(trace_parsed_, trace_string_, |
493 num_threads, num_events); | 512 num_threads, num_events); |
494 } | 513 } |
495 | 514 |
| 515 // Test that thread and process names show up in the trace |
| 516 TEST_F(TraceEventTestFixture, ThreadNames) { |
| 517 ManualTestSetUp(); |
| 518 |
| 519 // Create threads before we enable tracing to make sure |
| 520 // that tracelog still captures them. |
| 521 const int num_threads = 4; |
| 522 const int num_events = 10; |
| 523 Thread* threads[num_threads]; |
| 524 PlatformThreadId thread_ids[num_threads]; |
| 525 for (int i = 0; i < num_threads; i++) |
| 526 threads[i] = new Thread(StringPrintf("Thread %d", i).c_str()); |
| 527 |
| 528 // Enable tracing. |
| 529 TraceLog::GetInstance()->SetEnabled(true); |
| 530 |
| 531 // Now run some trace code on these threads. |
| 532 WaitableEvent* task_complete_events[num_threads]; |
| 533 for (int i = 0; i < num_threads; i++) { |
| 534 task_complete_events[i] = new WaitableEvent(false, false); |
| 535 threads[i]->Start(); |
| 536 thread_ids[i] = threads[i]->thread_id(); |
| 537 threads[i]->message_loop()->PostTask( |
| 538 FROM_HERE, NewRunnableFunction(&DataCapturedCallManyTraces, |
| 539 i, num_events, task_complete_events[i])); |
| 540 } |
| 541 for (int i = 0; i < num_threads; i++) { |
| 542 task_complete_events[i]->Wait(); |
| 543 } |
| 544 |
| 545 // Shut things down. |
| 546 TraceLog::GetInstance()->SetEnabled(false); |
| 547 for (int i = 0; i < num_threads; i++) { |
| 548 threads[i]->Stop(); |
| 549 delete threads[i]; |
| 550 delete task_complete_events[i]; |
| 551 } |
| 552 |
| 553 std::string tmp; |
| 554 int tmp_int; |
| 555 DictionaryValue* item; |
| 556 |
| 557 // Make sure we get thread name metadata. |
| 558 // Note, the test suite may have created a ton of threads. |
| 559 // So, we'll have thread names for threads we didn't create. |
| 560 std::vector<DictionaryValue*> items = |
| 561 FindTraceEntries(trace_parsed_, "thread_name"); |
| 562 for (int i = 0; i < static_cast<int>(items.size()); i++) { |
| 563 item = items[i]; |
| 564 EXPECT_TRUE(item); |
| 565 EXPECT_TRUE(item->GetInteger("tid", &tmp_int)); |
| 566 |
| 567 // See if this thread name is one of the threads we just created |
| 568 for (int j = 0; j < num_threads; j++) { |
| 569 if(static_cast<int>(thread_ids[j]) != tmp_int) |
| 570 continue; |
| 571 |
| 572 std::string expected_name = StringPrintf("Thread %d", j).c_str(); |
| 573 EXPECT_TRUE(item->GetString("ph", &tmp) && tmp == "M"); |
| 574 EXPECT_TRUE(item->GetInteger("pid", &tmp_int) && |
| 575 tmp_int == static_cast<int>(base::GetCurrentProcId())); |
| 576 EXPECT_TRUE(item->GetString("args.name", &tmp) && |
| 577 tmp == expected_name); |
| 578 } |
| 579 } |
| 580 } |
| 581 |
| 582 namespace { |
| 583 |
496 void TraceCallsWithCachedCategoryPointersPointers(const char* name_str) { | 584 void TraceCallsWithCachedCategoryPointersPointers(const char* name_str) { |
497 TRACE_EVENT0("category name1", name_str); | 585 TRACE_EVENT0("category name1", name_str); |
498 TRACE_EVENT_INSTANT0("category name2", name_str); | 586 TRACE_EVENT_INSTANT0("category name2", name_str); |
499 TRACE_EVENT_BEGIN0("category name3", name_str); | 587 TRACE_EVENT_BEGIN0("category name3", name_str); |
500 TRACE_EVENT_END0("category name4", name_str); | 588 TRACE_EVENT_END0("category name4", name_str); |
501 } | 589 } |
502 | 590 |
| 591 |
| 592 } // namespace |
| 593 |
| 594 |
503 // Test trace calls made after tracing singleton shut down. | 595 // Test trace calls made after tracing singleton shut down. |
504 // | 596 // |
505 // The singleton is destroyed by our base::AtExitManager, but there can be | 597 // The singleton is destroyed by our base::AtExitManager, but there can be |
506 // code still executing as the C++ static objects are destroyed. This test | 598 // code still executing as the C++ static objects are destroyed. This test |
507 // forces the singleton to destroy early, and intentinally makes trace calls | 599 // forces the singleton to destroy early, and intentinally makes trace calls |
508 // afterwards. | 600 // afterwards. |
509 TEST_F(TraceEventTestFixture, AtExit) { | 601 TEST_F(TraceEventTestFixture, AtExit) { |
510 // Repeat this test a few times. Besides just showing robustness, it also | 602 // Repeat this test a few times. Besides just showing robustness, it also |
511 // allows us to test that events at shutdown do not appear with valid events | 603 // allows us to test that events at shutdown do not appear with valid events |
512 // recorded after the system is started again. | 604 // recorded after the system is started again. |
(...skipping 114 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
627 | 719 |
628 std::string s; | 720 std::string s; |
629 EXPECT_TRUE(entry3->GetString("args.arg1", &s)); | 721 EXPECT_TRUE(entry3->GetString("args.arg1", &s)); |
630 EXPECT_EQ("val1", s); | 722 EXPECT_EQ("val1", s); |
631 EXPECT_TRUE(entry3->GetString("args.arg2", &s)); | 723 EXPECT_TRUE(entry3->GetString("args.arg2", &s)); |
632 EXPECT_EQ("val2", s); | 724 EXPECT_EQ("val2", s); |
633 } | 725 } |
634 | 726 |
635 } // namespace debug | 727 } // namespace debug |
636 } // namespace base | 728 } // namespace base |
OLD | NEW |