cc: Add logging to help pinpoint lost SetNeedsCommit

cc/trees/thread_proxy.cc

 // Copyright 2011 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.
 
 #include "cc/trees/thread_proxy.h"
 
 #include <algorithm>
 #include <string>
 
 #include "base/auto_reset.h"
@@ skipping 241 matching lines @@
 
 void ThreadProxy::SetRendererCapabilitiesMainThreadCopy(
     const RendererCapabilities& capabilities) {
   main().renderer_capabilities_main_thread_copy = capabilities;
 }
 
 void ThreadProxy::SendCommitRequestToImplThreadIfNeeded() {
   DCHECK(IsMainThread());
   if (main().commit_request_sent_to_impl_thread)
     return;
+  VLOG(2) << "ThreadProxy::SendCommitRequestToImplThreadIfNeeded";

[Ken Russell (switch to Gerrit), 2014/09/10 00:43:41]

Would it be better to log earlier and include the value of
main().commit_request_sent_to_impl_thread?

   main().commit_request_sent_to_impl_thread = true;
   Proxy::ImplThreadTaskRunner()->PostTask(
       FROM_HERE,
       base::Bind(&ThreadProxy::SetNeedsCommitOnImplThread,
                  impl_thread_weak_ptr_));
 }
 
 const RendererCapabilities& ThreadProxy::GetRendererCapabilities() const {
   DCHECK(IsMainThread());
   DCHECK(!layer_tree_host()->output_surface_lost());
   return main().renderer_capabilities_main_thread_copy;
 }
 
 void ThreadProxy::SetNeedsAnimate() {
   DCHECK(IsMainThread());
   if (main().animate_requested)
     return;
 
   TRACE_EVENT0("cc", "ThreadProxy::SetNeedsAnimate");
+  VLOG(2) << "ThreadProxy::SetNeedsAnimate";

[Ken Russell (switch to Gerrit), 2014/09/10 00:43:41]

Same question about logging earlier here.

   main().animate_requested = true;
   SendCommitRequestToImplThreadIfNeeded();
 }
 
 void ThreadProxy::SetNeedsUpdateLayers() {
   DCHECK(IsMainThread());
 
   if (main().commit_request_sent_to_impl_thread)
     return;
   TRACE_EVENT0("cc", "ThreadProxy::SetNeedsUpdateLayers");
@@ skipping 82 matching lines @@
   UpdateBackgroundAnimateTicking();
 }
 
 void ThreadProxy::NotifyReadyToActivate() {
   TRACE_EVENT0("cc", "ThreadProxy::NotifyReadyToActivate");
   impl().scheduler->NotifyReadyToActivate();
 }
 
 void ThreadProxy::SetNeedsCommitOnImplThread() {
   TRACE_EVENT0("cc", "ThreadProxy::SetNeedsCommitOnImplThread");
+  VLOG(2) << "ThreadProxy::SetNeedsCommitOnImplThread";
   DCHECK(IsImplThread());
   impl().scheduler->SetNeedsCommit();
 }
 
 void ThreadProxy::PostAnimationEventsToMainThreadOnImplThread(
     scoped_ptr<AnimationEventsVector> events) {
   TRACE_EVENT0("cc",
                "ThreadProxy::PostAnimationEventsToMainThreadOnImplThread");
   DCHECK(IsImplThread());
   Proxy::MainThreadTaskRunner()->PostTask(
@@ skipping 372 matching lines @@
   // Do not notify the impl thread of commit requests that occur during
   // the apply/animate/layout part of the BeginMainFrameAndCommit process since
   // those commit requests will get painted immediately. Once we have done
   // the paint, main().commit_requested will be set to false to allow new commit
   // requests to be scheduled.
   // On the other hand, the animate_requested flag should remain cleared
   // here so that any animation requests generated by the apply or animate
   // callbacks will trigger another frame.
   main().commit_requested = true;
   main().commit_request_sent_to_impl_thread = true;
+  VLOG(2) << "ThreadProxy::BeginMainFrame: Commit requests silenced.";
 
   layer_tree_host()->ApplyScrollAndScale(
       begin_main_frame_state->scroll_info.get());
 
   layer_tree_host()->WillBeginMainFrame();
 
   layer_tree_host()->BeginMainFrame(begin_main_frame_state->begin_frame_args);
   layer_tree_host()->AnimateLayers(
       begin_main_frame_state->begin_frame_args.frame_time);
   blocked_main().last_monotonic_frame_begin_time =
@@ skipping 34 matching lines @@
 
   layer_tree_host()->WillCommit();
 
   // Before calling animate, we set main().animate_requested to false. If it is
   // true now, it means SetNeedAnimate was called again, but during a state when
   // main().commit_request_sent_to_impl_thread = true. We need to force that
   // call to happen again now so that the commit request is sent to the impl
   // thread.
   if (main().animate_requested) {
     // Forces SetNeedsAnimate to consider posting a commit task.
+    VLOG(2) << "ThreadProxy::BeginMainFrame: RAF requested.";
     main().animate_requested = false;
     SetNeedsAnimate();
+  } else {
+    VLOG(2) << "ThreadProxy::BeginMainFrame: RAF NOT requested.";
   }
 
   if (!updated && can_cancel_this_commit) {
     TRACE_EVENT_INSTANT0("cc", "EarlyOut_NoUpdates", TRACE_EVENT_SCOPE_THREAD);
     VLOG(2) << "ThreadProxy::BeginMainFrame: EarlyOut_NoUpdates";
     bool did_handle = true;
     Proxy::ImplThreadTaskRunner()->PostTask(
         FROM_HERE,
         base::Bind(&ThreadProxy::BeginMainFrameAbortedOnImplThread,
                    impl_thread_weak_ptr_,
@@ skipping 569 matching lines @@
 
   impl().timing_history.DidActivateSyncTree();
 }
 
 void ThreadProxy::DidManageTiles() {
   DCHECK(IsImplThread());
   impl().scheduler->DidManageTiles();
 }
 
 }  // namespace cc