Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
AW: [aspectj-users] Overall problem with AJDT performance

Yes zip 3 and I din't change the confg yet. The trace was from a full ws build. Loos very promising.


----- Ursprüngliche Nachricht -----
Von: Andy Clement <andrew.clement@xxxxxxxxx>
Gesendet: Samstag, 10. Oktober 2009 18:04
An: aspectj-users@xxxxxxxxxxx <aspectj-users@xxxxxxxxxxx>
Betreff: Re: [aspectj-users] Overall problem with AJDT performance


Hi Thomas,

It isn't clear to me which zip you used, did you use the 2nd one or
just the 3rd one?  I need to know which was used to decide if the
enhancement needs more work.  I presume you used the 3rd one.

You also don't appear to have turned off the xlint ?  In one project
below 86seconds is spent matching, 84 of which is in the xlint
processing.  Can you try with the xlint turned off?

So your full build time is now down at 12minutes?

Andy

2009/10/10 Thomas Hofmann <email@xxxxxxxxxxxxxxxxx>:
> Still too long but already much better:
>
> 10:55:30 Removed problems and tasks for project com.dcx.ivkmds.fwk.test.ass
> 10:55:30 Builder: Tidied output folder(s), removed class files and derived resources
> 10:55:31 Timer event: 5ms: Delete markers: com.dcx.ivkmds.fwk.test.ass (Finished deleting markers for com.dcx.ivkmds.fwk.test.ass)
> 10:55:43 Compiler configuration for project com.dcx.ivkmds.fwk.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
> 10:55:43 ===========================================================================================
> 10:55:43 Build kind = FULLBUILD
> 10:55:43 Project=com.dcx.ivkmds.fwk.test.ass, kind of build requested=Full AspectJ compilation
> 10:55:43 Timer event: 0ms: Flush included source file cache
> 10:55:43 Timer event: 0ms: Check delta
> 10:55:43 Builder: Tidied output folder(s), removed class files and derived resources
> 10:55:43 Timer event: 212ms: Pre compile
> 10:55:43 Compiler configuration for project com.dcx.ivkmds.fwk.test.ass has been read by compiler.  Resetting.
> 10:55:43      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
> 10:55:43 Resetting list of modified source files.  Was null
> 10:55:43 Preparing for build: not going to be incremental because no successful previous full build
> 10:55:44 Timer event: 1027ms: Time to first compiled message
> 10:55:45 Timer event: 1309ms: Time to first woven message
> 10:56:14 AspectJ reports build successful, build was: FULL
> 10:56:14 AJDE Callback: finish. Was full build: true
> 10:56:14 Timer event: 30751ms: Total time spent in AJDE
> 10:56:14 Timer event: 0ms: Refresh after build
> 10:56:14 Types affected during build = 24
> 10:56:14 Timer event: 30996ms: Total time spent in AJBuilder.build()
> 10:56:14 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.test.ass
> 10:56:14 Timer event: 1ms: Delete markers: com.dcx.ivkmds.fwk.test.ass (Finished deleting markers for com.dcx.ivkmds.fwk.test.ass)
> 10:56:20 Timer event: 6283ms: Create markers: com.dcx.ivkmds.fwk.test.ass (Finished creating markers for com.dcx.ivkmds.fwk.test.ass)
> 10:56:20 Created 572 markers in 24 files
>
>
> Timing ------------
> Entire time spent in the weaver instance created for this build:
>> performing model repairs=0ms
>> reweavable processing=0ms
>> verifying consistency=0ms
>> weaving aspects=260ms
>> weaving classes=27890ms
>  for those two weave steps, time spent pre-post calling the individual type wea
> ver instance: 37ms
>> weaving normal itds=17ms
>> weaving structural itds=0ms
>
> Breakdown of time spent in type weaver instances:
> class prep = 0ms
> typeWeaving = 0ms
> decaWeaving = 0ms
> fastShadowMatching = 0ms
> shadowMatching = 26470ms
> shadowWeaving = 1412ms
> postWeave = 3ms
> Total =27888ms
>
> Kinded pointcut matchInternal(): 22891ms
> Kinded pointcut match calls: 204036
> Kinded pointcut xlinttime: 20341ms
> ThisTarget pointcut matchInternal: 2166ms
>
> Timing: time spent in pipeline weaving: 28632ms
> Timing ------------
>
>
>
>
>
> Wow, I'm amazed. A second run on a different project (this was > 12 minutes but with a much larger heap when all was rebuild):
>
> 10:58:43 Removed problems and tasks for project com.dcx.ivkmds.application.ass
> 10:58:45 Builder: Tidied output folder(s), removed class files and derived resources
> 10:58:52 Compiler configuration for project com.dcx.ivkmds.application.ass doesn't know previous state, so assuming EVERYTHING has changed.
> 10:58:52 ===========================================================================================
> 10:58:52 Build kind = FULLBUILD
> 10:58:52 Project=com.dcx.ivkmds.application.ass, kind of build requested=Full AspectJ compilation
> 10:58:52 Timer event: 0ms: Flush included source file cache
> 10:58:52 Timer event: 0ms: Check delta
> 10:58:52 Builder: Tidied output folder(s), removed class files and derived resources
> 10:58:53 Timer event: 1452ms: Pre compile
> 10:58:54 Compiler configuration for project com.dcx.ivkmds.application.ass has been read by compiler.  Resetting.
> 10:58:54      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
> 10:58:54 Resetting list of modified source files.  Was null
> 10:58:54 Preparing for build: not going to be incremental because no successful previous full build
> 10:58:56 Timer event: 2834ms: Time to first compiled message
> 10:58:56 Timer event: 2866ms: Time to first woven message
> 10:59:44 AspectJ reports build successful, build was: FULL
> 10:59:45 AJDE Callback: finish. Was full build: true
> 10:59:45 Timer event: 51440ms: Total time spent in AJDE
> 10:59:45 Timer event: 0ms: Refresh after build
> 10:59:45 Types affected during build = 292
> 10:59:45 Timer event: 1ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.application.ass
> 10:59:45 Timer event: 52941ms: Total time spent in AJBuilder.build()
> 10:59:45 Timer event: 2ms: Delete markers: com.dcx.ivkmds.application.ass (Finished deleting markers for com.dcx.ivkmds.application.ass)
> 10:59:46 Timer event: 601ms: Create markers: com.dcx.ivkmds.application.ass (Finished creating markers for com.dcx.ivkmds.application.ass)
> 10:59:46 Created 2615 markers in 292 files
> 10:59:46 Timer event: 31ms: Delete markers: com.dcx.ivkmds.application.ass (Finished deleting markers for com.dcx.ivkmds.application.ass)
>
>
> Timing ------------
> Entire time spent in the weaver instance created for this build:
>> performing model repairs=1ms
>> reweavable processing=2ms
>> verifying consistency=0ms
>> weaving aspects=41ms
>> weaving classes=40926ms
>  for those two weave steps, time spent pre-post calling the individual type wea
> ver instance: 408ms
>> weaving normal itds=46ms
>> weaving structural itds=1ms
>
> Breakdown of time spent in type weaver instances:
> class prep = 6ms
> typeWeaving = 0ms
> decaWeaving = 1ms
> fastShadowMatching = 5ms
> shadowMatching = 37440ms
> shadowWeaving = 2172ms
> postWeave = 39ms
> Total =39667ms
>
> Kinded pointcut matchInternal(): 26404ms
> Kinded pointcut match calls: 182508
> Kinded pointcut xlinttime: 23990ms
> ThisTarget pointcut matchInternal: 7795ms
>
> Timing: time spent in pipeline weaving: 44233ms
> Timing ------------
> Unable to load cache.
>
>
>
>
>
>
>
> -----Original Message-----
> From: aspectj-users-bounces@xxxxxxxxxxx [mailto:aspectj-users-bounces@xxxxxxxxxxx] On Behalf Of Andy Clement
> Sent: Samstag, 10. Oktober 2009 03:07
> To: aspectj-users@xxxxxxxxxxx
> Subject: Re: [aspectj-users] Overall problem with AJDT performance
>
> One more thing...  I had an idea that it could be some of the
> assumptions in our pointcut rewriter don't suit your scenario.  All
> pointcuts are processed such that the cheaper tests are run first.  We
> currently consider 'call' cheaper than 'this' - but it could be for
> certain combinations of wildcarding in the call() that this() could be
> evaluated faster (this may even be the case in general, but I haven't
> thought that full through yet).  Anyway, I've uploaded one final zip
> at:
>
> http://www.eclipse.org/downloads/download.php?file=/tools/aspectj/dev/timedAspectJ3.zip
>
> In this zip I have reversed the costs and this() will be evaluated
> before call().  If this makes a positive impact for you we can looking
> adding some more smarts in the pointcut rewriter.
>
> Andy.
>
> 2009/10/9 Andy Clement <andrew.clement@xxxxxxxxx>:
>> new zip (has a 2 on the end of the name):
>>
>> http://www.eclipse.org/downloads/download.php?file=/tools/aspectj/dev/timedAspectJ2.zip
>>
>> this will produce 4 new numbers.
>> The time spent matching kinded pointcuts (which include call).
>> The number of times the kinded pointcut matcher is called.
>> Of that time, the amount actually spent computing the xlint.
>> The time spent matching this/target pointcuts.
>>
>> Kinded pointcut matchInternal(): 9438ms
>> Kinded pointcut match calls: 517465
>> Kinded pointcut xlinttime: 1463ms
>> ThisTarget pointcut matchInternal: 9ms
>>
>> And
>>
>> 2009/10/9 Andy Clement <andrew.clement@xxxxxxxxx>:
>>> I don't think you need to collect any more necessarily - we can spot
>>> the culprit in that trace :)
>>>
>>>> Breakdown of time spent in type weaver instances:
>>>> class prep = 0ms
>>>> typeWeaving = 0ms
>>>> decaWeaving = 0ms
>>>> fastShadowMatching = 0ms
>>>> shadowMatching = 122806ms
>>>> shadowWeaving = 0ms
>>>> postWeave = 3ms
>>>> Total =122811ms
>>>
>>> As we suspected, it is matching.  Surprised the weaving time is 0
>>> though.  And absolutely no fast matching.  That is where including
>>> within() with any execution()s would help (if you can).
>>>
>>> Next breakdown will be into where the shadow matching time is spent.
>>> I imagine it is millions of potential call joinpoints.  I'll be in
>>> touch with another timer zip shortly.
>>>
>>> To turn off the xlint go to project properties, AspectJ compiler, and
>>> turn off 'Unmatched super type in call pointcut designator'
>>>
>>> Andy
>>>
>>> 2009/10/9 Thomas Hofmann <email@xxxxxxxxxxxxxxxxx>:
>>>> Hi Andy,
>>>>
>>>> thanks for the zips. Here is a first result:
>>>>
>>>> 21:59:2 Compiler configuration for project com.dcx.ivkmds.fwk.test.ass doesn't know previous state, so assuming EVERYTHING has changed.
>>>> 21:59:2 ===========================================================================================
>>>> 21:59:2 Build kind = FULLBUILD
>>>> 21:59:2 Project=com.dcx.ivkmds.fwk.test.ass, kind of build requested=Full AspectJ compilation
>>>> 21:59:2 Timer event: 0ms: Flush included source file cache
>>>> 21:59:2 Timer event: 0ms: Check delta
>>>> 21:59:2 Builder: Tidied output folder(s), removed class files and derived resources
>>>> 21:59:2 Timer event: 526ms: Pre compile
>>>> 21:59:2 Compiler configuration for project com.dcx.ivkmds.fwk.test.ass has been read by compiler.  Resetting.
>>>> 21:59:2      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
>>>>
>>>> 21:59:2 Resetting list of modified source files.  Was null
>>>> 21:59:2 Preparing for build: not going to be incremental because no successful previous full build
>>>> 21:59:4 Timer event: 1141ms: Time to first compiled message
>>>> 21:59:4 Timer event: 1974ms: Time to first woven message
>>>> 22:1:9 AspectJ reports build successful, build was: FULL
>>>> 22:1:9 AJDE Callback: finish. Was full build: true
>>>> 22:1:9 Timer event: 126764ms: Total time spent in AJDE
>>>> 22:1:9 Timer event: 0ms: Refresh after build
>>>> 22:1:9 Types affected during build = 24
>>>> 22:1:9 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): com.dcx.ivkmds.fwk.test.ass
>>>> 22:1:9 Timer event: 127389ms: Total time spent in AJBuilder.build()
>>>> 22:1:9 Timer event: 16ms: Delete markers: com.dcx.ivkmds.fwk.test.ass (Finished deleting markers for com.dcx.ivkmds.fwk.test.ass)
>>>> 22:1:9 Timer event: 20ms: Delete markers: com.dcx.ivkmds._00_fwktest.ass (Finished deleting markers for com.dcx.ivkmds._00_fwktest.ass)
>>>> 22:1:13 Timer event: 3915ms: Create markers: com.dcx.ivkmds._00_fwktest.ass (Finished creating markers for com.dcx.ivkmds._00_fwktest.ass)
>>>> 22:1:13 Created 179 markers in 4 files
>>>> 22:1:16 Timer event: 12ms: Delete markers: com.dcx.ivkmds.fwk.test.ass (Finished deleting markers for com.dcx.ivkmds.fwk.test.ass)
>>>> 22:1:16 Timer event: 175ms: Delete markers: com.dcx.ivkmds.common.businessobjects.fwktest (Finished deleting markers for com.dcx.ivkmds.common.businessobjects.fwktest)
>>>> 22:1:19 Timer event: 2941ms: Create markers: com.dcx.ivkmds.common.businessobjects.fwktest (Finished creating markers for com.dcx.ivkmds.common.businessobjects.fwktest)
>>>> 22:1:19 Created 111 markers in 32 files
>>>> 22:1:24 Timer event: 7906ms: Create markers: com.dcx.ivkmds.fwk.test.ass (Finished creating markers for com.dcx.ivkmds.fwk.test.ass)
>>>> 22:1:24 Created 572 markers in 24 files
>>>>
>>>>
>>>> Timing ------------
>>>> Entire time spent in the weaver instance created for this build:
>>>>> performing model repairs=0ms
>>>>> reweavable processing=0ms
>>>>> verifying consistency=1ms
>>>>> weaving aspects=828ms
>>>>> weaving classes=123344ms
>>>>  for those two weave steps, time spent pre-post calling the individual type wea
>>>> ver instance: 37ms
>>>>> weaving normal itds=24ms
>>>>> weaving structural itds=1ms
>>>>
>>>> Breakdown of time spent in type weaver instances:
>>>> class prep = 0ms
>>>> typeWeaving = 0ms
>>>> decaWeaving = 0ms
>>>> fastShadowMatching = 0ms
>>>> shadowMatching = 122806ms
>>>> shadowWeaving = 0ms
>>>> postWeave = 3ms
>>>> Total =122811ms
>>>>
>>>> Timing: time spent in pipeline weaving: 124700ms
>>>> Timing ------------
>>>>
>>>>
>>>> More later...
>>>>
>>>>
>>>>
>>>>
>>>> -----Original Message-----
>>>> From: aspectj-users-bounces@xxxxxxxxxxx [mailto:aspectj-users-bounces@xxxxxxxxxxx] On Behalf Of Andy Clement
>>>> Sent: Freitag, 9. Oktober 2009 17:57
>>>> To: aspectj-users@xxxxxxxxxxx
>>>> Subject: Re: [aspectj-users] Overall problem with AJDT performance
>>>>
>>>> Hi Thomas,
>>>>
>>>> I've put a zip up on our download site containing two jars that
>>>> produce timing information.  The zip is here:
>>>>
>>>> http://www.eclipse.org/downloads/download.php?file=/tools/aspectj/dev/timedAspectJ.zip
>>>>
>>>> It contains jars ajde.jar and aspectjweaver.jar
>>>>
>>>> These are replacements for the jars in your org.aspectj.ajde and
>>>> org.aspectj.weaver plugins (in your eclipse plugins folder).  So
>>>> backup the jars you have and replace them with these.
>>>>
>>>> Now run your eclipse with the console view (-consolelog).
>>>>
>>>> When you build a project you should then see per build output like
>>>> this (I built a 1000 file project here as an example:)
>>>>
>>>> Timing ------------
>>>> Entire time spent in the weaver instance created for this build:
>>>>> performing model repairs=4ms
>>>>> reweavable processing=10ms
>>>>> verifying consistency=6ms
>>>>> weaving aspects=454ms
>>>>> weaving classes=27433ms
>>>>  for those two weave steps, time spent pre-post calling the
>>>> individual type weaver instance: 916ms
>>>>> weaving normal itds=45ms
>>>>> weaving structural itds=56ms
>>>>
>>>> Breakdown of time spent in type weaver instances:
>>>> class prep = 154ms
>>>> typeWeaving = 32ms
>>>> decaWeaving = 19ms
>>>> fastShadowMatching = 56ms
>>>> shadowMatching = 19303ms
>>>> shadowWeaving = 0ms
>>>> postWeave = 789ms
>>>> Total =20356ms
>>>>
>>>> Timing: time spent in pipeline weaving: 31963ms
>>>> Timing ------------
>>>>
>>>> That initial information will enable us to go into the right area
>>>> next.  Feel free to start emailing me directly rather than using the
>>>> list, or raise a bug and we can communicate through that.  Oh, I would
>>>> turn off build automatically and just build a single project so we
>>>> know what we are dealing with.  I guess it doesn't matter which, just
>>>> one you think is taking too long (I'd saying anything over a 1 or 2
>>>> minutes is too long).
>>>>
>>>> Your use of 'call()' is interesting and the fact that you get that
>>>> Xlint out.  But let's start with this.  I guess we are currently going
>>>> to suspect your shadowMatching time will be large.  Then we can look
>>>> at which parts of shadowmatching are taking a long time.  The use of
>>>> within() rather than relying on the declaring type in an execution()
>>>> pointcut to limit what is woven would enable the fastMatching time
>>>> above to increase and the shadowMatching time to decrease because
>>>> within() supports fast match and execution does not.  within() and
>>>> call() is not such a useful combination.  I might rework these timers
>>>> into something more permanent in the codebase.
>>>>
>>>> Andy
>>>>
>>>> 2009/10/9 Thomas Hofmann <email@xxxxxxxxxxxxxxxxx>:
>>>>> Hi Andy,
>>>>>
>>>>> yes we have Ant driven builds. One for the Rich Client Application (based on Eclipse RCP) and one for the J2EE server part that produces an EAR file.
>>>>> The former runs about 12-15 minutes but it does not contain the projects with .ass. in the project / package names. The project that took more than 12 minutes to build was one of these server projects. The other one was a test project which also isn't part of the client build. The creation of the EAR file uses Ant tasks that take what is already compiled in the eclipse workspace so I have no other numbers for that part.
>>>>>
>>>>> I'm not sure if my pointcuts are well written. My experience with AspectJ is not that big. Anyway, I can say that the aspects that are woven into the application.ass project (the one that takes more than 12 minutes) don't use within().I'm not quite sure what would be the benefit of using within. Almost all classes in the project need to have the advice applied.
>>>>>
>>>>> I'm using mostly execution and call together with matching based on types.
>>>>>
>>>>> Let me give you some more details for the most problematic project:
>>>>> com.dcx.ivkmds.application.ass
>>>>>
>>>>> It contains repositories that handle persistence using Hibernate internally. There is a Java interface and an implementation based on Hibernate for each repository. In addition there are some utility classes but only a few.
>>>>>
>>>>> I don't see how within() would make much difference in terms of types affected (but of course I would like to learn if I'm wrong).
>>>>>
>>>>> The aspects that are applied reside in another project: com.dcx.ivkmds.fwk.ass. This a part of our "framework". The aspects in this project apply to other projects that make use of the framework, not just to com.dcx.ivkmds.application.ass.
>>>>>
>>>>> com.dcx.ivkmds.fwk.ass contains the following aspects:
>>>>>
>>>>> AssComponentAspect:
>>>>> Contains ITDs for all classes that implement the AssComponent interface.
>>>>>
>>>>> BaseSessionLifecycleControl:
>>>>> Is an abstract aspect that contains an around advice to open and close the Hibernate session. It contains an abstract pointcut that subclasses of the aspect may you to specify the boundaries for Hibernate sessions.
>>>>>
>>>>> SessionLifecycleControl:
>>>>> A concrete subclass of BaseSessionLifecycleControl. It contains the pointcut that determines where the advice is to be applied.
>>>>>
>>>>> MeasuringPoint:
>>>>> Contains pointcuts and advice for performance logging.
>>>>>
>>>>> DatabaseConnectionCustomization:
>>>>> Contains two after advices and one before advice to make 3rd party JDBC driver specific calls on the JDBC connection when a new connection is retrieved.
>>>>>
>>>>> DatabaseErrorTransformation:
>>>>> Uses an around advice to add special error handling for exceptions from the database. The are inspected and transformed to application specific exception types.
>>>>>
>>>>>
>>>>> Only the last three aspects apply to the classes in com.dcx.ivkmds.application.ass.
>>>>>
>>>>> Will the other three aspects visible on the aspect path of com.dcx.ivkmds.application.ass have a great negative performance impact? Would this require within()?
>>>>>
>>>>> What I don't like about within() is that it kind of turns dependencies around. If I need to specify within() in the aspects that are part of the framework I need to know what other parts of the framework make use of them.
>>>>> I even have to make the clients of the framework visible to the framework. This would result in cycles I believe.
>>>>>
>>>>> I would be glad to try out a debug build that would provide more insight into where the time is spent.
>>>>> Regarding yourkit I can only say that I don't have a license for it. I could probably use the 15 day evalutation version but would need to get some instructions on how to configure it to filter the classes your are interessted in.
>>>>>
>>>>> My eclipse wasn't running short of memory. Heap space was 1200 MB. During the build 600-900 MB were used (which is too much - but this is a different issue).
>>>>>
>>>>> I can give you more details on the aspects but I don't want to spam the mailing list. So please tell me if you think this is the right place to discuss these issues. I could also open a bug in bugzilla or we could use direct email or skype for example to exchange further details.
>>>>> Posting lots of source code to the mailing list or bugzilla is not what I want to do. I would prefer direct (not public) communication for this.
>>>>>
>>>>> Do you see any obvious problems with the setup I described above?
>>>>>
>>>>> Regards,
>>>>>
>>>>> Thomas
>>>>>
>>>>>
>>>>> -----Original Message-----
>>>>> From: aspectj-users-bounces@xxxxxxxxxxx [mailto:aspectj-users-bounces@xxxxxxxxxxx] On Behalf Of Andy Clement
>>>>> Sent: Donnerstag, 8. Oktober 2009 17:37
>>>>> To: aspectj-users@xxxxxxxxxxx
>>>>> Subject: Re: [aspectj-users] Overall problem with AJDT performance
>>>>>
>>>>> Hi Thomas,
>>>>>
>>>>> Those build times do look unreasonable.  Do you do product builds
>>>>> outside of eclipse (perhaps Ant driven) - do these builds exhibit the
>>>>> same issue?
>>>>>
>>>>> I've never seen a project build take 12minutes so clearly something
>>>>> unusual is happening.  I presume all your aspects are using well
>>>>> written pointcuts that involve scoping within() clauses and don't just
>>>>> attempt matching with just kinded pointcuts (like execution).  To see
>>>>> all the affected joinpoints in one place, you can turn on the
>>>>> weaveinfo info messages for the project.  Are you using ITDs?
>>>>>
>>>>> I think we need more visibility into the build time - I could do you a
>>>>> debug build of the plugins that will include extra stats about where
>>>>> the time goes.  (Or even better you could do a yourkit profile and
>>>>> send it to me? That would make it obvious).
>>>>>
>>>>> Oh, and is your eclipse running tight on memory?  I wondered if you
>>>>> were running near the limit and it was thrashing.
>>>>>
>>>>> Andy
>>>>>
>>>>>
>>>>> 2009/10/8 Thomas Hofmann <email@xxxxxxxxxxxxxxxxx>:
>>>>>> Hi Andy, Andrew J
>>>>>>
>>>>>>
>>>>>>
>>>>>> I'm still having problems with the performance of AJDT and AspectJ in my
>>>>>> workspace.
>>>>>>
>>>>>>
>>>>>>
>>>>>> Let me start by describing my environment:
>>>>>>
>>>>>>
>>>>>>
>>>>>> Thinkpad T61p
>>>>>>
>>>>>>
>>>>>>
>>>>>> Eclipse Java EE IDE for Web Developers.
>>>>>>
>>>>>> Version: 1.2.0.20090621-0820
>>>>>>
>>>>>> Build id: 20090621-0832
>>>>>>
>>>>>> based on Eclipse 3.5.0
>>>>>>
>>>>>>
>>>>>>
>>>>>> Version: 2.0.1.e35x-20091001-1600
>>>>>>
>>>>>> AspectJ version: 1.6.6.20090930185500
>>>>>>
>>>>>>
>>>>>>
>>>>>> The workspace contains about 148 Java projects (and some others like
>>>>>> features, project set projects etc.)
>>>>>>
>>>>>>
>>>>>>
>>>>>> I disabled Build Automatically, restarted Eclipse and then cleaned the whole
>>>>>> workspace. Then I started the build with Build All. The AJDT trace was set
>>>>>> to the default values and opened. It is attached to this mail.
>>>>>>
>>>>>>
>>>>>>
>>>>>> Here are the most relevant parts:
>>>>>>
>>>>>>
>>>>>>
>>>>>> Line 192: 13:50:34 Project=com.dcx.ivkmds.application.ass, kind of build
>>>>>> requested=Full AspectJ compilation
>>>>>>
>>>>>> Line 208: 14:3:17 Types affected during build = 292
>>>>>>
>>>>>> Line 211:Timer event: 766396ms: Total time spent in AJBuilder.build() ->
>>>>>> more than 12 minutes!
>>>>>>
>>>>>> Line 707: 14:22:6 Timer event: 117857ms: Create markers:
>>>>>> com.dcx.ivkmds.application.ass (Finished creating markers for
>>>>>> com.dcx.ivkmds.application.ass)
>>>>>>
>>>>>>
>>>>>>
>>>>>> Line 370: 14:10:32 Project=com.dcx.ivkmds.fwk.test.ass, kind of build
>>>>>> requested=Full AspectJ compilation
>>>>>>
>>>>>> Line 387: 14:18:45 Types affected during build = 24
>>>>>>
>>>>>> Line 390; 14:18:46 Timer event: 493759ms: Total time spent in
>>>>>> AJBuilder.build() -> more than 8 minutes!
>>>>>>
>>>>>>
>>>>>>
>>>>>> Line 701: 14:21:10 Timer event: 62468ms: Create markers:
>>>>>> com.dcx.ivkmds.fwk.test.ass (Finished creating markers for
>>>>>> com.dcx.ivkmds.fwk.test.ass)
>>>>>>
>>>>>>
>>>>>>
>>>>>> I figure that the types in these projects have a lot of joinpoints. Is there
>>>>>> any place where I can see the number of joinpoints in these projects?
>>>>>>
>>>>>>
>>>>>>
>>>>>> Actually, the number of types involved isn't very high I would say.
>>>>>>
>>>>>>
>>>>>>
>>>>>> So the question is are these compile / weave times normal? For us it is a
>>>>>> major problem when the time to rebuild the whole workspace takes 38 minutes.
>>>>>>
>>>>>>
>>>>>>
>>>>>> Is there anything I could try to do to improve the performance besides
>>>>>> reducing the number of joinpoints?
>>>>>>
>>>>>>
>>>>>>
>>>>>> I really like the benefit AspectJ provides but under these circumstances it
>>>>>> is very unpleasant and difficult to work with it.
>>>>>>
>>>>>>
>>>>>>
>>>>>> I'm looking forward to your reply.
>>>>>>
>>>>>>
>>>>>>
>>>>>> Regards,
>>>>>>
>>>>>>
>>>>>>
>>>>>> Thomas
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> _______________________________________________
>>>>>> aspectj-users mailing list
>>>>>> aspectj-users@xxxxxxxxxxx
>>>>>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>>>>>
>>>>>>
>>>>> _______________________________________________
>>>>> aspectj-users mailing list
>>>>> aspectj-users@xxxxxxxxxxx
>>>>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>>>> _______________________________________________
>>>>> aspectj-users mailing list
>>>>> aspectj-users@xxxxxxxxxxx
>>>>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>>>>
>>>> _______________________________________________
>>>> aspectj-users mailing list
>>>> aspectj-users@xxxxxxxxxxx
>>>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>>> _______________________________________________
>>>> aspectj-users mailing list
>>>> aspectj-users@xxxxxxxxxxx
>>>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>>>
>>>
>>
> _______________________________________________
> aspectj-users mailing list
> aspectj-users@xxxxxxxxxxx
> https://dev.eclipse.org/mailman/listinfo/aspectj-users
> _______________________________________________
> aspectj-users mailing list
> aspectj-users@xxxxxxxxxxx
> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>
_______________________________________________
aspectj-users mailing list
aspectj-users@xxxxxxxxxxx
https://dev.eclipse.org/mailman/listinfo/aspectj-users


Back to the top