| 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/trace_event/trace_event_impl.h" | 5 #include "base/trace_event/trace_event_impl.h" |
| 6 | 6 |
| 7 #include <algorithm> | 7 #include <algorithm> |
| 8 | 8 |
| 9 #include "base/base_switches.h" | 9 #include "base/base_switches.h" |
| 10 #include "base/bind.h" | 10 #include "base/bind.h" |
| (...skipping 676 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 687 case TRACE_VALUE_TYPE_STRING: | 687 case TRACE_VALUE_TYPE_STRING: |
| 688 case TRACE_VALUE_TYPE_COPY_STRING: | 688 case TRACE_VALUE_TYPE_COPY_STRING: |
| 689 EscapeJSONString(value.as_string ? value.as_string : "NULL", true, out); | 689 EscapeJSONString(value.as_string ? value.as_string : "NULL", true, out); |
| 690 break; | 690 break; |
| 691 default: | 691 default: |
| 692 NOTREACHED() << "Don't know how to print this value"; | 692 NOTREACHED() << "Don't know how to print this value"; |
| 693 break; | 693 break; |
| 694 } | 694 } |
| 695 } | 695 } |
| 696 | 696 |
| 697 void TraceEvent::AppendAsJSON(std::string* out) const { | 697 void TraceEvent::AppendAsJSON( |
| 698 std::string* out, |
| 699 const EventFilterPredicate& event_filter_predicate) const { |
| 698 int64 time_int64 = timestamp_.ToInternalValue(); | 700 int64 time_int64 = timestamp_.ToInternalValue(); |
| 699 int process_id = TraceLog::GetInstance()->process_id(); | 701 int process_id = TraceLog::GetInstance()->process_id(); |
| 702 const char* category_group_name = |
| 703 TraceLog::GetCategoryGroupName(category_group_enabled_); |
| 704 |
| 700 // Category group checked at category creation time. | 705 // Category group checked at category creation time. |
| 701 DCHECK(!strchr(name_, '"')); | 706 DCHECK(!strchr(name_, '"')); |
| 702 StringAppendF(out, | 707 StringAppendF(out, "{\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 |
| 703 "{\"pid\":%i,\"tid\":%i,\"ts\":%" PRId64 "," | 708 "," |
| 704 "\"ph\":\"%c\",\"cat\":\"%s\",\"name\":\"%s\",\"args\":{", | 709 "\"ph\":\"%c\",\"cat\":\"%s\",\"name\":\"%s\",\"args\":{", |
| 705 process_id, | 710 process_id, thread_id_, time_int64, phase_, category_group_name, |
| 706 thread_id_, | 711 name_); |
| 707 time_int64, | |
| 708 phase_, | |
| 709 TraceLog::GetCategoryGroupName(category_group_enabled_), | |
| 710 name_); | |
| 711 | 712 |
| 712 // Output argument names and values, stop at first NULL argument name. | 713 // Output argument names and values, stop at first NULL argument name. |
| 713 for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { | 714 if (arg_names_[0]) { |
| 714 if (i > 0) | 715 bool allow_args = event_filter_predicate.is_null() || |
| 715 *out += ","; | 716 event_filter_predicate.Run(category_group_name, name_); |
| 716 *out += "\""; | |
| 717 *out += arg_names_[i]; | |
| 718 *out += "\":"; | |
| 719 | 717 |
| 720 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) | 718 if (allow_args) { |
| 721 convertable_values_[i]->AppendAsTraceFormat(out); | 719 for (int i = 0; i < kTraceMaxNumArgs && arg_names_[i]; ++i) { |
| 722 else | 720 if (i > 0) |
| 723 AppendValueAsJSON(arg_types_[i], arg_values_[i], out); | 721 *out += ","; |
| 722 *out += "\""; |
| 723 *out += arg_names_[i]; |
| 724 *out += "\":"; |
| 725 |
| 726 if (arg_types_[i] == TRACE_VALUE_TYPE_CONVERTABLE) |
| 727 convertable_values_[i]->AppendAsTraceFormat(out); |
| 728 else |
| 729 AppendValueAsJSON(arg_types_[i], arg_values_[i], out); |
| 730 } |
| 731 } else { |
| 732 *out += "\"stripped\":1"; |
| 733 } |
| 724 } | 734 } |
| 735 |
| 725 *out += "}"; | 736 *out += "}"; |
| 726 | 737 |
| 727 if (phase_ == TRACE_EVENT_PHASE_COMPLETE) { | 738 if (phase_ == TRACE_EVENT_PHASE_COMPLETE) { |
| 728 int64 duration = duration_.ToInternalValue(); | 739 int64 duration = duration_.ToInternalValue(); |
| 729 if (duration != -1) | 740 if (duration != -1) |
| 730 StringAppendF(out, ",\"dur\":%" PRId64, duration); | 741 StringAppendF(out, ",\"dur\":%" PRId64, duration); |
| 731 if (!thread_timestamp_.is_null()) { | 742 if (!thread_timestamp_.is_null()) { |
| 732 int64 thread_duration = thread_duration_.ToInternalValue(); | 743 int64 thread_duration = thread_duration_.ToInternalValue(); |
| 733 if (thread_duration != -1) | 744 if (thread_duration != -1) |
| 734 StringAppendF(out, ",\"tdur\":%" PRId64, thread_duration); | 745 StringAppendF(out, ",\"tdur\":%" PRId64, thread_duration); |
| (...skipping 738 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1473 // Notify observers outside the lock in case they trigger trace events. | 1484 // Notify observers outside the lock in case they trigger trace events. |
| 1474 for (size_t i = 0; i < observer_list.size(); ++i) | 1485 for (size_t i = 0; i < observer_list.size(); ++i) |
| 1475 observer_list[i]->OnTraceLogEnabled(); | 1486 observer_list[i]->OnTraceLogEnabled(); |
| 1476 | 1487 |
| 1477 { | 1488 { |
| 1478 AutoLock lock(lock_); | 1489 AutoLock lock(lock_); |
| 1479 dispatching_to_observer_list_ = false; | 1490 dispatching_to_observer_list_ = false; |
| 1480 } | 1491 } |
| 1481 } | 1492 } |
| 1482 | 1493 |
| 1494 void TraceLog::SetEventFilterPredicate( |
| 1495 const TraceEvent::EventFilterPredicate& event_filter_predicate) { |
| 1496 AutoLock lock(lock_); |
| 1497 event_filter_predicate_ = event_filter_predicate; |
| 1498 } |
| 1499 |
| 1483 TraceLog::InternalTraceOptions TraceLog::GetInternalOptionsFromTraceOptions( | 1500 TraceLog::InternalTraceOptions TraceLog::GetInternalOptionsFromTraceOptions( |
| 1484 const TraceOptions& options) { | 1501 const TraceOptions& options) { |
| 1485 InternalTraceOptions ret = | 1502 InternalTraceOptions ret = |
| 1486 options.enable_sampling ? kInternalEnableSampling : kInternalNone; | 1503 options.enable_sampling ? kInternalEnableSampling : kInternalNone; |
| 1487 switch (options.record_mode) { | 1504 switch (options.record_mode) { |
| 1488 case RECORD_UNTIL_FULL: | 1505 case RECORD_UNTIL_FULL: |
| 1489 return ret | kInternalRecordUntilFull; | 1506 return ret | kInternalRecordUntilFull; |
| 1490 case RECORD_CONTINUOUSLY: | 1507 case RECORD_CONTINUOUSLY: |
| 1491 return ret | kInternalRecordContinuously; | 1508 return ret | kInternalRecordContinuously; |
| 1492 case ECHO_TO_CONSOLE: | 1509 case ECHO_TO_CONSOLE: |
| (...skipping 248 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1741 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs)); | 1758 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs)); |
| 1742 return; | 1759 return; |
| 1743 } | 1760 } |
| 1744 | 1761 |
| 1745 FinishFlush(generation); | 1762 FinishFlush(generation); |
| 1746 } | 1763 } |
| 1747 | 1764 |
| 1748 // Usually it runs on a different thread. | 1765 // Usually it runs on a different thread. |
| 1749 void TraceLog::ConvertTraceEventsToTraceFormat( | 1766 void TraceLog::ConvertTraceEventsToTraceFormat( |
| 1750 scoped_ptr<TraceBuffer> logged_events, | 1767 scoped_ptr<TraceBuffer> logged_events, |
| 1751 const TraceLog::OutputCallback& flush_output_callback) { | 1768 const OutputCallback& flush_output_callback, |
| 1752 | 1769 const TraceEvent::EventFilterPredicate& event_filter_predicate) { |
| 1753 if (flush_output_callback.is_null()) | 1770 if (flush_output_callback.is_null()) |
| 1754 return; | 1771 return; |
| 1755 | 1772 |
| 1756 // The callback need to be called at least once even if there is no events | 1773 // The callback need to be called at least once even if there is no events |
| 1757 // to let the caller know the completion of flush. | 1774 // to let the caller know the completion of flush. |
| 1758 bool has_more_events = true; | 1775 bool has_more_events = true; |
| 1759 do { | 1776 do { |
| 1760 scoped_refptr<RefCountedString> json_events_str_ptr = | 1777 scoped_refptr<RefCountedString> json_events_str_ptr = |
| 1761 new RefCountedString(); | 1778 new RefCountedString(); |
| 1762 | 1779 |
| 1763 while (json_events_str_ptr->size() < kTraceEventBufferSizeInBytes) { | 1780 while (json_events_str_ptr->size() < kTraceEventBufferSizeInBytes) { |
| 1764 const TraceBufferChunk* chunk = logged_events->NextChunk(); | 1781 const TraceBufferChunk* chunk = logged_events->NextChunk(); |
| 1765 has_more_events = chunk != NULL; | 1782 has_more_events = chunk != NULL; |
| 1766 if (!chunk) | 1783 if (!chunk) |
| 1767 break; | 1784 break; |
| 1768 for (size_t j = 0; j < chunk->size(); ++j) { | 1785 for (size_t j = 0; j < chunk->size(); ++j) { |
| 1769 if (json_events_str_ptr->size()) | 1786 if (json_events_str_ptr->size()) |
| 1770 json_events_str_ptr->data().append(",\n"); | 1787 json_events_str_ptr->data().append(",\n"); |
| 1771 chunk->GetEventAt(j)->AppendAsJSON(&(json_events_str_ptr->data())); | 1788 chunk->GetEventAt(j)->AppendAsJSON(&(json_events_str_ptr->data()), |
| 1789 event_filter_predicate); |
| 1772 } | 1790 } |
| 1773 } | 1791 } |
| 1774 flush_output_callback.Run(json_events_str_ptr, has_more_events); | 1792 flush_output_callback.Run(json_events_str_ptr, has_more_events); |
| 1775 } while (has_more_events); | 1793 } while (has_more_events); |
| 1776 } | 1794 } |
| 1777 | 1795 |
| 1778 void TraceLog::FinishFlush(int generation) { | 1796 void TraceLog::FinishFlush(int generation) { |
| 1779 scoped_ptr<TraceBuffer> previous_logged_events; | 1797 scoped_ptr<TraceBuffer> previous_logged_events; |
| 1780 OutputCallback flush_output_callback; | 1798 OutputCallback flush_output_callback; |
| 1799 TraceEvent::EventFilterPredicate event_filter_predicate; |
| 1781 | 1800 |
| 1782 if (!CheckGeneration(generation)) | 1801 if (!CheckGeneration(generation)) |
| 1783 return; | 1802 return; |
| 1784 | 1803 |
| 1785 { | 1804 { |
| 1786 AutoLock lock(lock_); | 1805 AutoLock lock(lock_); |
| 1787 | 1806 |
| 1788 previous_logged_events.swap(logged_events_); | 1807 previous_logged_events.swap(logged_events_); |
| 1789 UseNextTraceBuffer(); | 1808 UseNextTraceBuffer(); |
| 1790 thread_message_loops_.clear(); | 1809 thread_message_loops_.clear(); |
| 1791 | 1810 |
| 1792 flush_message_loop_proxy_ = NULL; | 1811 flush_message_loop_proxy_ = NULL; |
| 1793 flush_output_callback = flush_output_callback_; | 1812 flush_output_callback = flush_output_callback_; |
| 1794 flush_output_callback_.Reset(); | 1813 flush_output_callback_.Reset(); |
| 1814 |
| 1815 event_filter_predicate = event_filter_predicate_; |
| 1816 event_filter_predicate_.Reset(); |
| 1795 } | 1817 } |
| 1796 | 1818 |
| 1797 if (use_worker_thread_ && | 1819 if (use_worker_thread_ && |
| 1798 WorkerPool::PostTask( | 1820 WorkerPool::PostTask( |
| 1799 FROM_HERE, | 1821 FROM_HERE, Bind(&TraceLog::ConvertTraceEventsToTraceFormat, |
| 1800 Bind(&TraceLog::ConvertTraceEventsToTraceFormat, | 1822 Unretained(this), Passed(&previous_logged_events), |
| 1801 Passed(&previous_logged_events), | 1823 flush_output_callback, event_filter_predicate), |
| 1802 flush_output_callback), | |
| 1803 true)) { | 1824 true)) { |
| 1804 return; | 1825 return; |
| 1805 } | 1826 } |
| 1806 | 1827 |
| 1807 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), | 1828 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), |
| 1808 flush_output_callback); | 1829 flush_output_callback, |
| 1830 event_filter_predicate); |
| 1809 } | 1831 } |
| 1810 | 1832 |
| 1811 // Run in each thread holding a local event buffer. | 1833 // Run in each thread holding a local event buffer. |
| 1812 void TraceLog::FlushCurrentThread(int generation) { | 1834 void TraceLog::FlushCurrentThread(int generation) { |
| 1813 { | 1835 { |
| 1814 AutoLock lock(lock_); | 1836 AutoLock lock(lock_); |
| 1815 if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get()) { | 1837 if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get()) { |
| 1816 // This is late. The corresponding flush has finished. | 1838 // This is late. The corresponding flush has finished. |
| 1817 return; | 1839 return; |
| 1818 } | 1840 } |
| (...skipping 30 matching lines...) Expand all Loading... |
| 1849 it != thread_message_loops_.end(); ++it) { | 1871 it != thread_message_loops_.end(); ++it) { |
| 1850 LOG(WARNING) << "Thread: " << (*it)->thread_name(); | 1872 LOG(WARNING) << "Thread: " << (*it)->thread_name(); |
| 1851 } | 1873 } |
| 1852 } | 1874 } |
| 1853 FinishFlush(generation); | 1875 FinishFlush(generation); |
| 1854 } | 1876 } |
| 1855 | 1877 |
| 1856 void TraceLog::FlushButLeaveBufferIntact( | 1878 void TraceLog::FlushButLeaveBufferIntact( |
| 1857 const TraceLog::OutputCallback& flush_output_callback) { | 1879 const TraceLog::OutputCallback& flush_output_callback) { |
| 1858 scoped_ptr<TraceBuffer> previous_logged_events; | 1880 scoped_ptr<TraceBuffer> previous_logged_events; |
| 1881 TraceEvent::EventFilterPredicate event_filter_predicate; |
| 1859 { | 1882 { |
| 1860 AutoLock lock(lock_); | 1883 AutoLock lock(lock_); |
| 1861 AddMetadataEventsWhileLocked(); | 1884 AddMetadataEventsWhileLocked(); |
| 1862 if (thread_shared_chunk_) { | 1885 if (thread_shared_chunk_) { |
| 1863 // Return the chunk to the main buffer to flush the sampling data. | 1886 // Return the chunk to the main buffer to flush the sampling data. |
| 1864 logged_events_->ReturnChunk(thread_shared_chunk_index_, | 1887 logged_events_->ReturnChunk(thread_shared_chunk_index_, |
| 1865 thread_shared_chunk_.Pass()); | 1888 thread_shared_chunk_.Pass()); |
| 1866 } | 1889 } |
| 1867 previous_logged_events = logged_events_->CloneForIteration().Pass(); | 1890 previous_logged_events = logged_events_->CloneForIteration().Pass(); |
| 1891 event_filter_predicate = event_filter_predicate_; |
| 1868 } // release lock | 1892 } // release lock |
| 1869 | 1893 |
| 1870 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), | 1894 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), |
| 1871 flush_output_callback); | 1895 flush_output_callback, |
| 1896 event_filter_predicate); |
| 1872 } | 1897 } |
| 1873 | 1898 |
| 1874 void TraceLog::UseNextTraceBuffer() { | 1899 void TraceLog::UseNextTraceBuffer() { |
| 1875 logged_events_.reset(CreateTraceBuffer()); | 1900 logged_events_.reset(CreateTraceBuffer()); |
| 1876 subtle::NoBarrier_AtomicIncrement(&generation_, 1); | 1901 subtle::NoBarrier_AtomicIncrement(&generation_, 1); |
| 1877 thread_shared_chunk_.reset(); | 1902 thread_shared_chunk_.reset(); |
| 1878 thread_shared_chunk_index_ = 0; | 1903 thread_shared_chunk_index_ = 0; |
| 1879 } | 1904 } |
| 1880 | 1905 |
| 1881 TraceEventHandle TraceLog::AddTraceEvent( | 1906 TraceEventHandle TraceLog::AddTraceEvent( |
| (...skipping 752 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 2634 } | 2659 } |
| 2635 | 2660 |
| 2636 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { | 2661 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { |
| 2637 if (*category_group_enabled_) { | 2662 if (*category_group_enabled_) { |
| 2638 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, | 2663 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, |
| 2639 name_, event_handle_); | 2664 name_, event_handle_); |
| 2640 } | 2665 } |
| 2641 } | 2666 } |
| 2642 | 2667 |
| 2643 } // namespace trace_event_internal | 2668 } // namespace trace_event_internal |
| OLD | NEW |