I've got a JEE application with some performance issues. I suspect that it
is due to MQ listeners (MessageDrivenBeans) that are not executing enough
threads concurrently and figured that an easy way to validate my theory
would be to write a quick Aspect to profile the number of threads being
triggered at the same time.
I'm using LTW in the rest of my application, so trying to use LTW for this
aspect as well.
While my Aspect works in theory, it seems to be advising the "wrong" beans;
that is- it is picking out what seem to be container generated beans
instead of my primary beans, and consequently, it is providing false
information. The 5 listeners that I want to advise extend a common
Abstract class which implements the onMessage() method. I'm trying to
advise this method for all beans.
My Aspect is as follows:
@Aspect("pertypewithin(business.security.tables.mq.*)")
public class ListenerThreadLoggingAspect {
// get a static slf4j logger for the class
protected static final Logger logger =
getLogger(ListenerThreadLoggingAspect.class);
private static AtomicInteger concurrentThreadCount = new AtomicInteger(0);
// pointcut to pick out the onMessage() method
@Pointcut("execution(!synthetic *
(*..mq.AbstractSecurityAccessTableListener+ &&
!*..mq.AbstractSecurityAccessTableListener).onMessage(..))")
public void onMessagePointcut() {
}
@Around("onMessagePointcut()")
public Object logThreadCount(ProceedingJoinPoint pjp) throws Throwable {
// entering message handler, so increment threads and log
int concurrentThreads = concurrentThreadCount.incrementAndGet();
logger.debug("ID[{}]: Start [{}]. Concurrent Threads: {}",
System.identityHashCode(this), pjp.getTarget().getClass().getName(),
concurrentThreads);
// execute the listener
Object result = pjp.proceed();
// done so decrement number of threads
concurrentThreads = concurrentThreadCount.decrementAndGet();
logger.trace("ID[{}]: Stop [{}]. Concurrent Threads: {}",
System.identityHashCode(this), pjp.getTarget().getClass().getName(),
concurrentThreads);
return result;
}
}
While the weaver indicates that the correct classes are being woven, the
execution shows a different trace:
2019-02-10 11:59:33,036 ERROR (default-threads - 5) [stderr]
[ModuleClassLoader@572dc861] weaveinfo Join point 'method-execution(void
business.security.tables.mq.SecurityAccessTablePurgeListener$$$endpoint11.onMessage(javax.jms.Message))'
in Type
'business.security.tables.mq.SecurityAccessTablePurgeListener$$$endpoint11'
(no debug info available) advised by around advice from
'izone.common.security.access.ListenerThreadLoggingAspect'
(ListenerThreadLoggingAspect.java)
2019-02-10 11:59:33,124 ERROR (default-threads - 4) [stderr]
[ModuleClassLoader@572dc861] weaveinfo Join point 'method-execution(void
business.security.tables.mq.SecurityAccessTableConsumeListener$$$endpoint14.onMessage(javax.jms.Message))'
in Type
'business.security.tables.mq.SecurityAccessTableConsumeListener$$$endpoint14'
(no debug info available) advised by around advice from
'izone.common.security.access.ListenerThreadLoggingAspect'
(ListenerThreadLoggingAspect.java)
2019-02-10 11:59:33,187 ERROR (default-threads - 10) [stderr]
[ModuleClassLoader@572dc861] weaveinfo Join point 'method-execution(void
business.security.tables.mq.SecurityAccessTableRequestListener$$$endpoint12.onMessage(javax.jms.Message))'
in Type
'business.security.tables.mq.SecurityAccessTableRequestListener$$$endpoint12'
(no debug info available) advised by around advice from
'izone.common.security.access.ListenerThreadLoggingAspect'
(ListenerThreadLoggingAspect.java)
2019-02-10 11:59:33,296 ERROR (default-threads - 7) [stderr]
[ModuleClassLoader@572dc861] weaveinfo Join point 'method-execution(void
business.security.tables.mq.SecurityAccessTableReadyListener$$$endpoint9.onMessage(javax.jms.Message))'
in Type
'business.security.tables.mq.SecurityAccessTableReadyListener$$$endpoint9'
(no debug info available) advised by around advice from
'izone.common.security.access.ListenerThreadLoggingAspect'
(ListenerThreadLoggingAspect.java)
2019-02-10 11:59:33,432 ERROR (default-threads - 6) [stderr]
[ModuleClassLoader@572dc861] weaveinfo Join point 'method-execution(void
business.security.tables.mq.SecurityAccessTableStatisticsListener$$$endpoint8.onMessage(javax.jms.Message))'
in Type
'business.security.tables.mq.SecurityAccessTableStatisticsListener$$$endpoint8'
(no debug info available) advised by around advice from
'izone.common.security.access.ListenerThreadLoggingAspect'
(ListenerThreadLoggingAspect.java)
Execution Log:
12:00:19,585 DEBUG [common.security.access.ListenerThreadLoggingAspect]
(Thread-30 (ActiveMQ-client-global-threads-508854362)) ID[1049816548]:
Start [business.securitytyAccessTableConsumeListener$$$endpoint14].
Concurrent Threads: 1
12:00:19,586 DEBUG [common.security.access.ListenerThreadLoggingAspect]
(Thread-30 (ActiveMQ-client-global-threads-508854362)) ID[984444654]:
Start [business.security.yAccessTableConsumeListener$$$view76]. Concurrent
Threads: 2
As you can see, in the Execution Log, I have 2 advised points which are
triggering the aspect:
business.securitytyAccessTableConsumeListener$$$endpoint14
business.security.yAccessTableConsumeListener$$$view76
I suspect this is due to the way Wildfly creates proxies for the EJB/MDBs
when instantiating them. However, I am not sure how to avoid this. I
_thought_ that was what the synthetic keyword would avoid, but it has made
no difference to the pointcut.
Is there a "correct" way to write this pointcut to avoid this issue and
only advise the "$$endpointXX" bean and not the "$$viewXX" bean? Excluding
it explicitly seems like an ugly hack.
Thanks,
Eric
_______________________________________________
aspectj-users mailing list
aspectj-users@eclipse.org
To change your delivery options, retrieve your password, or unsubscribe from
this list, visit
https://www.eclipse.org/mailman/listinfo/aspectj-users
