| 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 1279 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1322 } | 1324 } |
| 1323 | 1325 |
| 1324 void TraceLog::SetEnabled(const CategoryFilter& category_filter, | 1326 void TraceLog::SetEnabled(const CategoryFilter& category_filter, |
| 1325 Mode mode, | 1327 Mode mode, |
| 1326 Options options) { | 1328 Options options) { |
| 1327 std::vector<EnabledStateObserver*> observer_list; | 1329 std::vector<EnabledStateObserver*> observer_list; |
| 1328 { | 1330 { |
| 1329 AutoLock lock(lock_); | 1331 AutoLock lock(lock_); |
| 1330 | 1332 |
| 1331 // Can't enable tracing when Flush() is in progress. | 1333 // Can't enable tracing when Flush() is in progress. |
| 1332 DCHECK(!flush_message_loop_proxy_.get()); | 1334 DCHECK(!flush_task_runner_.get()); |
| 1333 | 1335 |
| 1334 Options old_options = trace_options(); | 1336 Options old_options = trace_options(); |
| 1335 | 1337 |
| 1336 if (IsEnabled()) { | 1338 if (IsEnabled()) { |
| 1337 if (options != old_options) { | 1339 if (options != old_options) { |
| 1338 DLOG(ERROR) << "Attempting to re-enable tracing with a different " | 1340 DLOG(ERROR) << "Attempting to re-enable tracing with a different " |
| 1339 << "set of options."; | 1341 << "set of options."; |
| 1340 } | 1342 } |
| 1341 | 1343 |
| 1342 if (mode != mode_) { | 1344 if (mode != mode_) { |
| (...skipping 204 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1547 }; | 1549 }; |
| 1548 | 1550 |
| 1549 void TraceLog::SetEventCallbackDisabled() { | 1551 void TraceLog::SetEventCallbackDisabled() { |
| 1550 AutoLock lock(lock_); | 1552 AutoLock lock(lock_); |
| 1551 subtle::NoBarrier_Store(&event_callback_, 0); | 1553 subtle::NoBarrier_Store(&event_callback_, 0); |
| 1552 UpdateCategoryGroupEnabledFlags(); | 1554 UpdateCategoryGroupEnabledFlags(); |
| 1553 } | 1555 } |
| 1554 | 1556 |
| 1555 // Flush() works as the following: | 1557 // Flush() works as the following: |
| 1556 // 1. Flush() is called in threadA whose message loop is saved in | 1558 // 1. Flush() is called in threadA whose message loop is saved in |
| 1557 // flush_message_loop_proxy_; | 1559 // flush_task_runner_; |
| 1558 // 2. If thread_message_loops_ is not empty, threadA posts task to each message | 1560 // 2. If thread_message_loops_ is not empty, threadA posts task to each message |
| 1559 // loop to flush the thread local buffers; otherwise finish the flush; | 1561 // loop to flush the thread local buffers; otherwise finish the flush; |
| 1560 // 3. FlushCurrentThread() deletes the thread local event buffer: | 1562 // 3. FlushCurrentThread() deletes the thread local event buffer: |
| 1561 // - The last batch of events of the thread are flushed into the main buffer; | 1563 // - The last batch of events of the thread are flushed into the main buffer; |
| 1562 // - The message loop will be removed from thread_message_loops_; | 1564 // - The message loop will be removed from thread_message_loops_; |
| 1563 // If this is the last message loop, finish the flush; | 1565 // If this is the last message loop, finish the flush; |
| 1564 // 4. If any thread hasn't finish its flush in time, finish the flush. | 1566 // 4. If any thread hasn't finish its flush in time, finish the flush. |
| 1565 void TraceLog::Flush(const TraceLog::OutputCallback& cb) { | 1567 void TraceLog::Flush(const TraceLog::OutputCallback& cb) { |
| 1566 if (IsEnabled()) { | 1568 if (IsEnabled()) { |
| 1567 // Can't flush when tracing is enabled because otherwise PostTask would | 1569 // Can't flush when tracing is enabled because otherwise PostTask would |
| 1568 // - generate more trace events; | 1570 // - generate more trace events; |
| 1569 // - deschedule the calling thread on some platforms causing inaccurate | 1571 // - deschedule the calling thread on some platforms causing inaccurate |
| 1570 // timing of the trace events. | 1572 // timing of the trace events. |
| 1571 scoped_refptr<RefCountedString> empty_result = new RefCountedString; | 1573 scoped_refptr<RefCountedString> empty_result = new RefCountedString; |
| 1572 if (!cb.is_null()) | 1574 if (!cb.is_null()) |
| 1573 cb.Run(empty_result, false); | 1575 cb.Run(empty_result, false); |
| 1574 LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled"; | 1576 LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled"; |
| 1575 return; | 1577 return; |
| 1576 } | 1578 } |
| 1577 | 1579 |
| 1578 int generation = this->generation(); | 1580 int generation = this->generation(); |
| 1579 { | 1581 { |
| 1580 AutoLock lock(lock_); | 1582 AutoLock lock(lock_); |
| 1581 DCHECK(!flush_message_loop_proxy_.get()); | 1583 DCHECK(!flush_task_runner_.get()); |
| 1582 flush_message_loop_proxy_ = MessageLoopProxy::current(); | 1584 // In unit tests, there may not be a task runner set |
| 1583 DCHECK(!thread_message_loops_.size() || flush_message_loop_proxy_.get()); | 1585 if (ThreadTaskRunnerHandle::IsSet()) |
| 1586 flush_task_runner_ = ThreadTaskRunnerHandle::Get(); |
| 1587 DCHECK(!thread_message_loops_.size() || flush_task_runner_.get()); |
| 1584 flush_output_callback_ = cb; | 1588 flush_output_callback_ = cb; |
| 1585 | 1589 |
| 1586 if (thread_shared_chunk_) { | 1590 if (thread_shared_chunk_) { |
| 1587 logged_events_->ReturnChunk(thread_shared_chunk_index_, | 1591 logged_events_->ReturnChunk(thread_shared_chunk_index_, |
| 1588 thread_shared_chunk_.Pass()); | 1592 thread_shared_chunk_.Pass()); |
| 1589 } | 1593 } |
| 1590 | 1594 |
| 1591 if (thread_message_loops_.size()) { | 1595 if (thread_message_loops_.size()) { |
| 1592 for (hash_set<MessageLoop*>::const_iterator it = | 1596 for (hash_set<MessageLoop*>::const_iterator it = |
| 1593 thread_message_loops_.begin(); | 1597 thread_message_loops_.begin(); |
| 1594 it != thread_message_loops_.end(); ++it) { | 1598 it != thread_message_loops_.end(); ++it) { |
| 1595 (*it)->PostTask( | 1599 (*it)->PostTask( |
| 1596 FROM_HERE, | 1600 FROM_HERE, |
| 1597 Bind(&TraceLog::FlushCurrentThread, Unretained(this), generation)); | 1601 Bind(&TraceLog::FlushCurrentThread, Unretained(this), generation)); |
| 1598 } | 1602 } |
| 1599 flush_message_loop_proxy_->PostDelayedTask( | 1603 flush_task_runner_->PostDelayedTask( |
| 1600 FROM_HERE, | 1604 FROM_HERE, |
| 1601 Bind(&TraceLog::OnFlushTimeout, Unretained(this), generation), | 1605 Bind(&TraceLog::OnFlushTimeout, Unretained(this), generation), |
| 1602 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs)); | 1606 TimeDelta::FromMilliseconds(kThreadFlushTimeoutMs)); |
| 1603 return; | 1607 return; |
| 1604 } | 1608 } |
| 1605 } | 1609 } |
| 1606 | 1610 |
| 1607 FinishFlush(generation); | 1611 FinishFlush(generation); |
| 1608 } | 1612 } |
| 1609 | 1613 |
| (...skipping 35 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 1645 if (!CheckGeneration(generation)) | 1649 if (!CheckGeneration(generation)) |
| 1646 return; | 1650 return; |
| 1647 | 1651 |
| 1648 { | 1652 { |
| 1649 AutoLock lock(lock_); | 1653 AutoLock lock(lock_); |
| 1650 | 1654 |
| 1651 previous_logged_events.swap(logged_events_); | 1655 previous_logged_events.swap(logged_events_); |
| 1652 UseNextTraceBuffer(); | 1656 UseNextTraceBuffer(); |
| 1653 thread_message_loops_.clear(); | 1657 thread_message_loops_.clear(); |
| 1654 | 1658 |
| 1655 flush_message_loop_proxy_ = NULL; | 1659 flush_task_runner_ = NULL; |
| 1656 flush_output_callback = flush_output_callback_; | 1660 flush_output_callback = flush_output_callback_; |
| 1657 flush_output_callback_.Reset(); | 1661 flush_output_callback_.Reset(); |
| 1658 } | 1662 } |
| 1659 | 1663 |
| 1660 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), | 1664 ConvertTraceEventsToTraceFormat(previous_logged_events.Pass(), |
| 1661 flush_output_callback); | 1665 flush_output_callback); |
| 1662 } | 1666 } |
| 1663 | 1667 |
| 1664 // Run in each thread holding a local event buffer. | 1668 // Run in each thread holding a local event buffer. |
| 1665 void TraceLog::FlushCurrentThread(int generation) { | 1669 void TraceLog::FlushCurrentThread(int generation) { |
| 1666 { | 1670 { |
| 1667 AutoLock lock(lock_); | 1671 AutoLock lock(lock_); |
| 1668 if (!CheckGeneration(generation) || !flush_message_loop_proxy_) { | 1672 if (!CheckGeneration(generation) || !flush_task_runner_) { |
| 1669 // This is late. The corresponding flush has finished. | 1673 // This is late. The corresponding flush has finished. |
| 1670 return; | 1674 return; |
| 1671 } | 1675 } |
| 1672 } | 1676 } |
| 1673 | 1677 |
| 1674 // This will flush the thread local buffer. | 1678 // This will flush the thread local buffer. |
| 1675 delete thread_local_event_buffer_.Get(); | 1679 delete thread_local_event_buffer_.Get(); |
| 1676 | 1680 |
| 1677 AutoLock lock(lock_); | 1681 AutoLock lock(lock_); |
| 1678 if (!CheckGeneration(generation) || !flush_message_loop_proxy_ || | 1682 if (!CheckGeneration(generation) || !flush_task_runner_ || |
| 1679 thread_message_loops_.size()) | 1683 thread_message_loops_.size()) |
| 1680 return; | 1684 return; |
| 1681 | 1685 |
| 1682 flush_message_loop_proxy_->PostTask( | 1686 flush_task_runner_->PostTask( |
| 1683 FROM_HERE, | 1687 FROM_HERE, Bind(&TraceLog::FinishFlush, Unretained(this), generation)); |
| 1684 Bind(&TraceLog::FinishFlush, Unretained(this), generation)); | |
| 1685 } | 1688 } |
| 1686 | 1689 |
| 1687 void TraceLog::OnFlushTimeout(int generation) { | 1690 void TraceLog::OnFlushTimeout(int generation) { |
| 1688 { | 1691 { |
| 1689 AutoLock lock(lock_); | 1692 AutoLock lock(lock_); |
| 1690 if (!CheckGeneration(generation) || !flush_message_loop_proxy_) { | 1693 if (!CheckGeneration(generation) || !flush_task_runner_) { |
| 1691 // Flush has finished before timeout. | 1694 // Flush has finished before timeout. |
| 1692 return; | 1695 return; |
| 1693 } | 1696 } |
| 1694 | 1697 |
| 1695 LOG(WARNING) << | 1698 LOG(WARNING) << |
| 1696 "The following threads haven't finished flush in time. " | 1699 "The following threads haven't finished flush in time. " |
| 1697 "If this happens stably for some thread, please call " | 1700 "If this happens stably for some thread, please call " |
| 1698 "TraceLog::GetInstance()->SetCurrentThreadBlocksMessageLoop() from " | 1701 "TraceLog::GetInstance()->SetCurrentThreadBlocksMessageLoop() from " |
| 1699 "the thread to avoid its trace events from being lost."; | 1702 "the thread to avoid its trace events from being lost."; |
| 1700 for (hash_set<MessageLoop*>::const_iterator it = | 1703 for (hash_set<MessageLoop*>::const_iterator it = |
| (...skipping 727 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 2428 } | 2431 } |
| 2429 | 2432 |
| 2430 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { | 2433 ScopedTraceBinaryEfficient::~ScopedTraceBinaryEfficient() { |
| 2431 if (*category_group_enabled_) { | 2434 if (*category_group_enabled_) { |
| 2432 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, | 2435 TRACE_EVENT_API_UPDATE_TRACE_EVENT_DURATION(category_group_enabled_, |
| 2433 name_, event_handle_); | 2436 name_, event_handle_); |
| 2434 } | 2437 } |
| 2435 } | 2438 } |
| 2436 | 2439 |
| 2437 } // namespace trace_event_internal | 2440 } // namespace trace_event_internal |
| OLD | NEW |