Hi,
> Are you confident your pointcuts aren't doing unnecessary matching, as
> that will also hurt startup time. Are they all using within() clauses
> to guard the set of types against which they will apply? You might
> want to use the timers support to see if the pointcuts are spending a
> lot of time matching:
>
> http://andrewclement.blogspot.com/2009/a11/aspectj-profiling-pointcut-matching.html
>
for within() clauses, I use include within options from aop.xml and only
include necessary classes, for example:
<include
within="com.services.factory.account.AccountDbServicesCareImpl"/>
<include
within="com.services.factory.mobile.MobileDbServicesCareImpl"/>
<include
within="com.services.factory.resetpassword.CommonResetPasswordServicesImpl"/>
<include within="com.services.tlg.utils.AddContractUtil"/>
<include within="com.servlets.SalesPortalServlet"/>
<include within="com.utils.CareComLogon"/>
<include within="com.utils.CareLogonUtil"/>
<include within="com.utils.CSSUtil"/>
. . . .
I have enabled the -timers option and below are from the logs:
Line 4199: [ChangeAwareClassLoader@1e50bd5] info Pointcut fast matching
cost (total=101ms for 3000 fast match calls):
Line 4226: [ChangeAwareClassLoader@1e50bd5] info Pointcut matching cost
(total=7805ms for 50000 joinpoint match calls):
I checked the time logs, most of them are about 0-2ms, several 200ish ms,
only two are outstanding (>1000ms):
fast matching:
Line 4200: [ChangeAwareClassLoader@1e50bd5] info Time:31ms (types:#428)
fast matching against ((((execution(* *(..)) &&
this(BindingTypePattern(java.lang.Object, 0))) &&
@annotation(org.springframework.transaction.annotation.Transactional)) &&
persingleton(org.springframework.transaction.aspectj.AnnotationTransactionAspect))
|| (((execution(public *
(@org.springframework.transaction.annotation.Transactional *).*(..)) &&
this(BindingTypePattern(java.lang.Object, 0))) &&
@this(org.springframework.transaction.annotation.Transactional)) &&
persingleton(org.springframework.transaction.aspectj.AnnotationTransactionAspect)))
Line 4205: [ChangeAwareClassLoader@1e50bd5] info Time:1ms (types:#108) fast
matching against (((call(*
com.cv.webservices.client.GenerateOOWQuestionsAnswers_Impl.*(..)) && if())
&& persingleton(com.aspect.CustomerVerifyAdvice)) || ((call(*
com.cv.webservices.client.GenerateOOWQuestionsAnswersPortType.*(..)) &&
if()) && persingleton(com.aspect.CustomerVerifyAdvice)))
matching:
Line 4227: [ChangeAwareClassLoader@1e50bd5] info Time:1745ms (jps:#4104)
matching against ((((execution(* *(..)) &&
this(BindingTypePattern(java.lang.Object, 0))) &&
@annotation(org.springframework.transaction.annotation.Transactional)) &&
persingleton(org.springframework.transaction.aspectj.AnnotationTransactionAspect))
|| (((execution(public *
(@org.springframework.transaction.annotation.Transactional *).*(..)) &&
this(BindingTypePattern(java.lang.Object, 0))) &&
@this(org.springframework.transaction.annotation.Transactional)) &&
persingleton(org.springframework.transaction.aspectj.AnnotationTransactionAspect)))
Line 4233: [ChangeAwareClassLoader@1e50bd5] info Time:4174ms (jps:#8095)
matching against (((call(*
com.cv.webservices.client.GenerateOOWQuestionsAnswers_Impl.*(..)) && if())
&& persingleton(com.aspect.CustomerVerifyAdvice)) || ((call(*
com.cv.webservices.client.GenerateOOWQuestionsAnswersPortType.*(..)) &&
if()) && persingleton(com.aspect.CustomerVerifyAdvice)))
However I don't think the matching time is the issue because our
application does not weave anything to the jsp classes (jsp is not even
included in our aop.xml), I checked the log all this weaving time info is
from changeAwareClassLoader only, nothing from the jspClassLoader.
I observed the log, when the jsp is loaded, changeAwareClassLoader is not
printing any log, the only related aspectj logs are registration of
jspclassloaders and the aspects.
I took the log for a page in our application and found out 8 jsp
classloaders were registered and each registration took about ~1-2s (the
log was moving slowly and after 1-2s another jsp class loader registration
started and took about the same time)
...
[JspClassLoader@14e2e89] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@14e2e89] info register classloader
weblogic.servlet.jsp.JspClassLoader@14e2e89
. . .
[JspClassLoader@1b150] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@1b150] info register classloader
weblogic.servlet.jsp.JspClassLoader@1b150
. . .
[JspClassLoader@1201afd] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@1201afd] info register classloader
weblogic.servlet.jsp.JspClassLoader@1201afd
. . .
[JspClassLoader@c0cd51] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@c0cd51] info register classloader
weblogic.servlet.jsp.JspClassLoader@c0cd51
. . .
[JspClassLoader@146b6a1] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@146b6a1] info register classloader
weblogic.servlet.jsp.JspClassLoader@146b6a1
. . .
[JspClassLoader@1b52826] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@1b52826] info register classloader
weblogic.servlet.jsp.JspClassLoader@1b52826
. . .
[JspClassLoader@1521eab] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@1521eab] info register classloader
weblogic.servlet.jsp.JspClassLoader@1521eab
. . .
[JspClassLoader@1cdee1f] info AspectJ Weaver Version 1.6.9 built on Monday
Jul 5, 2010 at 15:28:35 GMT
[JspClassLoader@1cdee1f] info register classloader
weblogic.servlet.jsp.JspClassLoader@1cdee1f
Regards,
- yohan chandra -
_______________________________________________
aspectj-users mailing list
[email protected]
https://dev.eclipse.org/mailman/listinfo/aspectj-users
