New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 719995 link

Starred by 2 users

Issue metadata

Status: Available
Owner: ----
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: ----
Pri: 3
Type: Bug


Participants' hotlists:
Test-Use-Cases


Sign in to add a comment

common layout test failure debugging workflow should be faster and easier

Project Member Reported by estaab@chromium.org, May 9 2017

Issue description

Currently when a layout test fails users are required to search through a ~10MB log file to find the relevant failure info. The file is large because every passing test name is printed in additional to the failing tests because the complete info is needed in some circumstances.

Since the full info isn't needed in the common case, it could be better to have two log levels similar to how server severity logs are written (e.g. INFO, ERROR, etc). The full log can continue to be written the way it is, but an additional log with just the failing tests and relevant output could be written to a separate file. This smaller file can be the first place devs go, saving needless loading and searching.
 
In general when a layout test fails, the log for the webkit_tests step is not used to debug the failure (and indeed, it is usually useless) -- instead, the archived results results.html is used.

That is, when looking at a failed build, users should look at the layout_test_results link in the archive_webkit_tests_results step. This is different from other tests, so sometimes people make the mistake of clicking on the webkit_tests stdout link.

Is there any way we can make it more obvious which is the right link to look at when debugging layout test results?
Cc: jparent@chromium.org qyears...@chromium.org jeffcarp@chromium.org
Adding qyearsly+jeffcarp to CC (as they have done a lot of work on Layout Tests lately).

IMHO - I don't think the passing test name output is problematic. People just skip to the end of the logs and it is useful to know that existing tests worked as expected.

The part which always confuses me is the following;
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/workers/thorough/redirect-nocors.html took 0.4 seconds
20:27:44.164 7608   external/wpt/html/dom/reflection-grouping.html took 0.4 seconds
20:27:44.164 7608   http/tests/inspector/indexeddb/database-names.html took 0.3 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/serviceworker/response.html took 0.3 seconds
20:27:44.164 7608   external/wpt/html/syntax/parsing/html5lib_innerHTML_foreign-fragment.html took 0.3 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/window/thorough/cookie-nocors.html took 0.3 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/workers/thorough/scheme-data-base-https-other-https.html took 0.3 seconds
20:27:44.164 7608   editing/selection/modify_move/move-by-word-visually-inline-block-positioned-element.html took 0.3 seconds
20:27:44.164 7608   external/wpt/html/browsers/the-window-object/apis-for-creating-and-navigating-browsing-contexts-by-name/open-features-non-integer-innerheight.html took 0.3 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/window/referrer-base-https-other-https.html took 0.3 seconds
20:27:44.164 7608   external/wpt/WebCryptoAPI/generateKey/test_successes_AES-CTR.https.html took 0.3 seconds
20:27:44.164 7608   inspector/console/console-originating-command.html took 0.3 seconds
20:27:44.164 7608   http/tests/fetch/serviceworker/response.html took 0.3 seconds
20:27:44.164 7608   virtual/threaded/fast/idle-callback/idle_periods.html took 0.2 seconds
20:27:44.164 7608   external/wpt/service-workers/cache-storage/worker/cache-delete.https.html took 0.2 seconds
20:27:44.164 7608   http/tests/websocket/no-crash-on-cookie-flood.html took 0.2 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/referrer/no-referrer-document.html took 0.2 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/workers/response-content.html took 0.2 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/serviceworker/fetch.html took 0.2 seconds
20:27:44.164 7608   cssom/cssvalue-comparison.html took 0.2 seconds
20:27:44.164 7608   http/tests/fetch/workers/headers.html took 0.2 seconds
20:27:44.164 7608   external/wpt/selection/addRange-44.html took 0.2 seconds
20:27:44.164 7608   external/wpt/service-workers/cache-storage/worker/cache-storage.https.html took 0.2 seconds
20:27:44.164 7608   http/tests/fetch/serviceworker/response-content-base-https-other-https.html took 0.2 seconds
20:27:44.164 7608   http/tests/fetch/workers/response-content-base-https-other-https.html took 0.2 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/window/cache-override.html took 0.2 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/window/block-mixed-content-base-https.html took 0.2 seconds
20:27:44.164 7608   crypto/subtle/aes-gcm/cloneKey.html took 0.1 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/window/filtered-response-other-https.html took 0.1 seconds
20:27:44.164 7608   virtual/mojo-loading/http/tests/fetch/workers/filtered-response.html took 0.1 seconds
20:27:44.164 7608   external/wpt/html/syntax/parsing/html5lib_innerHTML_tests4.html took 0.1 seconds
20:27:44.164 7608   external/wpt/selection/extend-40.html took 0.1 seconds
20:27:44.164 7608   external/wpt/html/browsers/browsing-the-web/history-traversal/persisted-user-state-restoration/scroll-restoration-fragment-scrolling-cross-origin.html took 0.1 seconds
20:27:44.165 7608   http/tests/fetch/window/response-content.html took 0.1 seconds
20:27:44.165 7608   external/wpt/html/browsers/browsing-the-web/history-traversal/persisted-user-state-restoration/scroll-restoration-navigation-cross-origin.html took 0.1 seconds
20:27:44.165 7608   http/tests/navigation/no-referrer-reset.html took 0.1 seconds
20:27:44.165 7608   virtual/threaded/fast/scroll-behavior/overflow-scroll-root-frame-animates.html took 0.1 seconds
20:27:44.165 7608   crypto/subtle/aes-ctr/generateKey-failures.html took 0.1 seconds
20:27:44.165 7608   crypto/subtle/ecdh/deriveKey-aes.html took 0.1 seconds
20:27:44.165 7608   virtual/mojo-loading/http/tests/fetch/chromium/discarded-window.html took 0.1 seconds
20:27:44.165 7608   crypto/subtle/aes-export-key.html took 0.1 seconds
20:27:44.165 7608   virtual/sharedarraybuffer/crypto/subtle/modify-verify-data-during-normalization.html took 0.1 seconds
20:27:44.165 7608   external/wpt/html/browsers/browsing-the-web/scroll-to-fragid/scroll-to-id-top.html took 0.1 seconds
20:27:44.165 7608   virtual/sharedarraybuffer/crypto/subtle/rsassa-pkcs1-v1_5/sign-verify.html took 0.1 seconds
20:27:44.165 7608   crypto/subtle/ec-export-public-key.html took 0.0 seconds
20:27:44.165 7608   crypto/subtle/ecdh/deriveBits-failures.html took 0.0 seconds
20:27:44.165 7608   crypto/subtle/hkdf/deriveKey.html took 0.0 seconds
20:27:44.165 7608   crypto/subtle/hmac/import-jwk.html took 0.0 seconds
20:27:44.165 7608   virtual/sharedarraybuffer/crypto/subtle/rsa-oaep/plaintext-length.html took 0.0 seconds
20:27:44.165 7608   crypto/subtle/pbkdf2/d=> Results: 6931/7008 tests passed (98.9%)

=> Tests to be fixed (1201):
     20 text-only failures       ( 1.7%)
     41 image-only failures      ( 3.4%)
      3 image and text failures  ( 0.2%)
     13 timeouts                 ( 1.1%)

=> Tests that will only be fixed if they crash (WONTFIX) (63):


Expected to timeout, but passed: (7)
  external/wpt/streams/byte-length-queuing-strategy.sharedworker.html
  external/wpt/streams/piping/error-propagation-forward.sharedworker.html
  external/wpt/streams/piping/transform-streams.sharedworker.html
  external/wpt/streams/readable-streams/bad-underlying-sources.sharedworker.html
  external/wpt/streams/readable-streams/general.sharedworker.html
  external/wpt/streams/readable-streams/templated.sharedworker.html
  virtual/mojo-loading/http/tests/permissions/test-query.html

Expected to fail, but passed: (5)
  external/wpt/css/vendor-imports/mozilla/mozilla-central-reftests/writing-modes-3/text-combine-upright-compression-003.html
  external/wpt/css/vendor-imports/mozilla/mozilla-central-reftests/writing-modes-3/text-combine-upright-compression-007.html
  fast/multicol/span/pseudo-before-after-in-content.html
  http/tests/security/cors-rfc1918/addressspace-document-csp-appcache.html
  virtual/threaded/printing/webgl-repeated-printing-preservedrawingbuffer.html


Regressions: Unexpected text-only failures (1)
  fast/css-grid-layout/grid-self-baseline-two-dimensional.html [ Failure ]

Regressions: Unexpected image-only failures (1)
  external/wpt/css/css-ui-3/outline-004.html [ Failure ]

------------------------------------------------------------------------------
eriveBits-failures.html took 0.0 seconds
20:27:44.166 7608   crypto/subtle/ecdsa/sign-verify.html took 0.0 seconds
20:27:44.166 7608   virtual/sharedarraybuffer/crypto/subtle/hkdf/exportKey.html took 0.0 seconds
20:27:44.166 7608   virtual/sharedarraybuffer/crypto/subtle/aes-key-algorithm-mismatch.html took 0.0 seconds
20:27:44.166 7608   inspector/console/console-log-side-effects.html took 0.0 seconds
20:27:44.166 7608   crypto/subtle/unwrapKey-lacks-usage.html took 0.0 seconds
20:27:44.166 7608   crypto/subtle/hmac/generateKey-failures.html took 0.0 seconds
20:27:44.166 7608   crypto/subtle/rsa-pss/verify.html took 0.0 seconds
20:27:44.166 7608   external/wpt/encrypted-media/drm-mp4-playback-temporary-expired.html took 0.0 seconds
20:27:44.166 7608   external/wpt/WebCryptoAPI/derive_bits_keys/test_hkdf.html took 0.0 seconds
20:27:44.166 7608   external/wpt/encrypted-media/drm-mp4-playback-temporary-setMediaKeys-immediately.html took 0.0 seconds
20:27:44.166 7608   external/wpt/encrypted-media/drm-mp4-playback-temporary-waitingforkey.html took 0.0 seconds
20:27:44.166 7608   external/wpt/encrypted-media/drm-mp4-playback-temporary.html took 0.0 seconds
20:27:44.166 7608 
20:27:44.166 7608 Tests that timed out or crashed:
20:27:44.166 7608   virtual/threaded/animations/combo-transform-rotate+scale.html took 30.1 seconds
20:27:44.166 7608   http/tests/inspector-protocol/request-mixed-content-status-blockable.html took 6.4 seconds
20:27:44.166 7608   virtual/mojo-loading/http/tests/inspector-protocol/network-data-length.html took 6.1 seconds
20:27:44.166 7608   external/wpt/fullscreen/api/element-request-fullscreen-two-iframes-manual.html took 6.1 seconds
20:27:44.166 7608   external/wpt/mixed-content/blockable/no-opt-in/same-host-http/form-tag/top-level/keep-scheme-redirect/no-opt-in-blocks.https.html took 6.1 seconds
20:27:44.166 7608   external/wpt/orientation-event/t012-manual.html took 6.1 seconds
20:27:44.166 7608   external/wpt/mixed-content/blockable/no-opt-in/cross-origin-http/form-tag/top-level/no-redirect/no-opt-in-blocks.https.html took 6.1 seconds
20:27:44.166 7608   external/wpt/mixed-content/blockable/no-opt-in/cross-origin-http/iframe-tag/top-level/swap-scheme-redirect/no-opt-in-blocks.https.html took 6.1 seconds
20:27:44.166 7608   external/wpt/cssom-view/matchMedia.xht took 6.1 seconds
20:27:44.166 7608   external/wpt/mixed-content/blockable/meta-csp/cross-origin-http/iframe-tag/top-level/no-redirect/opt-in-blocks.https.html took 6.1 seconds
20:27:44.166 7608   external/wpt/workers/semantics/structured-clone/shared.html took 6.1 seconds
20:27:44.166 7608   external/wpt/workers/semantics/multiple-workers/006.html took 6.1 seconds
20:27:44.166 7608   external/wpt/html/semantics/scripting-1/the-script-element/async_007.htm took 6.1 seconds
20:27:44.166 7608 
20:27:44.184 7608 Time to process slowest subdirectories:
20:27:44.184 7608   external/wpt/WebCryptoAPI/generateKey took 16.8 seconds to run 5 tests.
20:27:44.184 7608   external/wpt/XMLHttpRequest took 70.3 seconds to run 23 tests.
20:27:44.184 7608   locked_shard_1 took 137.8 seconds to run 366 tests.
20:27:44.184 7608   locked_shard_2 took 159.1 seconds to run 407 tests.
20:27:44.184 7608   paint/invalidation took 18.7 seconds to run 52 tests.
20:27:44.184 7608   virtual/disable-spinvalidation/paint/invalidation took 24.7 seconds to run 68 tests.
20:27:44.185 7608   virtual/gpu/fast/canvas took 20.0 seconds to run 48 tests.
20:27:44.185 7608   virtual/layout_ng/external/wpt/css/CSS2/normal-flow took 15.7 seconds to run 54 tests.
20:27:44.185 7608   virtual/threaded/animations took 49.4 seconds to run 30 tests.
20:27:44.185 7608 
20:27:44.185 7608 
20:27:44.185 7608 5802 tests ran as expected (5732 passed, 70 didn't), 19 didn't:
20:27:44.185 7608 
20:27:44.236 7608 Generating dashboard...
20:27:44.242 7608 Dashboard generated.
20:27:44.242 7608 
20:27:44.242 7608 Testing completed, Exit status: 2
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
The actual result of that is;

 ~5822 tests ran as expected, 2 that failed unexpectedly.

The two which failed are;
 * fast/css-grid-layout/grid-self-baseline-two-dimensional.html
 * external/wpt/css/css-ui-3/outline-004.html





Here is another output - this one actually had everything run as expected!
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
20:30:58.109 4252 Tests that timed out or crashed:
20:30:58.109 4252   harness-tests/timeout.html took 6.4 seconds
20:30:58.109 4252   virtual/threaded/transitions/position-background-transition.html took 6.2 seconds
20:30:58.109 4252   http/tests/permissions/chromium/test-request-multiple-window.html took 6.2 seconds
20:30:58.109 4252   external/wpt/XMLHttpRequest/event-readystatechange-loaded.htm took 6.2 seconds
20:30:58.109 4252   external/wpt/mixed-content/blockable/no-opt-in/same-host-http/iframe-tag/top-level/no-redirect/no-opt-in-blocks.https.html took 6.2 seconds
20:30:58.109 4252   external/wpt/orientation-event/t006-manual.html took 6.1 seconds
20:30:58.109 4252   external/wpt/fetch/api/basic/error-after-response.html took 6.1 seconds
20:30:58.109 4252   external/wpt/mixed-content/blockable/no-opt-in/same-host-http/form-tag/top-level/swap-scheme-redirect/no-opt-in-blocks.https.html took 6.1 seconds
20:30:58.109 4252   external/wpt/orientation-event/t023-manual.html took 6.1 seconds
20:30:58.109 4252   external/wpt/mixed-content/blockable/no-opt-in/cross-origin-http/form-tag/top-level/keep-scheme-redirect/no-opt-in-blocks.https.html took 6.1 seconds
20:30:58.109 4252   external/wpt/webaudio/the-audio-api/the-waveshapernode-interface/curve-tests.html took 6.1 seconds
20:30:58.109 4252   external/wpt/html/webappapis/idle-callbacks/cancel-invoked.html took 6.1 seconds
20:30:58.109 4252   external/wpt/XMLHttpRequest/abort-after-stop.htm took 6.1 seconds
20:30:58.109 4252   external/wpt/mixed-content/blockable/http-csp/same-host-http/form-tag/top-level/swap-scheme-redirect/opt-in-blocks.https.html took 6.1 seconds
20:30:58.109 4252   external/wpt/webaudio/the-audio-api/the-mediaelementaudiosourcenode-interface/mediaElementAudioSourceToScriptProcessorTest.html took 6.1 seconds
20:30:58.109 4252   external/wpt/orientation-event/t022-manual.html took 6.1 seconds
20:30:58.109 4252   external/wpt/html/webappapis/idle-callbacks/callback-idle-periods.html took 6.1 seconds
20:30:58.109 4252   external/wpt/orientation-event/t002-manual.html took 6.1 seconds
20:30:58.109 4252   virtual/mojo-loading/http/tests/security/xss-DENIED-xsl-document-securityOrigin.xml took 6.1 seconds
20:30:58.109 4252 
20:30:58.119 4252 Time to process slowest subdirectories:
20:30:58.119 425=> Results: 6899/7008 tests passed (98.4%)

=> Tests to be fixed (1193):
     21 text-only failures       ( 1.8%)
     61 image-only failures      ( 5.1%)
      8 image and text failures  ( 0.7%)
     19 timeouts                 ( 1.6%)

=> Tests that will only be fixed if they crash (WONTFIX) (45):


Expected to crash, but passed: (1)
  http/tests/security/setDomainRelaxationForbiddenForURLScheme.html

Expected to timeout, but passed: (3)
  external/wpt/streams/readable-streams/cancel.html
  http/tests/permissions/test-api-surface.html
  http/tests/permissions/test-query.html

Expected to fail, but passed: (1)
  virtual/threaded/printing/fixed-positioned-headers-and-footers-absolute-covering-some-pages.html


------------------------------------------------------------------------------
2   external/wpt/XMLHttpRequest took 39.7 seconds to run 20 tests.
20:30:58.120 4252   external/wpt/css/CSS2/normal-flow took 19.9 seconds to run 67 tests.
20:30:58.120 4252   external/wpt/css/CSS2/positioning took 16.2 seconds to run 46 tests.
20:30:58.120 4252   external/wpt/orientation-event took 24.7 seconds to run 4 tests.
20:30:58.120 4252   fast/css took 17.3 seconds to run 114 tests.
20:30:58.120 4252   locked_shard_1 took 142.7 seconds to run 389 tests.
20:30:58.120 4252   locked_shard_2 took 155.5 seconds to run 424 tests.
20:30:58.120 4252   media took 18.7 seconds to run 34 tests.
20:30:58.120 4252   virtual/gpu/fast/canvas took 17.7 seconds to run 41 tests.
20:30:58.120 4252   virtual/sharedarraybuffer/fast/css took 16.2 seconds to run 101 tests.
20:30:58.120 4252   virtual/threaded/fast/scroll-behavior took 18.9 seconds to run 4 tests.
20:30:58.120 4252 
20:30:58.120 4252 
20:30:58.120 4252 5869 tests ran as expected (5765 passed, 104 didn't), 10 didn't:
20:30:58.120 4252 
20:30:58.151 4252 Generating dashboard...
20:30:58.170 4252 Dashboard generated.
20:30:58.170 4252 
20:30:58.170 4252 Testing completed, Exit status: 0
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~


BTW My goal with the HTML formatting to make the output of a test failure link directly to the archived results with that test open (and other similar things like that).

I don't want a person to have to open the stdout. See what the output looks like now;
current-webkit-layout-tests-output.png
114 KB View Download
Actually, in pre-recipe days, we did have per-test links in the output, more or less, but we lost that when we switched to recipes. 

I agree that ideally we'd have links to just the output from each failure, and people would very rarely need to look at the whole log.

Comment 5 by jwo...@igalia.com, Aug 2 2017

Cc: jwo...@igalia.com
I propose putting a shortcut link from Gerrit straight to layout_test_results for failing blink layout test jobs. For me, the layout_test_results view of the situation is the most useful, and finding that link in a build log is impossible without being told where to look.

For example, linking from the "Trybots" section here:

https://chromium-review.googlesource.com/c/546941/6

straight to this page:

https://storage.googleapis.com/chromium-layout-test-archives/linux_trusty_blink_rel/12254/layout-test-results/results.html

without having to look here:

https://build.chromium.org/p/tryserver.blink/builders/linux_trusty_blink_rel/builds/12254

The most frustrating problem with the current system is that the UX of the build log misleads you to get lost in an enormous stdout dump and hides the much more valuable results page as the middle of three options on a short passing step that happens a few steps after the loud failure and has the name "archive" in it. For such a useful feature, it's very well hidden, which is a problem.

Comment 6 by foolip@chromium.org, Dec 15 2017

Status: Available (was: Untriaged)
dpranke@, I'm marking this as available, if that messes with your triage please shout. Comment #5 is a Gerrit feature request, so I'm not sure this is even in the right component.
Cc: aga...@chromium.org
Components: Infra>Codereview>Gerrit
I've added Infra>codereview>Gerrit component and cc'd agable, but, ideally issues should have only one component.  So if this has pivoted to a purely Gerrit (plugin) feature, let's clean it up and move it there.  agable, can you triage?
Components: -Blink>Infra -Infra>Codereview>Gerrit Infra>Client>Chrome
I don't think this is primarily a gerrit thing; really it's more of a chromium recipe thing (to present the results of a test step in the build output), at least in comments #1-4. 

jwolfe's idea is interesting and probably on the right longer-term track, but let's treat that separately.
Project Member

Comment 9 by sheriffbot@chromium.org, Dec 17

Labels: Hotlist-Recharge-Cold
Status: Untriaged (was: Available)
This issue has been Available for over a year. If it's no longer important or seems unlikely to be fixed, please consider closing it out. If it is important, please re-triage the issue.

Sorry for the inconvenience if the bug really should have been left as Available.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Status: Available (was: Untriaged)
Test failure debugging should be easier ideally. It's very hard for devs to find exactly where test results are. Our build pages aren't that easy to read.

Not sure what should be done with this bug. Marking as Available for now, although I'm worried it'll just stagnate for another year.
Cc: no...@chromium.org
+nodir for test results user journey

Sign in to add a comment