604648 - [exit][report] Quitting the browser during a test-run will mark all remaining tests as failed

Status: RESOLVED WORKSFORME

(Testing Graveyard :: Mozmill, defect)

Description

[Henrik Skupin [:whimboo][⌚️UTC+1]]

When you close the browser while a test-run is executed, the test itself and all remaining tests are marked as failed. This is kinda bad for our results tracking on the dashboard.

We really shouldn't try to execute the remaining tests. Only the results which have been added so far have to be part of the test results. Otherwise we will get too much negative results.

I'm sure that was working before. At least in 1.4.1. Marking as regression.

Comment 1

[cmtalbert]

(In reply to comment #0)
> When you close the browser while a test-run is executed, the test itself and
> all remaining tests are marked as failed. This is kinda bad for our results
> tracking on the dashboard.
> 
> We really shouldn't try to execute the remaining tests. Only the results which
> have been added so far have to be part of the test results. Otherwise we will
> get too much negative results.
> 
> I'm sure that was working before. At least in 1.4.1. Marking as regression.
Nothing has changed that would affect this. I don't see this happening when I kill mozmill half way through a run -- the log I get just has the state up to that point.  If something changed, it might be in the reporting or in the tests.  But honestly, I'd rather have all tests accounted for on each run so that you know the state of those tests.  By way of comparison, for mochitest, if the browser crashes then the remaining tests do not get run and those tests simply disappear from any accounting.  I'd much rather count them all as failed or as not run so that we can determine the true impact of a crash.  It's much better to test pessimistically than optimistically, in my opinion.

Comment 2

[Henrik Skupin [:whimboo][⌚️UTC+1]]

How do you kill Mozmill? On the command line with Ctrl+C? That's not what my initial comment states. You will have to close the browser during a test-run executes.

Something which will be ok is to mark those tests as skipped but please don't report them as failed. Given that we want to use this version of Mozmill with the crowd extension, there is a highly chance that people will cancel a test-run by closing the browser. Uploading or simply showing all those failed tests is IMO clearly wrong.

It's nothing which will block the first beta release of Mozmill 1.5.1 but I really would like to see it fixed for the final version.

Comment 3

[u279076]

I agree with Henrik on this one.  In fact, I'd go one step further to say that the only time a report should contain a failure is when Mozmill throws a failure.

Comment 4

[cmtalbert]

I have serious misgivings about futzing with this behavior but I'll take a look tonight.

Comment 5

[Henrik Skupin [:whimboo][⌚️UTC+1]]

I have some more information. As you can see in the following report the failures only happen in setupModule/teardownModule. The test itself is marked as skipped.

http://mozmill.hskupin.info/#/general/report/e8011cfc0a35c553e11c36b6d20002f4

Comment 6

[cmtalbert]

(In reply to comment #5)
> I have some more information. As you can see in the following report the
> failures only happen in setupModule/teardownModule. The test itself is marked
> as skipped.
> 
> http://mozmill.hskupin.info/#/general/report/e8011cfc0a35c553e11c36b6d20002f4
Yes, that's what I was seeing.  That's why I don't understand what the problem is.  This is the way that Mozmill has worked since we instituted setup/teardown stuff.  We added the ability to detect an unexpected shutdown in 1.5.0, which causes the currently executing test at the time of shutdown to fail.  I think that is the correct behavior.  We cannot know if the user shut us down or if the test did something wrong or if the browser crashed.  Therefore, we have to mark the currently executing test as failing unless the test told us it was shutting down the application.

So, if a setupModule fails, the test is skipped.  This is proper behavior.  You do not want a test executing if it did not pass its setupModule because then the test will execute with an incorrect state.

So, tests are skipped.  It sounds to me what you really want is a new feature that reports on Test-files rather than test-checks.

I think what you are asking for is something like this:
* Test Number1 - PASS (setupModule: pass, testFoo: pass, teardownModule: pass)
* Test Number2 - PASS 
* Test Number3 - FAIL (pretend the browser was shut down here)
* Test Number4 - SKIP (setupModule: fail, testFoo: skip, teardownModule:fail)

If that's what you want, that's going to involve major surgery to Mozmill's idea of a test. Right now, every function in a test file is a "test".  Some of those functions have special implications, like "setupModule" and "teardownModule".  But, they all report back to the python side using the same "startTest" and "endTest" listener.

If I were to capture the endTest event and find that setupModule failed, I could change it's flag to "skip", but what if setupModule *really* failed?  I don't see any way to determine that the reason setupModule failed is due to the unexpected shutdown versus a normal test failure.  They look the same to the python code.

And I'd rather save re-working our test listeners for 2.0.  It's too big and too scary for a dot-release (and it will likely break existing tests).

The only thing we might be able to do is munge the test status arrays in report_disconnect so that skips are accounted for this way.  However, that has the side-effect that *any legitimate failures* in setupModules/teardownModules will be lost and will not be reported upon the following scenarios: application crash, test abort, or user closing the application during the run.  I really don't think this is a good idea.  There is no good way for Mozmill to know why the application under test closed at this point.  If we solve this for users closing the browser, then we lose the ability to properly mark tests failed upon crash.  

I'm continuing to look at this, but most of the ways I see to fix this are fairly invasive.

Comment 7

[cmtalbert]

Attachment: What this looks like in the log file

Here's what this looks like in the log file, which is pretty readable and clear. (Maybe I've been reading these things for too long) :)

Comment 8

[cmtalbert]

The best way to solve this is to put in a new event called "beginning testfile" which fires upon test file load, and "ending testfile" which is called after all functions in the test are finished.  Then we could construct objects that are more like:
Test FOO.js[
  testfunc1: <unreadable JSON here>
  testfunc2: <more unreadable JSON>
  testfunc3: <that's right, I LOVE unreadable JSON>
]
Test BAR.js[
   same stuff...
]
Then we could pull the results together in a more sane way (maybe even doing something about unreadable JSON), but we'd still be left with trying to ascertain between a legitimate setupModule failure and a "user executed application failure" to mark a test as skipped or not. Hmmm...

However, I do like the idea of adding these extra listeners - I think they could be quite useful, but that's not something I'm comfortable taking in 1.5.1.

Comment 9

[cmtalbert]

The other issue here is that the JS code is in a race against time the minute that "close" button gets clicked.  We only get info out that we can get out.  So more processing on that side is going to be difficult unless we put something in an "XPCOM Shutdown" listener which would be called on normal shutdown.  But that'd also be called on a normal test shutdown, and if the test accidentally ended the application without crashing it, then that listener would still be called. So we could have about 60% confidence in using that trick to distinguish between accidental shutdowns and real crashes.

Can this be more easily solved by post-processing the results?

Ok, I'll keep on looking and quit spamming you all with my random thoughts on this bug.

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+1]]

It's not something we can do with post-processing because we don't have any information anymore about the running application process. This has really to happen during the test-run. We see failed results and that's it. We can't tell if those are real failures, user aborts, or whatever else.

IMO jsbridge knows about the connection at any time during the test-run. Before a test gets started the connection should be checked and if a disconnect happened, it may be a crash or a user abort, the upcoming tests in a normal test-run shouldn't be executed. To indicate that in the results we should add the same "disconnect" exception as what we have when the browser hangs and stop the test-run. I don't see a reason why we should behave differently here compared to the global timeout.

Comment 11

[cmtalbert]

Henrik and I did some debugging on this today and all the options are bad ones.  We're gonna need to take some time to fix this and as such we decided that this is going to have to wait for the 1.5.2 train.  Changing whiteboard to indicate that.

The basic issue here is that in 1.5.0 we now detect when the application under test unexpectedly shuts down.  When this happens the mozmill code marks a failure for all the setupModule/teardown module steps of all remaining tests and marks all remaining tests as "SKIPPED".  If a test is skipped, then it's setup/teardown modules ought to logically be considered skipped too.  But there is no way to change this without tinkering around with what Mozmill considers a "test".  And that is not something we want to do days before a release.

This is something we want to do for 2.0, so I recommend fixing this correctly on the 2.0 branch.  And then backporting the smallest bit of that work as possible to the 1.5.2 branch.  It may well be that we backport the idea and spirit and we can't reuse any of the code, but I think that solving the problem properly on 2.0 will give us a lot of insight into how we want to address this in 1.5.2.

Comment 12

[Heather Arthur [:harth]]

This is no longer an issue on 1.5.2 (on all platforms), Instead, when the user closes the browser, an "Application unexpectedly quit" error is reported and no other results are reported.

Comment 13

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Checked all the check-ins for 1.5.2 and it has been fixed as a side-effect on bug 585106.

Comment 14

[Henrik Skupin [:whimboo][⌚️UTC+1]]

I still see this problem on master. Jeff, has something from bug 585106 not made it to 2.0, or could this be a fallout from another bigger refactoring?

Closing the browser on OS X with Cmd+Q while tests are run prints all tests as failed to the console and then end with an exception:

Traceback (most recent call last):
  File "/Volumes/data/testing/envs/mozmill-2/bin/mozmill", line 8, in <module>
    load_entry_point('mozmill==2.0a', 'console_scripts', 'mozmill')()
  File "/Volumes/data/build/tools/mozmill-2.0/mozmill/mozmill/__init__.py", line 637, in cli
    CLI(args).run()
  File "/Volumes/data/build/tools/mozmill-2.0/mozmill/mozmill/__init__.py", line 609, in run
    self.run_tests(MozMill, normal_tests, runner, results)
  File "/Volumes/data/build/tools/mozmill-2.0/mozmill/mozmill/__init__.py", line 579, in run_tests
    mozmill.run(tests)
  File "/Volumes/data/build/tools/mozmill-2.0/mozmill/mozmill/__init__.py", line 263, in run
    self.run_tests(tests)
  File "/Volumes/data/build/tools/mozmill-2.0/mozmill/mozmill/__init__.py", line 252, in run_tests
    frame.runTestDirectory(test)
  File "/Volumes/data/build/tools/mozmill-2.0/jsbridge/jsbridge/jsobjects.py", line 126, in __call__
    response = self._bridge_.execFunction(self._name_, args)
  File "/Volumes/data/build/tools/mozmill-2.0/jsbridge/jsbridge/network.py", line 218, in execFunction
    return self.run(_uuid, 'bridge.execFunction('+ ', '.join(exec_args)+')', interval)
  File "/Volumes/data/build/tools/mozmill-2.0/jsbridge/jsbridge/network.py", line 201, in run
    raise JSBridgeDisconnectError("Connected disconnected")
jsbridge.network.JSBridgeDisconnectError: Connected disconnected

Comment 15

[Jeff Hammel]

manifests have been implemented in completely different ways for mozmill 1.5.2 vs mozmill 2.0.  This is due to the fact that the API for 1.5.x does not support running mozmill and mozmill-restart tests in the same process.  So it is not surprising that there are differences in the way that bug 585106 may cause side effects.  The stopping conditions are also somewhat different.

Comment 16

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Looks fine on 1.5.2. Marking as verified fixed for hotfix-1.5.2.

Comment 17

[cmtalbert]

This fix will have to be carried forward for 2.0 (perhaps not the same code, but certainly the spirit of it).

Comment 18

[Jeff Hammel]

This may have been fixed in bug 584470 . But, I'm only vaguely aware of what is being asked here.  For a test file name 'foo.js' like

"""
function setupModule(module) {
sleep(10000);
}

function test1() {
}

function test2() {
}
"""

if I run via `mozmill -t foo.js -t foo.js -t foo.js` and close the browser during the first setupModule, what should be the pass, fail, skip numbers?

Or, could someone who knows what they are supposed to be try running with master (or introduce a similar test case)? (Please?)

Comment 19

[Jeff Hammel]

Attachment: example test

test file to talk about. running through by itself, I get:

(mozmill)│mozmill -t foo.js 

(process:6517): GLib-CRITICAL **: g_slice_set_config: assertion `sys_page_size == 0' failed
Xlib:  extension "GLX" missing on display ":0.0".
ERROR | Test Failure: {"message": "[JavaScript Error: \"Failed to decode base64 string!\" {file: \"resource:///components/nsUrlClassifierLib.js\" line: 1193}]"}
TEST-START | foo.js | setupModule
TEST-START | foo.js | test1
TEST-PASS | foo.js | test1
TEST-START | foo.js | test2
TEST-PASS | foo.js | test2
INFO | Passed: 2
INFO | Failed: 0
INFO | Skipped: 0

Running three times and closing browser window during the first setupModule, I get:

(mozmill)│mozmill -t foo.js -t foo.js -t foo.js

(process:6605): GLib-CRITICAL **: g_slice_set_config: assertion `sys_page_size == 0' failed
Xlib:  extension "GLX" missing on display ":0.0".

(process:6661): GLib-CRITICAL **: g_slice_set_config: assertion `sys_page_size == 0' failed
Xlib:  extension "GLX" missing on display ":0.0".
TEST-START | foo.js | setupModule
TEST-START | foo.js | test1
TEST-PASS | foo.js | test1
TEST-START | foo.js | test2
TEST-PASS | foo.js | test2
TEST-START | foo.js | setupModule
TEST-START | foo.js | test1
TEST-PASS | foo.js | test1
TEST-START | foo.js | test2
TEST-PASS | foo.js | test2
INFO | Passed: 4
INFO | Failed: 1
INFO | Skipped: 0

What should we get?

Comment 20

[cmtalbert]

This is what I'd expect to see.  The test is marked as fail when you kill the browser half-way through the test.

Comment 21

[cmtalbert]

Given comment 19 & 20, marking as WFM