time metric: record elapsed time from when the backgrounded and purged renderer is foregrounded unti

time metric: record elapsed time from when the backgrounded and purged renderer is foregrounded until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some 
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
Review-Url: https://codereview.chromium.org/2643723007
Cr-Commit-Position: refs/heads/master@{#449038}
Committed: https://chromium.googlesource.com/chromium/src/+/b95dbb50ccb02e2f5584419033d5409ae0e1d8f5

[tasak, 2017-01-20 05:12:30]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-01-20 05:12:44]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-20 05:14:23]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-20 05:14:24]

Dry run: Try jobs failed on following builders:
  ios-simulator-xcode-clang on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/ios-simulator-xco...)
  mac_chromium_rel_ng on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/mac_chromium_rel_...)

[tasak, 2017-01-20 05:17:02]

Description was changed from

==========
time metric: record elapsed time from when the backgrounded renderer becomes
visible until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some
caches, we need to recover the caches when the renderer is painted, i.e. whether
the recovery takes short time or not.

BUG=
==========

to

==========
time metric: record elapsed time from when the backgrounded renderer becomes
visible until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
==========

[tasak, 2017-01-20 06:09:28]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-01-20 06:09:43]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-20 08:44:02]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-20 08:44:03]

Dry run: Try jobs failed on following builders:
  linux_chromium_rel_ng on master.tryserver.chromium.linux (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/linux_chromium_...)

[tasak, 2017-01-20 10:12:32]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-01-20 10:12:52]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[tasak, 2017-01-20 10:19:28]

Patchset #3 (id:40001) has been deleted

[tasak, 2017-01-20 10:19:37]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-01-20 10:19:59]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[tasak, 2017-01-20 10:20:25]

Description was changed from

==========
time metric: record elapsed time from when the backgrounded renderer becomes
visible until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
==========

to

==========
time metric: record elapsed time from when the backgrounded and purged renderer
is foregrounded until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
==========

[tasak, 2017-01-20 10:22:05]

tasak@google.com changed reviewers:
+ haraken@chromium.org

[commit-bot: I haz the power, 2017-01-20 11:16:03]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-20 11:16:04]

Dry run: This issue passed the CQ dry run.

[tasak, 2017-01-20 11:52:31]

tasak@google.com changed reviewers:
+ esprehn@chromium.org

[tasak, 2017-01-20 11:52:31]

esprehn, would you advise me which is better way to add UMA, patch set 2 or
patch set 3?

Now I'm trying to add UMA for Purge+Suspend experiment.
The uma measures how long it takes for a backgrounded and purged renderer to
paint when the renderer is foregrounded.

I have two idea: (1) is to update FrameView (i.e.
third_party/WebKit/Source/core/frame/FrameView) and (2) is to update
RenderViewImpl(content/renderer/render_view_impl) and
RenderThreadImpl(content/renderer/render_thread_impl).
Purge+Suspend is implemented in TabManager and RenderThreadImpl.

Firstly I tried (1), i.e. patch set 2, but I found that it is difficult to know
whether purged or not in FrameView. As far as I investigated, there is no simple
way to obtain RenderView, RenderWidget or RenderFrame in RenderThreadImpl. 

So I tried (2), i.e. patch set 3. However, I'm not sure whether patch set 3 is
allowable or not.

Best regards,

[tasak, 2017-01-23 08:51:04]

tasak@google.com changed reviewers:
+ jam@chromium.org

[tasak, 2017-01-23 08:51:05]

Would you review this CL?

[haraken, 2017-01-25 03:06:04]

Elliott: Would you mind reviewing this CL? This metric is needed to evaluate the
tab switching cost of purge+throttle.

[esprehn, 2017-01-25 03:22:17]

This doesn't seem like the right layering, the RenderThread should expose the
metric times and the RenderWidget should ask for them and then report the UMA.
I'd rather not have more generic "OnWidgetDidStuff()" callbacks, they end up
being dumping grounds for more code in the future.

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
File content/renderer/render_thread_impl.cc (right):

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
content/renderer/render_thread_impl.cc:2450: if (record_first_active_paint_)
Can we put all of this code into RenderWidget instead and have it query the
times from the RenderThread?

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
File content/renderer/render_widget.cc (right):

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
content/renderer/render_widget.cc:926: if (RenderThreadImpl* render_thread =
RenderThreadImpl::current())
How can the thread be null if we're inside UpdateVisualState() ?

[tasak, 2017-01-26 06:25:46]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-01-26 06:26:02]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-01-26 07:34:06]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-01-26 07:34:08]

Dry run: This issue passed the CQ dry run.

[tasak, 2017-01-26 09:39:40]

Thank you for review.

I moved the code into RenderWidget. To do so, I added a new IPC message, which
is used for RenderViewHost to notify RenderWidget of Purge+Suspend.

Or I should add some getter method to see record_first_active_paint_ in
RenderWidget?

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
File content/renderer/render_thread_impl.cc (right):

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
content/renderer/render_thread_impl.cc:2450: if (record_first_active_paint_)
On 2017/01/25 03:22:17, esprehn wrote:
> Can we put all of this code into RenderWidget instead and have it query the
> times from the RenderThread?

I moved the code into RenderWidget.

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
File content/renderer/render_widget.cc (right):

https://codereview.chromium.org/2643723007/diff/70001/content/renderer/render...
content/renderer/render_widget.cc:926: if (RenderThreadImpl* render_thread =
RenderThreadImpl::current())
On 2017/01/25 03:22:17, esprehn wrote:
> How can the thread be null if we're inside UpdateVisualState() ?

I'm afraid that some unittests creates RenderWidget without any
RenderThreadImpl. However, all trybots seem to pass. I think, we don't need this
check.

Done.

[haraken, 2017-01-27 09:49:39]

Elliott: Would you review this when you have a moment? We might want to get some
metric before BlinkOn :)

[esprehn, 2017-01-27 16:48:54]

Hmm why do we need a new IPC? It's strange to have an IPC that's just for this
metric, what ipcs normally turn purge and suspend on and off?

[tasak, 2017-01-30 05:31:04]

On 2017/01/27 16:48:54, esprehn wrote:
> Hmm why do we need a new IPC? It's strange to have an IPC that's just for this
> metric, what ipcs normally turn purge and suspend on and off?

As far as I investigated, it is difficult to find RenderWidget, RenderView, and
RenderFrame in RenderThreadImpl.
(It is very easy to find RenderThreadImpl in RenderView and RenderWidget...)

So I think, there are probably the following ways:

(1) moves all Purge+Suspend code from RenderThreadImpl to RenderWidget (or
RenderView),
(2) adds "Getter" to RenderThreadImpl, which returns whether purged or not,
(3) sends IPC message to RenderWidget, and RenderWidget tells RenderThreadImpl
to purge, or
(4) sends IPC message to RenderWidget too,

The newest patch is (4). I'm not sure which is the best way to add this metric.

[esprehn, 2017-01-30 17:16:54]

Description was changed from

==========
time metric: record elapsed time from when the backgrounded and purged renderer
is foregrounded until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
==========

to

==========
time metric: record elapsed time from when the backgrounded and purged renderer
is foregrounded until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some 
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
==========

[esprehn, 2017-01-30 17:19:27]

esprehn@chromium.org changed reviewers:
+ oysteine@chromium.org

[esprehn, 2017-01-30 17:19:28]

oysteine@ This seems like a good place for the PCU system. I don't think we
should be adding new infrastructure and IPCs for this metric.

The renderer should be adding an entry to the internal performance timeline for
visibility, resume, and paint events. To compute the metric the patch is trying
to compute we just need to install a PerformanceObserver on ["purge", "resume",
"paint"], and then at idle time we can process the event stream and report the
metric.

[oystein (OOO til 10th of July), 2017-01-31 18:56:02]

On 2017/01/30 17:19:28, esprehn wrote:
> oysteine@ This seems like a good place for the PCU system. I don't think we
> should be adding new infrastructure and IPCs for this metric.
> 
> The renderer should be adding an entry to the internal performance timeline
for
> visibility, resume, and paint events. To compute the metric the patch is
trying
> to compute we just need to install a PerformanceObserver on ["purge",
"resume",
> "paint"], and then at idle time we can process the event stream and report the
> metric.

I agree, any time we need custom plumbing code to implement a metric there's a
clear signal that we'd be better off with a central service for this.

What's the timeline for when this metric is necessary? (BlinkOn was mentioned,
but that's a bit late now unfortunately). Is this something we want to land for
now and then use as one of the first use-cases to convert to the pcu, or block
on?

[haraken, 2017-01-31 19:10:45]

On 2017/01/31 18:56:02, oystein wrote:
> On 2017/01/30 17:19:28, esprehn wrote:
> > oysteine@ This seems like a good place for the PCU system. I don't think we
> > should be adding new infrastructure and IPCs for this metric.
> > 
> > The renderer should be adding an entry to the internal performance timeline
> for
> > visibility, resume, and paint events. To compute the metric the patch is
> trying
> > to compute we just need to install a PerformanceObserver on ["purge",
> "resume",
> > "paint"], and then at idle time we can process the event stream and report
the
> > metric.
> 
> I agree, any time we need custom plumbing code to implement a metric there's a
> clear signal that we'd be better off with a central service for this.
> 
> What's the timeline for when this metric is necessary? (BlinkOn was mentioned,
> but that's a bit late now unfortunately). Is this something we want to land
for
> now and then use as one of the first use-cases to convert to the pcu, or block
> on?

Asap :) We want to collect the metric so that we can ship purge+throttle in M58.

[haraken, 2017-02-03 04:12:18]

On 2017/01/31 19:10:45, haraken wrote:
> On 2017/01/31 18:56:02, oystein wrote:
> > On 2017/01/30 17:19:28, esprehn wrote:
> > > oysteine@ This seems like a good place for the PCU system. I don't think
we
> > > should be adding new infrastructure and IPCs for this metric.
> > > 
> > > The renderer should be adding an entry to the internal performance
timeline
> > for
> > > visibility, resume, and paint events. To compute the metric the patch is
> > trying
> > > to compute we just need to install a PerformanceObserver on ["purge",
> > "resume",
> > > "paint"], and then at idle time we can process the event stream and report
> the
> > > metric.
> > 
> > I agree, any time we need custom plumbing code to implement a metric there's
a
> > clear signal that we'd be better off with a central service for this.
> > 
> > What's the timeline for when this metric is necessary? (BlinkOn was
mentioned,
> > but that's a bit late now unfortunately). Is this something we want to land
> for
> > now and then use as one of the first use-cases to convert to the pcu, or
block
> > on?
> 
> Asap :) We want to collect the metric so that we can ship purge+throttle in
M58.

Oystein: Friendly ping :)

[oystein (OOO til 10th of July), 2017-02-03 23:18:17]

On 2017/02/03 at 04:12:18, haraken wrote:
> On 2017/01/31 19:10:45, haraken wrote:
> > On 2017/01/31 18:56:02, oystein wrote:
> > > On 2017/01/30 17:19:28, esprehn wrote:
> > > > oysteine@ This seems like a good place for the PCU system. I don't think
we
> > > > should be adding new infrastructure and IPCs for this metric.
> > > > 
> > > > The renderer should be adding an entry to the internal performance
timeline
> > > for
> > > > visibility, resume, and paint events. To compute the metric the patch is
> > > trying
> > > > to compute we just need to install a PerformanceObserver on ["purge",
> > > "resume",
> > > > "paint"], and then at idle time we can process the event stream and
report
> > the
> > > > metric.
> > > 
> > > I agree, any time we need custom plumbing code to implement a metric
there's a
> > > clear signal that we'd be better off with a central service for this.
> > > 
> > > What's the timeline for when this metric is necessary? (BlinkOn was
mentioned,
> > > but that's a bit late now unfortunately). Is this something we want to
land
> > for
> > > now and then use as one of the first use-cases to convert to the pcu, or
block
> > > on?
> > 
> > Asap :) We want to collect the metric so that we can ship purge+throttle in
M58.
> 
> Oystein: Friendly ping :)

If it's blocking shipping purge+throttle my view would be to land it now with a
filed bug and a TODO to replace it ASAP once GRC has enough parts to centralize
this, so non-owner lgtm. Deferring to esprehn@ if any of the ways mentioned in
#33 would be cleaner though, the new IPC is really unfortunate.

[haraken, 2017-02-06 23:23:08]

On 2017/02/03 23:18:17, oystein wrote:
> On 2017/02/03 at 04:12:18, haraken wrote:
> > On 2017/01/31 19:10:45, haraken wrote:
> > > On 2017/01/31 18:56:02, oystein wrote:
> > > > On 2017/01/30 17:19:28, esprehn wrote:
> > > > > oysteine@ This seems like a good place for the PCU system. I don't
think
> we
> > > > > should be adding new infrastructure and IPCs for this metric.
> > > > > 
> > > > > The renderer should be adding an entry to the internal performance
> timeline
> > > > for
> > > > > visibility, resume, and paint events. To compute the metric the patch
is
> > > > trying
> > > > > to compute we just need to install a PerformanceObserver on ["purge",
> > > > "resume",
> > > > > "paint"], and then at idle time we can process the event stream and
> report
> > > the
> > > > > metric.
> > > > 
> > > > I agree, any time we need custom plumbing code to implement a metric
> there's a
> > > > clear signal that we'd be better off with a central service for this.
> > > > 
> > > > What's the timeline for when this metric is necessary? (BlinkOn was
> mentioned,
> > > > but that's a bit late now unfortunately). Is this something we want to
> land
> > > for
> > > > now and then use as one of the first use-cases to convert to the pcu, or
> block
> > > > on?
> > > 
> > > Asap :) We want to collect the metric so that we can ship purge+throttle
in
> M58.
> > 
> > Oystein: Friendly ping :)
> 
> If it's blocking shipping purge+throttle my view would be to land it now with
a
> filed bug and a TODO to replace it ASAP once GRC has enough parts to
centralize
> this, so non-owner lgtm. Deferring to esprehn@ if any of the ways mentioned in
> #33 would be cleaner though, the new IPC is really unfortunate.

Elliott: Would you take another look?

[esprehn, 2017-02-08 04:57:46]

I don't think we should be adding a new IPC here, just expose the times from the
render thread impl like GetSuspendTime() and use it inside the RenderWidget when
we paint?

[tasak, 2017-02-08 05:02:10]

On 2017/02/08 04:57:46, esprehn wrote:
> I don't think we should be adding a new IPC here, just expose the times from
the
> render thread impl like GetSuspendTime() and use it inside the RenderWidget
when
> we paint?

Yeah, it is almost the same as "(2) adds "Getter" to RenderThreadImpl, which
returns whether purged or not".
I think, probably the method also returns "purged or not".

[tasak, 2017-02-08 06:12:58]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-02-08 06:13:24]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[tasak, 2017-02-08 06:15:09]

esprehn@, would you take a look at the newest patch?

I added NeedsToRecordFirstActivePaint() to RenderThreadImpl and made
RenderWidget to see whether purged or not.

foregrounded_time_ in RenderThreadImpl was moved and now was_shown_time_ in
RenderWidget.

[esprehn, 2017-02-08 06:23:06]

lgtm w/ some nits. We really to start making progress on the perf timeline
service and events so this metric could be recorded transparently to the code by
just sampling the Suspend and Paint events.

https://codereview.chromium.org/2643723007/diff/110001/content/renderer/rende...
File content/renderer/render_widget.cc (right):

https://codereview.chromium.org/2643723007/diff/110001/content/renderer/rende...
content/renderer/render_widget.cc:937: if (!time_to_first_active_paint_recorded_
&&
You want to do the time_to_first_active_paint_recorded_ first, and then do
RenderThreadImpl::current() inside a block. Otherwise we're doing the extra TLS
lookup every time even though we early out at the bool.

if (time_to_first_active_paint_recorded_)
  return;
RenderThreadImpl* thread_impl = RenderThreadImpl::current();
...

[tasak, 2017-02-08 06:45:21]

The CQ bit was checked by tasak@google.com to run a CQ dry run

[commit-bot: I haz the power, 2017-02-08 06:45:42]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[tasak, 2017-02-08 06:49:08]

Thank you for review.

https://codereview.chromium.org/2643723007/diff/110001/content/renderer/rende...
File content/renderer/render_widget.cc (right):

https://codereview.chromium.org/2643723007/diff/110001/content/renderer/rende...
content/renderer/render_widget.cc:937: if (!time_to_first_active_paint_recorded_
&&
On 2017/02/08 06:23:06, esprehn wrote:
> You want to do the time_to_first_active_paint_recorded_ first, and then do
> RenderThreadImpl::current() inside a block. Otherwise we're doing the extra
TLS
> lookup every time even though we early out at the bool.
> 
> if (time_to_first_active_paint_recorded_)
>   return;
> RenderThreadImpl* thread_impl = RenderThreadImpl::current();
> ...

Done.

[commit-bot: I haz the power, 2017-02-08 07:47:50]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2017-02-08 07:47:51]

Dry run: This issue passed the CQ dry run.

[tasak, 2017-02-08 10:24:19]

tasak@google.com changed reviewers:
+ rkaplow@chromium.org

[tasak, 2017-02-08 10:24:20]

rkaplow@, would you review histograms.xml's change?

[rkaplow, 2017-02-08 15:30:12]

lgtm

histogram lg

[haraken, 2017-02-08 18:01:35]

The CQ bit was checked by haraken@chromium.org

[haraken, 2017-02-08 18:01:36]

The patchset sent to the CQ was uploaded after l-g-t-m from
oysteine@chromium.org, esprehn@chromium.org
Link to the patchset: https://codereview.chromium.org/2643723007/#ps130001
(title: "Fixed.")

[commit-bot: I haz the power, 2017-02-08 18:02:32]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2017-02-08 18:07:54]

CQ is committing da patch.

Bot data: {"patchset_id": 130001, "attempt_start_ts": 1486576895557050,
"parent_rev": "6dfbe4f358c788d7ed86c49ea1846c51fd9c25ee", "commit_rev":
"b95dbb50ccb02e2f5584419033d5409ae0e1d8f5"}

[commit-bot: I haz the power, 2017-02-08 18:08:36]

Description was changed from

==========
time metric: record elapsed time from when the backgrounded and purged renderer
is foregrounded until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some 
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419
==========

to

==========
time metric: record elapsed time from when the backgrounded and purged renderer
is foregrounded until the renderer is painted.

Record the effect of purge-and-suspend experiment. Since the purge clears some 
caches, we need to recover the caches when the renderer is painted,
i.e. whether the recovery takes short time or not.

BUG=635419

Review-Url: https://codereview.chromium.org/2643723007
Cr-Commit-Position: refs/heads/master@{#449038}
Committed:
https://chromium.googlesource.com/chromium/src/+/b95dbb50ccb02e2f5584419033d5...
==========

[commit-bot: I haz the power, 2017-02-08 18:08:41]

Committed patchset #7 (id:130001) as
https://chromium.googlesource.com/chromium/src/+/b95dbb50ccb02e2f5584419033d5...