| 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_impl.h" | 5 #include "base/debug/trace_event_impl.h" |
| 6 | 6 |
| 7 #include <algorithm> | 7 #include <algorithm> |
| 8 | 8 |
| 9 #include "base/bind.h" | 9 #include "base/bind.h" |
| 10 #include "base/debug/leak_annotations.h" | 10 #include "base/debug/leak_annotations.h" |
| (...skipping 209 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 220 start_pos += 2; | 220 start_pos += 2; |
| 221 } | 221 } |
| 222 *out += "\""; | 222 *out += "\""; |
| 223 break; | 223 break; |
| 224 default: | 224 default: |
| 225 NOTREACHED() << "Don't know how to print this value"; | 225 NOTREACHED() << "Don't know how to print this value"; |
| 226 break; | 226 break; |
| 227 } | 227 } |
| 228 } | 228 } |
| 229 | 229 |
| 230 void TraceEvent::AppendEventsAsJSON(const std::vector<TraceEvent>& events, | |
| 231 size_t start, | |
| 232 size_t count, | |
| 233 std::string* out) { | |
| 234 for (size_t i = 0; i < count && start + i < events.size(); ++i) { | |
| 235 if (i > 0) | |
| 236 *out += ","; | |
| 237 events[i + start].AppendAsJSON(out); | |
| 238 } | |
| 239 } | |
| 240 | |
| 241 void TraceEvent::AppendAsJSON(std::string* out) const { | 230 void TraceEvent::AppendAsJSON(std::string* out) const { |
| 242 int64 time_int64 = timestamp_.ToInternalValue(); | 231 int64 time_int64 = timestamp_.ToInternalValue(); |
| 243 int process_id = TraceLog::GetInstance()->process_id(); | 232 int process_id = TraceLog::GetInstance()->process_id(); |
| 244 // Category name checked at category creation time. | 233 // Category name checked at category creation time. |
| 245 DCHECK(!strchr(name_, '"')); | 234 DCHECK(!strchr(name_, '"')); |
| 246 StringAppendF(out, | 235 StringAppendF(out, |
| 247 "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 "," | 236 "{\"cat\":\"%s\",\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 "," |
| 248 "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{", | 237 "\"ph\":\"%c\",\"name\":\"%s\",\"args\":{", |
| 249 TraceLog::GetCategoryName(category_enabled_), | 238 TraceLog::GetCategoryName(category_enabled_), |
| 250 process_id, | 239 process_id, |
| (...skipping 91 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 342 callback_copy_.Run(notification_); | 331 callback_copy_.Run(notification_); |
| 343 } | 332 } |
| 344 | 333 |
| 345 // static | 334 // static |
| 346 TraceLog* TraceLog::GetInstance() { | 335 TraceLog* TraceLog::GetInstance() { |
| 347 return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get(); | 336 return Singleton<TraceLog, StaticMemorySingletonTraits<TraceLog> >::get(); |
| 348 } | 337 } |
| 349 | 338 |
| 350 TraceLog::TraceLog() | 339 TraceLog::TraceLog() |
| 351 : enable_count_(0), | 340 : enable_count_(0), |
| 341 continuous_tracing_(false), |
| 342 logged_events_newest_(0), |
| 343 logged_events_oldest_(0), |
| 352 dispatching_to_observer_list_(false), | 344 dispatching_to_observer_list_(false), |
| 353 watch_category_(NULL) { | 345 watch_category_(NULL) { |
| 354 // Trace is enabled or disabled on one thread while other threads are | 346 // Trace is enabled or disabled on one thread while other threads are |
| 355 // accessing the enabled flag. We don't care whether edge-case events are | 347 // accessing the enabled flag. We don't care whether edge-case events are |
| 356 // traced or not, so we allow races on the enabled flag to keep the trace | 348 // traced or not, so we allow races on the enabled flag to keep the trace |
| 357 // macros fast. | 349 // macros fast. |
| 358 // TODO(jbates): ANNOTATE_BENIGN_RACE_SIZED crashes windows TSAN bots: | 350 // TODO(jbates): ANNOTATE_BENIGN_RACE_SIZED crashes windows TSAN bots: |
| 359 // ANNOTATE_BENIGN_RACE_SIZED(g_category_enabled, sizeof(g_category_enabled), | 351 // ANNOTATE_BENIGN_RACE_SIZED(g_category_enabled, sizeof(g_category_enabled), |
| 360 // "trace_event category enabled"); | 352 // "trace_event category enabled"); |
| 361 for (int i = 0; i < TRACE_EVENT_MAX_CATEGORIES; ++i) { | 353 for (int i = 0; i < TRACE_EVENT_MAX_CATEGORIES; ++i) { |
| (...skipping 235 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 597 } | 589 } |
| 598 | 590 |
| 599 void TraceLog::SetNotificationCallback( | 591 void TraceLog::SetNotificationCallback( |
| 600 const TraceLog::NotificationCallback& cb) { | 592 const TraceLog::NotificationCallback& cb) { |
| 601 AutoLock lock(lock_); | 593 AutoLock lock(lock_); |
| 602 notification_callback_ = cb; | 594 notification_callback_ = cb; |
| 603 } | 595 } |
| 604 | 596 |
| 605 void TraceLog::Flush(const TraceLog::OutputCallback& cb) { | 597 void TraceLog::Flush(const TraceLog::OutputCallback& cb) { |
| 606 std::vector<TraceEvent> previous_logged_events; | 598 std::vector<TraceEvent> previous_logged_events; |
| 599 uint32 oldest_event; |
| 600 uint32 newest_event; |
| 607 { | 601 { |
| 608 AutoLock lock(lock_); | 602 AutoLock lock(lock_); |
| 609 previous_logged_events.swap(logged_events_); | 603 previous_logged_events.swap(logged_events_); |
| 604 |
| 605 oldest_event = logged_events_oldest_; |
| 606 newest_event = logged_events_newest_; |
| 607 |
| 608 logged_events_oldest_ = logged_events_newest_ = 0; |
| 610 } // release lock | 609 } // release lock |
| 611 | 610 |
| 612 for (size_t i = 0; | 611 while (true) { |
| 613 i < previous_logged_events.size(); | 612 if (oldest_event == newest_event) |
| 614 i += kTraceEventBatchSize) { | 613 break; |
| 614 |
| 615 scoped_refptr<RefCountedString> json_events_str_ptr = | 615 scoped_refptr<RefCountedString> json_events_str_ptr = |
| 616 new RefCountedString(); | 616 new RefCountedString(); |
| 617 TraceEvent::AppendEventsAsJSON(previous_logged_events, | 617 |
| 618 i, | 618 for (size_t i = 0; i < kTraceEventBatchSize; ++i) { |
| 619 kTraceEventBatchSize, | 619 if (i > 0) |
| 620 &(json_events_str_ptr->data())); | 620 *(&(json_events_str_ptr->data())) += ","; |
| 621 |
| 622 previous_logged_events[oldest_event].AppendAsJSON( |
| 623 &(json_events_str_ptr->data())); |
| 624 |
| 625 oldest_event++; |
| 626 if (oldest_event >= kTraceEventBufferSize) |
| 627 oldest_event = 0; |
| 628 if (oldest_event == newest_event) |
| 629 break; |
| 630 } |
| 631 |
| 621 cb.Run(json_events_str_ptr); | 632 cb.Run(json_events_str_ptr); |
| 622 } | 633 } |
| 623 } | 634 } |
| 624 | 635 |
| 636 void TraceLog::AddEvent(const TraceEvent& event) { |
| 637 if (logged_events_newest_ < logged_events_.size()) |
| 638 logged_events_[logged_events_newest_] = event; |
| 639 else |
| 640 logged_events_.push_back(event); |
| 641 |
| 642 logged_events_newest_++; |
| 643 if (logged_events_newest_ >= kTraceEventBufferSize) |
| 644 logged_events_newest_ = 0; |
| 645 if (logged_events_newest_ == logged_events_oldest_) { |
| 646 logged_events_oldest_++; |
| 647 if (logged_events_oldest_ >= kTraceEventBufferSize) |
| 648 logged_events_oldest_ = 0; |
| 649 } |
| 650 } |
| 651 |
| 625 void TraceLog::AddTraceEvent(char phase, | 652 void TraceLog::AddTraceEvent(char phase, |
| 626 const unsigned char* category_enabled, | 653 const unsigned char* category_enabled, |
| 627 const char* name, | 654 const char* name, |
| 628 unsigned long long id, | 655 unsigned long long id, |
| 629 int num_args, | 656 int num_args, |
| 630 const char** arg_names, | 657 const char** arg_names, |
| 631 const unsigned char* arg_types, | 658 const unsigned char* arg_types, |
| 632 const unsigned long long* arg_values, | 659 const unsigned long long* arg_values, |
| 633 unsigned char flags) { | 660 unsigned char flags) { |
| 634 DCHECK(name); | 661 DCHECK(name); |
| 635 | 662 |
| 636 #if defined(OS_ANDROID) | 663 #if defined(OS_ANDROID) |
| 637 SendToATrace(phase, GetCategoryName(category_enabled), name, | 664 SendToATrace(phase, GetCategoryName(category_enabled), name, |
| 638 num_args, arg_names, arg_types, arg_values); | 665 num_args, arg_names, arg_types, arg_values); |
| 639 #endif | 666 #endif |
| 640 | 667 |
| 641 TimeTicks now = TimeTicks::NowFromSystemTraceTime() - time_offset_; | 668 TimeTicks now = TimeTicks::NowFromSystemTraceTime() - time_offset_; |
| 642 NotificationHelper notifier(this); | 669 NotificationHelper notifier(this); |
| 643 { | 670 { |
| 644 AutoLock lock(lock_); | 671 AutoLock lock(lock_); |
| 645 if (*category_enabled != CATEGORY_ENABLED) | 672 if (*category_enabled != CATEGORY_ENABLED) |
| 646 return; | 673 return; |
| 647 if (logged_events_.size() >= kTraceEventBufferSize) | 674 if (!continuous_tracing_ && |
| 675 logged_events_.size() >= kTraceEventBufferSize) |
| 648 return; | 676 return; |
| 649 | 677 |
| 650 int thread_id = static_cast<int>(PlatformThread::CurrentId()); | 678 int thread_id = static_cast<int>(PlatformThread::CurrentId()); |
| 651 | 679 |
| 652 const char* new_name = PlatformThread::GetName(); | 680 const char* new_name = PlatformThread::GetName(); |
| 653 // Check if the thread name has been set or changed since the previous | 681 // Check if the thread name has been set or changed since the previous |
| 654 // call (if any), but don't bother if the new name is empty. Note this will | 682 // call (if any), but don't bother if the new name is empty. Note this will |
| 655 // not detect a thread name change within the same char* buffer address: we | 683 // not detect a thread name change within the same char* buffer address: we |
| 656 // favor common case performance over corner case correctness. | 684 // favor common case performance over corner case correctness. |
| 657 if (new_name != g_current_thread_name.Get().Get() && | 685 if (new_name != g_current_thread_name.Get().Get() && |
| (...skipping 15 matching lines...) Expand all Loading... |
| 673 if (!found) { | 701 if (!found) { |
| 674 existing_name->second.push_back(','); | 702 existing_name->second.push_back(','); |
| 675 existing_name->second.append(new_name); | 703 existing_name->second.append(new_name); |
| 676 } | 704 } |
| 677 } | 705 } |
| 678 } | 706 } |
| 679 | 707 |
| 680 if (flags & TRACE_EVENT_FLAG_MANGLE_ID) | 708 if (flags & TRACE_EVENT_FLAG_MANGLE_ID) |
| 681 id ^= process_id_hash_; | 709 id ^= process_id_hash_; |
| 682 | 710 |
| 683 logged_events_.push_back( | 711 AddEvent(TraceEvent(thread_id, |
| 684 TraceEvent(thread_id, | 712 now, phase, category_enabled, name, id, |
| 685 now, phase, category_enabled, name, id, | 713 num_args, arg_names, arg_types, arg_values, |
| 686 num_args, arg_names, arg_types, arg_values, | 714 flags)); |
| 687 flags)); | |
| 688 | 715 |
| 689 if (logged_events_.size() == kTraceEventBufferSize) | 716 if (!continuous_tracing_ && logged_events_.size() == kTraceEventBufferSize) |
| 690 notifier.AddNotificationWhileLocked(TRACE_BUFFER_FULL); | 717 notifier.AddNotificationWhileLocked(TRACE_BUFFER_FULL); |
| 691 | 718 |
| 692 if (watch_category_ == category_enabled && watch_event_name_ == name) | 719 if (watch_category_ == category_enabled && watch_event_name_ == name) |
| 693 notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION); | 720 notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION); |
| 694 } // release lock | 721 } // release lock |
| 695 | 722 |
| 696 notifier.SendNotificationIfAny(); | 723 notifier.SendNotificationIfAny(); |
| 697 } | 724 } |
| 698 | 725 |
| 699 void TraceLog::AddTraceEventEtw(char phase, | 726 void TraceLog::AddTraceEventEtw(char phase, |
| (...skipping 23 matching lines...) Expand all Loading... |
| 723 const std::string& event_name) { | 750 const std::string& event_name) { |
| 724 const unsigned char* category = GetCategoryEnabled(category_name.c_str()); | 751 const unsigned char* category = GetCategoryEnabled(category_name.c_str()); |
| 725 int notify_count = 0; | 752 int notify_count = 0; |
| 726 { | 753 { |
| 727 AutoLock lock(lock_); | 754 AutoLock lock(lock_); |
| 728 watch_category_ = category; | 755 watch_category_ = category; |
| 729 watch_event_name_ = event_name; | 756 watch_event_name_ = event_name; |
| 730 | 757 |
| 731 // First, search existing events for watch event because we want to catch it | 758 // First, search existing events for watch event because we want to catch it |
| 732 // even if it has already occurred. | 759 // even if it has already occurred. |
| 733 for (size_t i = 0u; i < logged_events_.size(); ++i) { | 760 size_t idx = logged_events_oldest_; |
| 734 if (category == logged_events_[i].category_enabled() && | 761 while (true) { |
| 735 strcmp(event_name.c_str(), logged_events_[i].name()) == 0) { | 762 if (idx == logged_events_newest_) |
| 763 break; |
| 764 |
| 765 if (category == logged_events_[idx].category_enabled() && |
| 766 strcmp(event_name.c_str(), logged_events_[idx].name()) == 0) { |
| 736 ++notify_count; | 767 ++notify_count; |
| 737 } | 768 } |
| 769 |
| 770 idx++; |
| 771 if (idx >= kTraceEventBufferSize) |
| 772 idx = 0; |
| 738 } | 773 } |
| 739 } // release lock | 774 } // release lock |
| 740 | 775 |
| 741 // Send notification for each event found. | 776 // Send notification for each event found. |
| 742 for (int i = 0; i < notify_count; ++i) { | 777 for (int i = 0; i < notify_count; ++i) { |
| 743 NotificationHelper notifier(this); | 778 NotificationHelper notifier(this); |
| 744 lock_.Acquire(); | 779 lock_.Acquire(); |
| 745 notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION); | 780 notifier.AddNotificationWhileLocked(EVENT_WATCH_NOTIFICATION); |
| 746 lock_.Release(); | 781 lock_.Release(); |
| 747 notifier.SendNotificationIfAny(); | 782 notifier.SendNotificationIfAny(); |
| (...skipping 10 matching lines...) Expand all Loading... |
| 758 lock_.AssertAcquired(); | 793 lock_.AssertAcquired(); |
| 759 for(hash_map<int, std::string>::iterator it = thread_names_.begin(); | 794 for(hash_map<int, std::string>::iterator it = thread_names_.begin(); |
| 760 it != thread_names_.end(); | 795 it != thread_names_.end(); |
| 761 it++) { | 796 it++) { |
| 762 if (!it->second.empty()) { | 797 if (!it->second.empty()) { |
| 763 int num_args = 1; | 798 int num_args = 1; |
| 764 const char* arg_name = "name"; | 799 const char* arg_name = "name"; |
| 765 unsigned char arg_type; | 800 unsigned char arg_type; |
| 766 unsigned long long arg_value; | 801 unsigned long long arg_value; |
| 767 trace_event_internal::SetTraceValue(it->second, &arg_type, &arg_value); | 802 trace_event_internal::SetTraceValue(it->second, &arg_type, &arg_value); |
| 768 logged_events_.push_back( | 803 AddEvent(TraceEvent(it->first, |
| 769 TraceEvent(it->first, | 804 TimeTicks(), TRACE_EVENT_PHASE_METADATA, |
| 770 TimeTicks(), TRACE_EVENT_PHASE_METADATA, | 805 &g_category_enabled[g_category_metadata], |
| 771 &g_category_enabled[g_category_metadata], | 806 "thread_name", trace_event_internal::kNoEventId, |
| 772 "thread_name", trace_event_internal::kNoEventId, | 807 num_args, &arg_name, &arg_type, &arg_value, |
| 773 num_args, &arg_name, &arg_type, &arg_value, | 808 TRACE_EVENT_FLAG_NONE)); |
| 774 TRACE_EVENT_FLAG_NONE)); | |
| 775 } | 809 } |
| 776 } | 810 } |
| 777 } | 811 } |
| 778 | 812 |
| 779 void TraceLog::DeleteForTesting() { | 813 void TraceLog::DeleteForTesting() { |
| 780 DeleteTraceLogForTesting::Delete(); | 814 DeleteTraceLogForTesting::Delete(); |
| 781 } | 815 } |
| 782 | 816 |
| 783 void TraceLog::Resurrect() { | 817 void TraceLog::Resurrect() { |
| 784 StaticMemorySingletonTraits<TraceLog>::Resurrect(); | 818 StaticMemorySingletonTraits<TraceLog>::Resurrect(); |
| 785 } | 819 } |
| 786 | 820 |
| 787 void TraceLog::SetProcessID(int process_id) { | 821 void TraceLog::SetProcessID(int process_id) { |
| 788 process_id_ = process_id; | 822 process_id_ = process_id; |
| 789 // Create a FNV hash from the process ID for XORing. | 823 // Create a FNV hash from the process ID for XORing. |
| 790 // See http://isthe.com/chongo/tech/comp/fnv/ for algorithm details. | 824 // See http://isthe.com/chongo/tech/comp/fnv/ for algorithm details. |
| 791 unsigned long long offset_basis = 14695981039346656037ull; | 825 unsigned long long offset_basis = 14695981039346656037ull; |
| 792 unsigned long long fnv_prime = 1099511628211ull; | 826 unsigned long long fnv_prime = 1099511628211ull; |
| 793 unsigned long long pid = static_cast<unsigned long long>(process_id_); | 827 unsigned long long pid = static_cast<unsigned long long>(process_id_); |
| 794 process_id_hash_ = (offset_basis ^ pid) * fnv_prime; | 828 process_id_hash_ = (offset_basis ^ pid) * fnv_prime; |
| 795 } | 829 } |
| 796 | 830 |
| 797 void TraceLog::SetTimeOffset(TimeDelta offset) { | 831 void TraceLog::SetTimeOffset(TimeDelta offset) { |
| 798 time_offset_ = offset; | 832 time_offset_ = offset; |
| 799 } | 833 } |
| 800 | 834 |
| 801 } // namespace debug | 835 } // namespace debug |
| 802 } // namespace base | 836 } // namespace base |
| OLD | NEW |