Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
Re: [ajdt-dev] AJDT Performance Issues

Hi Andy,

 

Thanks for taking the time to respond and providing me with very relevant information..

 

Here are a few responses and follow-up questions

 

·         We are using 2.2.3 of AJDT in Eclipse 4.3. We’ve left AJDT using the default RT JAR (1.7.3). I did try it on 1.8.1 but there was no obvious difference.

·         We do not have any cflow pointcuts

·         I wonder if it’s more popular to use aspect with LTW insead of CTW. Perhaps we are approaching this wrong.

·         10404 marker might be about right.. we’re advising all getter and setters in our entities as you say 14 * 700 would get you this and 14 attributes on average in an entity would sound correct.

·         In relation to the markers I’ve attached a file with a few back to back “clean project” calls.. The marker creation times are about 30 sec (299509 à 318863)

o    When profiling and looking at the output I did notice that our project has LOTS of compiler warnings (un-used imports, raw types, type safety, deprecated API calls etc). Would this be adding an extra overhead to AJDT that JDT manages better?

cid:image008.png@01CFDF33.77B46170

·          

·         You are correct the timings I was providing were compile + weave times… Prior to making our AspectJ project an eclipse FULL compile was taking roughly 70 seconds.. So it’s now 1.5 times slower?

o    I’m guessing what makes us more conscious of a FULL compile time now is it seems to occur much more frequently now that the builder is the ajbuilder and we have acpects.. I’m guessing the triggers which I’ve seen in AJDT Trace are affected by the type of pointcuts we have defined. So even though we have Incremental enabled a lot of the time if decides to do a FULL build rather than incremental

·         I have grepped for “org.aspectj.weaver.WeaverState” and it is only in the  700 classes we except to weaved so I’m guessing the other types are that debug information the compiler added.. Also the advise markers and cross references in Eclipse have always looked pretty correct.

·         I have attempted to use the non-standard compiler options you mentioned in another blog post. This improves the stability of Eclipse greatly as much less memory is used however weaving takes much longer initially

 

17:46:49 Timer event: 2609387ms: Total time spent in AJBuilder.build()

·         So the profiling… I’ve attached the file with the profiling output

o    None of these numbers are particularly shocking…. So I assume these times are not per class file but an overall time spent matching for full weave?

o    The obvious big number is the call advise.. We hope to remove this and place the logic in an execute

o    We do use within() to limit the pointcuts to classes annotated with @Entity yet and we know it only weaves 700 classes yet it seems to find types:#17731 on fast match.. Is within() not behaving as expected

§  Perhaps other wildcard pointcuts are making the match not so certain?

·         When we weave in our build (via ANT) we weave into the byte code.. We invoke the weave command 12 times to account for the various modules and the total time spent weaving is about 2 mins… Which suggests weaving requires a significant amount of time.

o    Unfortunately we are not in a position to split out our eclipse project based on these modules delineations

·         I’ve also attached our aspect (minus the code in the advices) in case that helps when reviewing

 

Thanks again for helping with this.

 

Rich

 

From: ajdt-dev-bounces@xxxxxxxxxxx [mailto:ajdt-dev-bounces@xxxxxxxxxxx] On Behalf Of Andy Clement
Sent: 02 October 2014 17:42
To:
ajdt-dev@xxxxxxxxxxx; aspectj-users@xxxxxxxxxxx
Subject: Re: [ajdt-dev] AJDT Performance Issues

 

Hi Rich,

 

Very fortunate I happened to check this ajdt mailing list, I don't do it very often. I tend to hang around on the aspectj users/dev list (or stack overflow) - that might be a better place for the discussion (at least more people will see the discussion).

 

Anyway, there is a lot to talk about there but let me start at the beginning:

 

> At this time we have defined a single aspect file which contains ~9 pointcuts and ~ 8 join-points..

 

You don't define join points. You define pointcuts:

 

pointcut p(): execution(* somemethod(..));

 

and advice attached to pointcuts:

 

before(): p() {...}

 

Join points are matched by pointcuts. Every program has lots of join points but using the pointcut patterns AspectJ selects a subset to which the advice gets attached.

 

 

> I think my terminology is correct in saying we have mostly statically determined pointcuts. 

 

That is great that they are statically determinable but the cost for matching each one can vary wildly depending on the which elements of the pointcut are specified and which are wildcarded. Using annotations or type names can speed up matching (as large numbers of join points can be dismissed very quickly) but I know you have said you don't want to specify type or package names.

 

> Right now the pointcuts do have lots of operators (mainly OR’s). Are these know to be less performant? 

 

Doesn't really matter about the operators. All pointcuts are translated into a DNF form and the individual components are sorted to ensure those cheaper to analyze are first.

 

> In terms of “Execution Time” the weave process takes ~2.5 mins.

 

When you say 'weave time' should I assume you mean compile and weave time? i.e. the time from when you press 'clean project' to the time when the whole process finishes?  If your project is an AspectJ project then AspectJ is responsible for compilation and weaving - for compilation it is using a modified variant of the JDT compiler.

 

> Our eclipse project is large. It consists of 11334 types (files). Of these types we’re expecting that only types annotated with @Entity (~700 classes) would be weaved. But AJDT seems to report that 10404 makers are created and if I search the generated bytecode 19228 class files (of 21058) have references to “org.aspectj” in the bytecode. However only the @Entity classes have the inner $AjcClosure classes so I’m guessing it is advising correctly. Inspecting the non @Entity bytecode which does have references to “org.aspectj” it typically seems to be something like

> org.aspectj.weaver.MethodDeclarationLineNumber: length = 0x8

>  

> Reading online this seems to be some form of debug information? So what we are seeing it is taking 2.5mins+ and potentially weaving more than it should.

 

grepping through the byte code isn't a great way to tell what was woven. The MethodDeclarationLineNumbers are used if something is advised since Java does not include the line numbers for method declarations. It is produced during compilation, *not* during weaving. I would expect all classes compiled in an AspectJ project to have these MethodDeclarationLineNumber elements in them (if they contain method declarations) so I presume that is why 19228 of your 21058 files have them. If you want to identify which files have actually been woven, grep the byte code for the attribute 'org.aspectj.weaver.WeaverState'. My gut reaction is that 10404 markers feels like a lot but I suppose if you have 700 classes that should be advised, it is only 14 per file.  In the markers view in eclipse have you seen any markers that look wrong?

 

Perhaps we need to tweak our pointcuts to skip over classes quicker?

 

Yes, I'm more suspicious of the matching time for pointcuts than the actual weaving time. You don't mention what version of AJDT you are on, I hope it is something recent?

 

I wrote an article a while back on profiling how long your pointcuts are taking to match:

 

 

And here is one on how to see that information in AJDT:

 

 

It would be interesting to know if you have any pointcuts that are spending a lot of time in the matching.  And whether you are using the more adventurous pointcut designators like cflow.

 

> Is it possible to turn off markers (or perhaps only install the weaver) and not take advantage of advise markers.

 

I've often thought we need that but I don't think we have it right now. Are you able to do a command line build of this project - how does that compare when AJDT is not in the loop?

 

 

I'm certainly happy to work with you to dig into this. Taking a look at the pointcuts may be the next step.

 

cheers,

Andy

 

On 26 September 2014 05:24, Richard Fanning <Richard.Fanning@xxxxxxxxxx> wrote:

Hi there,

 

We’re recently started a proof of concept of using AOP (AspectJ) in our existing product/project. At this time we have defined a single aspect file which contains ~9 pointcuts and ~ 8 join-points.. I think my terminology is correct in saying we have mostly statically determined pointcuts. Right now the pointcuts do have lots of operators (mainly OR’s). Are these know to be less performant? The aspect lives in a framework JAR and projects which use this framework configure Eclipse with the framework JAR in the Aspect path.

 

We’re encountering some performance problems weaving using AJDT in Eclipse and was hoping for some recommendations from this mailing list.

 

I’d categorize the performance problems as follows

 

1.       Execution Time

2.       Memory and hanging up Eclipse

 

In terms of “Execution Time” the weave process takes ~2.5 mins. Full output attached but here are snippets from AJDT trace

 

11:1:59 Timer event: 212035ms: Total time spent in AJBuilder.build()                                    This is after initial startup

11:7:3 Timer event: 141006ms: Total time spent in AJBuilder.build()                                     This is after subsequently doing a CLEAN build

 

11:2:23 Created 10404 markers in 11334 files

11:7:17 Created 10404 markers in 11334 files

 

 

Our eclipse project is large. It consists of 11334 types (files). Of these types we’re expecting that only types annotated with @Entity (~700 classes) would be weaved. But AJDT seems to report that 10404 makers are created and if I search the generated bytecode 19228 class files (of 21058) have references to “org.aspectj” in the bytecode. However only the @Entity classes have the inner $AjcClosure classes so I’m guessing it is advising correctly. Inspecting the non @Entity bytecode which does have references to “org.aspectj” it typically seems to be something like

 

org.aspectj.weaver.MethodDeclarationLineNumber: length = 0x8

 

Reading online this seems to be some form of debug information? So what we are seeing it is taking 2.5mins+ and potentially weaving more than it should. Our aspect does not / can not filter by package.. Does not filter by class name (i.e. our Entity classes are not postfixed with Entity i.e. AccountEntity). Our eclipse setup right now intermingles @Entity classes with other code so we cannot in Eclipse specify an inpath of certain class folders. We are using compile time byte code weaving so can’t use an aop.xml to filter.. So for now let’s assume re-organising the project is not an option where should be look for improving this performance? We are trying to target ~ 700 classes of ~12000 and targeting the classes by classes annotated with @Entity and the aspect then advises various methods of that class. Is that execution time about right? Perhaps we need to tweak our pointcuts to skip over classes quicker?

 

In terms of 2) Memory usage and eclipse hanging up it’s been a bit of a struggle for developers in Eclipse.. We have incremental compilation enabled but waiting 2.5mins at times really kills productivity. On top of the wait time even with eclipse.ini configured with lots of RAM and multiple VM tuning settings we often need to restart eclipse because

 

A.      It runs out of memory. Here are some graphics of the memory spikes for the executions above

 

First Execution

 

cid:image001.jpg@01CFDF2F.24A2CDE0  cid:image002.jpg@01CFDF2F.24A2CDE0

 

 

Second Execution (can still see first)

 

cid:image003.jpg@01CFDF2F.24A2CDE0  cid:image004.jpg@01CFDF2F.24A2CDE0

 

Profiling CPU using jvisualvm seems to be a pretty IO intensive operation (as expected)

 

cid:image005.jpg@01CFDF2F.24A2CDE0

       

        Here is a graphic of a heap dump I took at one point… Could there be a leak at play?

 

cid:image006.jpg@01CFDF2F.24A2CDE0

 

B.      Secondly on occasion the “Delete & Update markers” process will completely hang blocking other threads in Eclipse. It appears as if we’ve entered a loop of some sort.

 

cid:image007.jpg@01CFDF2F.24A2CDE0

 

Is it possible to turn off markers (or perhaps only install the weaver) and not take advantage of advise markers.

 

 

My Environment

 

·         Windows 7, Oracle (Sun) JDK Java 7_45 64bit, 8GB RAM, i7 quad core processor

 

Here are some of the setting from eclipse.ini… Some of these have improved things somewhat

 

 

-Xms1024m

-Xmx4048m

-XX:MaxPermSize=512m

-Xverify:none

-XX:+UseG1GC

-XX:-DontCompileHugeMethods

-XX:MaxInlineSize=1024 

-XX:FreqInlineSize=1024

-Xss1m

-XX:+UseCMSCompactAtFullCollection

-XX:+CMSClassUnloadingEnabled

-XX:+DoEscapeAnalysis

-XX:+UseCompressedOops

-XX:+AggressiveOpts

-XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses

 

Any recommendations/advice would be greatly appreciated. Let me know if you need additional information.

 

Thanks

 

Rich

 

__________________________________________________________
FINEOS Corporation is the global brand name of FINEOS Corporation and its affiliated
group companies worldwide.

The information contained in this e-mail is confidential, may be privileged and is intended
only for the use of the recipient named above. If you are not the intended recipient or a
representative of the intended recipient, you have received this e-mail in error and must
not copy, use or disclose the contents of this e-mail to anybody else. 

If you have received this e-mail in error, please notify the sender immediately by return
e-mail and permanently delete the copy you received.  This e-mail has been swept for
computer viruses. However, you should carry out your own virus checks.
Registered in Ireland, No. 205721.  http://www.FINEOS.com
__________________________________________________________

15:53:6 Startup information: 
   AJDT version: 2.2.3.e43x-RELEASE-20130627-0800
   AspectJ Compiler version: 1.7.3
   usingVisualiser=true
   usingXref=true
   usingCUprovider=true
   org.eclipse.ajdt.internal.ui.tracing.checked.filters = set: Compiler,Builder
   ajde.version.at.previous.startup = 2.2.3.e43x-RELEASE-20130627-0800
15:53:43 Compiler configuration for project FO_JEE6 doesn't know previous state, so assuming EVERYTHING has changed.
15:53:43 ===========================================================================================
15:53:43 Build kind = AUTOBUILD
15:53:43 Project=FO_JEE6, kind of build requested=Incremental AspectJ compilation
15:53:43 Timer event: 1ms: Flush included source file cache
15:53:43 Timer event: 137ms: Check delta
15:53:43 CoreCompilerConfiguration for project FO_JEE6 registered a configuration change: [JAVAOPTIONS_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED]
15:53:43 Timer event: 55ms: Looking for and marking configuration changes in FO_JEE6
15:53:43 	Configuration changes found: true
15:53:43 Timer event: 55ms: Look for source/resource changes
15:53:57 Builder: Tidied output folder(s), removed class files and derived resources
15:54:0 Timer event: 17254ms: Pre compile
15:54:6 Compiler configuration for project FO_JEE6 has been read by compiler.  Resetting.
15:54:6      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
15:54:6 Resetting list of modified source files.  Was null
15:54:6 Preparing for build: not going to be incremental because no successful previous full build
15:54:36 Timer event: 36230ms: Time to first compiled message
15:54:36 Timer event: 36239ms: Time to first woven message
15:57:12 AspectJ reports build successful, build was: FULL
15:57:12 AJDE Callback: finish. Was full build: true
15:57:12 Timer event: 192019ms: Total time spent in AJDE
15:57:12 Timer event: 0ms: Refresh after build
15:57:18 Types affected during build = 11335
15:57:31 Timer event: 228014ms: Total time spent in AJBuilder.build()
15:57:31 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): FO_JEE6
15:57:31 ===========================================================================================
15:57:31 Build kind = FULLBUILD
15:57:31 Project=FO_JEE6, kind of build requested=Full AspectJ compilation
15:57:31 Timer event: 0ms: Flush included source file cache
15:57:31 Timer event: 0ms: Check delta
15:57:39 Builder: Tidied output folder(s), removed class files and derived resources
15:57:40 Timer event: 8903ms: Pre compile
15:57:40 Timer event: 9408ms: Delete markers: FO_JEE6 (Finished deleting markers for FO_JEE6)
15:57:41 Timer event: 487ms: Create markers: FO_JEE6 (Finished creating markers for FO_JEE6)
15:57:41 Created 0 markers in 11334 files
15:57:44 Compiler configuration for project FO_JEE6 has been read by compiler.  Resetting.
15:57:44      Configuration was []
15:57:44 Resetting list of modified source files.  Was []
15:57:44 Preparing for build: not going to be incremental because no successful previous full build
15:57:59 Timer event: 19189ms: Time to first compiled message
15:57:59 Timer event: 19193ms: Time to first woven message
15:59:52 AspectJ reports build successful, build was: FULL
15:59:52 AJDE Callback: finish. Was full build: true
15:59:52 Timer event: 131683ms: Total time spent in AJDE
15:59:52 Timer event: 0ms: Refresh after build
15:59:58 Types affected during build = 11335
16:0:5 Timer event: 153354ms: Total time spent in AJBuilder.build()
16:0:5 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): FO_JEE6
16:0:5 Timer event: 63ms: Delete markers: FO_JEE6 (Finished deleting markers for FO_JEE6)
16:5:4 Timer event: 299509ms: Create markers: FO_JEE6 (Finished creating markers for FO_JEE6)
16:5:4 Created 10404 markers in 11335 files
16:6:46 Removed problems and tasks for project FO_JEE6
16:6:55 Builder: Tidied output folder(s), removed class files and derived resources
16:6:55 Timer event: 91ms: Delete markers: FO_JEE6 (Finished deleting markers for FO_JEE6)
16:6:55 Compiler configuration for project FO_JEE6 doesn't know previous state, so assuming EVERYTHING has changed.
16:6:55 ===========================================================================================
16:6:55 Build kind = FULLBUILD
16:6:55 Project=FO_JEE6, kind of build requested=Full AspectJ compilation
16:6:55 Timer event: 0ms: Flush included source file cache
16:6:55 Timer event: 0ms: Check delta
16:6:55 Builder: Tidied output folder(s), removed class files and derived resources
16:6:57 Timer event: 1654ms: Pre compile
16:7:0 Compiler configuration for project FO_JEE6 has been read by compiler.  Resetting.
16:7:0      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
16:7:0 Resetting list of modified source files.  Was null
16:7:0 Preparing for build: not going to be incremental because no successful previous full build
16:7:22 Timer event: 25799ms: Time to first compiled message
16:7:22 Timer event: 25803ms: Time to first woven message
16:8:58 AspectJ reports build successful, build was: FULL
16:8:58 AJDE Callback: finish. Was full build: true
16:8:58 Timer event: 121224ms: Total time spent in AJDE
16:8:58 Timer event: 0ms: Refresh after build
16:9:4 Types affected during build = 11335
16:9:10 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): FO_JEE6
16:9:10 Timer event: 134943ms: Total time spent in AJBuilder.build()
16:9:10 Timer event: 183ms: Delete markers: FO_JEE6 (Finished deleting markers for FO_JEE6)
16:14:29 Timer event: 318863ms: Create markers: FO_JEE6 (Finished creating markers for FO_JEE6)
16:14:29 Created 10404 markers in 11335 files
14:49:37 Startup information: 
   AJDT version: 2.2.3.e43x-RELEASE-20130627-0800
   AspectJ Compiler version: 1.7.3
   usingVisualiser=true
   usingXref=true
   usingCUprovider=true
   org.eclipse.ajdt.internal.ui.tracing.checked.filters = set: Compiler,Builder
   ajde.version.at.previous.startup = 2.2.3.e43x-RELEASE-20130627-0800
14:49:37 Compiler configuration for project FO_JEE6 doesn't know previous state, so assuming EVERYTHING has changed.
14:49:37 ===========================================================================================
14:49:37 Build kind = AUTOBUILD
14:49:37 Project=FO_JEE6, kind of build requested=Incremental AspectJ compilation
14:49:37 Timer event: 2ms: Flush included source file cache
14:49:37 Timer event: 95ms: Check delta
14:49:37 Timer event: 1ms: Looking for and marking configuration changes in FO_JEE6
14:49:37 	Configuration changes found: false
14:49:37 build: Examined delta - no source file or classpath changes for project FO_JEE6
14:49:37 Timer event: 0ms: Looking for and marking configuration changes in FO_JEE6
14:49:37 	Configuration changes found: false
14:49:37 Compiler configuration for project FO_JEE6 has been read by compiler.  Resetting.
14:49:37      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
14:49:37 Resetting list of modified source files.  Was null
14:49:37 Timer event: 9ms: Look for source/resource changes
14:49:37 No source/resource changes found, exiting build
14:49:37 Timer event: 133ms: Total time spent in AJBuilder.build()
14:50:46 Removed problems and tasks for project FO_JEE6
14:51:1 Builder: Tidied output folder(s), removed class files and derived resources
14:51:1 Timer event: 152ms: Delete markers: FO_JEE6 (Finished deleting markers for FO_JEE6)
14:51:1 Compiler configuration for project FO_JEE6 doesn't know previous state, so assuming EVERYTHING has changed.
14:51:1 ===========================================================================================
14:51:1 Build kind = FULLBUILD
14:51:1 Project=FO_JEE6, kind of build requested=Full AspectJ compilation
14:51:1 Timer event: 0ms: Flush included source file cache
14:51:1 Timer event: 0ms: Check delta
14:51:1 Builder: Tidied output folder(s), removed class files and derived resources
14:51:4 Timer event: 3293ms: Pre compile
14:51:11 Compiler configuration for project FO_JEE6 has been read by compiler.  Resetting.
14:51:11      Configuration was [PROJECTSOURCEFILES_CHANGED, JAVAOPTIONS_CHANGED, ASPECTPATH_CHANGED, CLASSPATH_CHANGED, INPATH_CHANGED, NONSTANDARDOPTIONS_CHANGED, OUTJAR_CHANGED, PROJECTSOURCERESOURCES_CHANGED, OUTPUTDESTINATIONS_CHANGED, INJARS_CHANGED]
14:51:11 Resetting list of modified source files.  Was null
14:51:11 Preparing for build: not going to be incremental because no successful previous full build
14:51:42 Timer event: 37507ms: Time to first compiled message
14:51:42 Timer event: 37518ms: Time to first woven message
14:55:47 AspectJ reports build successful, build was: FULL
14:55:47 Pointcut matching cost (total=11505ms for 282774 joinpoint match calls):
14:55:47 Time:379ms (jps:#95866) matching against ((((within((@com.abc.bo.annotation.Entity *)) && execution(void set*((java.lang.String || (java.math.BigDecimal || (com.abc.types.TaBlob || (boolean || (com.abc.util.DateTime || (com.abc.util.DateOnly || (long || (int || (com.abc.kernel.Money || (com.abc.kernel.TaEnum || com.abc.kernel.ITaEnum))))))))))))) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 1))) && args(BindingTypePattern(java.lang.Object, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:139ms (jps:#17927) matching against (((within((@com.abc.bo.annotation.Entity *)) && execution(new(..))) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:9080ms (jps:#64374) matching against ((!within(com.abc.bo.BusinessEntityRef+) && call(com.abc.bo.BusinessEntityImpl+.new(..))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:928ms (jps:#11671) matching against (((((((((within((@com.abc.bo.annotation.Entity *)) && !get(@com.abc.bo.annotation.Transient private * *)) && !execution(public java.lang.String com.abc.bo.BusinessEntityImpl+.getBOCaption())) && !execution(public int com.abc.bo.BusinessEntityImpl+.getClassId())) && execution((java.lang.String || (java.math.BigDecimal || (com.abc.types.TaBlob || (boolean || (com.abc.util.DateTime || (com.abc.util.DateOnly || (long || (int || (com.abc.kernel.Money || (com.abc.kernel.TaEnum || com.abc.kernel.ITaEnum)))))))))) com.abc.bo.BusinessEntityImpl+.get*())) && !execution(public * com.abc.bo.BusinessEntityImpl+.*ConcurrentGuard())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && !target(com.abc.bo.BusinessEntityImpl)) && persingleton(com.abc.EntityAspect)) || (((((((((within((@com.abc.bo.annotation.Entity *)) && !get(@com.abc.bo.annotation.Transient private * *)) && !execution(public java.lang.String com.abc.bo.BusinessEntityImpl+.getBOCaption())) && !execution(public int com.abc.bo.BusinessEntityImpl+.getClassId())) && execution((java.lang.String || (java.math.BigDecimal || (com.abc.types.TaBlob || (boolean || (com.abc.util.DateTime || (com.abc.util.DateOnly || (long || (int || (com.abc.kernel.Money || (com.abc.kernel.TaEnum || com.abc.kernel.ITaEnum)))))))))) com.abc.bo.BusinessEntityImpl+.get*())) && !execution(com.abc.bo.BusinessEntity+ com.abc.bo.BusinessEntityImpl+.get*())) && !execution(public * com.abc.bo.BusinessEntityImpl+.*ConcurrentGuard())) && !execution(List<(com.abc.bo.BusinessEntity+)> com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)))
14:55:47 Time:240ms (jps:#57923) matching against (((within((@com.abc.bo.annotation.Entity *)) && set(@com.abc.bo.annotation.OneToOne private * *)) && args(BindingTypePattern(java.lang.Object, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:140ms (jps:#11671) matching against (((within((@com.abc.bo.annotation.Entity *)) && execution(Rel<(com.abc.bo.BusinessEntity+)> com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:310ms (jps:#11671) matching against ((((within((@com.abc.bo.annotation.Entity *)) && execution(com.abc.bo.BusinessEntity+ com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)) || (((within((@com.abc.bo.annotation.Entity *)) && execution(List<(com.abc.bo.BusinessEntity+)> com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)))
14:55:47 Time:285ms (jps:#11671) matching against ((((((within((@com.abc.bo.annotation.Entity *)) && execution(boolean com.abc.bo.BusinessEntityImpl+.add*(com.abc.bo.BusinessEntityImpl+))) && !execution(boolean com.abc.bo.BusinessEntityImpl+.removeThe*(com.abc.bo.BusinessEntityImpl+))) && args(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)) || ((((within((@com.abc.bo.annotation.Entity *)) && execution(boolean com.abc.bo.BusinessEntityImpl+.remove*(com.abc.bo.BusinessEntityImpl+))) && !execution(boolean com.abc.bo.BusinessEntityImpl+.removeThe*(com.abc.bo.BusinessEntityImpl+))) && args(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect))) || ((((within((@com.abc.bo.annotation.Entity *)) && execution(void com.abc.bo.BusinessEntityImpl+.set*((com.abc.bo.BusinessEntityImpl+ || List<(com.abc.bo.BusinessEntity+)>)))) && !execution(boolean com.abc.bo.BusinessEntityImpl+.removeThe*(com.abc.bo.BusinessEntityImpl+))) && args(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)))
14:55:47 ---
14:55:47 Pointcut fast matching cost (total=5816ms for 141848 fast match calls):
14:55:47 Time:34ms (types:#17731) fast matching against ((((within((@com.abc.bo.annotation.Entity *)) && execution(void set*((java.lang.String || (java.math.BigDecimal || (com.abc.types.TaBlob || (boolean || (com.abc.util.DateTime || (com.abc.util.DateOnly || (long || (int || (com.abc.kernel.Money || (com.abc.kernel.TaEnum || com.abc.kernel.ITaEnum))))))))))))) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 1))) && args(BindingTypePattern(java.lang.Object, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:59ms (types:#17731) fast matching against (((within((@com.abc.bo.annotation.Entity *)) && execution(new(..))) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:854ms (types:#17731) fast matching against ((!within(com.abc.bo.BusinessEntityRef+) && call(com.abc.bo.BusinessEntityImpl+.new(..))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:12ms (types:#17731) fast matching against (((within((@com.abc.bo.annotation.Entity *)) && set(@com.abc.bo.annotation.OneToOne private * *)) && args(BindingTypePattern(java.lang.Object, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:3894ms (types:#17731) fast matching against (((((((((within((@com.abc.bo.annotation.Entity *)) && !get(@com.abc.bo.annotation.Transient private * *)) && !execution(public java.lang.String com.abc.bo.BusinessEntityImpl+.getBOCaption())) && !execution(public int com.abc.bo.BusinessEntityImpl+.getClassId())) && execution((java.lang.String || (java.math.BigDecimal || (com.abc.types.TaBlob || (boolean || (com.abc.util.DateTime || (com.abc.util.DateOnly || (long || (int || (com.abc.kernel.Money || (com.abc.kernel.TaEnum || com.abc.kernel.ITaEnum)))))))))) com.abc.bo.BusinessEntityImpl+.get*())) && !execution(public * com.abc.bo.BusinessEntityImpl+.*ConcurrentGuard())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && !target(com.abc.bo.BusinessEntityImpl)) && persingleton(com.abc.EntityAspect)) || (((((((((within((@com.abc.bo.annotation.Entity *)) && !get(@com.abc.bo.annotation.Transient private * *)) && !execution(public java.lang.String com.abc.bo.BusinessEntityImpl+.getBOCaption())) && !execution(public int com.abc.bo.BusinessEntityImpl+.getClassId())) && execution((java.lang.String || (java.math.BigDecimal || (com.abc.types.TaBlob || (boolean || (com.abc.util.DateTime || (com.abc.util.DateOnly || (long || (int || (com.abc.kernel.Money || (com.abc.kernel.TaEnum || com.abc.kernel.ITaEnum)))))))))) com.abc.bo.BusinessEntityImpl+.get*())) && !execution(com.abc.bo.BusinessEntity+ com.abc.bo.BusinessEntityImpl+.get*())) && !execution(public * com.abc.bo.BusinessEntityImpl+.*ConcurrentGuard())) && !execution(List<(com.abc.bo.BusinessEntity+)> com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)))
14:55:47 Time:108ms (types:#17731) fast matching against (((within((@com.abc.bo.annotation.Entity *)) && execution(Rel<(com.abc.bo.BusinessEntity+)> com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect))
14:55:47 Time:320ms (types:#17731) fast matching against ((((within((@com.abc.bo.annotation.Entity *)) && execution(com.abc.bo.BusinessEntity+ com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)) || (((within((@com.abc.bo.annotation.Entity *)) && execution(List<(com.abc.bo.BusinessEntity+)> com.abc.bo.BusinessEntityImpl+.get*())) && target(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)))
14:55:47 Time:531ms (types:#17731) fast matching against ((((((within((@com.abc.bo.annotation.Entity *)) && execution(boolean com.abc.bo.BusinessEntityImpl+.add*(com.abc.bo.BusinessEntityImpl+))) && !execution(boolean com.abc.bo.BusinessEntityImpl+.removeThe*(com.abc.bo.BusinessEntityImpl+))) && args(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)) || ((((within((@com.abc.bo.annotation.Entity *)) && execution(boolean com.abc.bo.BusinessEntityImpl+.remove*(com.abc.bo.BusinessEntityImpl+))) && !execution(boolean com.abc.bo.BusinessEntityImpl+.removeThe*(com.abc.bo.BusinessEntityImpl+))) && args(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect))) || ((((within((@com.abc.bo.annotation.Entity *)) && execution(void com.abc.bo.BusinessEntityImpl+.set*((com.abc.bo.BusinessEntityImpl+ || List<(com.abc.bo.BusinessEntity+)>)))) && !execution(boolean com.abc.bo.BusinessEntityImpl+.removeThe*(com.abc.bo.BusinessEntityImpl+))) && args(BindingTypePattern(com.abc.bo.BusinessEntityImpl, 0))) && persingleton(com.abc.EntityAspect)))
14:55:47 ---
14:55:47 AJDE Callback: finish. Was full build: true
14:55:47 AJDE Callback: finish. Was full build: true
14:55:47 Timer event: 282589ms: Total time spent in AJDE
14:55:47 Timer event: 0ms: Refresh after build
14:55:52 Printing crosscutting model for all AspectJ projects in the workspace
14:55:52 
14:55:52 --------------------------------------
14:55:52 Printing crosscutting model for FO_JEE6
14:55:52 No structure model available for FO_JEE6
14:55:52 --------------------------------------
14:55:52 
14:56:3 Types affected during build = 11335
14:56:20 Timer event: 319227ms: Total time spent in AJBuilder.build()
14:56:21 Timer event: 361ms: Delete markers: FO_JEE6 (Finished deleting markers for FO_JEE6)
15:16:38 Timer event: 1217622ms: Create markers: FO_JEE6 (Finished creating markers for FO_JEE6)
15:16:38 Created 10404 markers in 11335 files
15:21:35 Timer event: 0ms: Update visualizer, xref, advice listeners for (separate thread): FO_JEE6

Attachment: EntityAspect.aj
Description: EntityAspect.aj


Back to the top