Java(TM) Boutique - Enterprise Logging for Distributed J2EE Applications

Tutorials : Enterprise Logging for Distributed J2EE Applications :

The Transaction-based Approach

This approach exploits the fact that all the service component's session beans join the caller transaction. In other words, the transaction attribute used is "Required." So first, we used Weblogic 8.1 as the app server and Weblogic JTA to provide extensions to javax.transaction. Next, the transaction that supports the associating user-defined key/value pairs with the JTA transaction. So, we set the LRID value with the current transaction context at the point where the transaction begins. Then, during the remote call, the session bean callee would be able to retrieve the LRID value from the transaction context and store it as part of the MDC. AspectJ performs the task of setting and retrieving the LRID value transparent to the developers. We Aspect all our session bean implementations with the following aspect:

public aspect BusinessLayerSetLoggingContextAspect {
    pointcut interceptEJBMethodCall(): execution(public * javax.ejb.SessionBean+.*(..))     
	&& !execution(public * javax.ejb.SessionBean+.ejb*())    
	&& !execution(public * javax.ejb.SessionBean+.setSessionContext(javax.ejb.SessionContext)); 
   
	before():interceptEJBMethodCall () {
		Transaction transaction = (Transaction)
		TransactionHelper.getTransactionHelper().getTransaction();
		if(thisJoinPoint.getArgs()[0] instanceof ApplicationContext) {	
			//this block gets executed when transaction begins.
			ApplicationContext ctx = (ApplicationContext)thisJoinPoint.getArgs()[0];
			transaction.setProperty("LRID", ctx.getLogReferenceId());
			MDC.put("LRID", ctx.getLogReferenceId());
		} else {
			//retrieve the LRID from transaction context
			String lrid = (String) transaction.getProperty(LRID_KEY);
			MDC.put(LRID_KEY, lrid);
			}    
		}
}

Since the Web layer does not initiate the a JTA transaction, we propagated the LRID from Web layer to the business layer by adding a custom parameter called ApplicationContext to all the exposed business interfaces. ApplicationContext holds the LRID value and is assumed to be the first method parameter of the EJB remote interface.

If the above code gets blocked, it is then executed in the LoanManagerServiceBean's method retrieveLiabilitiesForLoan(loan no) since the LoanManagerServiceBean is being invoked by a Web delegate in the Credit Liability Rendering Use case. This is also where the JTA transaction starts—hence, retrieving the LRID value from the ApplicationContext object is set as part of the current transaction context. When LoanManagerServiceBean makes a remote call to StipServiceBean and CreditServiceBean, these two session beans join the transaction started by LoanManagerServiceBean and are then able to retrieve the LRID from the transaction context (above else, the block gets executed).

This approach has a few limitations:

It forces all session beans to use a transaction attribute of "Required." You may not want to do this, as it could cause a transaction to propagate or the bean to start a new transaction.
It is dependent on application server-specific API to set and retrieve the custom name/value pairs from the transaction context. This limits the app's portability to a specific server.
The session bean exposed to the Web layer has to include a custom parameter called ApplicationContext to propagate the LRID from Web layer to business layer. This can be tough to maintain, as you have to pass the context info part of the session bean APIs apart from the regular objects.

The RMI and User Principal-based Approach

In this approach, we made an assumption that only a single user will login with a given user ID at any given point of time. So, we defined an RMI implementation with methods like put(key, value) and get(key). This RMI object is then bound to the JNDI tree using a startup servlet. The servlet filter, in addition to generating the LRID, also looks up the RMI object and stores the LRID in the RMI object using the logged in user ID as the key. When the session method is invoked, the logged in user ID is retrieved using SessionContext.getCallerPrincipal().getName() and a get(user id) method is invoked on the RMI object, which retrieves the LRID and then sets it in MDC. In short, the logged in user ID is used as a joining key by the caller and the callee to retrieve the LRID from the RMI object hosted on an RMI server. Again, we used AspectJ to retrieve the LRID from the RMI server at the session bean method entry point.

This approach has one limitation: allowing a single user to logon more than once will produce indeterminate behavior—this means that ogin statements cannot be guaranteed to accompany the correct LRID.

Which Approach Did We Choose?

Because our LOS requires single user log-in only, we need to be able to port it any application server in the future. So we went for the second approach. Obviously, the specifics of your application will drive your choice of approach.

Displaying the LRID to Enable Request Traceability

In a multiple-user application, many LRIDs will be generated at any given point in time. So how do you make the LRID values accessible to developers for the given request?

One potential place to embed the LRID is in an HTML comment that then gets streamed to the browser, along with the output HTML, as shown below:

<!-- LRID value = joe--4028dd0:d767dc:109f8bbb3c9:-8000 -->

This way, a developer suspecting any misbehavior in the system—not leading to any exception in the executed use case—could view the HTML source on the Web browser, search for the LRID value, and then trace all the logs using that value.

Error Reporting and Trouble Shooting

When an error occurs, the exception stack trace is logged to the log file. Additionally, the user is redirected to a System Error page where the LRID for that request is displayed which the end user could use to report the problem to help desk. To facilitate quick resolution, logged error information must be adequate to trace the error to its source. Any logging without a mechanism for cross-reference is useless in this capacity.

In this application, the support team digs through the application logs using the LRID to understand the system behavior. Additionally, it would be beneficial if the state of the system was also dumped to the log file when the exception occurred. The business data that could comprise the system's state are:

The HttpRequest/HttpSession Object: To record the HttpRequest/HttpSession object, catch all exceptions in the Web Action class, and then dump the HttpRequest object into the log file.
The Method Call Stack (Stack of method input arguments): For the Method call stack, use an Aspect to insert a piece of code at method entry to push the method input arguments onto a stack object (to be stored in the thread local variable) and at the method exit point to pop the object from the stack.

In our application, we selected only the session bean methods to do the described push/pop operations. At each tier, the exception is intercepted (which you can set up using AspectJ) and stack object contents are dumped to the log file. The stack object data will provide the contextual business information for the request that resulted in an exception. This data will be handy when you try to reproduce the problem--since most issues are business data-driven. The Enterprise Logging solution that we implemented for LOS has proved very vital in our client's production and QA environments. We've seen that issue resolution takes less time, due to the fact that by facilitating dev/support folks can cross-reference an exception with the application logs. The fact that the solution also providesa lot of contextual business info helps to study the root cause of the exceptions.

Acknowledgements

The author would like to thank Amitav Chakravartty and Srinivas Narayanan for their valuable suggestions during working on the solution and helping to shape this article.

References

About the Author

Venkatray Kamath is a Technical Lead at Tavant Technologies India Pvt Limited, Bangalore. Venkat has four years of experience building Java enterprise applications on the J2EE platform. For the past two years, he hass been working on SOA-based applications--designing and implementing various frameworks like logging, Async Correlation Framework, Entity Caching, and Weblogic Domain Creation, to new a few.

Home / Articles / Enterprise Logging for Distributed J2EE Applications / 1 / 2 / 3 / 4 /

Applet Index
(sorted alphabetically)
A B C D E F G H I J K
L M N O P Q R S T U
V W X Y Z #s

The Java Source
(applets w/source code)
A B C D E F G H I J K
L M N O P Q R S T U
V W X Y Z

How to Add Java Applets to Your Site

New on the Java Boutique:

New Review:

Time Management Made Easy with the Quartz Enterprise Job Scheduler
Why not just use the Java timer API? This open source scheduling API boasts simplicity, ease-of-integration, a well-rounded feature set, and it's free!

New Applet:

Reverse Complement
Reverse Complement is a simple applet that converts DNA or RNA sequences into three useful formats.