Friday, February 17, 2012

AOP - Aspect Oriented Programming

Okay, what is AOP or Aspect Oriented Programming and how does it fit with JSF?  Well, we have already been using a form of AOP - Transactions.  Transactions are a typical use case of AOP.  AOP addresses cross cutting concerns and applys that to our objects.  Let us look for a moment how AOP affected our use of transactions.

If we were not using declarative transactions, we would have had to manage the transactions ourselves.  i.e.
public void save(Entity entity) {
    try {
            em.getTransaction().begin();
            em.persist(entity);
            em.getTransaction().commit();
     } catch (TransactionException e) {
            logger.log(Level.SEVERE, "Fatal error in persistence environment: ", e);
     }

}
And that doesn't even get into the JNDI lookup, etc.  But, with AOP we created a standard way of wrapping the transaction such that we can rewrite the above method as:
@TransactionAttribute( TransactionAttributeType.REQUIRED)
public void save(Entity entity) {
       em.persist(entity);
}
And that transaction already includes the JNDI lookup.  Now if we implement a new transaction manager, method, etc.  What do we change?  All we have to change is the AOP method.  AOP is implemented on our beans, just as we saw with our transactions.  Although there is no limit on what AOP can be applied to, some real world applications are: logging, security, auditing, read/write locks, exception handling, performance monitoring, caching, and of course transaction management.

Let us take a simple example.  Logging.  Suppose we normally have a class that looks something like:
public class MyClass {
    private  Logger logger = Logger.getLogger("MyClass");
    public void doSomething(Object someObject) {
        logger.log(Level.FINE, "doSomething ", someObject);
        try {
           ...
        } catch (SomeException e) {
             logger.log(Level.SEVER, "doSomething", e);
        }
        ...
    }
    ...
}


Now we can re-write that as:
@Trace
public class MyClass {
   @LogException
   public void doSomething(Object someObject) {
       ...
   }
   ...
}
And to change the logging all we have to change is the implementation of the @Trace, or @LogException and all the classes annotated by the above will change.

Let us look at a complete example.  This first example has a non binding parameter attached to it so that it will have to be interpreted at run time.  There are 4 files we have to deal with when implementing the AOP.  We need the actual interceptor, we need the annotation for the interceptor, we need to register the interceptor in beans.xml, and of course, we need to annotate our class with the annotation.

The interceptor: com/sample/interceptors/TracerInterceptor.java

package com.sample.interceptors;
import java.lang.annotation.Annotation;
import java.lang.reflect.Method;
import java.util.Arrays;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.interceptor.AroundInvoke;
import javax.interceptor.Interceptor;
import javax.interceptor.InvocationContext;
/**
 * @author Thomas Dias
 */
@Traceable
@Interceptor

package com.sample.interceptors;
import java.lang.annotation.Annotation;
import java.lang.reflect.Method;
import java.util.Arrays;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.interceptor.AroundInvoke;
import javax.interceptor.Interceptor;
import javax.interceptor.InvocationContext;
/**
 * @author Thomas Dias
 */
@Traceable
@Interceptor
public class TracerInterceptor {
    @AroundInvoke
    public Object log(InvocationContext ctx) throws Exception {
        Logger logger = Logger.getLogger(ctx.getTarget().getClass().getName());
        logger.setUseParentHandlers(true); // log to the container logs
        logger.setLevel(Level.ALL); // set this based on some configuration file
        Level curLevel = getTraceableAnnotation(ctx.getMethod()).logLevel().getLevel();
        if (logger.isLoggable(curLevel)) {
            StringBuilder msg = new StringBuilder();
            msg.append("Entering: ");
            msg.append(ctx.getMethod());
            msg.append(" Parameters: ");
            msg.append(Arrays.toString(ctx.getParameters()));
            logger.log(curLevel, msg.toString());
            Object returnMe = ctx.proceed();
            msg.setLength(0);
            msg.append("Exited: ");
            msg.append(ctx.getMethod());
            msg.append(" Returned : ");
            if (returnMe != null) {
                msg.append(returnMe.toString());
            }
            logger.log(curLevel, msg.toString());
            return returnMe;
        } else {
            return ctx.proceed();
        }
    }
    public Traceable getTraceableAnnotation(Method method) {
        for (Annotation a : method.getAnnotations()) {
            if (a instanceof Traceable) {
                return (Traceable) a;
            }
        }
        for (Annotation a : method.getDeclaringClass().getAnnotations()) {
            if (a instanceof Traceable) {
                return (Traceable) a;
            }
        }
        return null;
    }
}
Notice we have an "extra" method here to find out which annotation was used to call the interceptor.  This method then returns the parameter we put in our annotation.  i.e. @Traceable(logLevel=Traceable.LogLevelType.FINE) will return the FINE LogLevelType for the method Traceable.logLevel();

Otherwise we see that this interceptor will find the class name we are calling, get a Logger for that classname, log to its parents logger, set the log level to all (although this should come from a configuration), get the desired log level from the annotation being used, and if the annotation level for logging is less then the ALL loglevel, it will log a record before and after the method call.  We use this interceptor by putting @Traceable on the class in which case all methods will be logged, or we can put the @Traceable at the method which will then only log calls to that method.

The annotaion: com/sample/interceptors/Traceable.java

package com.sample.interceptors;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
import java.util.logging.Level;
import javax.enterprise.util.Nonbinding;
import javax.interceptor.InterceptorBinding;
/**
 * @author Thomas Dias
 */
@InterceptorBinding
@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.TYPE, ElementType.METHOD})
public @interface Traceable {
    public enum LogLevelType {
        FINE(Level.FINE), WARN(Level.WARNING), SEVERE(Level.SEVERE);
        private Level level;
        LogLevelType(Level level) {
            this.level = level;
        }
        public Level getLevel() {
            return level;
        }
    }
    @Nonbinding
    public LogLevelType logLevel() default LogLevelType.FINE;
}
Notice here, we included an enum to support the different types the logLevel could be bound to.

beans.xml

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://java.sun.com/xml/ns/javaee"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/beans_1_0.xsd">
    <interceptors>
        <class>com.sample.interceptors.TracerInterceptor</class>
    </interceptors>
</beans>
Just keep adding <class>...</class> for each interceptor you want to use.

And a bean using the annotation: com/sample/beans/TreeBean.java

package com.sample.beans;
import com.sample.entities.OrderEntity;
import com.sample.entities.OrderPartsEntity;
import com.sample.interceptors.Traceable;
import java.io.Serializable;
import javax.enterprise.context.Dependent;
import javax.inject.Named;
import org.primefaces.event.NodeSelectEvent;
import org.primefaces.model.DefaultTreeNode;
import org.primefaces.model.TreeNode;
/**
 * @author Thomas Dias
 */
@Named("treeBean")
@Dependent
@Traceable(logLevel=Traceable.LogLevelType.FINE)
public class TreeBean implements Serializable {
    MainSampleViewBean mainSampleViewBean;
    /** Creates a new instance of TreeBean */
    public TreeBean() {
    }
    private TreeNode selectedNode;
    private TreeNode treeRoot;
    private void addNode(OrderPartsEntity part, TreeNode parent) {
        TreeNode newNode = new DefaultTreeNode(part, parent);
        for (OrderPartsEntity subPart : part.getSubOrderParts()) {
            addNode(subPart, newNode);
        }
    }
    public TreeNode getOrderTree() {
        return treeRoot;
    }
    public void buildTree(OrderEntity orderEntity) {
        treeRoot = new DefaultTreeNode(null, null);
        if (orderEntity == null) {
            selectedNode = null;
            return;
        }
        TreeNode node = new DefaultTreeNode(orderEntity, treeRoot);
        for (OrderPartsEntity part : orderEntity.getOrderedParts()) {
            if (part.getParent() == null) {
                addNode(part, node);
            }
        }
        setSelectedNode(node);
        onNodeSelect(null);
    }
    public TreeNode getSelectedNode() {
        return selectedNode;
    }
    public void setSelectedNode(TreeNode selectedNode) {
        this.selectedNode = selectedNode;
    }
    public void onNodeSelect(NodeSelectEvent event) {
        if (selectedNode != null) {
            selectedNode.setSelected(true);
            selectedNode.setExpanded(true);
            Object nodeData = selectedNode.getData();
            StringBuilder msg = new StringBuilder("Selected Node: ");
            msg.append(nodeData);
            msg.append(", Parts Id: ");
            Long id = null;
            if (nodeData instanceof OrderPartsEntity) {
                id = ((OrderPartsEntity) nodeData).getPart().getId();
                msg.append(id);
                msg.append(", Order Entity Id: ");
                msg.append(((OrderPartsEntity) nodeData).getOrderEntity().getId());
            } else {
                msg.append("null, Order Entity Id: ");
                msg.append(((OrderEntity) nodeData).getId());
            }
        }
        mainSampleViewBean.partSelected();
    }
    @Traceable(logLevel=Traceable.LogLevelType.WARN)
    public MainSampleViewBean getMainSampleViewBean() {
        return mainSampleViewBean;
    }
    @Traceable(logLevel=Traceable.LogLevelType.WARN)
    public void setMainSampleViewBean(MainSampleViewBean mainSampleViewBean) {
        this.mainSampleViewBean = mainSampleViewBean;
    }
    public TreeNode getTreeRoot() {
        return treeRoot;
    }
    public void setTreeRoot(TreeNode treeRoot) {
        this.treeRoot = treeRoot;
    }
}

We have seen this bean before.  The only addition is the @Traceable line.  Notice here we overroad the log level at the method for get and set MainSampleViewBean.  This was actually overridden because when we did our annotation lookup in our interceptor, the getTraceableAnnotation looked first at the method annotations, then at the class annotations.

Our second complete example demonstrates if we bind the parameter to the interceptor.  Unlike the first one where we had to go find the annotation and figure out what value the developer set, here we know what the value is, but we have to make a separate interceptor for each possible value.  Now we have to deal with beans.xml, the bean we are going to annotate with the interceptor, the interceptors for each value, the annotation, and I included a utility class so I didn't have to duplicate the code.

The new beans.xml

 <?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://java.sun.com/xml/ns/javaee"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/beans_1_0.xsd">
    <interceptors>
        <class>com.sample.interceptors.TracerInterceptor</class>
        <class>com.sample.interceptors.LogFineInterceptor</class>
        <class>com.sample.interceptors.LogWarnInterceptor</class>
    </interceptors>
</beans>

We are still using the first interceptor for the other bean, so we did not remove it from the beans.xml.  If we do remove it from there, the interceptor will be disabled.  We don't have to recompile to disable or enable interceptors.

The interceptor for the fine value: LogFineInterceptor.java

package com.sample.interceptors;
import java.util.logging.Level;
import javax.interceptor.AroundInvoke;
import javax.interceptor.Interceptor;
import javax.interceptor.InvocationContext;
/**
 * @author Thomas Dias
 */
@Loggable("FINE")
@Interceptor
public class LogFineInterceptor {
    @AroundInvoke
    public Object log(InvocationContext ctx) throws Exception {
        LogIt.enter(Level.FINE, ctx);
        Object returnMe = ctx.proceed();
        LogIt.exit(Level.FINE, ctx, returnMe);
        return returnMe;
    }
}

The interceptor for the warn value: LogWarnInterceptor.java

package com.sample.interceptors;
import java.util.logging.Level;
import javax.interceptor.AroundInvoke;
import javax.interceptor.Interceptor;
import javax.interceptor.InvocationContext;
/**
 * @author Thomas Dias
 */
@Loggable("WARN")
@Interceptor
public class LogWarnInterceptor {
    @AroundInvoke
    public Object log(InvocationContext ctx) throws Exception {
        LogIt.enter(Level.WARNING, ctx);
        Object returnMe = ctx.proceed();
        LogIt.exit(Level.WARNING, ctx, returnMe);
        return returnMe;
    }
}

The annotation: Loggable.java

package com.sample.interceptors;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
import javax.interceptor.InterceptorBinding;
/**
 * @author Thomas Dias
 */
@InterceptorBinding
@Retention(RetentionPolicy.RUNTIME)
@Target({ElementType.TYPE, ElementType.METHOD})
public @interface Loggable {
    public String value() default "FINE";
}

The utility class: LogIt.java

import java.util.Arrays;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.interceptor.InvocationContext;
/**
 * @author Thomas Dias
 */
public class LogIt {
    private static Logger logger = null;
    public static void init(InvocationContext ctx) {
        logger = Logger.getLogger(ctx.getTarget().getClass().getName());
        logger.setUseParentHandlers(true); // log to the container logs
        logger.setLevel(Level.ALL); // set this based on some configuration file
    }
    public static void enter(Level level, InvocationContext ctx) {
        if(logger==null) init(ctx);
        if (logger.isLoggable(Level.FINE)) {
            StringBuilder msg = new StringBuilder();
            msg.append("Entering: ");
            msg.append(ctx.getMethod());
            msg.append(" Parameters: ");
            msg.append(Arrays.toString(ctx.getParameters()));
            logger.log(Level.FINE, msg.toString());
        }
    }
    public static void exit(Level level, InvocationContext ctx, Object returned) {
        if (logger.isLoggable(level)) {
            StringBuilder msg = new StringBuilder("Exited: ");
            msg.append(ctx.getMethod());
            msg.append(" Returned : ");
            if (returned != null) {
                msg.append(returned.toString());
            }
            logger.log(level, msg.toString());
        }
    }
}

and the bean we are annotating: RestBean.java

package com.sample.beans;
import com.sample.interceptors.Loggable;
import com.sample.webservice.client.PartEntityRESTClient;
import com.sample.webservice.other.Part;
import java.io.Serializable;
import javax.enterprise.context.RequestScoped;
import javax.faces.event.ActionEvent;
import javax.inject.Named;
/**
 * JSF Named bean for interacting with a RESTful web service via REST client
 * Request Scope
 * @author Thomas Dias
 */
@Named(value = "restBean")
@RequestScoped
@Loggable("FINE")
public class RestBean implements Serializable {
    private String name = "", parentName = "", msg = "";
    /** Default constructor */
    public RestBean() {
    }
    /**
     * Listener method to create a part via an http GET - gets part with name of name
     * @param event
     */
    @Loggable("WARN")
    public void createByGet(ActionEvent event) {
        createByGet();
    }
    /**
     * Action method to create a part via an http GET - gets part with name of name
     * @return empty string
     */
    public String createByGet() {
        Part part = new PartEntityRESTClient().createByGet(parentName, name);
        msg = "Created " + part.getId() + " " + part.getName();
        return "";
    }
    /**
     * Listener method to create a part via an http POST - creates part whose name is name, and parent is parentname
     * @param event
     */
    public void createByPost(ActionEvent event) {
        createByPost();
    }
    /**
     * Action method to create a part via an http POST - creates part whose name is name, and parent is parentname
     * @return empty string
     */
    public String createByPost() {
        new PartEntityRESTClient().create_XML(new Part(name, parentName));
        msg = "Created by post";
        return "";
    }
    /**
     * Listener method for deleting a part - deletes part whose id = name
     * @param event
     */
    public void delete(ActionEvent event) {
        delete();
    }
    /**
     * Action method for deleting a part - deletes part whose id = name
     * @return empty string
     */
    public String delete() {
        PartEntityRESTClient client = new PartEntityRESTClient();
        Part part = client.findByName(name);
        if (part.getId() == 0l) {
            msg = "No Part Found";
        } else {
            client.remove(part.getId().toString());
            msg = "Deleted " + name;
        }
        return "";
    }
    /**
     * Listener method for retrieving a part whose name is name
     * @param event
     */
    public void find(ActionEvent event) {
        find();
    }
    /**
     * Action method for retrieving a part whose name is name
     * @return empty string
     */
    public String find() {
        Part part = new PartEntityRESTClient().findByName(name);
        msg = part.toString();
        return "";
    }
    // *** Standard getters and setters below this line
    public String getMsg() {
        return msg;
    }
    public void setMsg(String msg) {
        this.msg = msg;
    }
    public String getName() {
        return name;
    }
    public void setName(String name) {
        this.name = name;
    }
    public String getParentName() {
        return parentName;
    }
    public void setParentName(String parentName) {
        this.parentName = parentName;
    }
}


4 comments:

  1. Hello, this is very nice AOP tutorial, but for some reason it doesn't work with my JSF project. I created annotation, interceptor, put beans.xml to WEB-INF... And still annotated method is not intercepted. What could be wrong?

    ReplyDelete
  2. Just to be sure: I don't use EJB, it's pure very simple JSF with Managed beans.

    ReplyDelete