Add flow trace event to WaitableEvent

Provide more information by adding a trace event to WaitableEvent::Wait.
Connect WaitableEvent::Signal with the end of WaitableEvent::TimedWait by a flow event.

Make the implementation of WaitableEvent::Wait cross-platform and move
it in waitable_event.cc.

Bug: 1043616
Change-Id: I07d13d43e951d6fa223202ccd5f6a076559b416f
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2267160Reviewed-by: Gabriel Charette <gab@chromium.org>
Reviewed-by: Alexander Timin <altimin@chromium.org>
Reviewed-by: Albert J. Wong <ajwong@chromium.org>
Commit-Queue: Karel Král <karelkral@google.com>
Cr-Commit-Position: refs/heads/master@{#791831}

base/BUILD.gn

@@ -581,6 +581,7 @@ jumbo_component("base") {
     "synchronization/lock.cc",
     "synchronization/lock.h",
     "synchronization/lock_impl.h",
+    "synchronization/waitable_event.cc",
     "synchronization/waitable_event.h",
     "synchronization/waitable_event_watcher.h",
     "sys_byteorder.h",

base/synchronization/waitable_event.cc

+// Copyright 2020 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#ifndef BASE_SYNCHRONIZATION_WAITABLE_EVENT_INC_
+#define BASE_SYNCHRONIZATION_WAITABLE_EVENT_INC_
+
+#include "base/synchronization/waitable_event.h"
+
+#include "base/trace_event/base_tracing.h"
+
+namespace base {
+
+void WaitableEvent::Wait() {
+  TRACE_EVENT0("base", "WaitableEvent::Wait");
+  bool result = TimedWait(TimeDelta::Max());
+  DCHECK(result) << "TimedWait() should never fail with infinite timeout";
+}
+
+bool WaitableEvent::TimedWait(const TimeDelta& wait_delta) {
+  TRACE_EVENT1("base", "WaitableEvent::TimedWait", "wait_delta_ms",
+               wait_delta.InMillisecondsF());
+  bool was_signaled = WaitableEvent::TimedWaitImpl(wait_delta);
+  TRACE_EVENT_WITH_FLOW0("base", "WaitableEvent::TimedWait WaitFinished", this,
+                         TRACE_EVENT_FLAG_FLOW_IN);
+  return was_signaled;
+}
+
+}  // namespace base
+
+#endif  // BASE_SYNCHRONIZATION_WAITABLE_EVENT_INC_

base/synchronization/waitable_event.h

@@ -165,6 +165,11 @@ class BASE_EXPORT WaitableEvent {
  private:
   friend class WaitableEventWatcher;
 
+  // The platform specific implementation used by Wait()/TimedWait().
+  // Returns true if this call resolves because this WaitableEvent was signaled
+  // (false if it times out).
+  bool TimedWaitImpl(const TimeDelta& wait_delta);
+
 #if defined(OS_WIN)
   win::ScopedHandle handle_;
 #elif defined(OS_MACOSX)

base/synchronization/waitable_event_mac.cc

@@ -20,6 +20,7 @@
 #include "base/threading/thread_restrictions.h"
 #include "base/time/time.h"
 #include "base/time/time_override.h"
+#include "base/trace_event/base_tracing.h"
 #include "build/build_config.h"
 
 namespace base {
@@ -50,6 +51,8 @@ void WaitableEvent::Reset() {
 
 // NO_THREAD_SAFETY_ANALYSIS: Runtime dependent locking.
 void WaitableEvent::Signal() NO_THREAD_SAFETY_ANALYSIS {
+  TRACE_EVENT_WITH_FLOW0("base", "WaitableEvent::Signal", this,
+                         TRACE_EVENT_FLAG_FLOW_OUT);
   // If using the slow watch-list, copy the watchers to a local. After
   // mach_msg(), the event object may be deleted by an awoken thread.
   const bool use_slow_path = UseSlowWatchList(policy_);
@@ -105,12 +108,7 @@ bool WaitableEvent::IsSignaled() {
   return PeekPort(receive_right_->Name(), policy_ == ResetPolicy::AUTOMATIC);
 }
 
-void WaitableEvent::Wait() {
-  bool result = TimedWait(TimeDelta::Max());
-  DCHECK(result) << "TimedWait() should never fail with infinite timeout";
-}
-
-bool WaitableEvent::TimedWait(const TimeDelta& wait_delta) {
+bool WaitableEvent::TimedWaitImpl(const TimeDelta& wait_delta) {
   if (wait_delta <= TimeDelta())
     return IsSignaled();
 

base/synchronization/waitable_event_posix.cc

@@ -18,6 +18,7 @@
 #include "base/threading/thread_restrictions.h"
 #include "base/time/time.h"
 #include "base/time/time_override.h"
+#include "base/trace_event/base_tracing.h"
 
 // -----------------------------------------------------------------------------
 // A WaitableEvent on POSIX is implemented as a wait-list. Currently we don't
@@ -58,6 +59,8 @@ void WaitableEvent::Reset() {
 
 void WaitableEvent::Signal() {
   base::AutoLock locked(kernel_->lock_);
+  TRACE_EVENT_WITH_FLOW0("base", "WaitableEvent::Signal", this,
+                         TRACE_EVENT_FLAG_FLOW_OUT);
 
   if (kernel_->signaled_)
     return;
@@ -153,12 +156,7 @@ class SyncWaiter : public WaitableEvent::Waiter {
   base::ConditionVariable cv_;
 };
 
-void WaitableEvent::Wait() {
-  bool result = TimedWait(TimeDelta::Max());
-  DCHECK(result) << "TimedWait() should never fail with infinite timeout";
-}
-
-bool WaitableEvent::TimedWait(const TimeDelta& wait_delta) {
+bool WaitableEvent::TimedWaitImpl(const TimeDelta& wait_delta) {
   if (wait_delta <= TimeDelta())
     return IsSignaled();
 
@@ -300,7 +298,7 @@ size_t WaitableEvent::WaitMany(WaitableEvent** raw_waitables,
   sw.lock()->Release();
 
   // The address of the WaitableEvent which fired is stored in the SyncWaiter.
-  WaitableEvent *const signaled_event = sw.signaling_event();
+  WaitableEvent* const signaled_event = sw.signaling_event();
   // This will store the index of the raw_waitables which fired.
   size_t signaled_index = 0;
 

base/synchronization/waitable_event_win.cc

@@ -18,6 +18,7 @@
 #include "base/threading/thread_restrictions.h"
 #include "base/time/time.h"
 #include "base/time/time_override.h"
+#include "base/trace_event/base_tracing.h"
 
 namespace base {
 
@@ -44,6 +45,8 @@ void WaitableEvent::Reset() {
 }
 
 void WaitableEvent::Signal() {
+  TRACE_EVENT_WITH_FLOW0("base", "WaitableEvent::Signal", this,
+                         TRACE_EVENT_FLAG_FLOW_OUT);
   SetEvent(handle_.Get());
 }
 
@@ -54,26 +57,7 @@ bool WaitableEvent::IsSignaled() {
   return result == WAIT_OBJECT_0;
 }
 
-void WaitableEvent::Wait() {
-  // Record the event that this thread is blocking upon (for hang diagnosis) and
-  // consider it blocked for scheduling purposes. Ignore this for non-blocking
-  // WaitableEvents.
-  Optional<debug::ScopedEventWaitActivity> event_activity;
-  Optional<internal::ScopedBlockingCallWithBaseSyncPrimitives>
-      scoped_blocking_call;
-  if (waiting_is_blocking_) {
-    event_activity.emplace(this);
-    scoped_blocking_call.emplace(FROM_HERE, BlockingType::MAY_BLOCK);
-  }
-
-  DWORD result = WaitForSingleObject(handle_.Get(), INFINITE);
-  // It is most unexpected that this should ever fail.  Help consumers learn
-  // about it if it should ever fail.
-  DPCHECK(result != WAIT_FAILED);
-  DCHECK_EQ(WAIT_OBJECT_0, result);
-}
-
-bool WaitableEvent::TimedWait(const TimeDelta& wait_delta) {
+bool WaitableEvent::TimedWaitImpl(const TimeDelta& wait_delta) {
   if (wait_delta <= TimeDelta())
     return IsSignaled();