64886 2011-07-20 13:02:17 -0700 new-run-webkit-tests hung while acquiring http lock on snow leopard bots 2012-01-04 15:44:54 -0800 1 1 1 Unclassified WebKit Tools / Tests 528+ (Nightly build) Unspecified Unspecified RESOLVED FIXED P2 Normal --- 1 eric dpranke abarth abecsi dpranke kkristof ossy rgabor rniwa tony oldest_to_newest 439945 0 eric 2011-07-20 13:02:17 -0700 new-run-webkit-tests hung while acquiring http lock on snow leopard bots Example: http://build.webkit.org/builders/SnowLeopard%20Intel%20Release%20%28Tests%29/builds/31580/steps/layout-test/logs/stdio 2011-07-20 09:44:53,076 67417 printing.py:469 INFO Acquiring http lock ... 2011-07-20 09:44:53,100 67417 http_lock.py:123 DEBUG Creating lock file: /var/folders/g7/g7uo9NaMFTqOewnSEAm43U+++TI/-Tmp-/WebKitHttpd.lock.21 command timed out: 1200 seconds without output, killing pid 67415 process killed by signal 9 program finished with exit code -1 elapsedTime=1240.833448 I suspect that we're hanging in this while loop: def wait_for_httpd_lock(self): """Create a lock file and wait until it's turn comes. If something goes wrong it wont do any locking.""" if not self._create_lock_file(): _log.debug("Warning, http locking failed!") return while self._curent_lock_pid() != os.getpid(): time.sleep(1) It's unclear why we need to loop there, since we just wrote the file. :) Ossy wrote the code, so perhaps he has some idea what it's trying to do. At the least that while loop should exit after some timeout. 439952 1 eric 2011-07-20 13:10:36 -0700 I don't think our filelock code is correct. def acquire_lock(self): self._lock_file_descriptor = os.open(self._lock_file_path, os.O_TRUNC | os.O_CREAT) start_time = time.time() while True: try: self._create_lock() return True except IOError: if time.time() - start_time > self._max_wait_time_sec: _log.debug("File locking failed: %s" % str(sys.exc_info())) os.close(self._lock_file_descriptor) self._lock_file_descriptor = None return False Notice how we're calling os.open, with trunc/create *OUTSIDE* of any lock. I think we should be opening with "append" or some non-harmful mode, since it's very easy for two processes to try and grab the same lock, and blast away each other's lock just by opening the file, no? 439962 2 eric 2011-07-20 13:22:16 -0700 I'm not sure my diagnosis is correct. flock doesnt' write anything to the file as far as I can tell, so it shouldn't matter what mode we opened it with. 440045 3 rniwa 2011-07-20 15:02:13 -0700 Also causing problems on Chromium Linux: http://build.webkit.org/builders/Chromium%20Linux%20Release%20%28Tests%29/builds/21294 http://build.chromium.org/p/chromium.webkit/builders/Webkit%20Linux%2032/builds/3081 http://build.chromium.org/p/chromium.webkit/builders/Webkit%20Linux/builds/10834 440050 4 tony 2011-07-20 15:07:01 -0700 Looks like this might be causing a similar problem to the commit queue? http://webkit-commit-queue.appspot.com/results/9193426 440052 5 eric 2011-07-20 15:07:41 -0700 Nope, those are unrelated. They were caused by bug 64885. 453541 6 104435 dpranke 2011-08-18 18:53:52 -0700 Created attachment 104435 Patch 453542 7 104435 rniwa 2011-08-18 18:55:30 -0700 Comment on attachment 104435 Patch Thanks for doing this! 453543 8 104435 rniwa 2011-08-18 18:55:53 -0700 Comment on attachment 104435 Patch View in context: https://bugs.webkit.org/attachment.cgi?id=104435&action=review > Tools/ChangeLog:9 > + Nit: Missing Reviewed By here. 453544 9 104435 rniwa 2011-08-18 18:56:28 -0700 Comment on attachment 104435 Patch cq- because of the above nit. 453545 10 dpranke 2011-08-18 18:57:38 -0700 Okay, I"ve posted a patch that disables the file locking. In theory, what'll happen is that we'll kill the old http and websocket servers, and the new tests will run fine. Supposedly we're also seeing a lot of stale NRWT processes themselves; this patch will not fix that. However, in theory (again), those processes will be done doing whatever they were doing and be idle, so there shouldn't be too much downside. This isn't a real fix, we shouldn't close this bug, and we still need to figure out what's going on. Unfortunately, I can't even really test this patch at the moment because test-webkitpy is hanging on my machine in a rebaselining test, and someone apparently has broken all of the integration tests that I wrote for these functions (but which aren't tested by default on the bots, so I can't blame them too much). If someone can get me the buildbot logs for when these things are getting wedged, that would be helpful. 453546 11 dpranke 2011-08-18 18:58:16 -0700 (In reply to comment #8) > (From update of attachment 104435 [details]) > View in context: https://bugs.webkit.org/attachment.cgi?id=104435&action=review > > > Tools/ChangeLog:9 > > + > > Nit: Missing Reviewed By here. Interesting. The changelog was generated from webkit-patch upload ... I wonder what happened to the OOPS line? 453547 12 dpranke 2011-08-18 18:59:06 -0700 Committed r93383: <http://trac.webkit.org/changeset/93383> 453548 13 dpranke 2011-08-18 18:59:45 -0700 Okay, patch landed. Feel free to revert this if it causes other problems. 456464 14 dpranke 2011-08-24 15:25:11 -0700 I took a brief look at some of the buildbot logs from when a master restarts (I've attached a snippet from one such log). It looks like the buildbot slave is hard-killing the current command to abort it, and that means that we're probably not getting a chance to clean up the subprocesses we've spawned. Given that, I'm not sure that there's much we can do to shut down cleanly, which means we need to be able to clean up on startup. Chromium has a step that the bot runs (on Windows only) that kills stray processes. Maybe the thing to do is to take that, make it portable (if necessary), and introduce it here? 456470 15 105083 dpranke 2011-08-24 15:32:14 -0700 Created attachment 105083 snipped of twistd.log from apple-xserve-8 buildbot log showing a master restart 481854 16 eric 2011-10-11 13:17:58 -0700 I thought we disabled http locking on Mac? Can we close this? 481903 17 rniwa 2011-10-11 14:08:33 -0700 (In reply to comment #16) > I thought we disabled http locking on Mac? Can we close this? Yes, I think so. But it'll be nice if we could file another bug to deal with stable child process issue (i.e. only manager.py is killed) on bots. 525615 18 eric 2011-12-21 14:34:27 -0800 Attachment 104435 was posted by a committer and has review+, assigning to Dirk Pranke for commit. 529839 19 dpranke 2012-01-04 15:44:54 -0800 The patch was landed in r93383, so I'm clearing the flags. Also, we updated the kill-old-processes script to address the other concerns in r97341 (bug 63651) so I'm closing this as fixed. 104435 2011-08-18 18:53:52 -0700 2012-01-04 15:43:48 -0800 Patch bug-64886-20110818185351.patch text/plain 2036 dpranke U3VidmVyc2lvbiBSZXZpc2lvbjogOTMzODIKZGlmZiAtLWdpdCBhL1Rvb2xzL0NoYW5nZUxvZyBi L1Rvb2xzL0NoYW5nZUxvZwppbmRleCA2MWFhNTZiOThiYTEyZDQyODllZWRmOTM3MGJiNjc0NDc4 ZDJhNmFjLi41YzAzMjAyMmRlNjVmZTBlMmQ0ZGY2MjQ4ZGU2NWNiZDhmMGUyNzBjIDEwMDY0NAot LS0gYS9Ub29scy9DaGFuZ2VMb2cKKysrIGIvVG9vbHMvQ2hhbmdlTG9nCkBAIC0xLDMgKzEsMTQg QEAKKzIwMTEtMDgtMTggIERpcmsgUHJhbmtlICA8ZHByYW5rZUBjaHJvbWl1bS5vcmc+CisKKyAg ICAgICAgbmV3LXJ1bi13ZWJraXQtdGVzdHMgaHVuZyB3aGlsZSBhY3F1aXJpbmcgaHR0cCBsb2Nr IG9uIHNub3cgbGVvcGFyZCBib3RzCisgICAgICAgIGh0dHBzOi8vYnVncy53ZWJraXQub3JnL3No b3dfYnVnLmNnaT9pZD02NDg4NgorCisgICAgICAgIFRlbXBvcmFyaWx5IGRpc2FibGUgdGhlIGh0 dHAgbG9ja2luZyB0byB3b3JrIGFyb3VuZCB0aGUgaXNzdWUuCisgICAgICAgIEknbSBub3QgYWN0 dWFsbHkgc3VyZSBpZiB0aGlzIGlzIGdvaW5nIHRvIHdvcmsgb3IgaW1wcm92ZSB0aGluZ3MKKyAg ICAgICAgbXVjaC4KKworICAgICAgICAqIFNjcmlwdHMvd2Via2l0cHkvbGF5b3V0X3Rlc3RzL3Bv cnQvbWFjLnB5OgorCiAyMDExLTA4LTE4ICBUb255IENoYW5nICA8dG9ueUBjaHJvbWl1bS5vcmc+ CiAKICAgICAgICAgYWRkIGVtYmVkZGVkIHBuZyBjaGVja3N1bXMgdG8gV2ViS2l0VGVzdFJ1bm5l cgpkaWZmIC0tZ2l0IGEvVG9vbHMvU2NyaXB0cy93ZWJraXRweS9sYXlvdXRfdGVzdHMvcG9ydC9t YWMucHkgYi9Ub29scy9TY3JpcHRzL3dlYmtpdHB5L2xheW91dF90ZXN0cy9wb3J0L21hYy5weQpp bmRleCA4MzhlZDJlYjI2YTZiMTJhODc4ZjAyZTRkNWYwN2M3YWFmMDY1ODQ5Li5kMTUzNTM5NzBi YTAzZWQ3NjI1OTVjYzE3OTZiNmZhNWQ4YmNhNjU4IDEwMDY0NAotLS0gYS9Ub29scy9TY3JpcHRz L3dlYmtpdHB5L2xheW91dF90ZXN0cy9wb3J0L21hYy5weQorKysgYi9Ub29scy9TY3JpcHRzL3dl YmtpdHB5L2xheW91dF90ZXN0cy9wb3J0L21hYy5weQpAQCAtMTU1LDMgKzE1NSwyMCBAQCBjbGFz cyBNYWNQb3J0KEFwcGxlUG9ydCk6CiAKICAgICBkZWYgc2hvd19yZXN1bHRzX2h0bWxfZmlsZShz ZWxmLCByZXN1bHRzX2ZpbGVuYW1lKToKICAgICAgICAgc2VsZi5fcnVuX3NjcmlwdCgncnVuLXNh ZmFyaScsIFsnLU5TT3BlbicsIHJlc3VsdHNfZmlsZW5hbWVdKQorCisgICAgIyBGSVhNRTogVGhl IG5leHQgdHdvIHJvdXRpbmVzIHR1cm4gb2ZmIHRoZSBodHRwIGxvY2tpbmcgaW4gb3JkZXIKKyAg ICAjIHRvIHdvcmsgYXJvdW5kIGZhaWx1cmVzIG9uIHRoZSBib3RzIGNhdXNlZCB3aGVuIHRoZSBz bGF2ZSByZXN0YXJ0cy4KKyAgICAjIFNlZSBodHRwczovL2J1Z3Mud2Via2l0Lm9yZy9zaG93X2J1 Zy5jZ2k/aWQ9NjQ4ODYgZm9yIG1vcmUgaW5mby4KKyAgICAjIFRoZSBwcm9wZXIgZml4IGlzIHRv IG1ha2Ugc3VyZSB0aGUgc2xhdmUgaXMgYWN0dWFsbHkgc3RvcHBpbmcgTlJXVAorICAgICMgcHJv cGVybHkgb24gcmVzdGFydC4gTm90ZSB0aGF0IGJ5IHJlbW92aW5nIHRoZSBsb2NrIGZpbGUgYW5k IG5vdCB3YWl0aW5nLAorICAgICMgdGhlIHJlc3VsdCBzaG91bGQgYmUgdGhhdCBpZiB0aGVyZSBp cyBhIHdlYiBzZXJ2ZXIgYWxyZWFkeSBydW5uaW5nLAorICAgICMgaXQnbGwgYmUga2lsbGVkIGFu ZCB0aGlzIG9uZSB3aWxsIGJlIHN0YXJ0ZWQgaW4gaXRzIHBsYWNlOyB0aGlzCisgICAgIyBtYXkg bGVhZCB0byB3ZWlyZCB0aGluZ3MgaGFwcGVuaW5nIGluIHRoZSBvdGhlciBydW4uIEhvd2V2ZXIs IEkgZG9uJ3QKKyAgICAjIHRoaW5rIHdlJ3JlIChpbnRlbnRpb25hbGx5KSBhY3R1YWxseSBydW5u aW5nIG11bHRpcGxlIHJ1bnMgY29uY3VycmVudGx5CisgICAgIyBvbiBhbnkgTWFjIGJvdHMuCisK KyAgICBkZWYgYWNxdWlyZV9odHRwX2xvY2soc2VsZik6CisgICAgICAgIHBhc3MKKworICAgIGRl ZiByZWxlYXNlX2h0dHBfbG9jayhzZWxmKToKKyAgICAgICAgcGFzcwo= 105083 2011-08-24 15:32:14 -0700 2011-08-24 15:32:14 -0700 snipped of twistd.log from apple-xserve-8 buildbot log showing a master restart restart.log application/octet-stream 3578 dpranke MjAxMS0wOC0xNyAxMTo1MDoyMS0wNzAwIFtCcm9rZXIsY2xpZW50XSAgIGFyZ3Y6IFsncGVybCcs ICcuL1Rvb2xzL1NjcmlwdHMvcnVuLXdlYmtpdC10ZXN0cycsICctLW5vLWxhdW5jaC1zYWZhcmkn LCAnLS1uby1uZXctdGVzdC1yZXN1bHRzJywgJy0tbm8tc2FtcGxlLW9uLXRpbWVvdXQnLCAnLS1y ZXN1bHRzLWRpcmVjdG9yeScsICdsYXlvdXQtdGVzdC1yZXN1bHRzJywgJy0tdXNlLXJlbW90ZS1s aW5rcy10by10ZXN0cycsICctLWJ1aWxkZXItbmFtZScsICdTbm93TGVvcGFyZCBJbnRlbCBEZWJ1 ZyAoVGVzdHMpJywgJy0tYnVpbGQtbnVtYmVyJywgJzE3MjAnLCAnLS1tYXN0ZXItbmFtZScsICd3 ZWJraXQub3JnJywgJy0tdGVzdC1yZXN1bHRzLXNlcnZlcicsICd0ZXN0LXJlc3VsdHMuYXBwc3Bv dC5jb20nLCAnLS1kZWJ1ZycsICctLWV4aXQtYWZ0ZXItbi1jcmFzaGVzLW9yLXRpbWVvdXRzJywg JzIwJywgJy0tZXhpdC1hZnRlci1uLWZhaWx1cmVzJywgJzUwMCddCjIwMTEtMDgtMTcgMTE6NTA6 MjEtMDcwMCBbQnJva2VyLGNsaWVudF0gIGVudmlyb25tZW50OiB7J0FwcGxlX1B1YlN1Yl9Tb2Nr ZXRfUmVuZGVyJzogJy90bXAvbGF1bmNoLVV5Umtvdi9SZW5kZXInLCAnVkVSU0lPTkVSX1BZVEhP Tl9WRVJTSU9OJzogJzIuNicsICdfX0RvQXBwbGVJbnRlcm5hbExvZ2dpbmdfXyc6ICd0cnVlJywg J1ZFUlNJT05FUl9QWVRIT05fUFJFRkVSXzMyX0JJVCc6ICdubycsICdTU0hfQVVUSF9TT0NLJzog Jy90bXAvbGF1bmNoLW5vcEpJWi9MaXN0ZW5lcnMnLCAnX19DRl9VU0VSX1RFWFRfRU5DT0RJTkcn OiAnMHgxRjU6MDowJywgJ1BXRCc6ICcvVm9sdW1lcy9CaWcvc2xhdmUvc25vd2xlb3BhcmQtaW50 ZWwtZGVidWctdGVzdHMvYnVpbGQnLCAnU0hFTEwnOiAnL2Jpbi9iYXNoJywgJ0xPR05BTUUnOiAn YnVpbGRib3QnLCAnVVNFUic6ICdidWlsZGJvdCcsICdQQVRIJzogJy91c3IvYmluOi9iaW46L3Vz ci9zYmluOi9zYmluJywgJ0hPTUUnOiAnL1VzZXJzL2J1aWxkYm90JywgJ0RJU1BMQVknOiAnL3Rt cC9sYXVuY2gtd2hIQ21hL29yZy54OjAnLCAnVE1QRElSJzogJy92YXIvZm9sZGVycy9zSy9zS21p b0VGSEhYMDdqbzBOTmN0aWxVKysrVEkvLVRtcC0vJ30KMjAxMS0wOC0xNyAxMTo1MDoyMS0wNzAw IFtCcm9rZXIsY2xpZW50XSAgIGNsb3Npbmcgc3RkaW4KMjAxMS0wOC0xNyAxMTo1MDoyMS0wNzAw IFtCcm9rZXIsY2xpZW50XSAgIHVzaW5nIFBUWTogRmFsc2UKMjAxMS0wOC0xNyAxMTo1MTo1MS0w NzAwIFstXSBzZW5kaW5nIGFwcC1sZXZlbCBrZWVwYWxpdmUKMjAxMS0wOC0xNyAxMjowMDo0NS0w NzAwIFtCcm9rZXIsY2xpZW50XSBsb3N0IHJlbW90ZQoyMDExLTA4LTE3IDEyOjAwOjQ1LTA3MDAg W0Jyb2tlcixjbGllbnRdIGxvc3QgcmVtb3RlIHN0ZXAKMjAxMS0wOC0xNyAxMjowMDo0NS0wNzAw IFtCcm9rZXIsY2xpZW50XSBzdG9wQ29tbWFuZDogaGFsdGluZyBjdXJyZW50IGNvbW1hbmQgPGJ1 aWxkc2xhdmUuY29tbWFuZHMuc2hlbGwuU2xhdmVTaGVsbENvbW1hbmQgaW5zdGFuY2UgYXQgMHgx MDFhNzFmODA+CjIwMTEtMDgtMTcgMTI6MDA6NDUtMDcwMCBbQnJva2VyLGNsaWVudF0gY29tbWFu ZCBpbnRlcnJ1cHRlZCwga2lsbGluZyBwaWQgMzI0OTEKMjAxMS0wOC0xNyAxMjowMDo0NS0wNzAw IFtCcm9rZXIsY2xpZW50XSB0cnlpbmcgb3Mua2lsbCgtcGlkLCA5KQoyMDExLTA4LTE3IDEyOjAw OjQ1LTA3MDAgW0Jyb2tlcixjbGllbnRdIHRyeWluZyBwcm9jZXNzLnNpZ25hbFByb2Nlc3MoJ0tJ TEwnKQoyMDExLTA4LTE3IDEyOjAwOjQ1LTA3MDAgW0Jyb2tlcixjbGllbnRdICBzaWduYWwgS0lM TCBzZW50IHN1Y2Nlc3NmdWxseQoyMDExLTA4LTE3IDEyOjAwOjQ1LTA3MDAgW0Jyb2tlcixjbGll bnRdIExvc3QgY29ubmVjdGlvbiB0byBidWlsZC53ZWJraXQub3JnOjE3MDAwCjIwMTEtMDgtMTcg MTI6MDA6NDUtMDcwMCBbQnJva2VyLGNsaWVudF0gPHR3aXN0ZWQuaW50ZXJuZXQudGNwLkNvbm5l Y3RvciBpbnN0YW5jZSBhdCAweDEwMDZjM2RkMD4gd2lsbCByZXRyeSBpbiAyIHNlY29uZHMKMjAx MS0wOC0xNyAxMjowMDo0NS0wNzAwIFtCcm9rZXIsY2xpZW50XSBTdG9wcGluZyBmYWN0b3J5IDxi dWlsZHNsYXZlLmJvdC5Cb3RGYWN0b3J5IGluc3RhbmNlIGF0IDB4MTAxNGJmOGMwPgoyMDExLTA4 LTE3IDEyOjAwOjQ1LTA3MDAgWy1dIGNvbW1hbmQgZmluaXNoZWQgd2l0aCBzaWduYWwgOSwgZXhp dCBjb2RlIE5vbmUsIGVsYXBzZWRUaW1lOiA2MjQuMDQ2MDA4CjIwMTEtMDgtMTcgMTI6MDA6NDUt MDcwMCBbLV0gU2xhdmVCdWlsZGVyLmNvbW1hbmRDb21wbGV0ZSBOb25lCjIwMTEtMDgtMTcgMTI6 MDA6NDgtMDcwMCBbLV0gU3RhcnRpbmcgZmFjdG9yeSA8YnVpbGRzbGF2ZS5ib3QuQm90RmFjdG9y eSBpbnN0YW5jZSBhdCAweDEwMTRiZjhjMD4KMjAxMS0wOC0xNyAxMjowMDo0OC0wNzAwIFstXSBD b25uZWN0aW5nIHRvIGJ1aWxkLndlYmtpdC5vcmc6MTcwMDAKMjAxMS0wOC0xNyAxMjowMToxMy0w NzAwIFtCcm9rZXIsY2xpZW50XSBtZXNzYWdlIGZyb20gbWFzdGVyOiBhdHRhY2hlZAoyMDExLTA4 LTE3IDEyOjAxOjM4LTA3MDAgW0Jyb2tlcixjbGllbnRdIFNsYXZlQnVpbGRlci5yZW1vdGVfcHJp bnQoU25vd0xlb3BhcmQgSW50ZWwgRGVidWcgKFRlc3RzKSk6IG1lc3NhZ2UgZnJvbSBtYXN0ZXI6 IGF0dGFjaGVkCjIwMTEtMDgtMTcgMTI6MDE6MzgtMDcwMCBbQnJva2VyLGNsaWVudF0gQ29ubmVj dGVkIHRvIGJ1aWxkLndlYmtpdC5vcmc6MTcwMDA7IHNsYXZlIGlzIHJlYWR5CjIwMTEtMDgtMTcg MTI6MDE6MzgtMDcwMCBbQnJva2VyLGNsaWVudF0gc2VuZGluZyBhcHBsaWNhdGlvbi1sZXZlbCBr ZWVwYWxpdmVzIGV2ZXJ5IDYwMCBzZWNvbmRzCjIwMTEtMDgtMTcgMTI6MDE6NDAtMDcwMCBbQnJv a2VyLGNsaWVudF0gU2xhdmVCdWlsZGVyLnJlbW90ZV9wcmludChTbm93TGVvcGFyZCBJbnRlbCBE ZWJ1ZyAoVGVzdHMpKTogbWVzc2FnZSBmcm9tIG1hc3RlcjogcGluZwoyMDExLTA4LTE3IDEyOjAx OjQwLTA3MDAgW0Jyb2tlcixjbGllbnRdICBzdGFydENvbW1hbmQ6c3ZuIFtpZCA0XQoyMDExLTA4 LTE3IDEyOjAxOjQwLTA3MDAgW0Jyb2tlcixjbGllbnRdIFJ1blByb2Nlc3MuX3N0YXJ0Q29tbWFu ZAoyMDExLTA4LTE3IDEyOjAxOjQwLTA3MDAgW0Jyb2tlcixjbGllbnRdICAvdXNyL2Jpbi9zdm4g dXBkYXRlIC0tbm9uLWludGVyYWN0aXZlIC0tbm8tYXV0aC1jYWNoZSAtLXJldmlzaW9uIDkzMjE5 CjIwMTEtMDgtMTcgMTI6MDE6NDAtMDcwMCBbQnJva2VyLGNsaWVudF0gICBpbiBkaXIgL1ZvbHVt ZXMvQmlnL3NsYXZlL3Nub3dsZW9wYXJkLWludGVsLWRlYnVnLXRlc3RzL2J1aWxkICh0aW1lb3V0 IDEyMDAgc2VjcykKMjAxMS0wOC0xNyAxMjowMTo0MC0wNzAwIFtCcm9rZXIsY2xpZW50XSAgIHdh dGNoaW5nIGxvZ2ZpbGVzIHt9CjIwMTEtMDgtMTcgMTI6MDE6NDAtMDcwMCBbQnJva2VyLGNsaWVu dF0gICBhcmd2OiBbJy91c3IvYmluL3N2bicsICd1cGRhdGUnLCAnLS1ub24taW50ZXJhY3RpdmUn LCAnLS1uby1hdXRoLWNhY2hlJywgJy0tcmV2aXNpb24nLCAnOTMyMTknXQo=