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 |