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