tricky-tot-chrome-pfq-informational just failed at http://cros-goldeneye/chromeos/healthmonitoring/buildDetails?buildbucketId=8946267770698695808 with similar errors:

video_ChromeHWDecodeUsed.h264         [ FAILED ]
video_ChromeHWDecodeUsed.h264           ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%
video_ChromeHWDecodeUsed.vp9          [ FAILED ]
video_ChromeHWDecodeUsed.vp9            ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%
video_ChromeHWDecodeUsed.vp9          [ FAILED ]
video_ChromeHWDecodeUsed.vp9            ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%
video_ChromeHWDecodeUsed.h264         [ FAILED ]
video_ChromeHWDecodeUsed.h264           ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%

And now caroline-tot-chrome-pfq-informational at http://cros-goldeneye/chromeos/healthmonitoring/buildDetails?buildbucketId=8946268728871471168:

  video_ChromeHWDecodeUsed.h264         [ FAILED ]
  video_ChromeHWDecodeUsed.h264           ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%
  video_ChromeHWDecodeUsed.vp8          [ FAILED ]
  video_ChromeHWDecodeUsed.vp8            ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%
  video_ChromeHWDecodeUsed.vp8          [ FAILED ]
  video_ChromeHWDecodeUsed.vp8            ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%
  video_ChromeRTCHWDecodeUsed.vp8       [ FAILED ]
  video_ChromeRTCHWDecodeUsed.vp8         ERROR: Media.RTCVideoDecoderInitDecodeSucces not loaded or histogram bucket not found or histogram bucket found at < 100%
  video_ChromeHWDecodeUsed.h264         [ FAILED ]
  video_ChromeHWDecodeUsed.h264           ERROR: Media.GpuVideoDecoderInitializeStatus not loaded or histogram bucket not found or histogram bucket found at < 100%

Is there anyone in PDT who works on video? I haven't received any replies to my message to chromeos-video@ about these failures. I suspect that this is going to make tonight's PFQ run fail.

eve-tot-chrome-pfq-informational: http://cros-goldeneye/chromeos/healthmonitoring/buildDetails?buildbucketId=8946269507034380480

veyron_minnie-tot-chrome-pfq-informational: http://cros-goldeneye/chromeos/healthmonitoring/buildDetails?buildbucketId=8946266055051821104

Thanks for looking. I'm also in the process of deploying a ToT caroline build to see what those histograms look like on it.

I don't see any obviously-related errors in the Chrome log on my caroline device (using 10688.0.0 with Chrome 68.0.3434.0 at r559727). There are these, though:

[3788:3793:0517/171705.332330:VERBOSE1:drm_device_manager.cc(53)] Could not initialize DRM device for /sys/devices/platform/vgem/drm/card1
...client/cros/video/histogram_verifier.py:
[3788:3793:0517/171706.365102:ERROR:drm_device.cc(751)] CTM is empty. Expected a 3x3 matrix.
[3788:3793:0517/171706.365227:ERROR:drm_display.cc(181)] Failed to set color correction for display: crtc_id = 26

I watched a YouTube video (with a pre-roll ad) after logging in. At chrome://histograms, Media.GpuVideoDecoderInitializeStatus has two samples in the "15" bucket. Per tools/metrics/histograms/enums.xml, I think that that's DECODER_ERROR_NOT_SUPPORTED.

I don't know how to debug this further. The error reporting here seems like it could be improved -- unless I'm missing it, Chrome isn't logging any sort of errors about this; it's just reporting a histogram. verify() in client/cros/video/histogram_verifier.py should also provide more detail about value that it's expecting and what it actually saw instead of a generic "either the histogram is missing or the bucket is missing or the bucket had the wrong value" error message. 

The Media.GpuVideoDecoderInitializeStatus DECODER_ERROR_NOT_SUPPORTED is expected and WAI. Caroline does not have HW decoding support for VP9, so I expect this was the reason it was reported (this can be verifying by checking "Codecs" in "Stats for nerds", accessible via right-click menu on the video player).

The drm errors do not appear to be critical (+dnicoara@ for confirmation please).

Logs from test failures do not appear to contain any video failures, and video decode appears to be successful there.

I could also not reproduce any video playback nor rtc loopback issues on eve and on pyro, with 10688.0.0, and both Chrome ToT and at r559727.

This would indicate that there may be an issue with the test itself. The functionality that the test is supposed to verify appears to be working fine.

Dean, would you be able to take a look whether this is a test issue please? Thank you!

How do I see chrome CL diffs?

peach_pit-tot-chrome-pfq-informational:
https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/buildDetails?buildbucketId=8946268162737134448

From the log, it looks ok. But the test failed.
[10011:10011:0517/100223.631326:VERBOSE2:v4l2_video_decode_accelerator.cc(198)] Initialize(): profile: 1, output_mode=0
[10011:10011:0517/100223.641449:VERBOSE2:v4l2_video_decode_accelerator.cc(2308)] SetupFormats(): Output format=842091854
[10011:10011:0517/100223.641929:VERBOSE2:v4l2_video_decode_accelerator.cc(746)] TryToSetupDecodeOnSeparateThread(): 
[10011:10622:0517/100223.642354:VERBOSE2:v4l2_video_decode_accelerator.cc(293)] InitializeTask(): 
[10011:10622:0517/100223.643873:VERBOSE2:v4l2_video_decode_accelerator.cc(2182)] CreateInputBuffers(): 
[10011:10622:0517/100223.723973:VERBOSE2:v4l2_video_decode_accelerator.cc(1708)] IsDecoderCmdSupported(): V4L2_DEC_CMD_STOP is not supported.
[10011:10622:0517/100224.155136:VERBOSE2:v4l2_video_decode_accelerator.cc(2146)] GetVisibleSize(): Fallback to VIDIOC_G_CROP
[10011:10622:0517/100224.155372:VERBOSE2:v4l2_video_decode_accelerator.cc(2160)] GetVisibleSize(): visible rectangle is 0,0 640x360
[10011:10622:0517/100224.156350:VERBOSE2:v4l2_video_decode_accelerator.cc(1347)] DequeueResolutionChangeEvent(): got resolution change event.
[10011:10622:0517/100224.156523:VERBOSE2:v4l2_video_decode_accelerator.cc(1961)] StartResolutionChange(): Initiate resolution change
[10011:10622:0517/100224.156849:VERBOSE2:v4l2_video_decode_accelerator.cc(1906)] StopOutputStream(): 
[10011:10622:0517/100224.156963:VERBOSE2:v4l2_video_decode_accelerator.cc(2536)] DestroyOutputBuffers(): 
[10011:10622:0517/100224.157048:VERBOSE2:v4l2_video_decode_accelerator.cc(1989)] FinishResolutionChange(): 
[10011:10622:0517/100224.157155:VERBOSE2:v4l2_video_decode_accelerator.cc(2146)] GetVisibleSize(): Fallback to VIDIOC_G_CROP
[10011:10622:0517/100224.157247:VERBOSE2:v4l2_video_decode_accelerator.cc(2160)] GetVisibleSize(): visible rectangle is 0,0 640x360
[10011:10622:0517/100224.157345:VERBOSE2:v4l2_video_decode_accelerator.cc(2123)] CreateBuffersForFormat(): new resolution: 640x368, visible size: 640x360, decoder output planes count: 2, EGLImage size: 640x368, EGLImage plane count: 2
[10011:10622:0517/100224.157483:VERBOSE2:v4l2_video_decode_accelerator.cc(2461)] CreateOutputBuffers(): 
[10011:10011:0517/100224.163889:VERBOSE2:v4l2_video_decode_accelerator.cc(336)] AssignPictureBuffers(): buffer_count=10
[10011:10622:0517/100224.164095:VERBOSE2:v4l2_video_decode_accelerator.cc(347)] AssignPictureBuffersTask(): 
[10011:10011:0517/100255.973749:VERBOSE2:v4l2_video_decode_accelerator.cc(704)] Flush(): 
[10011:10622:0517/100255.977134:VERBOSE2:v4l2_video_decode_accelerator.cc(1619)] FlushTask(): 
[10011:10622:0517/100255.984748:VERBOSE2:v4l2_video_decode_accelerator.cc(858)] DecodeBufferTask(): enqueued flush buffer
[10011:10622:0517/100256.210003:VERBOSE2:v4l2_video_decode_accelerator.cc(1906)] StopOutputStream(): 
[10011:10622:0517/100256.210400:VERBOSE2:v4l2_video_decode_accelerator.cc(1933)] StopInputStream(): 
[10011:10622:0517/100256.211064:VERBOSE2:v4l2_video_decode_accelerator.cc(1692)] NotifyFlushDoneIfNeeded(): returning flush
[10011:10622:0517/100256.463607:VERBOSE2:v4l2_video_decode_accelerator.cc(1347)] DequeueResolutionChangeEvent(): got resolution change event.
[10011:10622:0517/100256.464224:VERBOSE2:v4l2_video_decode_accelerator.cc(1961)] StartResolutionChange(): Initiate resolution change
[10011:10622:0517/100256.465146:VERBOSE2:v4l2_video_decode_accelerator.cc(1906)] StopOutputStream(): 
[10011:10622:0517/100256.465866:VERBOSE2:v4l2_video_decode_accelerator.cc(2536)] DestroyOutputBuffers(): 
[10011:10622:0517/100256.475041:VERBOSE2:v4l2_video_decode_accelerator.cc(1989)] FinishResolutionChange(): 
[10011:10622:0517/100256.475422:VERBOSE2:v4l2_video_decode_accelerator.cc(2146)] GetVisibleSize(): Fallback to VIDIOC_G_CROP
[10011:10622:0517/100256.475701:VERBOSE2:v4l2_video_decode_accelerator.cc(2160)] GetVisibleSize(): visible rectangle is 0,0 1280x720
[10011:10622:0517/100256.475974:VERBOSE2:v4l2_video_decode_accelerator.cc(2123)] CreateBuffersForFormat(): new resolution: 1280x720, visible size: 1280x720, decoder output planes count: 2, EGLImage size: 1280x720, EGLImage plane count: 2
[10011:10622:0517/100256.476248:VERBOSE2:v4l2_video_decode_accelerator.cc(2461)] CreateOutputBuffers(): 
[10011:10011:0517/100256.489861:VERBOSE2:v4l2_video_decode_accelerator.cc(336)] AssignPictureBuffers(): buffer_count=10
[10011:10622:0517/100256.490152:VERBOSE2:v4l2_video_decode_accelerator.cc(347)] AssignPictureBuffersTask(): 
[10011:10011:0517/100303.051095:VERBOSE2:v4l2_video_decode_accelerator.cc(720)] Destroy(): 
[10011:10622:0517/100303.051423:VERBOSE2:v4l2_video_decode_accelerator.cc(1835)] DestroyTask(): 
[10011:10622:0517/100303.051950:VERBOSE2:v4l2_video_decode_accelerator.cc(1906)] StopOutputStream(): 
[10011:10622:0517/100303.052430:VERBOSE2:v4l2_video_decode_accelerator.cc(1933)] StopInputStream(): 
[10011:10622:0517/100303.053416:VERBOSE2:v4l2_video_decode_accelerator.cc(2509)] DestroyInputBuffers(): 
[10011:10622:0517/100303.215006:VERBOSE2:v4l2_video_decode_accelerator.cc(2536)] DestroyOutputBuffers(): 
[10011:10011:0517/100303.215671:VERBOSE2:v4l2_video_decode_accelerator.cc(740)] Destroy(): Destroyed.

What's the difference between PFQ and informational PFQ?

https://cros-goldeneye.corp.google.com/chromeos/legoland/builderSummary?builderGroups=chrome_pfq%2Cinformational&limit=3&buildBranch=master

Passed:
https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/buildDetails?id=2579956
chrome revision c70cdb314e37ae58980dd993433748d9c09e64dc

Failed:
https://cros-goldeneye.corp.google.com/chromeos/healthmonitoring/buildDetails?id=2580185
chrome revision b148b4788bc90804d3848878db99aff8167c5096

#14: See http://doc/13zse2T7S-rMaFEvd0HhFvF95GWJWbuwY-QfeWUlOwbg#heading=h.pu3765eisg6b

https://chromium.googlesource.com/chromium/src/+log/68.0.3433.0..68.0.3434.0?n=10000

Maybe this one?
[Histograms] Revamp of the chrome://histograms page
https://chromium.googlesource.com/chromium/src/+/18170a49b39546ea32d21dc7d61bc82d61529fd0

Nice catch; that seems likely. For posterity, here's the full commit list between the two builds in #15:

% git log --pretty=oneline --abbrev-commit c70cdb314e37ae58980dd993433748d9c09e64dc..b148b4788bc90804d3848878db99aff8167c5096
b148b4788bc9 cc: Remove glFinish call during cc shutdown.
7f65a1f2176a Introduce password specific accessory sheet view
47d67ced1797 Update PasswordManager when a relevant credential is removed by the user.
4aa3e99bca50 [Unity][Android] Disable sign-in controls while sign-in is in progress
2dacc3740d40 Remove  crbug.com/546165  and  crbug.com/546167  TODOs.
9327148ca68b Show cancel button when the omnibox is focused
54fe857107bf android: crazy-linker: Support recursive dlopen() operations.
0181d8b347f3 Fix TaskSchedulerWorkerPoolHistogramTest.NumTasksBeforeCleanup failure on Fuschia.
aa703718de4d Move snap fling logic to cc.
dec5afddcc71 bluetooth: Fix clusterfuzz presubmit script
87feef2cd968 Flag virtual/exotic-color-space/images/color-profile-layer-filter.html slow on Mac
8004bde35ba5 Fix inter-process completion timestamp conversion
70fa918b43be Android test exclusions: don't exclude mojo_test_apk
78599b5331d9 Android test exclusions: don't exclude latency_unittests
ff0b29494cc6 Update V8 to version 6.8.244.
81cad4732ff6 Reporting: Clearly separate IO and UI thread concerns
b4a07f8fb37e Fix some WebSocket-related comments.
5a1960552742 Remove GL context use from LayerTreeResourceProvider.
afd440c7ab46 Do not check for license type if enrollment is forced by server.
211e27c281bd touch_hud: Remove mash::mojom::Launchable interface
177f6ea9952d Update gesture-pinch-zoom-prevent-in-handler.html slimming-paint-v2 expectation
6f6da8452daa Add a field for deleted policies to policy_templates.json.
ace896ebf017 Use new OnURLsDeleted method for Subresourcefilter and improve deletion
f4867cc4e2c6 [Android WebView] Make sure to commit any cached metrics.
7103eb9923df VR: Storing clip rect in relative coordinates
6b33c6d64fbb [Code Coverage] Remove obsolete points from the FAQ list:
6b82d425cb76 ozone/drm: Implement support for plane overlay fences
9b822f03e769 Android test exclusions: don't exclude google_apis_unittests
f666fb8e5341 Android test exclusions: don't exclude libjingle_xmpp_unittests
8fd42c9bf01c Parameterize WebRtcGetUserMediaBrowserTest
5aab0f4c9e42 Remove duplicated CSS test
b3bae02534c8 Parameterize WebRtcGetMediaDevicesBrowserTest
843edef8401e customtabs: Remove obsolete LoadingPredictor from CustomTabs.
31f8df48a7c5 Win Native Notifications: Don't abort if AllowSetForegroundWindow fails.
3c9be59d1104 Make LeftViewProvider an Obj-C protocol.
15db5c5633b1 Remove OtherPossibleUsernames.
9214f5af9529 Fix the color of tools menu's disabled elements
18170a49b395 [Histograms] Revamp of the chrome://histograms page

It looks like they changed chrome://histograms page and broke all ChromeOS tests that parsed the page. If that's the case, we should fix histogram_verifier.py quickly or disable video tests in PFQ before autotest is fixed.

https://cs.corp.google.com/chromeos_public/src/third_party/autotest/files/client/cros/video/histogram_verifier.py

Mathieu, is it expected that https://crrev.com/c/890627 changed the format of chrome://histograms?

Chrome OS integration tests shouldn't be parsing human-readable pages like this, and certainly shouldn't be doing so without having unit tests on the Chrome side to ensure that the formatting doesn't change. Agreed with #19 that if the test code can't be updated quickly, we should disable the tests in the Chrome PFQ. I'll do the latter tomorrow morning if the tests can't be fixed sooner than that.

Confirm the bug is reproducible on eve:

With https://pantheon.corp.google.com/storage/browser/chromeos-image-archive/eve-tot-chrome-pfq-informational/R68-10686.0.0-b2579613  the test video_ChromeHWDecodeUsed.vp8 passed

With https://pantheon.corp.google.com/storage/browser/chromeos-image-archive/eve-tot-chrome-pfq-informational/R68-10687.0.0-b2580136 the test fail. 

Will try reverting the histograms change to see if it pass the test.

Confirm that the commit 
[Histograms] Revamp of the chrome://histograms page
is the culprit to break the test by building ToT Chrome with the commit reverted and the test passed.

Agree with #20 that the test should not depend on the human readable format. Let me check if we can fix the test soon.

FYI, now the failures started hitting the real daily PFQ (not only ToT-informational)
https://uberchromegw.corp.google.com/i/chromeos/builders/cyan-chrome-pfq/builds/3197
https://uberchromegw.corp.google.com/i/chromeos/builders/peach_pit-chrome-pfq/builds/5559

While investigating cros/video/histogram_verifier.py (crbug.com/844341), I found that with the histogram commit (https://crrev.com/c/890627), the histogram page: chrome://histograms/Media.GpuVideoDecoderInitializeStatus does not refresh counter after playing video.

Suspect histogram issue, investigating.

Mathieu, I found the suspect could be your commit. Here's the reproduce step:
1. Flash a DUT (board: eve) with chromiumos_test_image.tar.xz in https://pantheon.corp.google.com/storage/browser/chromeos-image-archive/eve-tot-chrome-pfq-informational/R68-10686.0.0-b2579613 
2. Login guest mode, visit chrome://histograms/Media.G shows no histogram.
3. Open a new tab, playing something from YouTube.
4. Now chrome://histograms/Media.G shows something, specifically GpuVideoDecoderInitializeStatus

5. Now flash DUT with chromiumos_test_image.tar.xz in
https://pantheon.corp.google.com/storage/browser/chromeos-image-archive/eve-tot-chrome-pfq-informational/R68-10687.0.0-b2580136
6. Login guest mode, visit chrome://histograms/Media.G shows no histogram.
7. Open a new tab, playing something from YouTube.
8. Now chrome://histograms/Media.G expected to see some histogram, but nothing there.


I can also reproduce it by deploying locally build Chromium (w/ and w/o your commit) on R68-10686.0.0 eve Chromebook.

Re comment #8:

[3788:3793:0517/171705.332330:VERBOSE1:drm_device_manager.cc(53)] Could not initialize DRM device for /sys/devices/platform/vgem/drm/card1

Failing to initialize DRM for the VGEM device is not an error. The VGEM device isn't a modesetting device, so we will not be using it to configure displays.

[3788:3793:0517/171706.365102:ERROR:drm_device.cc(751)] CTM is empty. Expected a 3x3 matrix.
[3788:3793:0517/171706.365227:ERROR:drm_display.cc(181)] Failed to set color correction for display: crtc_id = 26

These are unrelated errors during initialization. They won't affect video tests. For those interested, there is a fix in the works for these errors: https://chromium-review.googlesource.com/c/chromium/src/+/1045867

In review https://chromium-review.googlesource.com/c/chromium/src/+/1065462

Verified that Mathieu's fix solved the issue. Thanks for your quick response.

Thanks! I'll use issue 844341 to track the Chrome regression and this to track the PFQ failure.

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

commit f8af727643a16136e731c3d0eeab8b78a3023b60
Author: Mathieu Perreault <mathp@chromium.org>
Date: Fri May 18 15:17:50 2018

[Histograms page] Import histograms before querying for them.

Without this function, only a partial list is returned.

Bug: 844341,  844121 
Change-Id: I45fa43a68e899cce2b14b7b1f75e6edd5c48a146
Reviewed-on: https://chromium-review.googlesource.com/1065462
Reviewed-by: Dan Erat <derat@chromium.org>
Reviewed-by: Avi Drissman <avi@chromium.org>
Commit-Queue: Mathieu Perreault <mathp@chromium.org>
Cr-Commit-Position: refs/heads/master@{#559897}
[modify] https://crrev.com/f8af727643a16136e731c3d0eeab8b78a3023b60/content/browser/histograms_internals_ui.cc

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

commit ca1d7eba59817ec476d5d3b20e5f8ebfe5d69a04
Author: Daniel Erat <derat@chromium.org>
Date: Fri May 18 19:29:03 2018

[Histograms page] Import histograms before querying for them.

Without this function, only a partial list is returned.

TBR=mathp@chromium.org

(cherry picked from commit f8af727643a16136e731c3d0eeab8b78a3023b60)

Bug: 844341,  844121 
Change-Id: I45fa43a68e899cce2b14b7b1f75e6edd5c48a146
Reviewed-on: https://chromium-review.googlesource.com/1065462
Reviewed-by: Dan Erat <derat@chromium.org>
Reviewed-by: Avi Drissman <avi@chromium.org>
Commit-Queue: Mathieu Perreault <mathp@chromium.org>
Cr-Original-Commit-Position: refs/heads/master@{#559897}
Reviewed-on: https://chromium-review.googlesource.com/1066561
Cr-Commit-Position: refs/branch-heads/3434@{#3}
Cr-Branched-From: 1d3d3febb6d20bde02d02e49ee0d6b6fe0cec0f7-refs/heads/master@{#559775}
[modify] https://crrev.com/ca1d7eba59817ec476d5d3b20e5f8ebfe5d69a04/content/browser/histograms_internals_ui.cc

https://stainless.corp.google.com/search?view=matrix&row=model&col=build&first_date=2018-05-23&last_date=2018-05-25&test=video_ChromeRTCHWDecodeUsed%7Cvideo_ChromeHWDecodeUsed&build=R68-*&board=pit%7Ceve&exclude_cts=false&exclude_not_run=false&exclude_non_release=true&exclude_au=true&exclude_acts=true&exclude_retried=true&exclude_non_production=false