Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
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:

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

2009/3/22 Oliver Böhm <boehm@xxxxxxxxxx <mailto:boehm@xxxxxxxxxx>>

    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@xxxxxxxxxx
        <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 list
        aspectj-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@xxxxxxxxxxx <mailto: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

--
Oliver Böhm
http://www.javatux.de


Back to the top