95243 2012-08-28 14:10:27 -0700 webkit-patch rebaseline-expectations hangs 2012-08-29 15:23:04 -0700 1 1 1 Unclassified WebKit Tools / Tests 528+ (Nightly build) Unspecified Unspecified RESOLVED FIXED P2 Normal --- 1 jchaffraix dpranke abarth dpranke ojan pdr robert webkit.review.bot oldest_to_newest 706718 0 jchaffraix 2012-08-28 14:10:27 -0700 Here is a trace of webkit-patch --verbose rebaseline-expectations run inside the LayoutTests/ subdirectory when it hang: webkitpy.common.system.autoinstall: [DEBUG] URL for mechanize already downloaded. Skipping... webkitpy.common.system.autoinstall: [DEBUG] "http://pypi.python.org/packages/source/m/mechanize/mechanize-0.2.5.tar.gz" webkitpy.common.system.executive: [DEBUG] "svn info" took 0.07s webkitpy.common.system.executive: [DEBUG] "svn info" took 0.06s webkitpy.common.system.executive: [DEBUG] "svn info" took 0.06s webkitpy.common.system.executive: [DEBUG] "svn info" took 0.07s webkitpy.common.system.executive: [DEBUG] "perl Tools/Scripts/webkit-build-directory --chromium-linux" took 0.08s webkitpy.common.find_files: [DEBUG] Test gathering took 0.017516 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.025551 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000436 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000176 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.010846 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.025721 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000427 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000175 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.010764 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.025546 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000514 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000176 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.010848 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.025513 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000683 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000278 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.010931 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.025781 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000428 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000177 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.010792 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.025706 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000423 seconds webkitpy.common.find_files: [DEBUG] Test gathering took 0.000177 seconds webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/efl/Skipped webkitpy.layout_tests.port.base: [DEBUG] Skipped does not exist: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/gtk/Skipped webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/mac/Skipped webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/mac-lion/Skipped webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/mac/Skipped webkitpy.common.system.executive: [DEBUG] "qmake -v" took 0.02s webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/qt-4.8/Skipped webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/qt-linux/Skipped webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/qt/Skipped webkitpy.layout_tests.port.base: [DEBUG] Using Skipped file: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/win/Skipped webkitpy.layout_tests.port.base: [DEBUG] Skipped does not exist: /usr/local/google/Projects/Gardening/WebKit/LayoutTests/platform/win-7sp0/Skipped ps reports the following: 139751 32266 3.1 0.7 169804 89668 pts/6 Sl+ 14:01 0:04 python /home/jchaffraix/Projects//Gardening/WebKit/Tools/Scripts/webkit-patch -v rebaseline-expectations I don't know what the triggers is as it happens randomly after several rebaselinings. Once it started, it is happening consistently and the only I found around that is blowing off the entire repository :( 706727 1 jchaffraix 2012-08-28 14:21:05 -0700 Let's forget about SVN, I got it to happen on a GIT checkout too. Same trace, different repository. 706880 2 jchaffraix 2012-08-28 16:49:46 -0700 After more debugging, here is the reason why we are hanging up: * AbstractParallelRebaselineCommand's _rebaseline is called with an empty test_list ({}) * Because we have no test, we call Executive's run_in_parallel without any command to run. * We then call join() we wait forever as there is nothing to wait for. Now, what I don't understand is how we get no test to rebaseline when there are entries that match. 706883 3 ojan 2012-08-28 16:53:41 -0700 rebasline-expectations just delegates to rebaseline-json. Can you print out the rebaseline-json command that's used? 706926 4 dpranke 2012-08-28 17:44:08 -0700 perhaps we're not able to retrieve the results from the bots? I've actually seen this happen a few times in the past hour or two as well. As an aside, we also don't check the return values from the commands and don't notice if they fail :(. 706930 5 dpranke 2012-08-28 17:47:17 -0700 Fixing this is simple but it would be nice if we could see the rebaseline-json command first to confirm that there isn't also another bug cropping up. 707448 6 jchaffraix 2012-08-29 07:52:28 -0700 (In reply to comment #5) > Fixing this is simple but it would be nice if we could see the rebaseline-json command first to confirm that there isn't also another bug cropping up. Any pointer as to how to dump this command? I tried to understand how rebaseline-expectations goes through rebaseline-json but couldn't so it's hard to know where to do the dump. 707546 7 dpranke 2012-08-29 09:51:26 -0700 Sorry, Ojan's comment was wrong and threw me off. rebaseline-expectations delegates to rebaseline-test-internal, not rebaseline-json. It would be interesting to see if we're making it to the call in _rebaseline (on line 302), and we could wrap those lines in some _log.debug() calls. That said, it sounds like maybe your hang is different than mine (and the trace looks different than I would've expected as well), which is why it would be interesting to dig a little further ... 707636 8 jchaffraix 2012-08-29 10:53:35 -0700 > It would be interesting to see if we're making it to the call in _rebaseline (on line 302), and we could wrap those lines in some _log.debug() calls. Mmh, I posted a kinda stacktrace in comment #2 which confirms that _rebaseline (line 300) is indeed called. The issue is that |test_list| is empty when we do and that leads webkit-patch to hang on line 302: command_results = self._tool.executive.run_in_parallel(commands) > That said, it sounds like maybe your hang is different than mine (and the trace looks different than I would've expected as well), which is why it would be interesting to dig a little further ... Let me digg further as it is preventing me from doing any meaningful rebaselining. 707676 9 dpranke 2012-08-29 11:21:00 -0700 (In reply to comment #8) > > It would be interesting to see if we're making it to the call in _rebaseline (on line 302), and we could wrap those lines in some _log.debug() calls. > > Mmh, I posted a kinda stacktrace in comment #2 which confirms that _rebaseline (line 300) is indeed called. The issue is that |test_list| is empty when we do and that leads webkit-patch to hang on line 302: > > command_results = self._tool.executive.run_in_parallel(commands) > Right, I saw that, and it's definitely a bug. I'll post a patch for it shortly. That said, the trace in the bug description looks different than what I would expect ... > > That said, it sounds like maybe your hang is different than mine (and the trace looks different than I would've expected as well), which is why it would be interesting to dig a little further ... > > Let me digg further as it is preventing me from doing any meaningful rebaselining. I assume you've worked around this for now? Definitely let me know if you're blocked on something. 707751 10 jchaffraix 2012-08-29 12:43:07 -0700 > I assume you've worked around this for now? Definitely let me know if you're blocked on something. I haven't found a real work-around apart from forcefully blowing off the source tree which is slow and annoying. Debugging further it looks like TestExpectationModel doesn't contain any REBASELINE test (self._modifier_to_tests[MODIFIERS.REBASELINE] is empty) when this happens even if Chromium's TestExpectation was changed. 707927 11 161328 dpranke 2012-08-29 15:15:51 -0700 Created attachment 161328 Patch 707929 12 161328 tony 2012-08-29 15:18:19 -0700 Comment on attachment 161328 Patch OK 707934 13 dpranke 2012-08-29 15:23:04 -0700 Committed r127057: <http://trac.webkit.org/changeset/127057> 161328 2012-08-29 15:15:51 -0700 2012-08-29 15:18:18 -0700 Patch bug-95243-20120829151540.patch text/plain 3894 dpranke U3VidmVyc2lvbiBSZXZpc2lvbjogMTI3MDI0CmRpZmYgLS1naXQgYS9Ub29scy9DaGFuZ2VMb2cg Yi9Ub29scy9DaGFuZ2VMb2cKaW5kZXggZDc4NjNlMjA2OGIxMzRlMzRhMTJjNzE5N2Q4ZTRmNDJl MmY0MTMzNi4uZjYzZGYzOWViYTNjYzA5MzI5YTYyOWM4NGM0ODc1OWY4YmJlOGE5NiAxMDA2NDQK LS0tIGEvVG9vbHMvQ2hhbmdlTG9nCisrKyBiL1Rvb2xzL0NoYW5nZUxvZwpAQCAtMSwzICsxLDIx IEBACisyMDEyLTA4LTI5ICBEaXJrIFByYW5rZSAgPGRwcmFua2VAY2hyb21pdW0ub3JnPgorCisg ICAgICAgIHdlYmtpdC1wYXRjaCByZWJhc2VsaW5lLWV4cGVjdGF0aW9ucyBoYW5ncworICAgICAg ICBodHRwczovL2J1Z3Mud2Via2l0Lm9yZy9zaG93X2J1Zy5jZ2k/aWQ9OTUyNDMKKworICAgICAg ICBSZXZpZXdlZCBieSBOT0JPRFkgKE9PUFMhKS4KKworICAgICAgICBEb24ndCB0cnkgdG8gcnVu IG5vIGNvbW1hbmRzIGluIHBhcmFsbGVsOyByZXBvcnQgYW4gZXJyb3IKKyAgICAgICAgaW5zdGVh ZCB0aGF0IHdlIGRpZG4ndCBmaW5kIGFueSB0ZXN0cyB0byByZWJhc2VsaW5lLgorCisgICAgICAg IEZpbGVkIGJ1ZyA5NTM4NyBhcyB3ZWxsIHRvIG1ha2Ugc3VyZSBydW5faW5fcGFyYWxsZWwoKSBk b2Vzbid0IGhhbmcgZm9yZXZlci4KKworICAgICAgICAqIFNjcmlwdHMvd2Via2l0cHkvdG9vbC9j b21tYW5kcy9yZWJhc2VsaW5lLnB5OgorICAgICAgICAoUmViYXNlbGluZUV4cGVjdGF0aW9ucy5l eGVjdXRlKToKKyAgICAgICAgKiBTY3JpcHRzL3dlYmtpdHB5L3Rvb2wvY29tbWFuZHMvcmViYXNl bGluZV91bml0dGVzdC5weToKKyAgICAgICAgKF9hc3NlcnRfY29tbWFuZCk6CisgICAgICAgICh0 ZXN0X3JlYmFzZWxpbmVfZXhwZWN0YXRpb25zX25vb3ApOgorCiAyMDEyLTA4LTI5ICBLYW1pbCBC bGFuayAgPGsuYmxhbmtAc2Ftc3VuZy5jb20+CiAKICAgICAgICAgW0VGTF0gQWRkIHNldHRpbmcg QVBJIGZvciBhbGxvdyB1bml2ZXJzYWwvZmlsZSBhY2Nlc3MgZnJvbSBmaWxlIFVSTHMuCmRpZmYg LS1naXQgYS9Ub29scy9TY3JpcHRzL3dlYmtpdHB5L3Rvb2wvY29tbWFuZHMvcmViYXNlbGluZS5w eSBiL1Rvb2xzL1NjcmlwdHMvd2Via2l0cHkvdG9vbC9jb21tYW5kcy9yZWJhc2VsaW5lLnB5Cmlu ZGV4IDYzZGUzMjNkMTNlMjMwMzAzMGZjYjYzMmQ1ZGNmMzc3YWI1ZmUwNTMuLmU0OGQ1OWIxZTAw MWY5ZGMwNTI3NTZkNDBiZDZjZWUxYTM4MTQyZDEgMTAwNjQ0Ci0tLSBhL1Rvb2xzL1NjcmlwdHMv d2Via2l0cHkvdG9vbC9jb21tYW5kcy9yZWJhc2VsaW5lLnB5CisrKyBiL1Rvb2xzL1NjcmlwdHMv d2Via2l0cHkvdG9vbC9jb21tYW5kcy9yZWJhc2VsaW5lLnB5CkBAIC0zNTUsNiArMzU1LDEwIEBA IGNsYXNzIFJlYmFzZWxpbmVFeHBlY3RhdGlvbnMoQWJzdHJhY3RQYXJhbGxlbFJlYmFzZWxpbmVD b21tYW5kKToKICAgICAgICAgc2VsZi5fdGVzdF9saXN0ID0ge30KICAgICAgICAgZm9yIHBvcnRf bmFtZSBpbiB0b29sLnBvcnRfZmFjdG9yeS5hbGxfcG9ydF9uYW1lcygpOgogICAgICAgICAgICAg c2VsZi5fYWRkX3Rlc3RzX3RvX3JlYmFzZWxpbmVfZm9yX3BvcnQocG9ydF9uYW1lKQorICAgICAg ICBpZiBub3Qgc2VsZi5fdGVzdF9saXN0OgorICAgICAgICAgICAgX2xvZy53YXJuaW5nKCJEaWQg bm90IGZpbmQgYW55IHRlc3RzIG1hcmtlZCBSRUJBU0VMSU5FLiIpCisgICAgICAgICAgICByZXR1 cm4KKwogICAgICAgICBzZWxmLl9yZWJhc2VsaW5lKG9wdGlvbnMsIHNlbGYuX3Rlc3RfbGlzdCkK IAogICAgICAgICBmb3IgcG9ydF9uYW1lIGluIHRvb2wucG9ydF9mYWN0b3J5LmFsbF9wb3J0X25h bWVzKCk6CmRpZmYgLS1naXQgYS9Ub29scy9TY3JpcHRzL3dlYmtpdHB5L3Rvb2wvY29tbWFuZHMv cmViYXNlbGluZV91bml0dGVzdC5weSBiL1Rvb2xzL1NjcmlwdHMvd2Via2l0cHkvdG9vbC9jb21t YW5kcy9yZWJhc2VsaW5lX3VuaXR0ZXN0LnB5CmluZGV4IGNlYTZlMmU5OWIwZTM4NGFlM2Q5MjQw MTgzMzhjZTRkODU1NDExNDQuLjk3ZGYyNGM0Mzk0NGVlMmM2YWYxYTI4MTc1N2NiZmFkMWJhMmVl ZDUgMTAwNjQ0Ci0tLSBhL1Rvb2xzL1NjcmlwdHMvd2Via2l0cHkvdG9vbC9jb21tYW5kcy9yZWJh c2VsaW5lX3VuaXR0ZXN0LnB5CisrKyBiL1Rvb2xzL1NjcmlwdHMvd2Via2l0cHkvdG9vbC9jb21t YW5kcy9yZWJhc2VsaW5lX3VuaXR0ZXN0LnB5CkBAIC0zMTIsNiArMzEyLDI3IEBAIE1PQ0sgcnVu X2NvbW1hbmQ6IFsncW1ha2UnLCAnLXYnXSwgY3dkPU5vbmUKICAgICAgICAgY29tbWFuZC5fdGVz dHNfdG9fcmViYXNlbGluZSA9IGxhbWJkYSBwb3J0OiB7J3VzZXJzY3JpcHRzL2Fub3RoZXItdGVz dC5odG1sJzogc2V0KFsndHh0J10pLCAndXNlcnNjcmlwdHMvaW1hZ2VzLnN2Zyc6IHNldChbJ3Bu ZyddKX0KICAgICAgICAgT3V0cHV0Q2FwdHVyZSgpLmFzc2VydF9vdXRwdXRzKHNlbGYsIGNvbW1h bmQuZXhlY3V0ZSwgW01vY2tPcHRpb25zKG9wdGltaXplPVRydWUpLCBbXSwgdG9vbF0sIGV4cGVj dGVkX2xvZ3M9ZXhwZWN0ZWRfbG9ncywgZXhwZWN0ZWRfc3Rkb3V0PWV4cGVjdGVkX3N0ZG91dCwg ZXhwZWN0ZWRfc3RkZXJyPWV4cGVjdGVkX3N0ZGVycl93aXRoX29wdGltaXplKQogCisgICAgZGVm IF9hc3NlcnRfY29tbWFuZChzZWxmLCBjb21tYW5kLCBvcHRpb25zPU5vbmUsIGFyZ3M9Tm9uZSwg ZXhwZWN0ZWRfc3Rkb3V0PScnLCBleHBlY3RlZF9zdGRlcnI9JycsIGV4cGVjdGVkX2xvZ3M9Jycp OgorICAgICAgICAjIEZJWE1FOiBnZW5lcmFsaXplIHNvIG1vcmUgdGVzdHMgdXNlIHRoaXMgdG8g Z2V0IHJpZCBvZiBib2lsZXJwbGF0ZS4KKyAgICAgICAgb3B0aW9ucyA9IG9wdGlvbnMgb3IgTW9j a09wdGlvbnMob3B0aW1pemU9VHJ1ZSwgYnVpbGRlcnM9Tm9uZSwgc3VmZml4ZXM9Wyd0eHQnXSwg dmVyYm9zZT1GYWxzZSkKKyAgICAgICAgYXJncyA9IGFyZ3Mgb3IgW10KKworICAgICAgICB0b29s ID0gTW9ja1Rvb2woKQorICAgICAgICBjb21tYW5kLmJpbmRfdG9fdG9vbCh0b29sKQorCisgICAg ICAgIHBvcnQgPSB0b29sLnBvcnRfZmFjdG9yeS5nZXQoJ2Nocm9taXVtLW1hYy1saW9uJykKKyAg ICAgICAgdG9vbC5maWxlc3lzdGVtLndyaXRlX3RleHRfZmlsZShwb3J0LnBhdGhfZnJvbV9jaHJv bWl1bV9iYXNlKCdza2lhJywgJ3NraWFfdGVzdF9leHBlY3RhdGlvbnMudHh0JyksICcnKQorCisg ICAgICAgIGZvciBwb3J0X25hbWUgaW4gdG9vbC5wb3J0X2ZhY3RvcnkuYWxsX3BvcnRfbmFtZXMo KToKKyAgICAgICAgICAgIHBvcnQgPSB0b29sLnBvcnRfZmFjdG9yeS5nZXQocG9ydF9uYW1lKQor ICAgICAgICAgICAgZm9yIHBhdGggaW4gcG9ydC5leHBlY3RhdGlvbnNfZmlsZXMoKToKKyAgICAg ICAgICAgICAgICB0b29sLmZpbGVzeXN0ZW0ud3JpdGVfdGV4dF9maWxlKHBhdGgsICcnKQorCisg ICAgICAgIE91dHB1dENhcHR1cmUoKS5hc3NlcnRfb3V0cHV0cyhzZWxmLCBjb21tYW5kLmV4ZWN1 dGUsIFtvcHRpb25zLCBhcmdzLCB0b29sXSwgZXhwZWN0ZWRfc3Rkb3V0PWV4cGVjdGVkX3N0ZG91 dCwgZXhwZWN0ZWRfc3RkZXJyPWV4cGVjdGVkX3N0ZGVyciwgZXhwZWN0ZWRfbG9ncz1leHBlY3Rl ZF9sb2dzKQorCisgICAgZGVmIHRlc3RfcmViYXNlbGluZV9leHBlY3RhdGlvbnNfbm9vcChzZWxm KToKKyAgICAgICAgc2VsZi5fYXNzZXJ0X2NvbW1hbmQoUmViYXNlbGluZUV4cGVjdGF0aW9ucygp LCBleHBlY3RlZF9sb2dzPSdkaWQgbm90IGZpbmQgYW55IHRlc3RzIG1hcmtlZCBSRUJBU0VMSU5F XG4nKQorCiAgICAgZGVmIHRlc3Rfb3ZlcnJpZGVzX2FyZV9pbmNsdWRlZF9jb3JyZWN0bHkoc2Vs Zik6CiAgICAgICAgIGNvbW1hbmQgPSBSZWJhc2VsaW5lRXhwZWN0YXRpb25zKCkKICAgICAgICAg dG9vbCA9IE1vY2tUb29sKCkK