Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 321064

Summary: No JUnit TestReport created for huge report files
Product: z_Archived Reporter: Matthias Kappeller <mkappeller>
Component: BuckminsterAssignee: buckminster.core-inbox <buckminster.core-inbox>
Status: RESOLVED FIXED QA Contact:
Severity: normal    
Priority: P3 CC: achim.demelt, mkappeller
Version: unspecified   
Target Milestone: ---   
Hardware: PC   
OS: Windows XP   
Whiteboard:
Attachments:
Description Flags
Path uses a CountDownLatch to wait until session has finished
none
mylyn/context/zip
none
This image will show the two threads running during junit execution
none
More around the 'waitForFinish' Patch
none
mylyn/context/zip
none
Unit test for 'waitForFinish' method
none
Updated patch
none
Updated Patch
achim.demelt: iplog+
Updated Unit Test none

Description Matthias Kappeller CLA 2010-07-27 15:55:10 EDT
In some of our builds the output for junit test reports are around 500MB. Sometimes these reports are not written out.
After some debugging I found out that this happens because the org.eclipse.buckminster.junit.internal.TestListener get the call for sessionFinished asynchronous while org.eclipse.buckminster.junit.JUnitCommand tries to receive the testSession in another thread.

If the output is huge the duration until sessionFinished is called is longer than the execution of the JUnit process will take. So the method getTestRunSession() returns null (called by JUnitCommand) and the output is not written by exportTestRunSession.

I've created a patch to avoid this problem (looking forward to append it to this bug).
Comment 1 Matthias Kappeller CLA 2010-07-27 15:57:14 EDT
Created attachment 175350 [details]
Path uses a CountDownLatch to wait until session has finished

This patch helps to avoid the problem with a CountDownLatch.
Comment 2 Matthias Kappeller CLA 2010-07-27 15:57:16 EDT
Created attachment 175351 [details]
mylyn/context/zip
Comment 3 Matthias Kappeller CLA 2010-07-27 15:58:20 EDT
Created attachment 175352 [details]
This image will show the two threads running during junit execution
Comment 4 Matthias Kappeller CLA 2010-07-27 16:01:26 EDT
Another possible solution can be to use Object.wait() and Object.notifyAll()
Comment 5 Achim Demelt CLA 2010-07-28 02:21:52 EDT
Wow, tough one! Thanks a lot for the patch. I'll try to look into it on Friday.
Comment 6 Achim Demelt CLA 2010-07-30 08:10:38 EDT
Looks pretty good. I'd suggest minor changes, though:

* The 10 seconds default timeout should go into a final static constant, with a TODO comment to maybe make this configurable in the future
* When the timeout expires, the await() method returns false, but you then try to access the non-existent TestSession nonetheless. You may want to pass on that return value to the caller, which can then print an information message that the session data could not be exported.
* Can we gracefully handle that InterruptedException?

Can you spare some more time to work on these changes?
Comment 7 Matthias Kappeller CLA 2010-07-30 12:25:14 EDT
(In reply to comment #6)
> Looks pretty good. I'd suggest minor changes, though:
Ah, this was just a quick work around for me (and a suggestion ;-) ).
> 
> * The 10 seconds default timeout should go into a final static constant, with a
> TODO comment to maybe make this configurable in the future
Jeah you're right. But why adding a //TODO instead of just doing it ;-)
> * When the timeout expires, the await() method returns false, but you then try
> to access the non-existent TestSession nonetheless. You may want to pass on that
> return value to the caller, which can then print an information message that the
> session data could not be exported.
So in my opinion this checking should do the ResultSerializer - because he couldn't work with a 'null' testSession. Right?
> * Can we gracefully handle that InterruptedException?
Oh of course we can :) logging and setting the Thread.interrupted()
> 
> Can you spare some more time to work on these changes?
So because I have a five hour train ride behind me, I could have worked on this further on...
Comment 8 Matthias Kappeller CLA 2010-07-30 12:27:08 EDT
Created attachment 175590 [details]
More around the 'waitForFinish' Patch

this patch contains:
- a parameter --maxTimeAwaitJunitReport to make the timout configurable
- exception handling and error messages
- CountDownLatch replaced with Object.wait and notify
Comment 9 Matthias Kappeller CLA 2010-07-30 12:27:10 EDT
Created attachment 175591 [details]
mylyn/context/zip
Comment 10 Matthias Kappeller CLA 2010-07-30 12:29:01 EDT
Created attachment 175593 [details]
Unit test for 'waitForFinish' method

I've written a quick unit test to check the work done by the 'waitForFinish' method.
Comment 11 Matthias Kappeller CLA 2010-07-30 12:36:12 EDT
(In reply to comment #8)
> Created an attachment (id=175590)
> More around the 'waitForFinish' Patch
> 
> this patch contains:
> - a parameter --maxTimeAwaitJunitReport to make the timout configurable
> - exception handling and error messages
> - CountDownLatch replaced with Object.wait and notify
There is one thing in my patch I don't know exactly how to manage it.
To get the Integer out of an passed 'maxTimeAwaitJunitReport' value the string needs to be parsed. How should an NumberFormatException be handled?
(And i've recognized that there should be a 'Integer.parseInt' instead of a 'Integer.valueOf')
Comment 12 Achim Demelt CLA 2010-08-02 04:57:32 EDT
Created attachment 175693 [details]
Updated patch

Looks great, we're almost there. I've made the following minor changes to the code:

* Set the OptionValueType for the MAX_AWAIT_JUNIT_REPORT_DESCRIPTOR from NONE to REQUIRED so that the user has to pass a value after -t.
* Tried to clarify the help text.
* Always log the InterruptedException, even in "quiet" mode. -q only suppresses JUnit progress logging. It should not prevent logging of error messages.
* Changed the message for the InterruptedException from error to warning level.
* I took the liberty of mentioning you as a contributor in the file comments.

Two final points:
* What's the call to Thread.interrupted() good for? Just to reset the thread's  interrupted state?
* I actually preferred your first variant with CountDownLatch. With the notify()/wait() implementation, we might run into cases where the first thread calls notify() before the second thread has had a chance to wait(). This will then lead to the second thread being held for 10 seconds (or whatever has been configured) where there is actually no need to. The CountDownLatch returns immediately in this case without delay.
Comment 13 Matthias Kappeller CLA 2010-08-02 05:55:13 EDT
Created attachment 175697 [details]
Updated Patch

(In reply to comment #12)
> Created an attachment (id=175693)
> Updated patch
> 
> Looks great, we're almost there. I've made the following minor changes to the
> code:
> 
> * Set the OptionValueType for the MAX_AWAIT_JUNIT_REPORT_DESCRIPTOR from NONE to
> REQUIRED so that the user has to pass a value after -t.
Hmm I thought this is not necessary because of the default value of 10? And the most users (hopefully) don't have to adjust this value...?
> * Tried to clarify the help text.
> * Always log the InterruptedException, even in "quiet" mode. -q only suppresses
> JUnit progress logging. It should not prevent logging of error messages.
> * Changed the message for the InterruptedException from error to warning level.
> * I took the liberty of mentioning you as a contributor in the file comments.
> 
> Two final points:
> * What's the call to Thread.interrupted() good for? Just to reset the thread's
> interrupted state?
If you mean with reset to change the interrupted state from the cleared 'false' back to 'true', then yes that's the reason why.
> * I actually preferred your first variant with CountDownLatch. With the
> notify()/wait() implementation, we might run into cases where the first thread
> calls notify() before the second thread has had a chance to wait(). This will
> then lead to the second thread being held for 10 seconds (or whatever has been
> configured) where there is actually no need to. The CountDownLatch returns
> immediately in this case without delay.
Yeah you're right. I've reverted it to a countDownLatch.
Comment 14 Matthias Kappeller CLA 2010-08-02 05:57:30 EDT
Created attachment 175698 [details]
Updated Unit Test

I've updated the unit test to check the point you mentioned when the fist thread already called sessionFinished and then the second needn't to wait.
Comment 15 Achim Demelt CLA 2010-08-02 08:47:11 EDT
Patch applied to trunk, rev. 11538. Thanks a lot, Matthias!