Bug 299279 - [headless] JUnit 4 test launches fail to export results in some circumstances
Summary: [headless] JUnit 4 test launches fail to export results in some circumstances
Status: NEW
Alias: None
Product: z_Archived
Classification: Eclipse Foundation
Component: Buckminster (show other bugs)
Version: unspecified   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: buckminster.core-inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2010-01-11 09:45 EST by Joerg Buchberger CLA
Modified: 2019-02-25 14:40 EST (History)
2 users (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Joerg Buchberger CLA 2010-01-11 09:45:25 EST
Build Identifier: buckminster.core_1.1.360.r10874

if --loglevel option is set or if the emma command is used, no test summary is given on console and no result file will be created at the end for JUnit 4 launch configuration

the JUnit 3 plugin test launch configuration runs fine though

because of this, we have to run the tests always in separate invocations/scripts  and it is not possible to merge coverage results


exctracted from the logs:

Framework arguments:  --loglevel DEBUG --scriptfile D:\build-workfiles\emma.cquery
Command-line arguments:  --loglevel DEBUG -data D:\build-workfiles\eclipse-workspaces\xxx-tests --scriptfile D:\build-workfiles\emma.cquery

This is a continuation of log file D:\build-workfiles\eclipse-workspaces\xxx-tests\.metadata\.bak_0.log
Created Time: 2010-01-11 14:34:39.020

!ENTRY org.eclipse.buckminster.core 1 293 2010-01-11 14:34:39.020
!MESSAGE   ...OK [0s]

!ENTRY org.eclipse.buckminster.core 1 293 2010-01-11 14:34:39.036
!MESSAGE Running test xxx.rcm.data.core.settings.ProjectsEnabledModelTest.testModificationListenerNegative...

(...)

!ENTRY org.eclipse.buckminster.core 1 293 2010-01-11 14:34:40.098
!MESSAGE Running test xxx.rcm.data.oca.services.LocalServiceLocationTest.testGetters...

!ENTRY org.eclipse.buckminster.core 0 293 2010-01-11 14:34:40.114
!MESSAGE Doing full workspace refresh

!ENTRY org.eclipse.buckminster.core 0 293 2010-01-11 14:34:44.255
!MESSAGE Waiting for jobs to end

!ENTRY org.eclipse.buckminster.runtime 0 293 2010-01-11 14:34:46.551
!MESSAGE emma '-m' '-l' '/xxx.rcm.alltests/AllTests.launch' '-o' 'D:/build-workfiles/emma3.xml' '--xml' 'D:/build-workfiles/coverage.xml'

!ENTRY org.eclipse.update.configurator 4 0 2010-01-11 14:34:55.864
!MESSAGE Unable to find feature.xml in directory: D:\build-workfiles\hudson-data\jobs\xxx-tests\workspace\source\target-platform\eclipse\features\.svn

!ENTRY org.eclipse.buckminster.core 1 293 2010-01-11 14:35:03.130
!MESSAGE Starting test session AllTests

!ENTRY org.eclipse.buckminster.core 1 293 2010-01-11 14:35:03.130
!MESSAGE Running test xxx.rcm.base.core.splashHandlers.test.InteractiveSplashHandlerTest.testFocus...

!ENTRY org.eclipse.buckminster.core 1 293 2010-01-11 14:35:03.739
!MESSAGE   ...OK [0,609s]


Reproducible: Always
Comment 1 Achim Demelt CLA 2010-01-13 03:12:30 EST
That's weird. Technically, there is no difference in running JUnit 3 or JUnit 4 tests within Buckminster. There might, however, be an exception further down that we don't properly catch and thus don't terminate gracefully. I would expect to see such an exception in the log file. Do you see anything like that in the log?

Also, you might run out of memory when collecting test results for many consecutive test runs, which might also terminate the execution prematurely. Can you please try increasing your heap space for the Buckminster (host) VM?
Comment 2 Joerg Buchberger CLA 2010-01-13 08:30:39 EST
Unfortunately, I was not able to spot any exceptions besides those expected during tests.

Increasing the buckminster heap to 800m did not help either (our JUnit4 Testsuite contains only about 100 tests of more simple nature; whereas the JUnit3 Testsuite has more than 1500, many of them part of more complex plugin tests).

Did I mention, that the tests itself all run fine.
(It's really just the result statistics and file export that makes problems.)

My script looks like this:
emma -l /xxx/AllTestsJUnit4.launch -o D:/builds/emma4.xml
emma -m -l /xxx/AllJU3.launch -o D:/builds/emma3.xml --xml D:/builds/coverage.xml

emma4.xml is not written
emma3.xml is written
and merged coverage.xml only reflects tests from JUnit3

We use easymock and jmockit in some of the JUnit4 tests, though. Let me check, if we don't use them in JUnit3 tests (even though this doesn't mean anything in itself).
Comment 3 Achim Demelt CLA 2010-01-13 09:15:45 EST
Strange. Did I understand you correctly that the emma4.xml and the test summary is written correctly if you run the JUnit 4 tests in their own script? Or is the JUnit 4 support generally broken?

There's a slight chance that the recent refactorings of the Platform team have introduced this regression in our code. They've gone out of their way to enable JUnit4 testing with PDE/Build, and they had to make some changes to make this happen. I don't know about the exact nature of these changes, but maybe that's the cause.
Comment 4 Joerg Buchberger CLA 2010-01-13 10:25:12 EST
Sorry, I'll try to clarify this a little:

1) JUnit4 tests always succeed to run
2) JUnit4 test-result file-export only succeeds, if invoked like this:

buckminster -data D:\builds\workspace junit -l /xxx/JUnit4.launch -q -o D:/builds/junit4.xml

So, currently we are just able to run all our JUnit tests in separate runs.
This means, we cannot merge coverage results as this is said to only work within a single session.


Wait, I just found out another thing:

when I execute buckminster with a scriptfile containing only this line
    emma -q -l /xxx/JUnit4.launch --xml D:/builds/cov4.xml
this yields following output
    INFO:  emma '-q' '-l' '/xxx/JUnit4.launch' '--xml' 'D:/builds/cov4.xml'
    processing input files ...
    37 file(s) read and merged in 31 ms
    writing [xml] report to [D:\builds\cov4.xml] ...
but that cov4.xml contains results from JUnit3/emma launch rather than from the JUnit4 tests!

this
    emma -l /xxx/JUnit3.launch -o D:/builds/emma3.xml --xml D:/build-workfiles/cov3.xml
in contrast gives me the following
	INFO:  Running test xxx.http.OmtHouse...
	INFO:    ...OK [0,016s]
	INFO:  Tests finished.
	INFO:  Elapsed time: 39,969 seconds.
	INFO:  Total number of tests executed: 1439
	INFO:  Successful tests: 1365
	INFO:  Failed tests: 53
	INFO:  Errors: 21
	INFO:  Ignored tests: 0
	INFO:  Overall status: Error
	processing input files ...
	48 file(s) read and merged in 47 ms
	writing [xml] report to [D:\builds\cov3.xml] ...
where cov3.xml contains largely the same (but slightly more) info as cov4.xml

Note, that I always do a cleanbuild in between the test/coverage runs.
Comment 5 Achim Demelt CLA 2010-01-13 11:21:06 EST
Okay, I think I can clarify one thing: You don't see the test summary report for your JUnit 4 runs because of the "-q" (quiet) flag. You don't have that flag for your JUnit 3 run, so the output is different.

As for the contents of the cov4.xml file, I am tempted to argue that the /xxx/JUnit4.launch config doesn't actually run what you expect it to run. You should be able to verify this once you remove the "-q" flag. This would also explain why the XML outputs and coverage reports of the two launch configs are basically identical.

To double-check, I suggest opening your workspace and the JUnit4.launch config in the latest Eclipse 3.6 build. As I said, the Platform team made some changes for JUnit 4 support. Maybe there's a new flag in the *.launch files that somehow instructs the runtime to do something different than in a 3.5 environment.

Thanks for your help in digging into this problem!
Comment 6 Joerg Buchberger CLA 2010-01-13 12:05:44 EST
Well unfortunately, the summary for JUnit4 tests does not show, whether or not I use the -q flag. It's just the only way for me, that the result file gets exported at all.

When I remove the -q flag, I can see that the JUnit4 tests are executed as expected, with same results shown as in IDE, but with the drawback that the result file won't get exported.

Do you mean Helios-M4 IDE or do you mean latest integration build of 3.6 IDE?
And then check launch configurations with this IDE? (so that the launch files have all the latest information?)
Is that what you suggest me to do? I'll try. Is there anything else I can do to provide more useful information to you?

Thanks for the quick responses!
Comment 7 Achim Demelt CLA 2010-01-13 12:48:45 EST
Everything points to some exception being thrown in the listener that reports the test summary, because we see different behavior with or without the -q switch. Let's try to narrow that down. 

1) I would argue that the following script should work:

emma -q -l /xxx/AllTestsJUnit4.launch -o D:/builds/emma4.xml
emma -m -l /xxx/AllJU3.launch -o D:/builds/emma3.xml --xml
D:/builds/coverage.xml

Note the -q for the JUnit4.launch. You won't see a test summary on the console, but you should have an emma4.xml report file, as well as a merged coverage report.

2) When running _without_ the "-q" flag, are you sure that *all* JUnit4 tests are executed? If yes, then we're having a problem when writing the overall test session summary. If no, then it seems one particular test case is the problem.

3) You may also try to restrict the JUnit4.launch to one particular test class, and not the whole test suite. Do you still see no summary when running without "-q"?

4) Forget about checking your launch config with a 3.6 IDE. It seems that the launch is running the correct test cases, so no need to do this extra work.
Comment 8 Achim Demelt CLA 2010-01-13 13:02:30 EST
Oh, yeah, one more thing: Try running with "--displaystacktrace" :-) Sorry for not mentioning this earlier.

PS: Thanks Thomas for pointing me to the most obvious of all debugging options...
Comment 9 Joerg Buchberger CLA 2010-01-14 09:22:01 EST
> 1) I would argue that the following script should work:
> 
> emma -q -l /xxx/AllTestsJUnit4.launch -o D:/builds/emma4.xml
> emma -m -l /xxx/AllJU3.launch -o D:/builds/emma3.xml --xml
> D:/builds/coverage.xml
> 
> Note the -q for the JUnit4.launch. You won't see a test summary on the console,
> but you should have an emma4.xml report file, as well as a merged coverage
> report.

you are right  :-))  can confirm, that it worked repeatedly for all 278 JUnit4 tests (just wonder, how I could miss that one)


> 2) When running _without_ the "-q" flag, are you sure that *all* JUnit4 tests
> are executed? If yes, then we're having a problem when writing the overall test
> session summary. If no, then it seems one particular test case is the problem.

again you hit the sweet spot - when trying repeatedly, the number of JUnit4 test results appearing on the console varies between 222 and 235, which falls some 15-20% short of the total of 278 tests


> 3) You may also try to restrict the JUnit4.launch to one particular test class,
> and not the whole test suite. Do you still see no summary when running without
> "-q"?

when restricted to just one of the test suites, everything is fine - tests, export and summary


sorry for taking so much of your time, this really seems to be a problem with one or some of our test cases ... I guess, we have some discussions and reviews coming up in our team ...
Thanks for all the help and tracking that down!
Comment 10 Achim Demelt CLA 2010-01-14 09:32:20 EST
That's good news. But I think it's not (only) a problem in your test cases, but also in the Buckminster code. After all, the tests are running fine with the "-q" switch, so it's our test listener code that seems to be buggy and/or not fault-tolerant in certain cases.

So can you please try the "--displaystacktrace" switch and check the log for any exceptions? I'd like to have an indication where this thing breaks so we can catch it and handle it gracefully. If necessary, we need to inform the user that something went wrong during test execution and not just simply be quiet about it...
Comment 11 Joerg Buchberger CLA 2010-01-14 10:10:41 EST
> That's good news. But I think it's not (only) a problem in your test cases, but
> also in the Buckminster code. After all, the tests are running fine with the
> "-q" switch, so it's our test listener code that seems to be buggy and/or not
> fault-tolerant in certain cases.
> 
> So can you please try the "--displaystacktrace" switch and check the log for
> any exceptions? I'd like to have an indication where this thing breaks so we
> can catch it and handle it gracefully. If necessary, we need to inform the user
> that something went wrong during test execution and not just simply be quiet
> about it...

it's always on, but only stacktraces from failures and expected exceptions show up

I'll create launch configs for each of the JUnit4 suites, and try each one separately (tomorrow) to narrow down the problematic test(s) ...
Comment 12 Joerg Buchberger CLA 2010-01-18 04:57:57 EST
So far, I was not able to clearly identify what's going wrong.
This post is just there to give you a rough idea about current status. (Quick summary: thankless task this.)

My approach to narrow down the problem spot was, to split the JUnit4 test launch into 4 smaller pieces. Three suites which I assumed to be part of the problem, each were moved into separate junit launch configurations. However, all are still part of the same buckminster script.

Results as of now:
The big rest of the original JUnit4 suite always runs fine.
Two of the test suites now separated out, make trouble about once in 5 and about once in 10 runs respectively.
And one suite only succeeds to bring proper result output/summmary 10% of the time.

When I divided this further, and started playing with including/excluding test cases in the most problematic suite, I get a similar picture - i.e. one of the test classes accounts for 90% of problematic runs, but sometimes is OK, whereas the other ones are fine only most of the time.  ;-/
Comment 13 Joerg Buchberger CLA 2010-01-18 05:29:35 EST
My new theory is, that the zombie like problem takes a varying amount of time to show up and that it originates in the first suite launched by the script - with the effect that it rarely shows up during the first or third suite run, but almost always somewhere in the second suite launched.

Trying to verify that, I moved the other JUnit4 suite launches up front in the script. If my assumption is correct, then this should yield fine runs most of the time - with the problem showing up about once in half a dozen runs.
Comment 14 Achim Demelt CLA 2010-02-26 12:21:41 EST
Joerg, any new insights regarding this bug? Although it looks like there's some flaw in your test suite, there's still a slight chance that we have a bug in Buckminster's JUnit launching code. Or we might be able to improve diagnostic messages in some way. Any input is appreciated.