Replace DCHECK() upon unexpected x11 event time with a workaround

Replace DCHECK() upon unexpected x11 event time with a workaround

BUG=611950
Committed: https://crrev.com/905cedbf079a83c048c9cfcf526210efcf7c4abd
Cr-Commit-Position: refs/heads/master@{#397315}

[caseq, 2016-05-17 03:17:57]

caseq@chromium.org changed reviewers:
+ majidvp@chromium.org, sadrul@chromium.org, thestig@chromium.org

[caseq, 2016-05-17 03:17:57]

Let's use browser time in case we detect x11 time is not using the same time
base as TimeTicks. This happens at least in case of xtightvnc, but I guess will
also occur in case of a remote x11 server.

[caseq, 2016-05-17 03:21:30]

Patchset #1 (id:1) has been deleted

[caseq, 2016-05-17 03:21:50]

The CQ bit was checked by caseq@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-05-17 03:22:03]

Dry run: CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1982203002/20001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1982203002/20001

[commit-bot: I haz the power, 2016-05-17 04:33:35]

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

[commit-bot: I haz the power, 2016-05-17 04:33:36]

Dry run: This issue passed the CQ dry run.

[majidvp, 2016-05-17 13:27:53]

https://codereview.chromium.org/1982203002/diff/20001/ui/events/x/events_x_ut...
File ui/events/x/events_x_utils.cc (right):

https://codereview.chromium.org/1982203002/diff/20001/ui/events/x/events_x_ut...
ui/events/x/events_x_utils.cc:327: (base::TimeTicks::Now() -
base::TimeTicks()).InMilliseconds());
Please use ui::EventTimeForNow() instead.

I don't think we should limit these timestamps to milliseconds resolution if we
are using TimeTicks::Now().

https://codereview.chromium.org/1982203002/diff/20001/ui/events/x/events_x_ut...
ui/events/x/events_x_utils.cc:358: LOG(WARNING) << "Unexpected x11 timestamps,
will use browser time instead.";
I wonder if it makes sense to also collect UMA metrics for this.

I suspect this should not happen very often. But if this turns out to be a large
percentage of cases then it can impact the way we interpret our event latency
telemetry metrics on Linux.

+tdresser@ in case he has opinion one way or another.

[tdresser, 2016-05-17 13:55:27]

tdresser@chromium.org changed reviewers:
+ tdresser@chromium.org

[tdresser, 2016-05-17 13:55:27]

Let's add a metric recording how often this happens. That way we can ensure that
this number is low, and filter this data out if it grows at some point.

[caseq, 2016-05-20 23:41:32]

caseq@chromium.org changed reviewers:
+ isherman@chromium.org

[caseq, 2016-05-20 23:41:33]

+isherman for tools/metrics/OWNERS 

Comments addressed, ptal.

https://codereview.chromium.org/1982203002/diff/20001/ui/events/x/events_x_ut...
File ui/events/x/events_x_utils.cc (right):

https://codereview.chromium.org/1982203002/diff/20001/ui/events/x/events_x_ut...
ui/events/x/events_x_utils.cc:327: (base::TimeTicks::Now() -
base::TimeTicks()).InMilliseconds());
On 2016/05/17 13:27:53, majidvp wrote:
> Please use ui::EventTimeForNow() instead.
> 
> I don't think we should limit these timestamps to milliseconds resolution if
we
> are using TimeTicks::Now().

Done.

https://codereview.chromium.org/1982203002/diff/20001/ui/events/x/events_x_ut...
ui/events/x/events_x_utils.cc:358: LOG(WARNING) << "Unexpected x11 timestamps,
will use browser time instead.";
On 2016/05/17 13:27:53, majidvp wrote:
> I wonder if it makes sense to also collect UMA metrics for this.
> 
> I suspect this should not happen very often. But if this turns out to be a
large
> percentage of cases then it can impact the way we interpret our event latency
> telemetry metrics on Linux.
> 
> +tdresser@ in case he has opinion one way or another.

Done.

[majidvp, 2016-05-21 00:09:21]

lgtm with some comment on metric name.

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

https://codereview.chromium.org/1982203002/diff/40001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:12570: +<histogram
name="Event.X11TimestampsUsable" units="Boolean">
Can we just call it |Event.TimestampsUsable| or
|Event.TimestampHasValidTimebase|?

I plan to add similar checks for other platforms as well pretty soon.

[Ilya Sherman, 2016-05-21 00:16:10]

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

https://codereview.chromium.org/1982203002/diff/40001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:12570: +<histogram
name="Event.X11TimestampsUsable" units="Boolean">
nit: please s/units/enum, and use or define more custom-tailored enum labels for
this histogram.

[caseq, 2016-05-21 01:34:47]

Renamed the metric and converted it to enum, ptal.

[Ilya Sherman, 2016-05-23 18:36:33]

LGTM % nits:

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

https://codereview.chromium.org/1982203002/diff/60001/tools/metrics/histogram...
tools/metrics/histograms/histograms.xml:69678: +  <int value="1"
label="Timestamps use valid time base"/>
Optional nit: I'd omit the shared "Timestamps use" prefix, for the sake of a
smaller left column in the chart that's used to display histograms.

https://codereview.chromium.org/1982203002/diff/60001/ui/events/x/events_x_ut...
File ui/events/x/events_x_utils.cc (right):

https://codereview.chromium.org/1982203002/diff/60001/ui/events/x/events_x_ut...
ui/events/x/events_x_utils.cc:371: : UMA_EVENT_TIMESTAMPS_HAVE_VALID_TIMEBASE);
nit: No need to use an enum in the C++ code -- you can just log a boolean value
here.  In my previous comment, I was just asking you to update histograms.xml to
provide labels for users viewing the dashboard :)

[caseq, 2016-05-23 23:06:24]

The CQ bit was checked by caseq@chromium.org

[caseq, 2016-05-23 23:06:25]

The patchset sent to the CQ was uploaded after l-g-t-m from
majidvp@chromium.org, isherman@chromium.org
Link to the patchset: https://codereview.chromium.org/1982203002/#ps80001
(title: "removed enum prefixes, removed enum on the back-end")

[commit-bot: I haz the power, 2016-05-23 23:06:49]

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

[commit-bot: I haz the power, 2016-05-23 23:20:40]

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

[commit-bot: I haz the power, 2016-05-23 23:20:42]

Try jobs failed on following builders:
  chromium_presubmit on tryserver.chromium.linux (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.linux/builders/chromium_presub...)

[caseq, 2016-05-23 23:25:18]

sadrul, could you please stamp this for ui/events/OWNERS?

[caseq, 2016-05-23 23:36:06]

The CQ bit was checked by caseq@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-05-23 23:36:37]

Dry run: CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1982203002/100001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1982203002/100001

[commit-bot: I haz the power, 2016-05-24 02:42:02]

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

[commit-bot: I haz the power, 2016-05-24 02:42:04]

Dry run: This issue passed the CQ dry run.

[sadrul, 2016-05-26 01:50:15]

lgtm

[tdresser, 2016-05-26 12:20:45]

LGTM

[caseq, 2016-06-01 22:01:38]

The CQ bit was checked by caseq@chromium.org

[caseq, 2016-06-01 22:01:38]

The patchset sent to the CQ was uploaded after l-g-t-m from
majidvp@chromium.org, isherman@chromium.org
Link to the patchset: https://codereview.chromium.org/1982203002/#ps100001
(title: "removed dependency on event_utils, just inline EventTimeForNow() for
now")

[commit-bot: I haz the power, 2016-06-01 22:02:55]

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

[commit-bot: I haz the power, 2016-06-02 01:53:32]

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

[commit-bot: I haz the power, 2016-06-02 01:53:34]

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

[Lei Zhang, 2016-06-02 05:54:20]

The CQ bit was checked by thestig@chromium.org

[commit-bot: I haz the power, 2016-06-02 05:54:44]

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

[commit-bot: I haz the power, 2016-06-02 06:34:17]

Committed patchset #5 (id:100001)

[commit-bot: I haz the power, 2016-06-02 06:36:16]

Description was changed from

==========
Replace DCHECK() upon unexpected x11 event time with a workaround

BUG=611950
==========

to

==========
Replace DCHECK() upon unexpected x11 event time with a workaround

BUG=611950

Committed: https://crrev.com/905cedbf079a83c048c9cfcf526210efcf7c4abd
Cr-Commit-Position: refs/heads/master@{#397315}
==========

[commit-bot: I haz the power, 2016-06-02 06:36:18]

Patchset 5 (id:??) landed as
https://crrev.com/905cedbf079a83c048c9cfcf526210efcf7c4abd
Cr-Commit-Position: refs/heads/master@{#397315}