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

Bug 311419

Summary: Performance bug in the concurrent compiler (class ProcessTaskManager)
Product: [Eclipse Project] JDT Reporter: Markus Gaisbauer <markus.gaisbauer>
Component: CoreAssignee: Tomasz Zarna <tomasz.zarna>
Status: VERIFIED WONTFIX QA Contact:
Severity: normal    
Priority: P3 CC: daniel_megert, jarthana, markus.kell.r, Olivier_Thomann, srikanth_sankaran
Version: 3.6Keywords: performance
Target Milestone: 4.3 M1   
Hardware: PC   
OS: Linux   
Whiteboard:
Attachments:
Description Flags
Proposed patch: Use a simple blocking queue
none
Reproduce problem with this project none

Description Markus Gaisbauer CLA 2010-05-03 15:15:33 EDT
Build Identifier: I20100429-1549

I recently wondered why clean builds in Eclipse were so much slower
than clean builds with javac on my machine. During my search I
discovered a critical performance bug in the work queue of the
concurrent compiler (ProcessTaskManager). After locating and fixing
the problem, I was able to get the build duration down from about 100
seconds to under 30 seconds. I summarized the problem on the following
page: http://markus-gaisbauer.appspot.com/

Reproducible: Always

Steps to Reproduce:
1. Create a Java project with lots of small Java source files
2. Clean build the project a couple of times
3. Note that this does not consume a lot of CPU and takes much longer than compiling with javac.
Comment 1 Markus Gaisbauer CLA 2010-05-03 15:20:51 EDT
Created attachment 166854 [details]
Proposed patch: Use a simple blocking queue
Comment 2 Olivier Thomann CLA 2010-05-03 15:22:52 EDT
Srikanth, please take a look.
Comment 3 Markus Gaisbauer CLA 2010-05-03 15:24:21 EDT
Created attachment 166857 [details]
Reproduce problem with this project 

Run CodeGenerator.java
Refresh project
Clean build a couple of times.

On my machine compilation takes ~81 seconds with Eclipse 3.6 M7. With the proposed patch compilation takes ~2s.
Comment 4 Srikanth Sankaran CLA 2010-05-04 06:25:15 EDT
(In reply to comment #2)
> Srikanth, please take a look.

Will do. What timeframe did you have in mind ? The numbers look
very neat if can be sustained, it is a bit too close for comfort
for 3.6.
Comment 5 Olivier Thomann CLA 2010-05-04 11:09:32 EDT
Markus, this is the bug report I mentioned at the JDT call.

Srikanth,

If we believe this patch is rock solid, I would be tempted to release for 3.6. But we need a careful review of it.
Comment 6 Srikanth Sankaran CLA 2010-05-05 07:05:37 EDT
(In reply to comment #3)
> Created an attachment (id=166857) [details]
> Reproduce problem with this project 
> 
> Run CodeGenerator.java
> Refresh project
> Clean build a couple of times.
> 
> On my machine compilation takes ~81 seconds with Eclipse 3.6 M7. With the
> proposed patch compilation takes ~2s.

Perhaps this is a Linux specific thing: On my otherwise idle dual core
Windows XP SP2, I actually see a degradation. HEAD version takes on
average (over 4 runs) about ~17 seconds wall clock time to compile
these generated files, while with the patch it takes on average
about ~20 seconds, a 18% slow down.

I'll try on JDT/Core workspace itself as a second data point shortly.
Comment 7 Srikanth Sankaran CLA 2010-05-05 07:19:05 EDT
(In reply to comment #6)
> (In reply to comment #3)
> > Created an attachment (id=166857) [details] [details]
> > Reproduce problem with this project 

> I'll try on JDT/Core workspace itself as a second data point shortly.

With the patch I get about ~35 seconds (ignoring the wild variation in the
first run in each case) and without ~36. All wall clock. 

I'll also turn on the internal timers and gather data programatically.
Comment 8 Srikanth Sankaran CLA 2010-05-05 08:53:50 EDT
(In reply to comment #7)
> (In reply to comment #6)
> > (In reply to comment #3)
> > > Created an attachment (id=166857) [details] [details] [details]
> > > Reproduce problem with this project 
> 
> > I'll try on JDT/Core workspace itself as a second data point shortly.
> 
> With the patch I get about ~35 seconds (ignoring the wild variation in the
> first run in each case) and without ~36. All wall clock. 
> 
> I'll also turn on the internal timers and gather data programatically.

By turning on the timers in org.eclipse.jdt.internal.core.builder.JavaBuilder.build(int, Map, IProgressMonitor),
I observe a 4% degradation in both cases (JDT/Core dev workspace +
repro scenario in this bug). As before first runs were ignored in
each case, clean operation times are not included and results were
averaged over three runs each. The timers are based on 
System.currentTimeMillis()

I don't have a Linux desktop to validate the numbers there. Olivier,
if you run Linux or have a Linux box readily accessible let me know
if you can run these experiments there, otherwise, I will try and
organize it here.

I'll run the JDT/Core tests with this patch anyways and as well
take a peek at the changes.
Comment 9 Markus Gaisbauer CLA 2010-05-05 09:56:20 EDT
Thanks for testing my patch on Windows. I think it's quite interesting that Linux and Windows behave so differently here. I will try to find out what is going on.
Comment 10 Olivier Thomann CLA 2010-05-05 09:59:13 EDT
(In reply to comment #8)
> I don't have a Linux desktop to validate the numbers there. Olivier,
> if you run Linux or have a Linux box readily accessible let me know
> if you can run these experiments there, otherwise, I will try and
> organize it here.
I have a VMWare image of Linux Redhat 5. I'll give it a try.
Comment 11 Markus Keller CLA 2010-05-05 12:19:41 EDT
For me, the patch makes it slower.

On my WinXP machine (with SSD drive = low latency, but just a Core Duo processor), I have ~20s without the patch, but with the patch, I need ~25s to compile comment 3 (warm measurements, i.e. startup, clean, build, clean, measure build).

Compiling org.eclipse.jdt.ui takes about the same time with and without the patch.

Markus G., did you make sure you tested the two cases under equal conditions? File system caches can make a huge difference here, especially under Linux, which is known to have a good caching strategy.
Comment 12 Markus Gaisbauer CLA 2010-05-05 14:27:49 EDT
> Markus G., did you make sure you tested the two cases under equal conditions?
> File system caches can make a huge difference here, especially under Linux,
> which is known to have a good caching strategy.

Yes, I did make sure that both cases were tested with a full cache. The file system cache is much faster under Linux and this seems to be one of the reasons why the current code performs so badly under Linux. 

I can verify, that my reproducer does not show the described problem most of the time. Slow IO operations (mostly opening files) make one of the threads slower under Windows and therefore change the concurrent behaviour of the code. 

In order to show this in numbers, I instrumented the code in such a way, that it prints the number of times that the "wait" calls time out rather than waking up after being notified by the other thread. Here is the result for a typical run under Linux and Windows.

Linux:
371 timeouts in removeNextUnit, 149 timeouts in addNextUnit
407 timeouts in removeNextUnit, 163 timeouts in addNextUnit
190 timeouts in removeNextUnit, 76 timeouts in addNextUnit
98828 ms

Windows:
0 timeouts in removeNextUnit, 0 timeouts in addNextUnit
0 timeouts in removeNextUnit, 0 timeouts in addNextUnit
0 timeouts in removeNextUnit, 0 timeouts in addNextUnit
5348 ms
Comment 13 Markus Gaisbauer CLA 2010-05-05 14:48:40 EDT
Compiling 6232 JDT Core files is fast even under Linux (and much faster than compiling the 5000 empty classes of the reproducer).

2 timeouts in removeNextUnit, 0 timeouts in addNextUnit
0 timeouts in removeNextUnit, 0 timeouts in addNextUnit
0 timeouts in removeNextUnit, 0 timeouts in addNextUnit
9 timeouts in removeNextUnit, 0 timeouts in addNextUnit
1 timeouts in removeNextUnit, 0 timeouts in addNextUnit
9 timeouts in removeNextUnit, 0 timeouts in addNextUnit
0 timeouts in removeNextUnit, 0 timeouts in addNextUnit
1 timeouts in removeNextUnit, 0 timeouts in addNextUnit
13594 ms
Comment 14 Olivier Thomann CLA 2010-05-05 15:50:37 EDT
Are you also using a SSD drive on Windows ?
Comment 15 Markus Gaisbauer CLA 2010-05-05 16:01:16 EDT
(In reply to comment #14)
> Are you also using a SSD drive on Windows ?

No, the numbers posted my last 2 comments were observed on a 

Core 2 Duo E8400 3.00GHz
8 GB RAM
640 GB 7200rpm HDD
Ubuntu 10.04 (EXT4, 64 bit) / Windows 7 RC (NTFS, 64 bit)
Comment 16 Srikanth Sankaran CLA 2010-06-09 02:28:24 EDT
Satyam, can you please follow up on this for 3.6.1 ? Thanks!
Comment 17 Markus Gaisbauer CLA 2011-03-05 04:12:15 EST
Has the described problem already been addressed in Eclipse 3.7?
Comment 18 Satyam Kandula CLA 2011-03-06 23:55:30 EST
(In reply to comment #17)
> Has the described problem already been addressed in Eclipse 3.7?
Not yet. There is a small performance regression on Windows :(
Comment 19 Srikanth Sankaran CLA 2012-07-23 03:04:34 EDT
Tomek, More punishment for the good work in bug 383798: Could you follow 
up on this after the various bugs that you are working on in different 
stages ?

Patch needs to be thoroughly reviewed, tested and modified so we
don't see any degradation on windows. M1/M2 would be a good time
in general to consider introducing changes that could carry some 
risk with them.
Comment 20 Tomasz Zarna CLA 2012-07-23 06:59:44 EDT
(In reply to comment #1)
> Created attachment 166854 [details]
> Proposed patch: Use a simple blocking queue

Pushed to Gerrit as https://git.eclipse.org/r/#/c/6915/1

(In reply to comment #19)
> Could you follow up on this after the various bugs that you are working on in different
> stages ?

Sure, will have a look at this once my tasks list gets a little bit shorter.
Comment 21 Tomasz Zarna CLA 2012-07-31 11:45:21 EDT
I can confirm the performance regression on WinXp with the patch applied, see my latest comment on Gerrit.
Comment 22 Srikanth Sankaran CLA 2012-08-01 01:49:53 EDT
(In reply to comment #21)
> I can confirm the performance regression on WinXp with the patch applied,
> see my latest comment on Gerrit.

Thanks, so this pretty much seems established with yet another data point.
I would try to see if the numbers mentioned in comment#0 is are reproducible
and if they are - we could conditionally implement the new behavior for
Linux selectively. However, I would take this approach only if the numbers
are very good and if the changes are clean and safe.
Comment 23 Tomasz Zarna CLA 2012-08-03 12:38:32 EDT
(In reply to comment #22)
> I would try to see if the numbers mentioned in comment#0 is are reproducible

I have been running our perf tests on a Linux box for whole day (collected 120 samples for each case) and the numbers look bad:

testScanner +18,26%
testParser +7,48%
testFullBuildDefault +35,79%
testFullBuildProjectNoWarning +34,1%
testFullBuildProjectDefault +30,82%
testFullBuildProjectAllWarnings +29,54%
testBatchCompilerNoWarning +47,58%
testCompileJDTCoreProjectNoWarning +49,62%
testCompileJDTCoreProjectDefault +49,16%
testCompileJDTCoreProjectJavadoc +48,6%
testCompileJDTCoreProjectAllWarnings +45,49%
testCompileSWTProjectDefault +68,51%
testBuildGenericType +0,73%

Markus G, am I missing something obvious here? A specific VM for example. Have you run those tests with the patch?
Comment 24 Srikanth Sankaran CLA 2012-08-06 05:49:48 EDT
(In reply to comment #23)
> (In reply to comment #22)
> > I would try to see if the numbers mentioned in comment#0 is are reproducible
> 
> I have been running our perf tests on a Linux box for whole day (collected
> 120 samples for each case) and the numbers look bad:

Thanks Tom. At the moment, this looks headed to a WONTFIX resolution.
Comment 25 Srikanth Sankaran CLA 2012-08-07 04:38:11 EDT
Closing as WONTFIX.
Comment 26 Srikanth Sankaran CLA 2012-08-07 04:39:05 EDT
Verified for 4.3 M1