From f9be1053de943283ec72f4dbf2e6fce78fd2fea1 Mon Sep 17 00:00:00 2001 From: "wangxianzhu@chromium.org" Date: Wed, 18 Sep 2013 08:15:46 +0000 Subject: [PATCH] Fix --trace-shutdown with thread-local tracing. With thread-local tracing (r221766), TraceLog::Flush() is async and needs to be called from a thread having a message loop. It also requires that tracing has been stopped. BrowserShutdownProfileDumper is a special caller that TraceLog::Flush() was originally called from a thread without message loop. Now start another thread for flushing, and call TraceLog::SetDisabled() before TraceLog::Flush(). The calling thread needs to wait for the completion of the flush, otherwise the browser may shutdown before all trace events written. Temporarily allow the thread to wait in ThreadRestrictions. BUG=none TEST=manual run chrome with --trace-shutdown. Should not assert. Should generate correct trace file. Review URL: https://chromiumcodereview.appspot.com/24047007 git-svn-id: svn://svn.chromium.org/chrome/trunk/src@223819 0039d316-1c4b-4281-b951-d872f2087c98 --- base/debug/trace_event_impl.cc | 1 + base/threading/thread_restrictions.h | 2 ++ .../browser_shutdown_profile_dumper.cc | 33 +++++++++++++++++-- .../browser/browser_shutdown_profile_dumper.h | 4 +++ 4 files changed, 38 insertions(+), 2 deletions(-) diff --git a/base/debug/trace_event_impl.cc b/base/debug/trace_event_impl.cc index 39d23dd368fa03..fd683501efdb62 100644 --- a/base/debug/trace_event_impl.cc +++ b/base/debug/trace_event_impl.cc @@ -1334,6 +1334,7 @@ void TraceLog::Flush(const TraceLog::OutputCallback& cb) { scoped_refptr empty_result = new RefCountedString; if (!cb.is_null()) cb.Run(empty_result, false); + LOG(WARNING) << "Ignored TraceLog::Flush called when tracing is enabled"; return; } diff --git a/base/threading/thread_restrictions.h b/base/threading/thread_restrictions.h index bc25d6af9d9580..f52e64cf6ddde9 100644 --- a/base/threading/thread_restrictions.h +++ b/base/threading/thread_restrictions.h @@ -42,6 +42,7 @@ class Predictor; } namespace content { class BrowserGpuChannelHostFactory; +class BrowserShutdownProfileDumper; class BrowserTestBase; class GLHelper; class GpuChannelHost; @@ -176,6 +177,7 @@ class BASE_EXPORT ThreadRestrictions { private: // DO NOT ADD ANY OTHER FRIEND STATEMENTS, talk to jam or brettw first. // BEGIN ALLOWED USAGE. + friend class content::BrowserShutdownProfileDumper; friend class content::BrowserTestBase; friend class content::NestedMessagePumpAndroid; friend class content::RenderWidgetHelper; diff --git a/content/browser/browser_shutdown_profile_dumper.cc b/content/browser/browser_shutdown_profile_dumper.cc index fcf2299507f7c9..70e3e5389c1f35 100644 --- a/content/browser/browser_shutdown_profile_dumper.cc +++ b/content/browser/browser_shutdown_profile_dumper.cc @@ -11,6 +11,9 @@ #include "base/file_util.h" #include "base/files/file_path.h" #include "base/logging.h" +#include "base/synchronization/waitable_event.h" +#include "base/threading/thread.h" +#include "base/threading/thread_restrictions.h" #include "content/public/common/content_switches.h" namespace content { @@ -43,9 +46,31 @@ void BrowserShutdownProfileDumper::WriteTracesToDisc( WriteString("{\"traceEvents\":"); WriteString("["); + // TraceLog::Flush() requires the calling thread to have a message loop. + // As the message loop of the current thread may have quit, start another + // thread for flushing the trace. + base::WaitableEvent flush_complete_event(false, false); + base::Thread flush_thread("browser_shutdown_trace_event_flush"); + flush_thread.Start(); + flush_thread.message_loop()->PostTask( + FROM_HERE, + base::Bind(&BrowserShutdownProfileDumper::EndTraceAndFlush, + base::Unretained(this), + base::Unretained(&flush_complete_event))); + + bool original_wait_allowed = base::ThreadRestrictions::SetWaitAllowed(true); + flush_complete_event.Wait(); + base::ThreadRestrictions::SetWaitAllowed(original_wait_allowed); +} + +void BrowserShutdownProfileDumper::EndTraceAndFlush( + base::WaitableEvent* flush_complete_event) { + while (base::debug::TraceLog::GetInstance()->IsEnabled()) + base::debug::TraceLog::GetInstance()->SetDisabled(); base::debug::TraceLog::GetInstance()->Flush( base::Bind(&BrowserShutdownProfileDumper::WriteTraceDataCollected, - base::Unretained(this))); + base::Unretained(this), + base::Unretained(flush_complete_event))); } base::FilePath BrowserShutdownProfileDumper::GetFileName() { @@ -61,10 +86,13 @@ base::FilePath BrowserShutdownProfileDumper::GetFileName() { } void BrowserShutdownProfileDumper::WriteTraceDataCollected( + base::WaitableEvent* flush_complete_event, const scoped_refptr& events_str, bool has_more_events) { - if (!IsFileValid()) + if (!IsFileValid()) { + flush_complete_event->Signal(); return; + } if (blocks_) { // Blocks are not comma separated. Beginning with the second block we // start therefore to add one in front of the previous block. @@ -77,6 +105,7 @@ void BrowserShutdownProfileDumper::WriteTraceDataCollected( WriteString("]"); WriteString("}"); CloseFile(); + flush_complete_event->Signal(); } } diff --git a/content/browser/browser_shutdown_profile_dumper.h b/content/browser/browser_shutdown_profile_dumper.h index efccb3802ed997..f98a32cb9ca98d 100644 --- a/content/browser/browser_shutdown_profile_dumper.h +++ b/content/browser/browser_shutdown_profile_dumper.h @@ -14,6 +14,7 @@ namespace base { class FilePath; +class WaitableEvent; } namespace content { @@ -36,12 +37,15 @@ class BrowserShutdownProfileDumper { // Writes all traces which happened to disk. void WriteTracesToDisc(const base::FilePath& file_name); + void EndTraceAndFlush(base::WaitableEvent* flush_complete_event); + // Returns the file name where we should save the trace dump to. base::FilePath GetFileName(); // The callback for the |TraceLog::Flush| function. It saves all traces to // disc. void WriteTraceDataCollected( + base::WaitableEvent* flush_complete_event, const scoped_refptr& events_str, bool has_more_events);