search

dart-lang / sdk

The Dart SDK, including the VM, JS and Wasm compilers, analysis, core libraries, and more.
https://dart.dev
BSD 3-Clause "New" or "Revised" License
10.21k stars 1.57k forks source link

Some browser tests timing out when co19 is run #22050

Open whesse opened 9 years ago

whesse commented 9 years ago

We are getting timeouts of html/history_test on firefox, on the buildbot. There is a possibly related issue on history_test, which claims there is a problem with the unittest framework: https://code.google.com/p/dart/issues/detail?id=8183

From the Dart code, it is hard to see what could be causing a timeout, but it is happening.

Skipping the test on Firefox in the status file. Putting this in the unittest area for now, unless it is shown that that is not the problem.

There is no useful information in the buildbot output: FAILED: dart2js-ff release_ia32 html/history_test/history Expected: Pass Actual: Timeout CommandOutput[dart2js]: CommandOutput[ff]:

stdout: events:   [         {               type: debug               value: test_controller.js started               timestamp: 0         },         {               type: debug               value: Sending events to driver page (isFirstMessage = true, isStatusUpdate = true, isDone = false)               timestamp: 0         },         {               type: print               value: dart-calling-main               timestamp: 0.154         },         {               type: print               value: dart-main-done               timestamp: 0.192         },         {               type: message_received               value: dart-calling-main               timestamp: 0.233         },         {               type: message_received               value: unittest-suite-wait-for-done               timestamp: 0.234         },         {               type: message_received               value: dart-main-done               timestamp: 0.234         },         {               type: debug               value: Sending events to driver page (isFirstMessage = false, isStatusUpdate = true, isDone = false)               timestamp: 10.002         }, ....         {               type: debug               value: Sending events to driver page (isFirstMessage = false, isStatusUpdate = true, isDone = false)               timestamp: 60.008         },         {               type: dom               value: <head>                       <meta http-equiv="X-UA-Compatible" content="IE=edge">                       <meta name="dart.unittest" content="full-stack-traces">                       <title> Test /mnt/data/b/build/slave/dart2js-ff-linux-2-4-be/build/dart/tests/html/history_test.dart </title>                       <style>                          .unittest-table { font-family:monospace; border:1px; }                          .unittest-pass { background: #­6b3;}                          .unittest-fail { background: #d55;}                          .unittest-error { background: #a11;}                       </style>                     </head>                     <body>                       <h1> Running /mnt/data/b/build/slave/dart2js-ff-linux-2-4-be/build/dart/tests/html/history_test.dart </h1>                       <script type="text/javascript" src="/root_dart/tools/testing/dart/test_controller.js">                       </script>                       <script type="text/javascript" src="/root_build/generated_compilations/dart2js-sdk/tests_html_history_test/test.js" onerror="scriptTagOnErrorCallback(null)" defer="">                       </script>                       <script type="text/javascript" src="/root_dart/pkg/browser/lib/dart.js"></script>                                          </body>               timestamp: 60.009         },   ]    stderr: This test timed out. The delay until the test actually started was: 0:00:00.259683.

whesse commented 9 years ago

Certain tests are flakily timing out on the browser, on build slaves where we have started running the co19 browser tests as well. These are not co19 tests, but the additional load may be a factor in their timing out.

These tests are somewhat slow, but still in the 10 second or less range, when they don't time out, so the timeout is not just a test being slightly slower than ususal - it is some sort of bug.

Here are the tests, which are now being skipped on firefox and on chrome:

lib/convert/streamed_conversion_utf8_encode_test lib/convert/streamed_conversion_json_utf8_encode_test lib/async/slow_consumer2_test lib/async/stream_timeout_test pkg/collection/test/unmodifiable_collection_test

cc @ricowind. Set owner to @whesse. Removed Area-Pkg, Pkg-Unittest labels. Added Area-Library, Browser-Chrome, Library-Html labels. Changed the title to: "Some browser tests timing out when co19 is run".

whesse commented 9 years ago

html/element_types_test/constructors has also started flakily timing out since co19 tests started running on chrome.

whesse commented 9 years ago

lib/convert/streamed_conversion_utf8_decode_test has been added, since it now times out sometimes on Chrome 41 on macos.

alan-knight commented 9 years ago

I wonder if something in the co19 tests is leaving something in an invalid state, or even just leaking memory to the point where some random later tests is swapping or otherwise can't run. These tests seem to have very little in common, and don't seem like they should be very slow.

So are these running in a single browser instance or in multiple shards? Is the order of tests predictable? If not, is there any pattern to which tests were run before one of these failures? Could we try rolling back to Chrome 40 to see if it actually stops, or if it's coincidental?

Another thing that could be related is updating the dart:html library to the Chrome 39 IDL. Stephen noticed an issue yesterday that they've replaced a number of APIs that returned JS objects created from a particular constructor, i.e. with a known type, to arbitrary Objects, and that this is making our type inference worse. So we might have a number of tests with suddenly increased code size, or possibly some other effects. Did this flaking start appearing in any recent dev versions?

cc @terrylucas. cc @rakudrama.

ricowind commented 9 years ago

You can easily test that hypothesis locally by running with -j1 and monitoring memory usage.

Cheers, Rico

whesse commented 9 years ago

No, these are not just random tests. These particular tests time out on multiple different runs, and other tests don't time out at all. We have run the bots with -j1 when we did have problems like you suggest, and found and skipped all the tests that had that sort of effect, of making other tests fail.

I am pretty confident that these particular tests have problems - they fall into categories, and are suspicious. They also are not just slow tests, near the timeout limit. When they time out, they are hanging on something.

alan-knight commented 9 years ago

What's suspicious? Looking at the element_types_test or at unmodifiable_collection_test they seem very straightforward, although both do a lot of things. With element_types_test/constructors, that's a group. Is it a particular test within that which consistently times out, or is it random?

whesse commented 9 years ago

The tests are sharded between multiple browsers running in parallel, so the order of which test follows which is not deterministic. When we did have cases with a test which made later tests fail, we got a cluster of tests hanging flakily, with individual ones hanging at most 20% of the time. Additionally, they were co19 tests, running after a new co19 test that caused the problem. Many times they would even say "this test has not started running"

Note that most of these are from earlier, and the addition of the recent one with chrome 41 looks like just chance - it could have timed out before, since the other 3 similar tests already had.

I really don't know what is making these time out, but my experience with earlier flakes of tests due to external causes makes me feel that these aren't in that category - they just aren't behaving that way.

alan-knight commented 9 years ago

OK, I split html/element_types_test/constructors into several independent test files to narrow down what might be problematic. https://codereview.chromium.org/984133004

alan-knight commented 9 years ago

I have not seen any flaking on element_types_test since dividing into multiple pieces. So it doesn't seem like there was anything particularly bad about that test except its length. That seems troubling.