Re: [ajdt-dev] AJDT Performance Issues

[Andy Clement <andrew.clement@xxxxxxxxx>]

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:

http://andrewclement.blogspot.ca/2009/11/aspectj-profiling-pointcut-matching.html

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

http://contraptionsforprogramming.blogspot.ca/2009/11/getting-aspectj-pointcut-matching-timer.html

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

 

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

 

First Execution

 

 

 

 

Second Execution (can still see first)

 

 

 

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

 

       

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

 

 

2. 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.

 

 

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
__________________________________________________________

_______________________________________________
ajdt-dev mailing list
ajdt-dev@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/ajdt-dev