Add UMA histograms to track very brief or frequent tabs and JS dialogs.

Add UMA histograms to track very brief or frequent tabs and JS dialogs.

Committed: https://crrev.com/850904a0f10197a0ee95f182bfdb18ea838872a4
Cr-Commit-Position: refs/heads/master@{#374262}

[Joe Mason, 2016-01-26 20:34:00]

joenotcharles@chromium.org changed reviewers:
+ caitkp@chromium.org, isherman@chromium.org, sky@chromium.org

[Joe Mason, 2016-01-26 20:34:01]

PTAL

[Ilya Sherman, 2016-01-26 22:39:04]

It would be helpful for me to understand more about the motivation behind this
CL.  Is there a bug or design doc you could link to?

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
File base/metrics/histogram_macros.h (right):

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
base/metrics/histogram_macros.h:186: // up to a minute, using 100 buckets.
This description says that the lower bound is a millisecond, but it seems to be
100 microseconds.

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
base/metrics/histogram_macros.h:189: base::TimeDelta::FromMinutes(1), 100)
I'm not sure that it makes sense to add this macro here, rather than using
UMA_HISTOGRAM_CUSTOM_TIMES from your calling code.  The time range covered by
this histogram is not too different from UMA_HISTOGRAM_TIMES.  (I'm curious,
actually, why you chose the specific bounds that you did.)

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
File components/app_modal/javascript_app_modal_dialog.cc (right):

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
components/app_modal/javascript_app_modal_dialog.cc:101: base::TimeTicks::Now()
- creation_time_);
Is this intentionally the same histogram name as the one below?  If so, I'd
recommend writing a wrapper function to emit to this histogram, and maybe also
to document why this histogram is recorded in two different places.

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
components/app_modal/javascript_app_modal_dialog.cc:152: base::TimeTicks::Now()
- creation_time_);
This histogram is designed to distinguish a dialog that was open for 100
microseconds from one that was open for a millisecond from one that was open for
10 milliseconds.  All of those feel more or less instant to a user.  Could you
please provide me with a bit more context for what you're trying to measure and
understand?

[Joe Mason, 2016-01-27 16:51:21]

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
File base/metrics/histogram_macros.h (right):

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
base/metrics/histogram_macros.h:186: // up to a minute, using 100 buckets.
There's a design doc for this feature at
https://docs.google.com/document/d/14301hx1zc6qj9AXOoXqTnd-PwdGTECYBmkDE645P_kU/.
(See the start of the "Detailed Design" section.) The goal is to find out how
prevalent "abusive" popups are (eg. users being spammed with popups, or close
one tab and another immediately opens), and to try to find a more focused metric
on what counts as "abusive".

On 2016/01/26 22:39:04, Ilya Sherman wrote:
> This description says that the lower bound is a millisecond, but it seems to
be
> 100 microseconds.

The intent of the comment is that this captures useful variations "around" one
millisecond. The smallest buckets are smaller than that so that, as the size
exponentially increases, we don't start getting buckets of 2, 4, 8 milliseconds
immediately. I wanted at least one bucket to capture "far below 1 msec" and one
to capture "a bit under 1 msec" before starting to grow into buckets that are
wider than 1 msec.

Starting at 500 msec would probably be fine enough to capture that distinction,
but once I decided not to use a standard macro I decided to err on the side of
being more fine grained, since it's easy to aggregate buckets during analysis.

The standard macro may work as well, but I don't want to prejudge the data so I
wanted to capture some very fine gradations just in case they turn out to be
relevant.

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
base/metrics/histogram_macros.h:189: base::TimeDelta::FromMinutes(1), 100)
On 2016/01/26 22:39:04, Ilya Sherman wrote:
> I'm not sure that it makes sense to add this macro here, rather than using
> UMA_HISTOGRAM_CUSTOM_TIMES from your calling code.  The time range covered by
> this histogram is not too different from UMA_HISTOGRAM_TIMES.  (I'm curious,
> actually, why you chose the specific bounds that you did.)

Yeah, it's a judgement call - I thought it was a good idea because I'm using the
same parameters from 3 separate files in both chrome/ and components/, so the
use crosses enough boundaries to be worth putting in base/. I can repeat the
parameters in each file if you prefer.

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
File components/app_modal/javascript_app_modal_dialog.cc (right):

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
components/app_modal/javascript_app_modal_dialog.cc:152: base::TimeTicks::Now()
- creation_time_);
On 2016/01/26 22:39:04, Ilya Sherman wrote:
> This histogram is designed to distinguish a dialog that was open for 100
> microseconds from one that was open for a millisecond from one that was open
for
> 10 milliseconds.  All of those feel more or less instant to a user.  Could you
> please provide me with a bit more context for what you're trying to measure
and
> understand?

An example question I'm trying to answer with this: if users visit a page that
keeps reopening a tab every time they close it, do they keep trying or give up
and leave the tab open in the background? If the former we'd expect to see lots
of events with a short time between closing a tab and opening a tab. But it's
hard to tell before putting the histogram out there and looking at the results
what counts as "short".

Different bad behaviour by pages may result in different times between tabs,
even if they all feel "instant" to the user. The difference between < 1 msec, 1
msec, 2 msec and 10 msec may turn out to be important or it may not. I just
didn't want to prejudge.

[Joe Mason, 2016-01-27 19:43:50]

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
File components/app_modal/javascript_app_modal_dialog.cc (right):

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
components/app_modal/javascript_app_modal_dialog.cc:101: base::TimeTicks::Now()
- creation_time_);
On 2016/01/26 22:39:04, Ilya Sherman wrote:
> Is this intentionally the same histogram name as the one below?  If so, I'd
> recommend writing a wrapper function to emit to this histogram, and maybe also
> to document why this histogram is recorded in two different places.

Done.

[Ilya Sherman, 2016-01-28 05:25:26]

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
File base/metrics/histogram_macros.h (right):

https://codereview.chromium.org/1638013002/diff/1/base/metrics/histogram_macr...
base/metrics/histogram_macros.h:189: base::TimeDelta::FromMinutes(1), 100)
On 2016/01/27 16:51:21, joenotcharles wrote:
> On 2016/01/26 22:39:04, Ilya Sherman wrote:
> > I'm not sure that it makes sense to add this macro here, rather than using
> > UMA_HISTOGRAM_CUSTOM_TIMES from your calling code.  The time range covered
by
> > this histogram is not too different from UMA_HISTOGRAM_TIMES.  (I'm curious,
> > actually, why you chose the specific bounds that you did.)
> 
> Yeah, it's a judgement call - I thought it was a good idea because I'm using
the
> same parameters from 3 separate files in both chrome/ and components/, so the
> use crosses enough boundaries to be worth putting in base/. I can repeat the
> parameters in each file if you prefer.

You could also define a macro in the component, and use that macro from the
//chrome layer as well.  I don't think this macro is different enough from
UMA_HISTOGRAM_TIMES to define in histogram_macros.h.

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
File components/app_modal/javascript_app_modal_dialog.cc (right):

https://codereview.chromium.org/1638013002/diff/1/components/app_modal/javasc...
components/app_modal/javascript_app_modal_dialog.cc:152: base::TimeTicks::Now()
- creation_time_);
On 2016/01/27 16:51:21, joenotcharles wrote:
> On 2016/01/26 22:39:04, Ilya Sherman wrote:
> > This histogram is designed to distinguish a dialog that was open for 100
> > microseconds from one that was open for a millisecond from one that was open
> for
> > 10 milliseconds.  All of those feel more or less instant to a user.  Could
you
> > please provide me with a bit more context for what you're trying to measure
> and
> > understand?
> 
> An example question I'm trying to answer with this: if users visit a page that
> keeps reopening a tab every time they close it, do they keep trying or give up
> and leave the tab open in the background? If the former we'd expect to see
lots
> of events with a short time between closing a tab and opening a tab. But it's
> hard to tell before putting the histogram out there and looking at the results
> what counts as "short".
> 
> Different bad behaviour by pages may result in different times between tabs,
> even if they all feel "instant" to the user. The difference between < 1 msec,
1
> msec, 2 msec and 10 msec may turn out to be important or it may not. I just
> didn't want to prejudge.

Okay.  I guess it's okay to land these histograms as they are, but I'd encourage
you to plan to come back to them and tweak or remove any histograms that aren't
providing useful data.

https://codereview.chromium.org/1638013002/diff/20001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/1638013002/diff/20001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:17572: +<histogram
name="JSDialogs.FineTiming.DialogLifetime" units="ms">
If the units are milliseconds, what are time values less than one millisecond
recorded as?

[Joe Mason, 2016-01-28 15:57:16]

On 2016/01/28 05:25:26, Ilya Sherman wrote:
> Okay.  I guess it's okay to land these histograms as they are, but I'd
encourage
> you to plan to come back to them and tweak or remove any histograms that
aren't
> providing useful data.

Yes, I plan to remove these when they're replaced with the full metric.

>
https://codereview.chromium.org/1638013002/diff/20001/tools/metrics/histogram...
> File tools/metrics/histograms/histograms.xml (right):
> 
>
https://codereview.chromium.org/1638013002/diff/20001/tools/metrics/histogram...
> tools/metrics/histograms/histograms.xml:17572: +<histogram
> name="JSDialogs.FineTiming.DialogLifetime" units="ms">
> If the units are milliseconds, what are time values less than one millisecond
> recorded as?

...good question. This is what I get for using two different debug logs with
different units. I was reading the smallest timing differences I'd seen as
1/10's of msec - it's actually 10's of msec.  So, yes, the smallest buckets in
this histogram were always empty, and UMA_HISTOGRAM_MEDIUM_TIMES is most
appropriate for this measure.

[Ilya Sherman, 2016-01-29 01:10:18]

Alright, this makes a lot more sense to me now =)  LGTM.

[sky, 2016-01-29 17:25:51]

LGTM, but I would prefer a more descriptive name name as mentioned below.

https://codereview.chromium.org/1638013002/diff/40001/chrome/browser/ui/tabs/...
File chrome/browser/ui/tabs/tab_strip_model_stats_recorder.cc (right):

https://codereview.chromium.org/1638013002/diff/40001/chrome/browser/ui/tabs/...
chrome/browser/ui/tabs/tab_strip_model_stats_recorder.cc:46: base::TimeTicks
CreationTime() const { return creation_time_; }
nit: CreationTime->creation_time

https://codereview.chromium.org/1638013002/diff/40001/tools/metrics/histogram...
File tools/metrics/histograms/histograms.xml (right):

https://codereview.chromium.org/1638013002/diff/40001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:50728: +<histogram
name="Tabs.FineTiming.TimeSinceLastTabClosed" units="ms">
TimeSinceLastTabClosed is mildly confusing. Time between close and what? Maybe
TimeBetweenTabCloseAndNewTabCreated.

[Joe Mason, 2016-01-29 17:54:48]

On 2016/01/29 17:25:51, sky wrote:
>
https://codereview.chromium.org/1638013002/diff/40001/chrome/browser/ui/tabs/...
> chrome/browser/ui/tabs/tab_strip_model_stats_recorder.cc:46: base::TimeTicks
> CreationTime() const { return creation_time_; }
> nit: CreationTime->creation_time

Will fix before commit.

>
https://codereview.chromium.org/1638013002/diff/40001/tools/metrics/histogram...
> File tools/metrics/histograms/histograms.xml (right):
> 
>
https://codereview.chromium.org/1638013002/diff/40001/tools/metrics/histogram...
> tools/metrics/histograms/histograms.xml:50728: +<histogram
> name="Tabs.FineTiming.TimeSinceLastTabClosed" units="ms">
> TimeSinceLastTabClosed is mildly confusing. Time between close and what? Maybe
> TimeBetweenTabCloseAndNewTabCreated.

Since FineTiming already conveys time, how about
Tabs.FineTiming.TabCreatedToNextTabCreated, TabClosedToNextTabCreated, and
TabCreatedToSameTabClosed.

[sky, 2016-01-29 20:49:53]

IMO TimeBetweenTabCloseAndNewTabCreated is much clearer. Yes, it's a
bit longer, but does that really matter? Go for clarity!

On Fri, Jan 29, 2016 at 9:54 AM,  <joenotcharles@chromium.org> wrote:
>
> On 2016/01/29 17:25:51, sky wrote:
>>
>
https://codereview.chromium.org/1638013002/diff/40001/chrome/browser/ui/tabs/...
>> chrome/browser/ui/tabs/tab_strip_model_stats_recorder.cc:46:
>> base::TimeTicks
>> CreationTime() const { return creation_time_; }
>> nit: CreationTime->creation_time
>
> Will fix before commit.
>
>>
>
https://codereview.chromium.org/1638013002/diff/40001/tools/metrics/histogram...
>> File tools/metrics/histograms/histograms.xml (right):
>>
>>
>
https://codereview.chromium.org/1638013002/diff/40001/tools/metrics/histogram...
>> tools/metrics/histograms/histograms.xml:50728: +<histogram
>> name="Tabs.FineTiming.TimeSinceLastTabClosed" units="ms">
>> TimeSinceLastTabClosed is mildly confusing. Time between close and what?
>> Maybe
>> TimeBetweenTabCloseAndNewTabCreated.
>
> Since FineTiming already conveys time, how about
> Tabs.FineTiming.TabCreatedToNextTabCreated, TabClosedToNextTabCreated, and
> TabCreatedToSameTabClosed.
>
> https://codereview.chromium.org/1638013002/

-- 
You received this message because you are subscribed to the Google Groups
"Chromium-reviews" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to chromium-reviews+unsubscribe@chromium.org.

[Joe Mason, 2016-01-29 22:20:41]

joenotcharles@chromium.org changed reviewers:
+ avi@chromium.org
- caitkp@chromium.org, isherman@chromium.org

[Joe Mason, 2016-01-29 22:20:41]

avi, PTAL at the app_modal changes.

I'll be away next week so please CQ+ if you think it's ready.

I realized that if a page opens a dialog in a tight loop and the user blocks it,
the counts involving blocked dialogs become overwhelming quickly, so I made sure
blocked dialogs are completely ignored and do not affect any histograms. I'll
add a separate metric to record blocked dialogs when I get back.

[Avi (use Gerrit), 2016-01-30 04:41:31]

LGTM

https://codereview.chromium.org/1638013002/diff/60001/components/app_modal/ja...
File components/app_modal/javascript_app_modal_dialog.cc (right):

https://codereview.chromium.org/1638013002/diff/60001/components/app_modal/ja...
components/app_modal/javascript_app_modal_dialog.cc:166: // difference is not
significant, more common code could be moved here.
It's probably not significant, but I'm not 100% sure.

[Joe Mason, 2016-02-08 19:14:55]

The CQ bit was checked by joenotcharles@chromium.org

[Joe Mason, 2016-02-08 19:14:55]

The patchset sent to the CQ was uploaded after l-g-t-m from
isherman@chromium.org, sky@chromium.org
Link to the patchset: https://codereview.chromium.org/1638013002/#ps60001
(title: "Rename histograms; ignore blocked JS dialogs")

[commit-bot: I haz the power, 2016-02-08 19:21:20]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1638013002/60001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1638013002/60001

[commit-bot: I haz the power, 2016-02-08 19:47:34]

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

[commit-bot: I haz the power, 2016-02-08 19:47:35]

Try jobs failed on following builders:
  chromeos_x86-generic_chromium_compile_only_ng on tryserver.chromium.linux
(JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/chromeos_x86-ge...)

[Joe Mason, 2016-02-08 20:07:18]

The CQ bit was checked by joenotcharles@chromium.org

[commit-bot: I haz the power, 2016-02-08 20:13:34]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1638013002/60001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1638013002/60001

[commit-bot: I haz the power, 2016-02-09 01:50:54]

Committed patchset #4 (id:60001)

[commit-bot: I haz the power, 2016-02-09 01:51:51]

Description was changed from

==========
Add UMA histograms to track very brief or frequent tabs and JS dialogs.
==========

to

==========
Add UMA histograms to track very brief or frequent tabs and JS dialogs.

Committed: https://crrev.com/850904a0f10197a0ee95f182bfdb18ea838872a4
Cr-Commit-Position: refs/heads/master@{#374262}
==========

[commit-bot: I haz the power, 2016-02-09 01:51:52]

Patchset 4 (id:??) landed as
https://crrev.com/850904a0f10197a0ee95f182bfdb18ea838872a4
Cr-Commit-Position: refs/heads/master@{#374262}