| Re: [aspectj-users] compile time performance (Eclipse 3.3) |
Hi Andy,
I migrated one of our subprojects to Eclipse 3.4 and it seems that AJDT 1.6.3 is really a performance booster - the speed is really much, much better, especially the incremental compile. Here the times for AJBuilder.build():
full incremental
Eclipse 3.3 75s 34s
Eclipse 3.4 30s 1s
You have done a really good job with AJDT 1.6.3 - the incremental compile is more than 30 times faster as before.
regards
Oliver
Here the complete log:
ECLIPSE 3.3 (FULLBUILD)
23:1:11 Removed problems and tasks for project GiropayConnector
23:1:11 Builder: Tidied output folder(s), deleted 161 .class files
23:1:11 ===========================================================================================
23:1:11 Build kind = FULLBUILD
23:1:11 Project=GiropayConnector, kind of build requested=Full AspectJ compilation
23:1:11 Builder: Tidied output folder(s), deleted 0 .class files
23:1:12 Preparing for build: not going to be incremental because no successful previous full build
23:1:12 Timer event: 636ms: Time to first compiled message
23:1:12 Timer event: 721ms: Time to first woven message
23:1:47 AspectJ reports build successful, build was: FULL
23:1:47 AJDE Callback: finish. Was full build: true
23:1:47 Timer event: 35047ms: Total time spent in AJDE
23:2:26 Timer event: 39863ms: Create element map (40038 rels in project: GiropayConnector)
23:2:26 Types affected during build = 159
23:2:27 Timer event: 367ms: Add markers (8496 markers)
23:2:27 Timer event: 75487ms: Total time spent in AJBuilder.build()
ECLIPSE 3.3 (INCREMENTAL)
23:7:5 ===========================================================================================
23:7:5 Build kind = AUTOBUILD
23:7:6 Project=GiropayConnector, kind of build requested=Incremental AspectJ compilation
23:7:6 build: Examined delta - source file changes in required project GiropayConnector
23:7:6 Preparing for build: planning to be an incremental build
23:7:6 Starting incremental compilation loop 1 of possibly 5
23:7:6 Timer event: 227ms: Time to first compiled message
23:7:8 Timer event: 2718ms: Time to first woven message
23:7:8 AspectJ reports build successful, build was: INCREMENTAL
23:7:8 AJDE Callback: finish. Was full build: false
23:7:8 Timer event: 2723ms: Total time spent in AJDE
23:7:39 Timer event: 30516ms: Create element map (40041 rels in project: GiropayConnector)
23:7:39 Types affected during build = 1
23:7:39 Timer event: 336ms: Add markers (8496 markers)
23:7:39 Timer event: 33736ms: Total time spent in AJBuilder.build()
ECLIPSE 3.4 (FULLBUILD)
22:47:52 Removed problems and tasks for project GiropayConnector
22:47:52 Builder: Tidied output folder(s), removed class files and derived resources
22:47:52 Timer event: 49ms: Delete markers: GiropayConnector (Finished deleting markers for GiropayConnector)
22:47:52 Compiler configuration for project GiropayConnector doesn't know previous state, so assuming EVERYTHING has changed.
22:47:52 ===========================================================================================
22:47:52 Build kind = FULLBUILD
22:47:52 Project=GiropayConnector, kind of build requested=Full AspectJ compilation
22:47:52 Builder: Tidied output folder(s), removed class files and derived resources
22:47:52 Timer event: 28ms: Pre compile
22:47:52 Compiler configuration for project GiropayConnector has been read by compiler. Resetting.
22:47:52 Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
22:47:52 Resetting list of modified source files. Was null
22:47:52 Preparing for build: not going to be incremental because no successful previous full build
22:47:53 Timer event: 576ms: Time to first compiled message
22:47:53 Timer event: 638ms: Time to first woven message
22:48:11 AspectJ reports build successful, build was: FULL
22:48:11 AJDE Callback: finish. Was full build: true
22:48:11 Timer event: 18278ms: Total time spent in AJDE
22:48:11 Timer event: 7ms: Refresh after build
22:48:11 Types affected during build = 159
22:48:11 Timer event: 18325ms: Total time spent in AJBuilder.build()
22:48:11 Timer event: 1ms: Delete markers: GiropayConnector (Finished deleting markers for GiropayConnector)
22:48:11 Timer event: 0ms: Post compile
22:48:41 Timer event: 29863ms: Create markers: GiropayConnector (Finished creating markers for GiropayConnector)
ECLIPSE 3.4 (INCREMENTAL)
22:51:40 ===========================================================================================
22:51:40 Build kind = AUTOBUILD
22:51:40 Project=GiropayConnector, kind of build requested=Incremental AspectJ compilation
22:51:40 File: /home/oliver/projects/GiroPay2009/GiropayConnector/src/main/java/giropay/connect/SmokeTest.java has changed.
22:51:40 build: Examined delta - 1 changed, 0 added, and 0 deleted source files in required project GiropayConnector
22:51:40 Setting list of classpath elements with modified contents:
22:51:40 []
22:51:40 Timer event: 7ms: Pre compile
22:51:40 Sending the following configuration changes to the compiler: []
22:51:40 1 source file changes since last build
22:51:40 Compiler configuration for project GiropayConnector has been read by compiler. Resetting.
22:51:40 Configuration was []
22:51:40 Resetting list of modified source files. Was [/home/oliver/projects/GiroPay2009/GiropayConnector/src/main/java/giropay/connect/SmokeTest.java]
22:51:40 Preparing for build: planning to be an incremental build
22:51:40 Starting incremental compilation loop 1 of possibly 5
22:51:40 Timer event: 513ms: Time to first compiled message
22:51:41 Timer event: 956ms: Time to first woven message
22:51:41 AspectJ reports build successful, build was: INCREMENTAL
22:51:41 AJDE Callback: finish. Was full build: false
22:51:41 Timer event: 980ms: Total time spent in AJDE
22:51:41 Timer event: 7ms: Refresh after build
22:51:41 Types affected during build = 1
22:51:41 Timer event: 995ms: Total time spent in AJBuilder.build()
22:51:41 Timer event: 19ms: Post compile
22:51:41 Timer event: 223ms: Delete markers: GiropayConnector (Finished deleting markers for GiropayConnector)
Andy Clement schrieb:
2009/3/22 Oliver Böhm <boehm@xxxxxxxxxx <mailto:boehm@xxxxxxxxxx>>
> as I wrote to Andy an update to Eclipse 3.4 would hopefully solve our problem. The AJDT trace is helpful but it is difficult to > find the "bad" aspects.
As I say, you may not have bad aspects, you may be suffering from using the old analysis code. I guess just let us know what you find after following Andrews tips. You didn't mention the scenario where you believe the performance to be poor - is it on an incremental build? Or is it really the full build? I will say that the goal for an incremental build, if you have the AJDT event trace view open, is that the project involved rebuilds in less than 1second, ideally less than 100ms. This high level measure is the intention of the AJDT event trace view - it doesn't go into specifics for the pointcuts involved.
Beyond writing good pointcuts, I would say avoid making the project configuration too complicated in a quest for performance - if you start configuring things like 'inpath' then the performance may get worse as the mainline use case we focus all our optimization efforts on at the moment is normal project dependencies.
Andy.
Hi Andrew,
as I wrote to Andy an update to Eclipse 3.4 would hopefully solve
our problem. The AJDT trace is helpful but it is difficult to find
the "bad" aspects.
Since we have the aspect lib under our control I will take a look
into it and follow your advice to use within() for the right scope.
Also the tip with the abstract aspects can help us because each
aspect is already divided into a concrete and an abstract part.
Perhaps we will extract the concrete part into a separate jar.
regards
Oliver
Andrew Eisenberg schrieb:
On Sat, Mar 21, 2009 at 3:06 PM, Oliver Böhm <boehm@xxxxxxxxxxaspectj-users@xxxxxxxxxxx <mailto:aspectj-users@xxxxxxxxxxx><mailto:boehm@xxxxxxxxxx>> wrote:
Hello,
we use Eclipse 3.3 / ADJT 1.5.3 with Webtools in a project.
We had big
problem with one AspectJ lib (patterntesting-check). It has
some general
aspects which seems to slow down the compile time a lot. My
questions:
* Is the compile time performance of Eclipse 3.4 / AJDT
1.6.3 much better
than with AJDT 1.5.3?
We have done a significant amount of work to ensure that incremental
compilations are fast. You will likely see dramatic speedup for
simple edit-save-compile cycles on non-aspects in Eclipse. And our
latest work on the dev builds of AJDT 1.6.5 go even further in this
direction.
However, overly generic aspects will still slow the compile down.
Steps to minimize this are:
1. Ensure that your aspects are properly scoped through the use of a
within() pointcut.
2. Instead of writing a generic aspect, write an abstract
aspect, that
can be sub-classed for the specific situations you need it for.
3. However, neither of these will work for the situation where
you are
using a third party aspect. A proposed feature is to have the
ability
for the aop.xml to control weaving scope in static situations. This
feature would certainly help your situation. Andy Clement can talk
more about this.
However, I am fairly certain that the problem you are running
into is
that in 1.5.3, too many full builds were occurring when there are
aspects on the aspect path.
* Are there any "best practices" or performance tips
available how to use
AspectJ?
I assume you are talking about compilation performance, not runtime
performance. If so, see above, if not, then ask again. :-)
* Is it possible to profile the AspectJ compiler to see,
which aspects slow
down the compile time?
The best thing to do would be to look at the AJDT Event Trace view.
This view has all sorts of information about what the compiler is
doing and why it made certain decisions. I strongly recommend
moving
up to a newer version of AJDT.
Hope this helps,
--andrew
_______________________________________________
aspectj-users mailing listaspectj-users@xxxxxxxxxxx <mailto:aspectj-users@xxxxxxxxxxx> ------------------------------------------------------------------------
https://dev.eclipse.org/mailman/listinfo/aspectj-users
-- Oliver Böhm
http://www.javatux.de
_______________________________________________
aspectj-users mailing list
_______________________________________________
aspectj-users mailing list
aspectj-users@xxxxxxxxxxx
https://dev.eclipse.org/mailman/listinfo/aspectj-users
--
Oliver Böhm
http://www.javatux.de
_______________________________________________
aspectj-users mailing list
aspectj-users@xxxxxxxxxxx
https://dev.eclipse.org/mailman/listinfo/aspectj-users