(Spring) AOP Design of Transactions

Question

In our application we have several transactions, where each step is extensively logged.

Pseudocode:

@Component
public class OurServiceImpl implements OurService {

...
    @Transactional
    public void doComplexTransaction(...){
      String transactionId = generateTransactionId(userid, date)
      log.info("==========================Start Transaction" + transactionId);

      log.info("Doing A");
      doA(..., transcationId);

      log.info("Doing B");
      doB(..., transcationId);

      log.info("Doing C");
      doC(... transcationId);

      log.info("==========================End Transaction" + transactionId);
    }

...

    public void doA(..., transactionId){

      ...

      log.info("Doing SubA "+transactionId);
      doSubA();
    }

}

Because the logging is distracting, we decided to use AOP for that. The method doComplexTransaction(..) could be covered with @Around(execution(FQN.doComplexTransaction(..)))

The calls doA(), doB() and doC() could be refactored out to another class, so they could be covered with @Around likewise.

But then the following problem occurs:

How to pass the transcationId (generated in one advice) between different advices?

Or more general:

How to design "transactional logging (with identifier)" across several methodcalls and objects?

Could this be done with Spring-AOP?

My goal is to discern the different concurrent transactions in my log, that would make it easy queryable via elasticsearch et al.

Bruteforce-solution:

(similar to Steve Park's)

One idea, which I had, was generating the transactionId in the first advice and "inject" it for further calls in proceedingJoinPoint.proceed(..., transactionId). In any further advice, I could extract thetransactionIdvia.getArgs()and inject it in theproceed()`-call.

But this has two downsides:

1) It is aesthetically non pleasant, or just: awkward. It's a hack, though a working one.

2) This violates several design principles, first: the principle of least astonishment. If a reviewer looks at the POJO and sees a variable passed but never "used" - thanks to AOP - he would be at least astonished.

So, yes, that is one solution, but I am looking for a better one.

Answer 1

I'm not sure whether I fully understand your intention or not, but you don't need to pass transactionId between advices if you just want to get the transactionId on new advice, since you can get it from JoinPoint object. If I assume you setup new Around advice to cover the join points (doA, doB and doC on new service), all the input arguments on those join points (doA, doB and doC) are available from the JoinPoint object by getArgs() method like below. So, you just need to iterate input arguments with checking instance type or order of input argument to find the string type transactionId. I just refactor doA, doB and doC on AnotherSerivce to use Around advice.

OurService

@Service("ourService")
public class OurServiceImpl implements OurService {
    static Logger log = Logger.getLogger(OurServiceImpl.class.getName());

    @Autowired
    private AnotherService anotherService;

    @Override
    public void doComplexTransaction() {
        String transactionId = generateTransactionId(userid, date);
        anotherService.doA(transactionId);
        anotherService.doB(transactionId);
        anotherService.doC(transactionId);
    }

Service contains doA, doB and doC methods

@Service("anotherService")
public class AnotherServiceImpl implements AnotherService {
    static Logger log = Logger.getLogger(AnotherServiceImpl.class.getName());

    @Override
    public void doA(String transactionId) {
        // TODO Auto-generated method stub
        log.info("test inside of doA");
    }

    @Override
    public void doB(String transactionId) {
        // TODO Auto-generated method stub
        log.info("test inside of doB");
    }

    @Override
    public void doC(String transactionIds) {
        // TODO Auto-generated method stub
        log.info("test inside of doC");
    }
}

Aspect to track doA, doB and doC

@Aspect
@Component
public class TransactionTracker {

    static Logger log = Logger.getLogger(TransactionTracker.class.getName());

    @Around(value="execution(* com.my.AnotherServiceImpl.do*(..)) " )
    public void aroundProcess(ProceedingJoinPoint joinPoint) throws Throwable {
        Object[] args = joinPoint.getArgs();
        for(Object arg: args) {
            if(arg instanceof String) {
                log.info("Get string type input argument: ".concat(arg.toString()));
            }
        }
        try {
            joinPoint.proceed(args);
        } catch(Exception e) {
            log.error(e.getMessage());
            throw e;
        }
    }

    @Around(value="execution(* com.my.OurServiceImpl.do*(..)) " )
    public void aroundProcessForOurService(ProceedingJoinPoint joinPoint) throws Throwable {
        Object[] args = joinPoint.getArgs();
        log.info("start transaction");

        try {
            joinPoint.proceed(args);
        } catch(Exception e) {
            log.error(e.getMessage());
            throw e;
        }
        log.info("end transaction");
    }
}

app config file

@Configuration
@EnableAutoConfiguration
@EnableAspectJAutoProxy
@ComponentScan("com.my")
public class AppConfig {

}