668637 - "OSError: Could not kill process: ####" after running mutt/test_runnershutdown.js

Status: RESOLVED FIXED

(Testing Graveyard :: Mozmill, defect)

Description

[Heather Arthur [:harth]]

Running Mozmill 2.0 with 'mozmill -t mozmill/mutt/mutt/test/js/test_runnershutdown.js' will give this traceback after the summary printout:


TEST-PASS | mutt/mutt/tests/js/test_runnershutdown.js | testRunnerRestart
INFO | DEBUG: stop is calling kill
INFO | 
INFO | DEBUG: stop is calling kill
INFO | 
TEST-UNEXPECTED-FAIL | Disconnect Error: Application unexpectedly closed
INFO | Passed: 11
INFO | Failed: 19
INFO | Skipped: 2
ERROR | Traceback (most recent call last):
ERROR |   File "/Users/harth/repos/mozmill/mozmill/mozmill/__init__.py", line 647, in run
ERROR |     mozmill.run(*self.manifest.tests)
ERROR |   File "/Users/harth/repos/mozmill/mozmill/mozmill/__init__.py", line 379, in run
ERROR |     self.stop() # shutdown the test harness cleanly
ERROR |   File "/Users/harth/repos/mozmill/mozmill/mozmill/__init__.py", line 457, in stop
ERROR |     self.runner.cleanup()
ERROR |   File "/Users/harth/repos/mozmill/mozrunner/mozrunner/runner.py", line 259, in cleanup
ERROR |     self.stop()
ERROR |   File "/Users/harth/repos/mozmill/mozrunner/mozrunner/runner.py", line 249, in stop
ERROR |     self.process_handler.kill()
ERROR |   File "/Users/harth/repos/mozmill/mozprocess/mozprocess/processhandler.py", line 565, in kill
ERROR |     return self.proc.kill()
ERROR |   File "/Users/harth/repos/mozmill/mozprocess/mozprocess/processhandler.py", line 93, in kill
ERROR |     raise OSError("Could not kill process: %s" % self.pid)
ERROR | OSError: Could not kill process: 38237

Comment 1

[Jeff Hammel]

I'm wondering if this is an OSX only bug?  I haven't seen this locally and can't reproduce.  :(

Comment 2

[cmtalbert]

harth, is this mac only?

Comment 3

[Jeff Hammel]

So this is not mutt-only? does it happen with mutt and normally?

Is this consistent for you, :harth?

Comment 4

[cmtalbert]

Harth,

I'm not able to reproduce.  I'm seeing some python exceptions being thrown but those are due to the test working with shutdown I think.  I'm not seeing the problem you're experiencing.  Here's what I get:

(mozmill2.0)clint-talberts-macbook:mozmill clint$ mozmill -t mutt/mutt/tests/js/test_runnershutdown.js TEST-START | mutt/mutt/tests/js/test_runnershutdown.js | setupModule
TEST-START | mutt/mutt/tests/js/test_runnershutdown.js | testRunnerRestart
TEST-PASS | mutt/mutt/tests/js/test_runnershutdown.js | testRunnerRestart
INFO | error: uncaptured python exception, closing channel <jsbridge.network.BackChannel 127.0.0.1:24242 at 0x1d28878> (<class 'socket.error'>:[Errno 9] Bad file descriptor [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|readwrite|107] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|handle_expt_event|441] [<string>|getsockopt|1] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/socket.py|_dummy|165])
INFO | 
INFO | error: uncaptured python exception, closing channel <jsbridge.network.Bridge 127.0.0.1:24242 at 0x1d28af8> (<class 'socket.error'>:[Errno 9] Bad file descriptor [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|readwrite|107] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|handle_expt_event|441] [<string>|getsockopt|1] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/socket.py|_dummy|165])
INFO | 
TEST-START | mutt/mutt/tests/js/test_runnershutdown.js | setupModule
TEST-START | mutt/mutt/tests/js/test_runnershutdown.js | testFinal
TEST-PASS | mutt/mutt/tests/js/test_runnershutdown.js | testFinal
INFO | error: uncaptured python exception, closing channel <jsbridge.network.BackChannel 127.0.0.1:24242 at 0x1d22580> (<class 'socket.error'>:[Errno 9] Bad file descriptor [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|readwrite|107] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|handle_expt_event|441] [<string>|getsockopt|1] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/socket.py|_dummy|165])
INFO | 
INFO | error: uncaptured python exception, closing channel <jsbridge.network.Bridge 127.0.0.1:24242 at 0x1d22508> (<class 'socket.error'>:[Errno 9] Bad file descriptor [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|readwrite|107] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/asyncore.py|handle_expt_event|441] [<string>|getsockopt|1] [/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/socket.py|_dummy|165])
INFO | 
INFO | Passed: 2
INFO | Failed: 0
INFO | Skipped: 0

Close as WFM?

Comment 5

[Jeff Hammel]

Could you retest please harth?

Comment 6

[Heather Arthur [:harth]]

Unfortunately I can completely reproduce this with the current master.

Comment 7

[cmtalbert]

Attachment: This really shouldn't raise an error

This shouldn't raise an error.  We were asked to kill a process, the pid is not there when we attempt to kill it.  This happens on windows sometimes (and mac evidently) in that the process is running when we decide to kill it but by the time the kill code is called, the process has ended.  Instead of raising an error, we will simply print a notice to stderr, which is what mozprocess does for these sorts of "odd, but ok" errors.

Comment 8

[Jeff Hammel]

Comment on attachment 547874 [details] [diff] [review]
This really shouldn't raise an error

looks good!

Comment 9

[cmtalbert]

Landed: https://github.com/mozautomation/mozmill/commit/fdb4763fd45d897d8bc3979d8068eebfdbf96503