94505 2012-08-20 11:03:24 -0700 Intermittenly, many WebKit2 tests have results from the wrong test compared to the test just run, giving false failures. 2012-08-22 04:30:13 -0700 1 1 1 Unclassified WebKit Tools / Tests 528+ (Nightly build) All All RESOLVED FIXED P2 Normal --- 94277 1 beidson dpranke abarth dpranke jberlin kbalazs ojan sam simon.fraser thorton webkit.review.bot oldest_to_newest 699689 0 beidson 2012-08-20 11:03:24 -0700 Intermittenly, many WebKit2 tests have results from the wrong test compared to the test just run, giving false failures. This can easily be seen on the WK2 Lion bots, for example. where we bail early with 500+ failures. If you dig in to the failures you see that in many cases the wrong results are being attributed to the test, therefore causing the failure. If you're running locally and don't have the "abort after 500+ failures" flag, these tests are re-run as flakes and pass the 2nd time. This is huge pain point in regression testing right now. 699694 1 dpranke 2012-08-20 11:06:31 -0700 Is this a sub-bug of bug 94277, or do you see this as different somehow? 699696 2 dpranke 2012-08-20 11:09:08 -0700 Examples for the lazy: http://build.webkit.org/results/Apple%20Lion%20Release%20WK2%20(Tests)/r126041%20(2401)/results.html see especially the the dom failures, e.g.: http://build.webkit.org/results/Apple%20Lion%20Release%20WK2%20(Tests)/r126041%20(2401)/dom/html/level2/core/createDocument08-pretty-diff.html http://build.webkit.org/results/Apple%20Lion%20Release%20WK2%20(Tests)/r126041%20(2401)/results.html where it clearly looks like we're getting off-by-one issues ... 699701 3 beidson 2012-08-20 11:11:36 -0700 (In reply to comment #1) > Is this a sub-bug of bug 94277, or do you see this as different somehow? I think off-by-one is an identified symptom and therefore a distinct ticket. It might verywell be the *only* issue, at which point I'll clean up the bookkeeping. 699723 4 simon.fraser 2012-08-20 11:23:17 -0700 Did this problem start on > 1 bot at the same time? If so, maybe we can track it down to a specific commit. Otherwise, the test before or at the first failing test for each shard may be interesting. 699726 5 beidson 2012-08-20 11:24:19 -0700 (In reply to comment #4) > Did this problem start on > 1 bot at the same time? If so, maybe we can track it down to a specific commit. Otherwise, the test before or at the first failing test for each shard may be interesting. This started weeks ago (and went unnoticed) and the bots don't keep long enough history to know when it started. 699793 6 dpranke 2012-08-20 12:26:28 -0700 so, I'm able to reproduce something that looks at least similar, locally. It looks like what is happening is that the first test that fails in a shard (i.e., same directory) is failing with the message "Timed out waiting for final message from web process". Subsequent tests in the same shard then are failing with the output from the previous test, as if the output from the test that did time out isn't getting thrown away properly, and we're not communicating back to run-webkit-tests that something weird happened, and so run-webkit-tests doesn't know to recover/restart WTR either. I don't yet know why this is happening, and I don't know the code in WTR at all so I don't know if this sounds plausible. However, it should be easy to test/debug/work around, so I'm trying that now. 699847 7 159504 dpranke 2012-08-20 13:18:57 -0700 Created attachment 159504 Patch 699868 8 159504 ojan 2012-08-20 13:28:23 -0700 Comment on attachment 159504 Patch View in context: https://bugs.webkit.org/attachment.cgi?id=159504&action=review > Tools/Scripts/webkitpy/layout_tests/port/driver.py:163 > + if 'Timed out waiting for final message from web process' in text: This should probably have a FIXME. In theory at least, we should fix the WTR bug eventually and remove this special case, right? 699887 9 kbalazs 2012-08-20 13:44:16 -0700 (In reply to comment #8) > (From update of attachment 159504 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=159504&action=review > > > Tools/Scripts/webkitpy/layout_tests/port/driver.py:163 > > + if 'Timed out waiting for final message from web process' in text: > > This should probably have a FIXME. In theory at least, we should fix the WTR bug eventually and remove this special case, right? Before r124596, a change of mine, WTR was exiting in this case, so I think we should keep this behavior, although I'm not sure whether special case is needed in nrwt with that. 699897 10 dpranke 2012-08-20 13:48:41 -0700 It should have a fixme to either fix the underlying bug or at least make WTR communicate the need to restart in a more consistent and/or orderly manner. 699901 11 dpranke 2012-08-20 13:50:00 -0700 (In reply to comment #9) > (In reply to comment #8) > > (From update of attachment 159504 [details] [details]) > > View in context: https://bugs.webkit.org/attachment.cgi?id=159504&action=review > > > > > Tools/Scripts/webkitpy/layout_tests/port/driver.py:163 > > > + if 'Timed out waiting for final message from web process' in text: > > > > This should probably have a FIXME. In theory at least, we should fix the WTR bug eventually and remove this special case, right? > > Before r124596, a change of mine, WTR was exiting in this case, so I think we should keep this behavior, although I'm not sure whether special case is needed in nrwt with that. Is it possible your change is causing this bug? 699911 12 beidson 2012-08-20 13:56:38 -0700 For the lazy - http://trac.webkit.org/changeset/124596 is when the WKTR stopped exiting when the WebProcess timed out. I think we need to land this. 699916 13 dpranke 2012-08-20 13:59:57 -0700 Committed r126062: <http://trac.webkit.org/changeset/126062> 700178 14 ojan 2012-08-20 16:50:54 -0700 (In reply to comment #12) > For the lazy - http://trac.webkit.org/changeset/124596 is when the WKTR stopped exiting when the WebProcess timed out. > > I think we need to land this. I was just suggesting a FIXME. There's already a way that NRWT detects timing out tests. We should make WTR do that, then we don't need this special case. IIRC it something like spitting out a "#TIMEOUT" line. 700200 15 beidson 2012-08-20 17:01:35 -0700 (In reply to comment #14) > (In reply to comment #12) > > For the lazy - http://trac.webkit.org/changeset/124596 is when the WKTR stopped exiting when the WebProcess timed out. > > > > I think we need to land this. > > I was just suggesting a FIXME. There's already a way that NRWT detects timing out tests. We should make WTR do that, then we don't need this special case. IIRC it something like spitting out a "#TIMEOUT" line. I think Dirk and Balazas had much of that conversation on IRC today. Unsure what the outcome was (if any) 700222 16 dpranke 2012-08-20 17:16:38 -0700 (In reply to comment #15) > (In reply to comment #14) > > (In reply to comment #12) > > > For the lazy - http://trac.webkit.org/changeset/124596 is when the WKTR stopped exiting when the WebProcess timed out. > > > > > > I think we need to land this. > > > > I was just suggesting a FIXME. There's already a way that NRWT detects timing out tests. We should make WTR do that, then we don't need this special case. IIRC it something like spitting out a "#TIMEOUT" line. > > I think Dirk and Balazas had much of that conversation on IRC today. Unsure what the outcome was (if any) I did add the FIXME ... Balazs' patch was doing an end-run around the existing timeout detection logic, and he suggested another patch that would've exited instead of letting NRWT abort things, but I decided not to land that one. The problem seems to be that in http://trac.webkit.org/browser/trunk/Tools/WebKitTestRunner/TestInvocation.cpp#L201 I think false is being returned from resetStateToConsistentValues() (which seems like it would only happen if we timed out while trying to load about:blank). 700591 17 kbalazs 2012-08-21 03:50:10 -0700 > I did add the FIXME ... Balazs' patch was doing an end-run around the existing timeout detection logic, and he suggested another patch that would've exited instead of letting NRWT abort things, but I decided not to land that one. > > The problem seems to be that in > > http://trac.webkit.org/browser/trunk/Tools/WebKitTestRunner/TestInvocation.cpp#L201 > > I think false is being returned from resetStateToConsistentValues() (which seems like it would only happen if we timed out while trying to load about:blank). In my change I assumed that resetStateToConsistentValues() will never fail if there was no timeout before. In debug I added an assertion but in release this just mean we don't output anything on stderr so nrwt could not catch the error. I am going to take a try on whether removing this assumption fix this (without the patch we landed). 700794 18 kbalazs 2012-08-21 08:32:14 -0700 (In reply to comment #17) > > I did add the FIXME ... Balazs' patch was doing an end-run around the existing timeout detection logic, and he suggested another patch that would've exited instead of letting NRWT abort things, but I decided not to land that one. > > > > The problem seems to be that in > > > > http://trac.webkit.org/browser/trunk/Tools/WebKitTestRunner/TestInvocation.cpp#L201 > > > > I think false is being returned from resetStateToConsistentValues() (which seems like it would only happen if we timed out while trying to load about:blank). > > In my change I assumed that resetStateToConsistentValues() will never fail if there was no timeout before. In debug I added an assertion but in release this just mean we don't output anything on stderr so nrwt could not catch the error. I am going to take a try on whether removing this assumption fix this (without the patch we landed). My theory was wrong, this is not the reason. I think Dirk's patch fix the case when the test times out but resetStateToConsistentValues() does not fail (because if it fails we was restarting wtr anyway). I think the bug is that resetStateToConsistentValues() can return true even if the test is stil running. If I dump the #PROCESS UNRESPONSIVENESS message before calling resetStateToConsistentValues(), the off-by-one failures disappear. 700864 19 kbalazs 2012-08-21 10:02:33 -0700 Filed bug 94609 to remove the workaround. 700902 20 simon.fraser 2012-08-21 10:41:06 -0700 (In reply to comment #18) > (In reply to comment #17) > > > I did add the FIXME ... Balazs' patch was doing an end-run around the existing timeout detection logic, and he suggested another patch that would've exited instead of letting NRWT abort things, but I decided not to land that one. > > > > > > The problem seems to be that in > > > > > > http://trac.webkit.org/browser/trunk/Tools/WebKitTestRunner/TestInvocation.cpp#L201 > > > > > > I think false is being returned from resetStateToConsistentValues() (which seems like it would only happen if we timed out while trying to load about:blank). > > > > In my change I assumed that resetStateToConsistentValues() will never fail if there was no timeout before. In debug I added an assertion but in release this just mean we don't output anything on stderr so nrwt could not catch the error. I am going to take a try on whether removing this assumption fix this (without the patch we landed). > > My theory was wrong, this is not the reason. I think Dirk's patch fix the case when the test times out but resetStateToConsistentValues() does not fail (because if it fails we was restarting wtr anyway). I think the bug is that resetStateToConsistentValues() can return true even if the test is stil running. If I dump the #PROCESS UNRESPONSIVENESS message before calling resetStateToConsistentValues(), the off-by-one failures disappear. Does that mean that we still need a fix, and should reopen this bug? 700920 21 simon.fraser 2012-08-21 10:52:42 -0700 I guess the patch in bug 94609 implements the real fix. 701769 22 kbalazs 2012-08-22 04:30:13 -0700 (In reply to comment #21) > I guess the patch in bug 94609 implements the real fix. Yep. 159504 2012-08-20 13:18:57 -0700 2012-08-20 13:28:22 -0700 Patch bug-94505-20120820131818.patch text/plain 2171 dpranke U3VidmVyc2lvbiBSZXZpc2lvbjogMTI2MDQzCmRpZmYgLS1naXQgYS9Ub29scy9DaGFuZ2VMb2cg Yi9Ub29scy9DaGFuZ2VMb2cKaW5kZXggYjIwOTJmY2U2NzM3OTdiMWNlOTIxOTEyYmM0MTU1MzU3 YmMxNTJkYS4uYjE4MzgyYjhkNWU0NGMwMjJhZWEyOTVmMTM1NzFhMzM0NzZhNmQ5NSAxMDA2NDQK LS0tIGEvVG9vbHMvQ2hhbmdlTG9nCisrKyBiL1Rvb2xzL0NoYW5nZUxvZwpAQCAtMSwzICsxLDIz IEBACisyMDEyLTA4LTIwICBEaXJrIFByYW5rZSAgPGRwcmFua2VAY2hyb21pdW0ub3JnPgorCisg ICAgICAgIEludGVybWl0dGVubHksIG1hbnkgV2ViS2l0MiB0ZXN0cyBoYXZlIHJlc3VsdHMgZnJv bSB0aGUgd3JvbmcgdGVzdCBjb21wYXJlZCB0byB0aGUgdGVzdCBqdXN0IHJ1biwgZ2l2aW5nIGZh bHNlIGZhaWx1cmVzLgorICAgICAgICBodHRwczovL2J1Z3Mud2Via2l0Lm9yZy9zaG93X2J1Zy5j Z2k/aWQ9OTQ1MDUKKworICAgICAgICBSZXZpZXdlZCBieSBOT0JPRFkgKE9PUFMhKS4KKworICAg ICAgICBJdCBsb29rcyBsaWtlIGlmIHRoZSB3ZWJwcm9jZXNzIHRpbWVzIG91dCwgV1RSIG1heSB0 ZWxsIE5SV1QKKyAgICAgICAgdGhhdCB0aGUgdGVzdCBjb21wbGV0ZWQsIGJ1dCBub3QgcHJvcGVy bHkgcmVzZXQgaXRzIGludGVybmFsCisgICAgICAgIHN0YXRlLCBhbmQgdGhlbiByZXR1cm4gc3Rh bGUgb3V0cHV0IGZvciBzdWJzZXF1ZW50IHRlc3RzLgorCisgICAgICAgIFRoaXMgcGF0Y2ggbW9k aWZpZXMgTlJXVCB0ZW1wb3JhcmlseSB0byBjaGVjayBmb3IKKyAgICAgICAgIlRpbWVkIG91dCB3 YWl0aW5nIGZvciBmaW5hbCBtZXNzYWdlIGZyb20gd2ViIHByb2Nlc3MiIGluIHN0ZG91dAorICAg ICAgICBhbmQgdHJlYXQgdGhhdCBhcyBhIHRpbWVvdXQgKGFuZCB0aHVzIGtpbGwgV1RSKTsgdGhp cyBzZWVtcworICAgICAgICB0byBzb2x2ZSB0aGUgY2FzY2FkZSBvZiBmYWlsdXJlcywgYnV0IG9m IGNvdXJzZSB0aGVyZSdzIHByb2JhYmx5CisgICAgICAgIHN0aWxsIGEgYnVnIGluIFdUUiB0aGF0 IG5lZWRzIHRvIGJlIGZpeGVkLgorCisgICAgICAgICogU2NyaXB0cy93ZWJraXRweS9sYXlvdXRf dGVzdHMvcG9ydC9kcml2ZXIucHk6CisgICAgICAgIChEcml2ZXIucnVuX3Rlc3QpOgorCiAyMDEy LTA4LTE5ICBTdGVwaGFuaWUgTGV3aXMgIDxzbGV3aXNAYXBwbGUuY29tPgogCiAgICAgICAgIEFk ZCBtb3VudGFpbiBsaW9uIHRvIGJ1aWxkIGNvbmZpZy4KZGlmZiAtLWdpdCBhL1Rvb2xzL1Njcmlw dHMvd2Via2l0cHkvbGF5b3V0X3Rlc3RzL3BvcnQvZHJpdmVyLnB5IGIvVG9vbHMvU2NyaXB0cy93 ZWJraXRweS9sYXlvdXRfdGVzdHMvcG9ydC9kcml2ZXIucHkKaW5kZXggZDgzMmQ0MzI1MzE0NWNm NWFiNzViYWY4MzM4NWY2N2U1NjRiMzJiYy4uZGE2NzUzOTMxOGJlZDMzOGM4OTgxYzVkNTk2NDM4 MTQyNThjOTllNiAxMDA2NDQKLS0tIGEvVG9vbHMvU2NyaXB0cy93ZWJraXRweS9sYXlvdXRfdGVz dHMvcG9ydC9kcml2ZXIucHkKKysrIGIvVG9vbHMvU2NyaXB0cy93ZWJraXRweS9sYXlvdXRfdGVz dHMvcG9ydC9kcml2ZXIucHkKQEAgLTE2MCw2ICsxNjAsMTIgQEAgY2xhc3MgRHJpdmVyKG9iamVj dCk6CiAKICAgICAgICAgY3Jhc2hlZCA9IHNlbGYuaGFzX2NyYXNoZWQoKQogICAgICAgICB0aW1l ZF9vdXQgPSBzZWxmLl9zZXJ2ZXJfcHJvY2Vzcy50aW1lZF9vdXQKKyAgICAgICAgaWYgJ1RpbWVk IG91dCB3YWl0aW5nIGZvciBmaW5hbCBtZXNzYWdlIGZyb20gd2ViIHByb2Nlc3MnIGluIHRleHQ6 CisgICAgICAgICAgICBpZiBub3QgdGltZWRfb3V0OgorICAgICAgICAgICAgICAgIF9sb2cud2Fy bmluZygid2VicHJvY2VzcyB0aW1lZCBvdXQgYnV0IFdUUiBkaWRuJ3QsIGtpbGxpbmcgV1RSIikK KyAgICAgICAgICAgICAgICB0aW1lZF9vdXQgPSBUcnVlCisgICAgICAgICAgICBlbHNlOgorICAg ICAgICAgICAgICAgIF9sb2cud2FybmluZygid2VicHJvY2VzcyB0aW1lZCBvdXQgYW5kIHNvIGRp ZCBXVFIiKQogCiAgICAgICAgIGlmIHN0b3Bfd2hlbl9kb25lIG9yIGNyYXNoZWQgb3IgdGltZWRf b3V0OgogICAgICAgICAgICAgIyBXZSBjYWxsIHN0b3AoKSBldmVuIGlmIHdlIGNyYXNoZWQgb3Ig dGltZWQgb3V0IGluIG9yZGVyIHRvIGdldCBhbnkgcmVtYWluaW5nIHN0ZG91dC9zdGRlcnIgb3V0 cHV0Lgo=