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 #include <cmath> | 8 #include <cmath> |
9 | 9 |
10 #include "base/base_switches.h" | 10 #include "base/base_switches.h" |
11 #include "base/bind.h" | 11 #include "base/bind.h" |
12 #include "base/command_line.h" | 12 #include "base/command_line.h" |
13 #include "base/debug/leak_annotations.h" | 13 #include "base/debug/leak_annotations.h" |
14 #include "base/format_macros.h" | 14 #include "base/format_macros.h" |
15 #include "base/json/string_escape.h" | 15 #include "base/json/string_escape.h" |
16 #include "base/lazy_instance.h" | 16 #include "base/lazy_instance.h" |
17 #include "base/location.h" | |
18 #include "base/memory/singleton.h" | 17 #include "base/memory/singleton.h" |
| 18 #include "base/message_loop/message_loop.h" |
19 #include "base/process/process_metrics.h" | 19 #include "base/process/process_metrics.h" |
20 #include "base/stl_util.h" | 20 #include "base/stl_util.h" |
21 #include "base/strings/string_number_conversions.h" | 21 #include "base/strings/string_number_conversions.h" |
22 #include "base/strings/string_split.h" | 22 #include "base/strings/string_split.h" |
23 #include "base/strings/string_tokenizer.h" | 23 #include "base/strings/string_tokenizer.h" |
24 #include "base/strings/string_util.h" | 24 #include "base/strings/string_util.h" |
25 #include "base/strings/stringprintf.h" | 25 #include "base/strings/stringprintf.h" |
26 #include "base/strings/utf_string_conversions.h" | 26 #include "base/strings/utf_string_conversions.h" |
27 #include "base/synchronization/cancellation_flag.h" | 27 #include "base/synchronization/cancellation_flag.h" |
28 #include "base/synchronization/waitable_event.h" | 28 #include "base/synchronization/waitable_event.h" |
29 #include "base/sys_info.h" | 29 #include "base/sys_info.h" |
30 #include "base/third_party/dynamic_annotations/dynamic_annotations.h" | 30 #include "base/third_party/dynamic_annotations/dynamic_annotations.h" |
31 #include "base/thread_task_runner_handle.h" | |
32 #include "base/threading/platform_thread.h" | 31 #include "base/threading/platform_thread.h" |
33 #include "base/threading/thread_id_name_manager.h" | 32 #include "base/threading/thread_id_name_manager.h" |
34 #include "base/threading/worker_pool.h" | 33 #include "base/threading/worker_pool.h" |
35 #include "base/time/time.h" | 34 #include "base/time/time.h" |
36 #include "base/trace_event/trace_event.h" | 35 #include "base/trace_event/trace_event.h" |
37 #include "base/trace_event/trace_event_synthetic_delay.h" | 36 #include "base/trace_event/trace_event_synthetic_delay.h" |
38 | 37 |
39 #if defined(OS_WIN) | 38 #if defined(OS_WIN) |
40 #include "base/trace_event/trace_event_etw_export_win.h" | 39 #include "base/trace_event/trace_event_etw_export_win.h" |
41 #include "base/trace_event/trace_event_win.h" | 40 #include "base/trace_event/trace_event_win.h" |
(...skipping 1358 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1400 } | 1399 } |
1401 | 1400 |
1402 void TraceLog::SetEnabled(const CategoryFilter& category_filter, | 1401 void TraceLog::SetEnabled(const CategoryFilter& category_filter, |
1403 Mode mode, | 1402 Mode mode, |
1404 const TraceOptions& options) { | 1403 const TraceOptions& options) { |
1405 std::vector<EnabledStateObserver*> observer_list; | 1404 std::vector<EnabledStateObserver*> observer_list; |
1406 { | 1405 { |
1407 AutoLock lock(lock_); | 1406 AutoLock lock(lock_); |
1408 | 1407 |
1409 // Can't enable tracing when Flush() is in progress. | 1408 // Can't enable tracing when Flush() is in progress. |
1410 DCHECK(!flush_task_runner_); | 1409 DCHECK(!flush_message_loop_proxy_.get()); |
1411 | 1410 |
1412 InternalTraceOptions new_options = | 1411 InternalTraceOptions new_options = |
1413 GetInternalOptionsFromTraceOptions(options); | 1412 GetInternalOptionsFromTraceOptions(options); |
1414 | 1413 |
1415 InternalTraceOptions old_options = trace_options(); | 1414 InternalTraceOptions old_options = trace_options(); |
1416 | 1415 |
1417 if (IsEnabled()) { | 1416 if (IsEnabled()) { |
1418 if (new_options != old_options) { | 1417 if (new_options != old_options) { |
1419 DLOG(ERROR) << "Attempting to re-enable tracing with a different " | 1418 DLOG(ERROR) << "Attempting to re-enable tracing with a different " |
1420 << "set of options."; | 1419 << "set of options."; |
(...skipping 253 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1674 UpdateCategoryGroupEnabledFlags(); | 1673 UpdateCategoryGroupEnabledFlags(); |
1675 }; | 1674 }; |
1676 | 1675 |
1677 void TraceLog::SetEventCallbackDisabled() { | 1676 void TraceLog::SetEventCallbackDisabled() { |
1678 AutoLock lock(lock_); | 1677 AutoLock lock(lock_); |
1679 subtle::NoBarrier_Store(&event_callback_, 0); | 1678 subtle::NoBarrier_Store(&event_callback_, 0); |
1680 UpdateCategoryGroupEnabledFlags(); | 1679 UpdateCategoryGroupEnabledFlags(); |
1681 } | 1680 } |
1682 | 1681 |
1683 // Flush() works as the following: | 1682 // Flush() works as the following: |
1684 // 1. Flush() is called in thread A whose task runner is saved in | 1683 // 1. Flush() is called in threadA whose message loop is saved in |
1685 // flush_task_runner_; | 1684 // flush_message_loop_proxy_; |
1686 // 2. If thread_message_loops_ is not empty, thread A posts task to each message | 1685 // 2. If thread_message_loops_ is not empty, threadA posts task to each message |
1687 // loop to flush the thread local buffers; otherwise finish the flush; | 1686 // loop to flush the thread local buffers; otherwise finish the flush; |
1688 // 3. FlushCurrentThread() deletes the thread local event buffer: | 1687 // 3. FlushCurrentThread() deletes the thread local event buffer: |
1689 // - The last batch of events of the thread are flushed into the main buffer; | 1688 // - The last batch of events of the thread are flushed into the main buffer; |
1690 // - The message loop will be removed from thread_message_loops_; | 1689 // - The message loop will be removed from thread_message_loops_; |
1691 // If this is the last message loop, finish the flush; | 1690 // If this is the last message loop, finish the flush; |
1692 // 4. If any thread hasn't finish its flush in time, finish the flush. | 1691 // 4. If any thread hasn't finish its flush in time, finish the flush. |
1693 void TraceLog::Flush(const TraceLog::OutputCallback& cb, | 1692 void TraceLog::Flush(const TraceLog::OutputCallback& cb, |
1694 bool use_worker_thread) { | 1693 bool use_worker_thread) { |
1695 use_worker_thread_ = use_worker_thread; | 1694 use_worker_thread_ = use_worker_thread; |
1696 if (IsEnabled()) { | 1695 if (IsEnabled()) { |
1697 // Can't flush when tracing is enabled because otherwise PostTask would | 1696 // Can't flush when tracing is enabled because otherwise PostTask would |
1698 // - generate more trace events; | 1697 // - generate more trace events; |
1699 // - deschedule the calling thread on some platforms causing inaccurate | 1698 // - deschedule the calling thread on some platforms causing inaccurate |
1700 // timing of the trace events. | 1699 // timing of the trace events. |
1701 scoped_refptr<RefCountedString> empty_result = new RefCountedString; | 1700 scoped_refptr<RefCountedString> empty_result = new RefCountedString; |
1702 if (!cb.is_null()) | 1701 if (!cb.is_null()) |
1703 cb.Run(empty_result, false); | 1702 cb.Run(empty_result, false); |
1704 LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled"; | 1703 LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled"; |
1705 return; | 1704 return; |
1706 } | 1705 } |
1707 | 1706 |
1708 int generation = this->generation(); | 1707 int generation = this->generation(); |
1709 // Copy of thread_message_loops_ to be used without locking. | 1708 // Copy of thread_message_loops_ to be used without locking. |
1710 std::vector<scoped_refptr<SingleThreadTaskRunner> > | 1709 std::vector<scoped_refptr<SingleThreadTaskRunner> > |
1711 thread_message_loop_task_runners; | 1710 thread_message_loop_task_runners; |
1712 { | 1711 { |
1713 AutoLock lock(lock_); | 1712 AutoLock lock(lock_); |
1714 DCHECK(!flush_task_runner_); | 1713 DCHECK(!flush_message_loop_proxy_.get()); |
1715 flush_task_runner_ = ThreadTaskRunnerHandle::IsSet() | 1714 flush_message_loop_proxy_ = MessageLoopProxy::current(); |
1716 ? ThreadTaskRunnerHandle::Get() | 1715 DCHECK(!thread_message_loops_.size() || flush_message_loop_proxy_.get()); |
1717 : nullptr; | |
1718 DCHECK_IMPLIES(thread_message_loops_.size(), flush_task_runner_); | |
1719 flush_output_callback_ = cb; | 1716 flush_output_callback_ = cb; |
1720 | 1717 |
1721 if (thread_shared_chunk_) { | 1718 if (thread_shared_chunk_) { |
1722 logged_events_->ReturnChunk(thread_shared_chunk_index_, | 1719 logged_events_->ReturnChunk(thread_shared_chunk_index_, |
1723 thread_shared_chunk_.Pass()); | 1720 thread_shared_chunk_.Pass()); |
1724 } | 1721 } |
1725 | 1722 |
1726 if (thread_message_loops_.size()) { | 1723 if (thread_message_loops_.size()) { |
1727 for (hash_set<MessageLoop*>::const_iterator it = | 1724 for (hash_set<MessageLoop*>::const_iterator it = |
1728 thread_message_loops_.begin(); | 1725 thread_message_loops_.begin(); |
1729 it != thread_message_loops_.end(); ++it) { | 1726 it != thread_message_loops_.end(); ++it) { |
1730 thread_message_loop_task_runners.push_back((*it)->task_runner()); | 1727 thread_message_loop_task_runners.push_back((*it)->task_runner()); |
1731 } | 1728 } |
1732 } | 1729 } |
1733 } | 1730 } |
1734 | 1731 |
1735 if (thread_message_loop_task_runners.size()) { | 1732 if (thread_message_loop_task_runners.size()) { |
1736 for (size_t i = 0; i < thread_message_loop_task_runners.size(); ++i) { | 1733 for (size_t i = 0; i < thread_message_loop_task_runners.size(); ++i) { |
1737 thread_message_loop_task_runners[i]->PostTask( | 1734 thread_message_loop_task_runners[i]->PostTask( |
1738 FROM_HERE, | 1735 FROM_HERE, |
1739 Bind(&TraceLog::FlushCurrentThread, Unretained(this), generation)); | 1736 Bind(&TraceLog::FlushCurrentThread, Unretained(this), generation)); |
1740 } | 1737 } |
1741 flush_task_runner_->PostDelayedTask( | 1738 flush_message_loop_proxy_->PostDelayedTask( |
1742 FROM_HERE, | 1739 FROM_HERE, |
1743 Bind(&TraceLog::OnFlushTimeout, Unretained(this), generation), | 1740 Bind(&TraceLog::OnFlushTimeout, Unretained(this), generation), |
1744 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs)); | 1741 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs)); |
1745 return; | 1742 return; |
1746 } | 1743 } |
1747 | 1744 |
1748 FinishFlush(generation); | 1745 FinishFlush(generation); |
1749 } | 1746 } |
1750 | 1747 |
1751 // Usually it runs on a different thread. | 1748 // Usually it runs on a different thread. |
(...skipping 33 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
1785 if (!CheckGeneration(generation)) | 1782 if (!CheckGeneration(generation)) |
1786 return; | 1783 return; |
1787 | 1784 |
1788 { | 1785 { |
1789 AutoLock lock(lock_); | 1786 AutoLock lock(lock_); |
1790 | 1787 |
1791 previous_logged_events.swap(logged_events_); | 1788 previous_logged_events.swap(logged_events_); |
1792 UseNextTraceBuffer(); | 1789 UseNextTraceBuffer(); |
1793 thread_message_loops_.clear(); | 1790 thread_message_loops_.clear(); |
1794 | 1791 |
1795 flush_task_runner_ = NULL; | 1792 flush_message_loop_proxy_ = NULL; |
1796 flush_output_callback = flush_output_callback_; | 1793 flush_output_callback = flush_output_callback_; |
1797 flush_output_callback_.Reset(); | 1794 flush_output_callback_.Reset(); |
1798 } | 1795 } |
1799 | 1796 |
1800 if (use_worker_thread_ && | 1797 if (use_worker_thread_ && |
1801 WorkerPool::PostTask( | 1798 WorkerPool::PostTask( |
1802 FROM_HERE, | 1799 FROM_HERE, |
1803 Bind(&TraceLog::ConvertTraceEventsToTraceFormat, | 1800 Bind(&TraceLog::ConvertTraceEventsToTraceFormat, |
1804 Passed(&previous_logged_events), | 1801 Passed(&previous_logged_events), |
1805 flush_output_callback), | 1802 flush_output_callback), |
1806 true)) { | 1803 true)) { |
1807 return; | 1804 return; |
1808 } | 1805 } |
1809 | 1806 |
1810 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), | 1807 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), |
1811 flush_output_callback); | 1808 flush_output_callback); |
1812 } | 1809 } |
1813 | 1810 |
1814 // Run in each thread holding a local event buffer. | 1811 // Run in each thread holding a local event buffer. |
1815 void TraceLog::FlushCurrentThread(int generation) { | 1812 void TraceLog::FlushCurrentThread(int generation) { |
1816 { | 1813 { |
1817 AutoLock lock(lock_); | 1814 AutoLock lock(lock_); |
1818 if (!CheckGeneration(generation) || !flush_task_runner_) { | 1815 if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get()) { |
1819 // This is late. The corresponding flush has finished. | 1816 // This is late. The corresponding flush has finished. |
1820 return; | 1817 return; |
1821 } | 1818 } |
1822 } | 1819 } |
1823 | 1820 |
1824 // This will flush the thread local buffer. | 1821 // This will flush the thread local buffer. |
1825 delete thread_local_event_buffer_.Get(); | 1822 delete thread_local_event_buffer_.Get(); |
1826 | 1823 |
1827 AutoLock lock(lock_); | 1824 AutoLock lock(lock_); |
1828 if (!CheckGeneration(generation) || !flush_task_runner_ || | 1825 if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get() || |
1829 thread_message_loops_.size()) | 1826 thread_message_loops_.size()) |
1830 return; | 1827 return; |
1831 | 1828 |
1832 flush_task_runner_->PostTask( | 1829 flush_message_loop_proxy_->PostTask( |
1833 FROM_HERE, Bind(&TraceLog::FinishFlush, Unretained(this), generation)); | 1830 FROM_HERE, |
| 1831 Bind(&TraceLog::FinishFlush, Unretained(this), generation)); |
1834 } | 1832 } |
1835 | 1833 |
1836 void TraceLog::OnFlushTimeout(int generation) { | 1834 void TraceLog::OnFlushTimeout(int generation) { |
1837 { | 1835 { |
1838 AutoLock lock(lock_); | 1836 AutoLock lock(lock_); |
1839 if (!CheckGeneration(generation) || !flush_task_runner_) { | 1837 if (!CheckGeneration(generation) || !flush_message_loop_proxy_.get()) { |
1840 // Flush has finished before timeout. | 1838 // Flush has finished before timeout. |
1841 return; | 1839 return; |
1842 } | 1840 } |
1843 | 1841 |
1844 LOG(WARNING) << | 1842 LOG(WARNING) << |
1845 "The following threads haven't finished flush in time. " | 1843 "The following threads haven't finished flush in time. " |
1846 "If this happens stably for some thread, please call " | 1844 "If this happens stably for some thread, please call " |
1847 "TraceLog::GetInstance()->SetCurrentThreadBlocksMessageLoop() from " | 1845 "TraceLog::GetInstance()->SetCurrentThreadBlocksMessageLoop() from " |
1848 "the thread to avoid its trace events from being lost."; | 1846 "the thread to avoid its trace events from being lost."; |
1849 for (hash_set<MessageLoop*>::const_iterator it = | 1847 for (hash_set<MessageLoop*>::const_iterator it = |
(...skipping 786 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
2636 } | 2634 } |
2637 | 2635 |
2638 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { | 2636 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { |
2639 if (*category_group_enabled_) { | 2637 if (*category_group_enabled_) { |
2640 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, | 2638 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, |
2641 name_, event_handle_); | 2639 name_, event_handle_); |
2642 } | 2640 } |
2643 } | 2641 } |
2644 | 2642 |
2645 } // namespace trace_event_internal | 2643 } // namespace trace_event_internal |
OLD | NEW |