Overview

Skill Level: Intermediate

Requires understanding of Java, Maven and a bit of AspectJ.

This recipe will explain the importance of tracing and demonstrate a consistent enterprise Java tracing design with the help of AspectJ and enterprise-aspects AOP Java library.

Ingredients

Tested with the following configuration:

Step-by-step

  1. What is tracing and why it is important?

    There is a distinction between logging and tracing. Where logging provides a discrete view of important application events, tracing provides continuous insight into application internal state. While logging is usually used for auditing of, for example, calls to services or log-in attempts, tracing is usually used for debugging. Below is a trace example as printed in the trace.log file:

    [10/10/19 0:13:33:810 CEST] 000003ac com.my.package > myMethod ENTRY ["Input","parameters"]
    [10/10/19 0:13:33:811 CEST] 000003ac com.my.package 1 myMethod In-method trace entry.
    [10/10/19 0:13:33:811 CEST] 000003ac com.my.package < myMethod RETURN ["Result","object"]

     Trace commonly provides the following information: trace entry timestamp, method input parameters and return value, in-method trace information and thread id which processed a method invocation (i.e. thread 000003ac); from the provided information it is possible to understand the program flow and execution duration.

    But why is tracing important? Consider the following software design questions first:

    1. How will I troubleshoot production problems for my application?
    2. How long are my clients be prepared to wait for the problem’s root cause to be discovered and the problem fixed?
    3. How can my application be supported with limited involvement of the development team?

     

    Often, the exception stack trace will not provide enough information for deducing the reason why an exception occurred, or an application may behave in unexpected ways without throwing an exception:

    1. Some activities are slower than expected,
    2. results are not as expected,
    3. sporadic errors occur.

     

    Consider how will the above production situations, which will definitively occur, be solved for your application; I have found that most often a solution to a problem is found by:

    1. Discussing a problem with the users,
    2. searching logs for exceptions,
    3. enabling trace and examining input parameters and return values of methods involved in the problem.

     

    If an application is not designed for tracing, the third option above will not be available, so your problem will be harder to solve. Therefore, tracing is important because it is an important troubleshooting tool for resolving production problems.

    Let us examine a traditional approach to Java tracing concern implementation.

     

  2. Traditional approach to Java tracing concern implementation

    Traditional tracing concern implementation approach is highlighted in the following example:

    package samples.web.rest;

    import java.util.ArrayList;
    import java.util.List;
    import java.util.logging.Logger;
    import java.util.logging.Level;

    import javax.ws.rs.GET;
    import javax.ws.rs.Path;
    import javax.ws.rs.Produces;
    import javax.ws.rs.QueryParam;
    import javax.ws.rs.core.MediaType;

    import com.github.akovac35.enterprise.aspects.common.*;

    @Path("/TraditionalJavaTracingConcern")
    @Produces({ MediaType.APPLICATION_JSON })
    public class TraditionalJavaTracingConcern {
    private final static String CLASSNAME = TraditionalJavaTracingConcern.class.getName();
    private static final Logger _logger = Logger.getLogger(CLASSNAME);

    @GET
    @Path("/doSomething")
    public List<String> doSomething(@QueryParam("input1") String input1) {
    final String METHODNAME = "doSomething";
    if (_logger.isLoggable(Level.FINER)) {
    _logger.entering(CLASSNAME, METHODNAME, new String[] {input1});
    }

    // Do some work and add tracing in case it is needed
    if (_logger.isLoggable(Level.FINE)) {
    String tmp = DefaultStringifier.stringify(new int[] {3,2,1,0});
    _logger.logp(Level.FINE, CLASSNAME, METHODNAME, "Chasing pests.", tmp);
    }

    // Do some more work and produce a return
    ArrayList<String> ret = new ArrayList<String>();
    ret.add("Not a");
    ret.add("bug");

    if (_logger.isLoggable(Level.FINER)) {
    String retStr = DefaultStringifier.stringify(ret);
    _logger.exiting(CLASSNAME, METHODNAME, retStr);
    }

    return ret;
    }
    }

    Testing result as printed in the trace.log file: 

    [10/10/19 0:13:33:810 CEST] 000003ac samples.web.rest.TraditionalJavaTracingConcern > doSomething ENTRY Testing
    [10/10/19 0:13:33:811 CEST] 000003ac samples.web.rest.TraditionalJavaTracingConcern 1 doSomething Chasing pests.
    [3,2,1,0]
    [10/10/19 0:13:33:811 CEST] 000003ac samples.web.rest.TraditionalJavaTracingConcern < doSomething RETURN ["Not a","bug"]

     

    To be useful, the above approach must be implemented consistently and with the same coding style for basically every method of an application; manual implementation thus quickly becomes costly and time-consuming. Tracing code by itself will result in undiscovered bugs that will crash the application when it is enabled, or implementation may not be consistent and will require frequent development team involvement for problem resolution.

  3. Modern approach to Java tracing concern implementation

    Let’s adopt the traditional tracing example for modern approach using AspectJ and enterprise-aspects¬†AOP Java library:

    package samples.web.rest;

    import java.util.ArrayList;
    import java.util.List;

    import javax.ws.rs.GET;
    import javax.ws.rs.Path;
    import javax.ws.rs.Produces;
    import javax.ws.rs.QueryParam;
    import javax.ws.rs.core.MediaType;

    import com.github.akovac35.enterprise.aspects.tracing.*;

    @Path("/ModernJavaTracingConcern")
    @Produces({ MediaType.APPLICATION_JSON })
    public class ModernJavaTracingConcern {
    @GET
    @Path("/doSomething")
    public List<String> doSomething(@QueryParam("input1") String input1) {
    // Do some work and add tracing in case it is needed
    TracingHelper.fine("Chasing pests.", new int[] {3,2,1,0});

    // Do some more work and produce a return
    ArrayList<String> ret = new ArrayList<String>();
    ret.add("Not a");
    ret.add("bug");

    return ret;
    }
    }

    Testing result as printed in the trace.log file:

    [10/9/19 22:52:29:188 CEST] 000001a8 samples.web.rest.ModernJavaTracingConcern > doSomething ENTRY ["Testing"]
    [10/9/19 22:52:29:189 CEST] 000001a8 samples.web.rest.ModernJavaTracingConcern 1 Chasing pests.
    [3,2,1,0]
    [10/9/19 22:52:29:191 CEST] 000001a8 samples.web.rest.ModernJavaTracingConcern < doSomething RETURN ["Not a","bug"]

     

     We can quickly see that most of the tracing code has now been eliminated with the remainder being simpler than the traditional approach. Simplicity usually results in fewer bugs, better consistency and performance, and increased code coverage.

  4. Java tracing concern design considerations

    Tracing concern design should consider the following design aspects:

    1. Enabling and disabling tracing in production runtime,
    2. optimization of logger instantiation,
    3. pretty-printing objects without relying on any specific interface methods,
    4. performance impact of tracing code when tracing is not enabled,
    5. development effort to support tracing in custom code,
    6. ensuring tracing implementation consistency across the entire portfolio.

     

    The enterprise-aspects AOP Java library implements the listed tracing concern design aspects as follows:

    1. The default logger uses the standard java.util.logging.Logger functionality, but can be customized to use other logging libraries. This ensures that production runtime tracing functionality used is the one provided by the hosting runtime components,
    2. one instantiated named logger instance per class, used directly and without list or array search,
    3. a default stringifier for transforming any Java object to JSON can be replaced with a custom one,
    4. performance impact when tracing is not enabled is limited to testing whether tracing is enabled,
    5. development effort to support tracing in custom code is reduced to extending the tracing aspect and defining the package or type pattern to which it applies. Debugging advised code remains supported,
    6. tracing consistency is guaranteed by the tracing aspect’s advice implementation.

     

    An example of tracing aspect extension is provided below to illustrate the development effort needed to support tracing in custom code:

    package samples.web.aspects;

    import com.github.akovac35.enterprise.aspects.tracing.TracingAspect;

    public aspect TracingAspectImpl extends TracingAspect pertypewithin(samples..*) {

    public pointcut traceableCode(): !within(samples.web.rest.TraditionalJavaTracingConcern+);

    /* Optionally define custom logger
    @Override
    protected ILogger getLogger(String name) {
    return new DefaultLogger(name);
    }
    */

    /* Optionally define custom stringifier
    @Override
    protected String stringify(Object o) {
    return DefaultStringifier.stringify(o);
    }
    */
    }

     

Join The Discussion