Chromium Code Reviews
chromiumcodereview-hr@appspot.gserviceaccount.com (chromiumcodereview-hr) | Please choose your nickname with Settings | Help | Chromium Project | Gerrit Changes | Sign out
(584)

Side by Side Diff: base/debug/trace_event_impl.cc

Issue 12096115: Update tracing framework to optionally use a ringbuffer. (Closed) Base URL: svn://svn.chromium.org/chrome/trunk/src
Patch Set: Created 7 years, 10 months ago
Use n/p to move between diff chunks; N/P to move between comments. Draft comments are only viewable by you.
Jump to:
View unified diff | Download patch | Annotate | Revision Log
OLDNEW
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
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
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
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
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
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
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
OLDNEW

Powered by Google App Engine
This is Rietveld 408576698