cc: Add main frame timing info to frame timing tracker.

cc/trees/thread_proxy.cc

Index: cc/trees/thread_proxy.cc
diff --git a/cc/trees/thread_proxy.cc b/cc/trees/thread_proxy.cc
index ff2ca46615e8e2971beeb4b28d791fa6e5dce06c..bb9e3b01a75723170673632b8405a24542ca9f3f 100644
--- a/cc/trees/thread_proxy.cc
+++ b/cc/trees/thread_proxy.cc
@@ -366,6 +366,8 @@ void ThreadProxy::DidSwapBuffersCompleteOnImplThread() {
 
 void ThreadProxy::WillBeginImplFrame(const BeginFrameArgs& args) {
   impl().layer_tree_host_impl->WillBeginImplFrame(args);
+  impl().last_begin_impl_frame_args =
+      impl().layer_tree_host_impl->CurrentBeginFrameArgs();
 }
 
 void ThreadProxy::OnCanDrawStateChanged(bool can_draw) {
@@ -691,6 +693,7 @@ void ThreadProxy::ScheduledActionSendBeginMainFrame() {
       impl().layer_tree_host_impl->memory_allocation_priority_cutoff();
   begin_main_frame_state->evicted_ui_resources =
       impl().layer_tree_host_impl->EvictedUIResourcesExist();
+  impl().last_begin_main_frame_args = begin_main_frame_state->begin_frame_args;

[brianderson, 2015/03/20 21:14:05]

If main_frame_before_activation_enabled is true in SchedulerSettings, it's
possible for this line to run twice before DidActivateSyncTree gets called once.

main_frame_before_activation_enabled is experimental, so this isn't important to
fix as part of your patch, but can you add a TODO here so we don't accidentally
break your code in the future?

Alternatively, make impl().last_begin_main_frame_args a queue.

[vmpstr, 2015/03/20 22:31:27]

What's the expected behavior (if say this is made non experimental) from this?
That is, in terms of measuring frame times, this would mean that we have
overlapping frames? If so, would we also end up with two activates?

[brianderson, 2015/03/20 23:01:58]

Yes, we would have overlapping frames and we would end up with two activates,
unless the second commit gets aborted.

That second commit can get aborted before the fist commit activates, which is an
interesting case... Maybe best to make this a TODO =)

[vmpstr, 2015/03/23 20:26:43]

Done.

   Proxy::MainThreadTaskRunner()->PostTask(
       FROM_HERE,
       base::Bind(&ThreadProxy::BeginMainFrame,
@@ -935,8 +938,10 @@ void ThreadProxy::BeginMainFrameAbortedOnImplThread(
   DCHECK(impl().scheduler->CommitPending());
   DCHECK(!impl().layer_tree_host_impl->pending_tree());
 
-  if (CommitEarlyOutHandledCommit(reason))
+  if (CommitEarlyOutHandledCommit(reason)) {
     SetInputThrottledUntilCommitOnImplThread(false);
+    RecordMainFrameTiming();
+  }
   impl().layer_tree_host_impl->BeginMainFrameAborted(reason);
   impl().scheduler->BeginMainFrameAborted(reason);
 }
@@ -1356,6 +1361,7 @@ void ThreadProxy::DidActivateSyncTree() {
   }
 
   impl().timing_history.DidActivateSyncTree();
+  RecordMainFrameTiming();

[brianderson, 2015/03/20 21:14:06]

Regarding the interval / prediction issue, we should be able to wait for the
next BeginImpFrame's frame_time instead of predicting it.

We always request one more BeginFrame than we need before going idle to avoid
excess toggling of SetNeedsBeginFrames. The logic that does that is here:
https://code.google.com/p/chromium/codesearch#chromium/src/cc/scheduler/sched...

Can you do something like:
1) Add a last_begin_main_frame_activated_args and assign it to
last_begin_main_frame_args here.
2) If last_begin_main_frame_activated_args.IsValid() in WillBeginImplFrame, call
RecordMainFrameTiming there.

[vmpstr, 2015/03/20 22:31:27]

I think that's an excellent idea. I'm guessing the whole kick-off one more frame
before becoming idle idea is sticking around, right? :)

Also, is this going to happen in the case of CommitEarlyOutHandledCommit?

[brianderson, 2015/03/20 23:01:58]

There are no plans to get rid of it. It's especially important for requesting
BeginFrames from the Browser where we want to hide the latency of the thread
hops. We are moving all platforms to that model.
No. Good catch. 

You'd need to modify SchedulerStateMachine::UpdateStateOnCommit(true) to somehow
make ProactiveBeginFrameWanted true, which is something we should probably do
anyway.

[mithro-old, 2015/03/23 00:15:08]

I agree with Brian here.

[vmpstr, 2015/03/23 20:26:43]

Done.

 }
 
 void ThreadProxy::DidPrepareTiles() {
@@ -1370,4 +1376,13 @@ void ThreadProxy::DidCompletePageScaleAnimationOnImplThread() {
                             main_thread_weak_ptr_));
 }
 
+void ThreadProxy::RecordMainFrameTiming() {
+  // Last begin main frame args records the frame args that we last sent to the
+  // main thread. Last begin impl frame args, on the other hand, records the
+  // last time we started an impl frame which should be the frame during which
+  // this call is being run.
+  impl().layer_tree_host_impl->RecordMainFrameTiming(
+      impl().last_begin_main_frame_args, impl().last_begin_impl_frame_args);

[brianderson, 2015/03/20 21:14:06]

Although this is slightly wrong right now because begin_main_frame_args uses
Now() for it's frame time, while begin_impl_frame_args uses the original frame
time, I think it's good enough to land.

Tim's patch should make this 100% correct once it lands and I don't see a reason
to introduce workarounds in this patch, especially since getting this 100%
correct isn't urgent.

[vmpstr, 2015/03/20 22:31:27]

Acknowledged.

+}
+
 }  // namespace cc