Performance issue due to repeated attempts to find classes without FQN

[harrisric]

Hi, I've been using aspectj with a very large classpath and seeing some performance issues recently. Profiling showed ClassPathManager.find as a hotspot. Further investigation led me to see that we end up repeatedly looking for classes based on an incomplete class name and that this was slow because each jar on the classpath was rechecked each time the class is referenced. The examples of this that I found were where the aspect would have a simple class name without an import, typically things from the java.lang namespace such as String or Object, or else classes that are in the same package as the aspect. Implementing a simple cache of class names that weren't found generated a significant speed up.

[kriegaex]

Thanks for the PR. Of course, I will look at your contribution benevolently. To convince me that this actually solves a real-world problem and not just take your word for it, even though what you say sounds plausible, please provide a reproducer for the issue, i.e. some kind of sample program and configuration that makes AspectJ slow before and significantly faster after your proposed change.

[harrisric]

Hi @kriegaex - thanks for the quick response. Here is an example of usage, the jar being woven isn't relevant - the performance issue is in the set up. command line for org.aspectj.tools.ajc.Main -inpath commons-lang3-3.14.0.jar -classpath lib\aspectjrt-1.9.22.jar;lib\spring-tx-5.3.33.jar;lib\commons-logging-1.3.1.jar;lib\ant-1.10.14.jar;lib\activemq-client-5.15.16.jar -aspectpath sample-aspect.jar -outjar target\some.jar -source 11 -target 11 -encoding UTF-8

In this case the first three jars are required for the classpath the rest are unnecessary but fulfill the example - the more jars you add the slower you will see the setup to be, the same is true with more aspects that have similar characteristics. With ~1000 jars on the classpath the slowdown is notable (jar renamed as a zip so that it can be attached) sample-aspect.zip

EDIT: added commons-logging to the classpath for completeness.

[kriegaex]

Thank you. Please also attach the source code and ideally also the Maven coordinates for the classpath libraries.

[harrisric]

The project to generate the sample jar is below. The maven coordinates for required classpath libraries are in the pom for that, other items on the classpath are there to prove the problem and can largely be anything you choose. sample-aspect.zip

There may be some other improvement mechanism possible that means these incomplete class names are not searched for in the first place. In this example I believe that they originate from the pointcut syntax which contains simple names from either the local namespace or java.lang.

[kriegaex]

With this project and the handful of dependencies you suggested I cannot detect any noticeable difference in performance. I need the suggested change to be verifiable and measurable. Are you expecting me to create a project with 1,000 libraries from scratch? Like I said, your PR is welcome, but you need to sell it a bit better to convince me.

[kriegaex]

I think I found a simple way to unit-test the performance. The disadvantage of my test approach is a fixed timeout, which might cause tests to be brittle, but unless I keep the old way to search find types and add a toggle to be able to compare both approaches, there is no easy way to verify the PR's effectiveness.

[harrisric]

@kriegaex I think that my original profiling may have highlighted this area more due to my usage tipping over the 1000 threshold that is the default for org.aspectj.weaver.openarchives (I spotted this later) and therefore the impact is perhaps less than originally expected. It is notably affected by the number of aspects and the number of archives on the classpath.

To see an impact I upped the number of aspects to 10 (by copying) and generated ~1000 further jars for the classpath (copying using a script to get e.g. anyjar00001.jar, ..., anyjar.00995.jar - this kept it below 1000 in total so not triggering the file closing) In this case I can see by crude timing around the "setup" I see times of ~630ms vs ~570ms with my changes, so ~10% improvement.

[kriegaex]

Merged including my test. Thank you very much for your contribution, @harrisric.