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