[aspectj-users] What is the correct pointcut expression to use with Prox

[Eric B <ebenzacar@xxxxxxxxx>]

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