The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/31c0c1c2517f38fb1e0ed336c4e70d261b97e69d

commit 31c0c1c2517f38fb1e0ed336c4e70d261b97e69d
Author: Sadrul Habib Chowdhury <sadrul@chromium.org>
Date: Fri Oct 12 02:55:52 2018

android: Dump for delayed presentation timestamp.

It looks like on android, presentation timestamps can sometimes be very
large. DumpWithoutCrashing() in such cases to collect some data to
understand why/when/where this is happening.

BUG=894440

Cq-Include-Trybots: luci.chromium.try:android_optional_gpu_tests_rel
Change-Id: I22817f68014c3f57f7180accc593506eee86f291
Reviewed-on: https://chromium-review.googlesource.com/c/1276549
Commit-Queue: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: kylechar <kylechar@chromium.org>
Reviewed-by: Antoine Labour <piman@chromium.org>
Cr-Commit-Position: refs/heads/master@{#599079}
[modify] https://crrev.com/31c0c1c2517f38fb1e0ed336c4e70d261b97e69d/base/timer/elapsed_timer.h
[modify] https://crrev.com/31c0c1c2517f38fb1e0ed336c4e70d261b97e69d/components/viz/service/display/display.cc
[modify] https://crrev.com/31c0c1c2517f38fb1e0ed336c4e70d261b97e69d/components/viz/service/display/display.h

+vikassoni@, +brianderson@

Crash logs: https://crash.corp.google.com/browse?q=expanded_custom_data.ChromeCrashProto.magic_signature_1.name%3D%27%5BDump+without+crash%5D+viz%3A%3ADisplay%3A%3ADidReceivePresentationFeedback%27#-propertyselector,-daygraph,productname:1000,-magicsignature:50,-magicsignature2:50,-stablesignature:50

It looks like when the crash happens, the presentation-times we get are ahead of 'Now()'. Is that expected/allowed? Should we allow presentation-time to be a little bit ahead of Now()?

The relevant code is here: https://cs.chromium.org/chromium/src/components/viz/service/display/display.cc?l=523

Thanks Sadrul for investigating this!

Do we know how much ahead of Now() the timestamp is, in this case?

If it's just slightly ahead of Now() then it's possible there's a small clock skew issue (e.g. hardware may use a slightly different clock source that's not in sync with our clock source). If it's way ahead of Now() that suggests to me that the presentation timestamp is just invalid.

Do we have UMA histograms that tell us how far out of sync the presentation timestamp is with a timestamp that we trust? That seems like an important addition to get insight here.

I have put up https://chromium-review.googlesource.com/c/chromium/src/+/1294193 to report how far into the future the presentation timestamps are.

From the dump-reports, it doesn't look like this happens for too many users (we have dumps from only < 250 users [1]). From the dumps, it doesn't look like this is happening very frequently, i.e. it seems to happen for only a small number of users, and not very often. It will be interesting to see what the UMA data shows.

[1] https://crash.corp.google.com/browse?q=expanded_custom_data.ChromeCrashProto.magic_signature_1.name%3D%27%5BDump+without+crash%5D+viz%3A%3ADisplay%3A%3ADidReceivePresentationFeedback%27#-propertyselector,-daygraph,-samplereports,productname:1000,magicsignature:50,magicsignature2:50,-stablesignature:50,clientid:1000,gpuvendorid,gpudeviceid,gpudriverversion:100

sorry i missed this. +1 to bmcquade@ comments. UMA data will give more insights and we can make a decision based on that.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/32ae2261c1390ad14be3e48ea57af23b9d81f928

commit 32ae2261c1390ad14be3e48ea57af23b9d81f928
Author: Sadrul Habib Chowdhury <sadrul@chromium.org>
Date: Mon Oct 22 21:46:52 2018

viz: Report how far ahead invalid presentation timestamps are.

On android, it turns out the presentation timestamp coming from the
driver can be from the future. Report how far ahead in the future
these timestamps are.

BUG=894440

Change-Id: Ic9bf5620721de3279e8b74277273e8db63da0842
Reviewed-on: https://chromium-review.googlesource.com/c/1294193
Commit-Queue: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: Antoine Labour <piman@chromium.org>
Reviewed-by: Mark Pearson <mpearson@chromium.org>
Cr-Commit-Position: refs/heads/master@{#601737}
[modify] https://crrev.com/32ae2261c1390ad14be3e48ea57af23b9d81f928/components/viz/service/display/display.cc
[modify] https://crrev.com/32ae2261c1390ad14be3e48ea57af23b9d81f928/tools/metrics/histograms/histograms.xml

We have ~a week's data now [1]. Two observations:
 . Almost all of the cases (~99%) where the timestamp is from the future is a long time in the future (more than 3 minutes).
 . This still seems to happen only rarely, considering that we request the presentation timestamp every frame. Comparing the sample count with another metric that we report every frame: Compositing.DirectRenderer.GL.DrawFrameUs [2], the future-timestamp has ~500K samples, compared to ~8.5B samples for DrawFrameUs.


[1] https://uma.googleplex.com/p/chrome/histograms/?endDate=latest&dayCount=7&histograms=Graphics.PresentationTimestamp.InvalidFromFuture&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial
[2] https://uma.googleplex.com/p/chrome/histograms/?endDate=latest&dayCount=7&histograms=Compositing.DirectRenderer.GL.DrawFrameUs%2CGraphics.PresentationTimestamp.InvalidFromFuture&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial

I did some filters using gpu GL vendor. It seems like this issue is happening only on Intel gpu.

Qualcomm and ARM is fine. Maybe we need to blacklist Intel gpu.

https://uma.googleplex.com/p/chrome/histograms/?endDate=latest&dayCount=7&histograms=Graphics.PresentationTimestamp.InvalidFromFuture&fixupData=true&showMax=true&filters=platform%2Ceq%2CA%2Cchannel%2Ceq%2C1%2Cgpu_gl_vendor%2Ceq%2CIntel%2Cisofficial%2Ceq%2CTrue&implicitFilters=isofficial

I still think this happens rarely enough that we do not need to do blacklisting, and instead use chrome's timestamp when the timestamp is detected to be invalid.

yes i think that sounds good.

300 reports from 130+ clients in latest Dev- 72.0.3596.0.

Since work is in progress, adding and RB label for tracking purpose.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/665265a9e27b9df34cff6c7a9e07d01294225d70

commit 665265a9e27b9df34cff6c7a9e07d01294225d70
Author: Sadrul Habib Chowdhury <sadrul@chromium.org>
Date: Fri Nov 09 18:44:16 2018

viz: Report invalid older presentation-timestamps.

Report when the presentation-timestamp reporter by the driver is earlier
than the swap-time. Report this metric on all platforms. Change the
metric for reporting presentation-timestamps from the future to be
reported on all platforms (instead of just android).

This also removes DumpWithoutCrashing() for the future-timestamps.

BUG=894440

Change-Id: I663fdeab41b3f7de3e76f0e0ae440efbdae79bd8
Reviewed-on: https://chromium-review.googlesource.com/c/1325417
Commit-Queue: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: Antoine Labour <piman@chromium.org>
Reviewed-by: Robert Kaplow <rkaplow@chromium.org>
Cr-Commit-Position: refs/heads/master@{#606913}
[modify] https://crrev.com/665265a9e27b9df34cff6c7a9e07d01294225d70/components/viz/service/display/display.cc
[modify] https://crrev.com/665265a9e27b9df34cff6c7a9e07d01294225d70/components/viz/service/display/display_unittest.cc
[modify] https://crrev.com/665265a9e27b9df34cff6c7a9e07d01294225d70/tools/metrics/histograms/histograms.xml

CL from C#14 has resulted in Dump without crashes on Windows, Mac and Android in the recent M-72 canary.

Magic signature: [Dump without crash] viz::Display::DidReceivePresentationFeedback

Link to the crashes:
====================
https://crash.corp.google.com/browse?q=expanded_custom_data.ChromeCrashProto.magic_signature_1.name%3D%27%5BDump+without+crash%5D+viz%3A%3ADisplay%3A%3ADidReceivePresentationFeedback%27#-propertyselector,productname:1000,productversion:100,-magicsignature:50,-magicsignature2:50,-stablesignature:50

72.0.3607.0 win canary reported 1468 crashes from 1188 clients and Mac & Android canary has reported lesser(1-2 digits) crashes.

Though the Dump without crash are not real crashes but may result in skewing the crash metrics since this is showing considerable spike on win canary.

Marking this as M-72 Dev blocker for Desktop(Windows) for tracking.

sadrul@: Could you please revert the CL from C#14 to unblock the next M-72 dev release scheduled for tomorrow(11/13).

Thank you!

This is blocking our Dev release and contributes ~ 60% of Win browser crash. No reports from Mac and Android.

sadrul@ please revert the CL ASAP.

We shouldn't revert the CL. I am removing the release-block labels from our offline discussion, since this is not a crash. I will put up a separate CL to replace the DumpWithoutCrashing(), although having the dumps in the channels would be useful.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/dbeb9ae3da0d596b909d8ed3e48cdf2fca0815b3

commit dbeb9ae3da0d596b909d8ed3e48cdf2fca0815b3
Author: Sadrul Habib Chowdhury <sadrul@chromium.org>
Date: Mon Nov 12 23:56:15 2018

viz: Remove a DumpWithoutCrashing(), and report a UMA instead.

BUG=894440

Change-Id: I0757af5f6a2058d0c98b68ff1e71c3083a1a76f2
Reviewed-on: https://chromium-review.googlesource.com/c/1332774
Reviewed-by: Abdul Syed <abdulsyed@google.com>
Cr-Commit-Position: refs/branch-heads/3608@{#6}
Cr-Branched-From: 809d8fb01773e476e122ad1739530caa3d02dfed-refs/heads/master@{#607123}
[modify] https://crrev.com/dbeb9ae3da0d596b909d8ed3e48cdf2fca0815b3/components/viz/service/display/display.cc
[modify] https://crrev.com/dbeb9ae3da0d596b909d8ed3e48cdf2fca0815b3/tools/metrics/histograms/histograms.xml

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/b05de7e561c1c08ecefd5e98688668b80d1f92b8

commit b05de7e561c1c08ecefd5e98688668b80d1f92b8
Author: Sadrul Habib Chowdhury <sadrul@chromium.org>
Date: Tue Nov 13 01:35:54 2018

viz: Remove a DumpWithoutCrashing(), and report a UMA instead.

BUG=894440

Change-Id: I0757af5f6a2058d0c98b68ff1e71c3083a1a76f2
Reviewed-on: https://chromium-review.googlesource.com/c/1332249
Commit-Queue: Sadrul Chowdhury <sadrul@chromium.org>
Reviewed-by: Robert Kaplow <rkaplow@chromium.org>
Cr-Commit-Position: refs/heads/master@{#607411}
[modify] https://crrev.com/b05de7e561c1c08ecefd5e98688668b80d1f92b8/components/viz/service/display/display.cc
[modify] https://crrev.com/b05de7e561c1c08ecefd5e98688668b80d1f92b8/tools/metrics/histograms/histograms.xml

72.0.3608.4 Win canary has been live for 7 hrs and has not reported any crashes for '[Dump without crash] viz::Display::DidReceivePresentationFeedback'.

Looks to be fixed based on the available crash data and due to merge in C#18.

Updating the bug, since it looks like we can get large presentation times on Windows too. It also seems to happen pretty rarely, but good to keep an eye on it. Graphics.PresentationTimestamp.LargePresentationDelta tracks how often this happens, and how large they can get.

I hit this in 73.0.3671.1 (Official Build) canary-dcheck (32-bit) (cohort: ASAN). Could this be hit as a result of a system suspend-resume cycle at just the right time?