Update Viz Flow tracing and Rotation Debug Traces

With DCHECKs enabled base::HashInts uses a random seed, which is only
valid in its process. This means that a given viz::LocalSurfaceId would
have different hashes in different process. Which breaks performing
Traces with Flow.

Additionally while debugging issue 1060058 I noticed it was difficult to
know when Viz was blocked on pending surfaces, and when rotations were
occurring. This change adds a new trace to viz::Surface to list the
Surface being waited on. As well as adding new traces to LayerTreeHost
to denote the current viewport rect.

Bug: 1154826
Change-Id: I60d9f2f195ae6ca45e9eabd101df971462b34224
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2633098
Commit-Queue: Jonathan Ross <jonross@chromium.org>
Reviewed-by: kylechar <kylechar@chromium.org>
Cr-Commit-Position: refs/heads/master@{#844783}

cc/mojo_embedder/async_layer_tree_frame_sink.cc

@@ -123,11 +123,12 @@ void AsyncLayerTreeFrameSink::SubmitCompositorFrame(
   DCHECK(frame.metadata.begin_frame_ack.has_damage);
   DCHECK(frame.metadata.begin_frame_ack.frame_id.IsSequenceValid());
 
-  TRACE_EVENT_WITH_FLOW1(
+  TRACE_EVENT_WITH_FLOW2(
       "viz,benchmark", "Graphics.Pipeline",
       TRACE_ID_GLOBAL(frame.metadata.begin_frame_ack.trace_id),
       TRACE_EVENT_FLAG_FLOW_IN | TRACE_EVENT_FLAG_FLOW_OUT, "step",
-      "SubmitCompositorFrame");
+      "SubmitCompositorFrame", "local_surface_id",
+      local_surface_id_.ToString());
 
   if (local_surface_id_ == last_submitted_local_surface_id_) {
     DCHECK_EQ(last_submitted_device_scale_factor_, frame.device_scale_factor());

cc/trees/layer_tree_host.cc

@@ -1228,6 +1228,13 @@ void LayerTreeHost::SetViewportRectAndScale(
       local_surface_id_from_parent_;
   SetLocalSurfaceIdFromParent(local_surface_id_from_parent);
 
+  TRACE_EVENT_NESTABLE_ASYNC_END0("cc", "LayerTreeHostSize",
+                                  TRACE_ID_LOCAL(this));
+  TRACE_EVENT_NESTABLE_ASYNC_BEGIN2("cc", "LayerTreeHostSize",
+                                    TRACE_ID_LOCAL(this), "size",
+                                    device_viewport_rect.ToString(), "lsid",
+                                    local_surface_id_from_parent.ToString());
+
   bool device_viewport_rect_changed = false;
   if (device_viewport_rect_ != device_viewport_rect) {
     device_viewport_rect_ = device_viewport_rect;

components/viz/common/surfaces/local_surface_id.cc

@@ -4,11 +4,29 @@
 
 #include "components/viz/common/surfaces/local_surface_id.h"
 
+#include <limits>
+
+#include "base/hash/hash.h"
 #include "base/logging.h"
 #include "base/strings/stringprintf.h"
 
 namespace viz {
 
+size_t LocalSurfaceId::hash() const {
+  DCHECK(is_valid()) << ToString();
+  return base::HashInts(
+      static_cast<uint64_t>(
+          base::HashInts(parent_sequence_number_, child_sequence_number_)),
+      static_cast<uint64_t>(base::UnguessableTokenHash()(embed_token_)));
+}
+
+size_t LocalSurfaceId::persistent_hash() const {
+  DCHECK(is_valid()) << ToString();
+  return base::PersistentHash(
+      base::StringPrintf("%s, %u, %u", embed_token_.ToString().c_str(),
+                         parent_sequence_number_, child_sequence_number_));
+}
+
 std::string LocalSurfaceId::ToString() const {
   std::string embed_token = VLOG_IS_ON(1)
                                 ? embed_token_.ToString()

components/viz/common/surfaces/local_surface_id.h

@@ -8,10 +8,10 @@
 #include <inttypes.h>
 
 #include <iosfwd>
+#include <limits>
 #include <string>
 #include <tuple>
 
-#include "base/hash/hash.h"
 #include "base/unguessable_token.h"
 #include "components/viz/common/viz_common_export.h"
 #include "mojo/public/cpp/bindings/struct_traits.h"
@@ -111,11 +111,11 @@ class VIZ_COMMON_EXPORT LocalSurfaceId {
 
   // The |embed_trace_id| is used as the id for trace events associated with
   // embedding this LocalSurfaceId.
-  uint64_t embed_trace_id() const { return hash() << 1; }
+  uint64_t embed_trace_id() const { return persistent_hash() << 1; }
 
   // The |submission_trace_id| is used as the id for trace events associated
   // with submission of a CompositorFrame to a surface with this LocalSurfaceId.
-  uint64_t submission_trace_id() const { return (hash() << 1) | 1; }
+  uint64_t submission_trace_id() const { return (persistent_hash() << 1) | 1; }
 
   bool operator==(const LocalSurfaceId& other) const {
     return parent_sequence_number_ == other.parent_sequence_number_ &&
@@ -127,13 +127,14 @@ class VIZ_COMMON_EXPORT LocalSurfaceId {
     return !(*this == other);
   }
 
-  size_t hash() const {
-    DCHECK(is_valid()) << ToString();
-    return base::HashInts(
-        static_cast<uint64_t>(
-            base::HashInts(parent_sequence_number_, child_sequence_number_)),
-        static_cast<uint64_t>(base::UnguessableTokenHash()(embed_token_)));
-  }
+  // This implementation is fast and appropriate for a hash table lookup.
+  // However the hash differs per process, and is inappropriate for tracing.
+  size_t hash() const;
+
+  // This implementation is slow and not appropriate for a hash table lookup.
+  // However the hash is consistent across processes and can be used for
+  // tracing.
+  size_t persistent_hash() const;
 
   std::string ToString() const;
 
@@ -184,10 +185,6 @@ inline bool operator>=(const LocalSurfaceId& lhs, const LocalSurfaceId& rhs) {
   return !operator<(lhs, rhs);
 }
 
-struct LocalSurfaceIdHash {
-  size_t operator()(const LocalSurfaceId& key) const { return key.hash(); }
-};
-
 }  // namespace viz
 
 #endif  // COMPONENTS_VIZ_COMMON_SURFACES_LOCAL_SURFACE_ID_H_

components/viz/service/surfaces/surface.cc

@@ -15,6 +15,7 @@
 #include "base/stl_util.h"
 #include "base/time/tick_clock.h"
 #include "base/trace_event/trace_event.h"
+#include "base/trace_event/traced_value.h"
 #include "components/viz/common/quads/compositor_render_pass.h"
 #include "components/viz/common/resources/returned_resource.h"
 #include "components/viz/common/resources/transferable_resource.h"
@@ -267,6 +268,15 @@ Surface::QueueFrameResult Surface::QueueFrame(
     if (deadline_->HasDeadlinePassed()) {
       ActivatePendingFrameForDeadline();
     } else {
+      auto traced_value = std::make_unique<base::trace_event::TracedValue>();
+      traced_value->BeginArray("Pending");
+      for (auto& it : activation_dependencies_)
+        traced_value->AppendString(it.ToString());
+      traced_value->EndArray();
+      TRACE_EVENT_NESTABLE_ASYNC_BEGIN2(
+          "viz", "SurfaceQueuedPending", TRACE_ID_LOCAL(this), "LocalSurfaceId",
+          surface_info_.id().ToString(), "ActivationDependencies",
+          std::move(traced_value));
       result = QueueFrameResult::ACCEPTED_PENDING;
     }
   }
@@ -334,6 +344,11 @@ void Surface::ActivatePendingFrameForDeadline() {
   if (!pending_frame_data_)
     return;
 
+  if (!activation_dependencies_.empty()) {
+    TRACE_EVENT_NESTABLE_ASYNC_END0("viz", "SurfaceQueuedPending",
+                                    TRACE_ID_LOCAL(this));
+  }
+
   // If a frame is being activated because of a deadline, then clear its set
   // of blockers.
   activation_dependencies_.clear();
@@ -433,8 +448,8 @@ void Surface::RecomputeActiveReferencedSurfaces() {
 // A frame is activated if all its Surface ID dependencies are active or a
 // deadline has hit and the frame was forcibly activated.
 void Surface::ActivateFrame(FrameData frame_data) {
-  TRACE_EVENT1("viz", "Surface::ActivateFrame", "FrameSinkId",
-               surface_id().frame_sink_id().ToString());
+  TRACE_EVENT1("viz", "Surface::ActivateFrame", "SurfaceId",
+               surface_id().ToString());
 
   // Save root pass copy requests.
   std::vector<std::unique_ptr<CopyOutputRequest>> old_copy_requests;