0

I am trying to add Pointcut on execution of a method to total time taken by method to execute. But my pointcut is not getting called. Similar method which does not throws any exception , pointcut for that method is being called.I am not able to findout the exact root cause or issue with my pointcut expression.

@Pointcut(
  value =
      "execution(* com.customer.service.ExecuteCustomerService.initiateExecuteCustomer(..))")
private void logExecuteCustomer() {}

 @Around(
  value ="logExecuteCustomer()")
public Object TimerMonitoring(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
MethodSignature methodSignature = (MethodSignature) proceedingJoinPoint.getSignature();

// calculate method execution time
long startTime = System.currentTimeMillis();
Object result = proceedingJoinPoint.proceed();
long endTime = System.currentTimeMillis();

try {
  String desc =
      methodSignature.getDeclaringType().getSimpleName() + "." + methodSignature.getName();

  metricsService.metricsTimer(desc, (endTime - startTime));
} catch (Exception exception) {
  log.error("Error while processing metrics ", exception);
}
return result;
}

Method

public void initiateExecuteCustomer(
  ChargeTransaction chargeTransactionFromKafka, boolean ignoreCollectionDate)
  throws CustomerException {
String key = LOGGER_KEY + chargeTransactionFromKafka.getOrderNo();
long serviceStartTime = System.currentTimeMillis();
// some java code
}
Loren
  • 320
  • 1
  • 10
  • 25
  • I doubt it is the exception. One thing is that your around advice is a bit strange, I would expect the proceed to be executed in a `try/finally` block so that you always record metrics. Also Spring by default uses proxy based AOP so if you are internally calling this method this won't pass through the proxy but directly invoke the method on the target object. – M. Deinum Apr 24 '23 at 08:52
  • @M.Deinum If something is failing in proceed.. then also atleast it should atleast enter the method.. in debug mode I tested that this around is not being invoked only for this method – Loren Apr 24 '23 at 11:49
  • As mentioned (if you read the whole comment) it won't work for internal method invocations and I suspect you are calling this method internally. – M. Deinum Apr 24 '23 at 11:51

1 Answers1

0

Like M.Deinum said (credit to him for that), your aspect is simply implemented incorrectly. The logging code is simply never reached in case of an exception while proceeding to the original method. Try this (untested, just copied from your sample code and edited):

@Pointcut("execution(* com.customer.service.ExecuteCustomerService.initiateExecuteCustomer(..))")
private void logExecuteCustomer() {}

@Around("logExecuteCustomer()")
public Object TimerMonitoring(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
  MethodSignature methodSignature = (MethodSignature) proceedingJoinPoint.getSignature();
  long startTime = System.currentTimeMillis();
  try {
    return proceedingJoinPoint.proceed();
  }
  finally {
    try {
      String desc = methodSignature.getDeclaringType().getSimpleName() + "." + methodSignature.getName();
      metricsService.metricsTimer(desc, System.currentTimeMillis() - startTime);
    } catch (Exception exception) {
      log.error("Error while processing metrics ", exception);
    }
  }
}

Or you just avoid bits and pieces from the method signature and simply log the whole joinpoint, keeping the code simple:

@Around("logExecuteCustomer()")
public Object TimerMonitoring(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
  long startTime = System.currentTimeMillis();
  try {
    return proceedingJoinPoint.proceed();
  }
  finally {
    try {
      metricsService.metricsTimer(proceedingJoinPoint.toString(), System.currentTimeMillis() - startTime);
    } catch (Exception exception) {
      log.error("Error while processing metrics ", exception);
    }
  }
}
kriegaex
  • 63,017
  • 15
  • 111
  • 202