I am new to AOP and I came to know that it helps in separating crosscutting concerns, and seems to be a good feature which adds charm to OOPs programming.
As always, the classical example which I found was the "logging", in which using AOP, the logging can be done using AOP.
public void doSomething(String name, Object someObj) {
logger.info("Just entered doSomething() method));
int result;
// Some complex code
if(result != 0) {
logger.severe("There is some issues, fix it...");
// some other code
}
logger.trace("Did some more work, value is " +value);
// Other business code..
logger.info("Returning from method...");
}
Now, referring to online documentation/tutorial, the use-case of "logging advice" is that we can remove the logging code from the code and "logging advice" will do the logging, for example during entering , returning of method, using annotations.
In above example, I agree that using @Before, @After "advice" can help for entering, returning of the method call.
I am confused in how AOP helps in for the loggers which are withing inside the method, and ideally can be used anywhere, where we capture information at some point of time.
I referred to this SO question , but didn't get any clarity in how AOP can help situations like this.
Can anyone help me understand this?
The short answer is: AOP is not meant to look into your methods because methods get refactored all the time and should be considered black boxes.
So neither Spring AOP nor AspectJ will do for you what you expect them to. The idea of AOP is to implement cross-cutting concerns. Logging is but one such concern. If you think you need intra-method logging, you can still do it manually. But if clean code means anything to you, you can just refactor your code to be more maintainable (and also more logging-friendly). Methods should be short, not have too many input parameters and not too much complexity.
So you can break up your complex spaghetti code method into a set of smaller methods or even extract new classes and use those from your method. I did this for your code (see below). Furthermore, returning 0 or -1 or whatever instead of throwing an exception is not OOP but C-style programming. So instead of logging problems based on return values, log them based on thrown exceptions and handle those exceptions (or let them escalate, if there is a fatal error) according to your application logic. My sample code also shows that.
This example will work nicely with AspectJ because AspectJ is not based on delegating dynamic proxies and thus has no problems with self-invocation, e.g. internal method calls within a class.
package de.scrum_master.app;
public class UnexpectedResultException extends Exception {
private static final long serialVersionUID = 1L;
public UnexpectedResultException(String message) {
super(message);
}
}
As you can see, I have extracted a few methods from your complex one. In order to show you some more log output, I even added complexity into doSomething(..) again by calling the method doing complex stuff several times in a for-loop.
package de.scrum_master.app;
import java.util.Random;
public class Application {
public void doSomething(String name, Object someObj) {
int result = new Random().nextInt(100);
for (int counter = 0; counter < 5; counter++) {
try {
result = doComplexThing(result + 1);
} catch (UnexpectedResultException unexpectedResultException) {
result = 4;
}
}
result = doSomeMoreWork(result);
otherBusinessCode(result);
}
public int doComplexThing(int input) throws UnexpectedResultException {
if (input % 2 == 0)
throw new UnexpectedResultException("uh-oh");
return input % 5;
}
public int doSomeMoreWork(int input) {
return input * input;
}
public void otherBusinessCode(int input) {}
public static void main(String[] args) {
Application application = new Application();
application.doSomething("John Doe", new Integer(11));
}
}
The logging aspect could look like this:
package de.scrum_master.aspect;
import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.AfterThrowing;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
@Aspect
public class LoggingAspect {
@Pointcut("within (de.scrum_master.app..*) && execution(* *(..))")
private void loggingTargets() {}
@Before("loggingTargets()")
public void logEnterMethod(JoinPoint thisJoinPoint) {
System.out.println("ENTER " + thisJoinPoint);
}
@AfterReturning(pointcut = "loggingTargets()", returning = "result")
public void logExitMethod(JoinPoint thisJoinPoint, Object result) {
System.out.println("EXIT " + thisJoinPoint + " -> return value = " + result);
}
@AfterThrowing(pointcut = "loggingTargets()", throwing = "exception")
public void logException(JoinPoint thisJoinPoint, Exception exception) {
System.out.println("ERROR " + thisJoinPoint + " -> exception = " + exception);
}
}
The console log looks like this:
ENTER execution(void de.scrum_master.app.Application.main(String[]))
ENTER execution(void de.scrum_master.app.Application.doSomething(String, Object))
ENTER execution(int de.scrum_master.app.Application.doComplexThing(int))
ERROR execution(int de.scrum_master.app.Application.doComplexThing(int)) -> exception = de.scrum_master.app.UnexpectedResultException: uh-oh
ENTER execution(int de.scrum_master.app.Application.doComplexThing(int))
EXIT execution(int de.scrum_master.app.Application.doComplexThing(int)) -> return value = 0
ENTER execution(int de.scrum_master.app.Application.doComplexThing(int))
EXIT execution(int de.scrum_master.app.Application.doComplexThing(int)) -> return value = 1
ENTER execution(int de.scrum_master.app.Application.doComplexThing(int))
ERROR execution(int de.scrum_master.app.Application.doComplexThing(int)) -> exception = de.scrum_master.app.UnexpectedResultException: uh-oh
ENTER execution(int de.scrum_master.app.Application.doComplexThing(int))
EXIT execution(int de.scrum_master.app.Application.doComplexThing(int)) -> return value = 0
ENTER execution(int de.scrum_master.app.Application.doSomeMoreWork(int))
EXIT execution(int de.scrum_master.app.Application.doSomeMoreWork(int)) -> return value = 0
ENTER execution(void de.scrum_master.app.Application.otherBusinessCode(int))
EXIT execution(void de.scrum_master.app.Application.otherBusinessCode(int)) -> return value = null
EXIT execution(void de.scrum_master.app.Application.doSomething(String, Object)) -> return value = null
EXIT execution(void de.scrum_master.app.Application.main(String[])) -> return value = null
As you can see, you get all the logging you wanted to have in your initial question based on the new, more modular method structure. The old method becomes more readable and the new methods are simpler because they concentrate on doing the thing you extracted them for.
Please note: This sample code was run with AspectJ, not with the "AOP lite" framework Spring AOP. So in Spring AOP it would not work like this because:
main because it only can intercept public, non-static interface methods (when using Java dynamic proxies) or additionally protected and package-scoped methods (when using CGLIB proxies).So if you think about refactoring your code into what I suggested and also consider making some helper methods private but still want them logged, there is no other way than to configure Spring to use full AspectJ via LTW (load-time weaving) in order to use the full power of AOP.
If you rather want to stick with Spring AOP and its proxies, but still need those internally called methods logged via AOP, you need to go one step further in your refactoring and extract the three new methods into an extra Spring component/bean which you wire into your application. Then the method calls would no longer be internal but go across component/bean boundaries and thus be intercepted by a Spring AOP logging aspect.
The Application worker methods class would be extracted and called like this:
package de.scrum_master.app;
// Make this into a @Component
public class MyWorker {
public int doComplexThing(int input) throws UnexpectedResultException {
if (input % 2 == 0)
throw new UnexpectedResultException("uh-oh");
return input % 5;
}
public int doSomeMoreWork(int input) {
return input * input;
}
public void otherBusinessCode(int input) {}
}
package de.scrum_master.app;
import java.util.Random;
public class Application {
// In a Spring context this would be injected via configuration
private MyWorker worker = new MyWorker();
public void doSomething(String name, Object someObj) {
int result = new Random().nextInt(100);
for (int counter = 0; counter < 5; counter++) {
try {
result = worker.doComplexThing(result + 1);
} catch (UnexpectedResultException unexpectedResultException) {
result = 4;
}
}
result = worker.doSomeMoreWork(result);
worker.otherBusinessCode(result);
}
public static void main(String[] args) {
Application application = new Application();
application.doSomething("John Doe", new Integer(11));
}
}
The aspect can stay unchanged.
The log output changes to something like this:
ENTER execution(void de.scrum_master.app.Application.main(String[]))
ENTER execution(void de.scrum_master.app.Application.doSomething(String, Object))
ENTER execution(int de.scrum_master.app.MyWorker.doComplexThing(int))
EXIT execution(int de.scrum_master.app.MyWorker.doComplexThing(int)) -> return value = 2
ENTER execution(int de.scrum_master.app.MyWorker.doComplexThing(int))
EXIT execution(int de.scrum_master.app.MyWorker.doComplexThing(int)) -> return value = 3
ENTER execution(int de.scrum_master.app.MyWorker.doComplexThing(int))
ERROR execution(int de.scrum_master.app.MyWorker.doComplexThing(int)) -> exception = de.scrum_master.app.UnexpectedResultException: uh-oh
ENTER execution(int de.scrum_master.app.MyWorker.doComplexThing(int))
EXIT execution(int de.scrum_master.app.MyWorker.doComplexThing(int)) -> return value = 0
ENTER execution(int de.scrum_master.app.MyWorker.doComplexThing(int))
EXIT execution(int de.scrum_master.app.MyWorker.doComplexThing(int)) -> return value = 1
ENTER execution(int de.scrum_master.app.MyWorker.doSomeMoreWork(int))
EXIT execution(int de.scrum_master.app.MyWorker.doSomeMoreWork(int)) -> return value = 1
ENTER execution(void de.scrum_master.app.MyWorker.otherBusinessCode(int))
EXIT execution(void de.scrum_master.app.MyWorker.otherBusinessCode(int)) -> return value = null
EXIT execution(void de.scrum_master.app.Application.doSomething(String, Object)) -> return value = null
EXIT execution(void de.scrum_master.app.Application.main(String[])) -> return value = null