I have a spring AOP Aspect class which logs every time a service is invoked, I'm planning on printing more information in the logs, this time there will be unique identifier for each request, this identifier is stored in a request scoped object until the service returns. I tried injecting the request object into the @Aspect, it does not seem to work well.
If there is only one advice, it worked the one time I invoked the service, if i add more advices, it gives error.(end of the question)
@Aspect
public class LoggingAspect {
private Logger log = Logger.getLogger(getClass());
@Autowired
public RequestScopeObject params;
@Pointcut("within(net.company.dao..*)")
private void clDaoLayer() {
}
private String uniqueIdentifier(){
String uid = "";
if(this.params!=null && this.params.getId()!= null){
uid = "ID:"+this.params.getId()+" ";
}else{
uid = "";
}
return uid;
}
@Around("clDaoLayer()")
public Object clDaoLayerAdvice(ProceedingJoinPoint joinPoint)
throws Throwable {
String TAG = uniqueIdentifier();
// gets the system property dynamically for debugging purpose.
this.printObject = Boolean.parseBoolean(System.getProperty("printobject"));
Date start = new Date();
String methodInExcecuting = getSignature(joinPoint);
log.debug(TAG+"calling method.." + methodInExcecuting
+ " with arguments : " + Arrays.toString(joinPoint.getArgs()));
Object result = null;
String slug = "";
try {
result = joinPoint.proceed();
} catch (Exception e) {
log.error(TAG+" Exception .." + methodInExcecuting, e);
throw e;
}
try {
if (printObject == true) {
if (result == null) {
slug = " null ";
} else if (result instanceof List) {
slug = ((List) result).toString() + "\n"
+ ((List) result).size() + "";
} else if (result.getClass().toString().indexOf("[L") >= 0) {// if
// array
// get
// length
slug = ArrayUtils.toString(result) + ". "
+ ArrayUtils.getLength(result);
} else if (result != null) {
slug = result.toString() + ". 1 value ";
}
slug += "\nvalues/rows returned.";
} else {
slug = "";
}
} catch (Exception e) {
log.debug(TAG+"Error getting slug..");
}
Date end = new Date();
log.debug(TAG+" Time taken: "
+ (end.getTime() - start.getTime()) + " milliseconds."+"returning from " + methodInExcecuting + ". " + slug);
return result;
}
}
Error from the logs
java.lang.reflect.UndeclaredThrowableException
at org.jboss.ws.core.server.ServiceEndpointInvoker.invoke(ServiceEndpointInvoker.java:228)
at org.jboss.wsf.stack.jbws.RequestHandlerImpl.processRequest(RequestHandlerImpl.java:474)
at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleRequest(RequestHandlerImpl.java:295)
at org.jboss.wsf.stack.jbws.RequestHandlerImpl.doPost(RequestHandlerImpl.java:205)
at org.jboss.wsf.stack.jbws.RequestHandlerImpl.handleHttpRequest(RequestHandlerImpl.java:131)
at org.jboss.wsf.common.servlet.AbstractEndpointServlet.service(AbstractEndpointServlet.java:85)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:190)
at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:92)
at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126)
at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:598)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:447)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.StackOverflowError
at java.util.Date.<init>(Date.java:146)
at net.LoggingAspect.restClientHelperAdvice(LoggingAspect.java:134)
at sun.reflect.GeneratedMethodAccessor317.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at $Proxy593.getId(Unknown Source)
I have used the help of ThreadLocal for maintaining the info I'd like to print. I have used the static variable for holding the threadlocal variables
public class WorkThreadLocal {
public static ThreadLocal<String> id = new ThreadLocal<String>(){
@Override
protected String initialValue()
{
return "";
}
};
}
Updated LogginAspect.java is below
@Aspect
public class LoggingAspect {
private Logger log = Logger.getLogger(getClass());
@Autowired
public RequestScopeObject params;
@Pointcut("within(net.company.dao..*)")
private void clDaoLayer() {
}
private String uniqueIdentifier(){
String uid = "";
if (WorkThreadLocal.mwi != null) {
uid = WorkThreadLocal.id.get() + " ";
}
return uid;
}
@Around("clDaoLayer()")
public Object clDaoLayerAdvice(ProceedingJoinPoint joinPoint)
throws Throwable {
String TAG = uniqueIdentifier();
// gets the system property dynamically for debugging purpose.
this.printObject = Boolean.parseBoolean(System.getProperty("printobject"));
Date start = new Date();
String methodInExcecuting = getSignature(joinPoint);
log.debug(TAG+"calling method.." + methodInExcecuting
+ " with arguments : " + Arrays.toString(joinPoint.getArgs()));
Object result = null;
String slug = "";
try {
result = joinPoint.proceed();
} catch (Exception e) {
log.error(TAG+" Exception .." + methodInExcecuting, e);
throw e;
}
try {
if (printObject == true) {
if (result == null) {
slug = " null ";
} else if (result instanceof List) {
slug = ((List) result).toString() + "\n"
+ ((List) result).size() + "";
} else if (result.getClass().toString().indexOf("[L") >= 0) {// if
// array
// get
// length
slug = ArrayUtils.toString(result) + ". "
+ ArrayUtils.getLength(result);
} else if (result != null) {
slug = result.toString() + ". 1 value ";
}
slug += "\nvalues/rows returned.";
} else {
slug = "";
}
} catch (Exception e) {
log.debug(TAG+"Error getting slug..");
}
Date end = new Date();
log.debug(TAG+" Time taken: "
+ (end.getTime() - start.getTime()) + " milliseconds."+"returning from " + methodInExcecuting + ". " + slug);
return result;
}
}