自定义spring日志拦截

为了代码的简洁性，很多时候我们需要对某一类业务方法统一使用AOP来打印跟踪日志或者特定方法打印特定的日志，下面有几种自定义拦截和日志框架的示例。

• 一个简单的自定义日志拦截，打印方法耗时，以及在方法前后输出跟踪日志
  修改下面“com.winit..service”，改成自已的包路径

@Aspect
public class LogAspect {

    /**
     * 禁用计算调用方法耗时统计
     */
    private boolean disableWastesTime = false;

    @Around("(execution(public * com.winit..service.*.*(..)))")
    public Object traceMethod(final ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
        Object returnVal = null;
        final Logger logger = getLog(proceedingJoinPoint);
        final String methodName = proceedingJoinPoint.getSignature().getName();
        long start = System.currentTimeMillis();
        try {
            final Object[] args = proceedingJoinPoint.getArgs();
            final String arguments;
            if (args == null || args.length == 0) {
                arguments = "";
                logger.debug("Entering method [" + methodName + " with arguments [" + arguments + "]");
            } else {
                try {
                    arguments = JSON.toJSONString(args);
                    logger.debug("Entering method [{} with arguments [{}]", methodName, arguments);
                } catch (Exception e) {
                    logger.debug("Entering method [{} with arguments [{}]", methodName, Arrays.deepToString(args));
                }
            }
            returnVal = proceedingJoinPoint.proceed();
            if (!disableWastesTime) {
                long end = System.currentTimeMillis();
                logger.info("Calls method [{}] which took {} ms", methodName, (end - start));
            }
            return returnVal;
        } finally {
            logger.debug("Leaving method [{}] with return value [{}].",
                methodName,
                (returnVal != null ? returnVal.toString() : "void"));
        }
    }

    @AfterThrowing(pointcut = "(execution(public * com.winit..service.*.*(..)))", throwing = "e")
    public void doException(JoinPoint jp, Exception e) {
        final Logger logger = getLog(jp);
        if (e != null) {
            logger.error(e.getLocalizedMessage(), e);
        }
    }

    protected Logger getLog(final JoinPoint joinPoint) {
        final Object target = joinPoint.getTarget();

        if (target != null) {
            return LoggerFactory.getLogger(target.getClass());
        }

        return LoggerFactory.getLogger(getClass());
    }

    public void setDisableWastesTime(boolean disableWastesTime) {
        this.disableWastesTime = disableWastesTime;
    }

}

spring配置加上下面这段就可以正常使用

<bean class="com.winit.ums.common.aspect.LogAspect" />

• 自定义审计日志
  下面代码源于Yale Case用到的github发布审计日志框架，可以自定义Resolver和TrailManager，支持el表达式，扩展性很强

@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface Audit {

    /**
     * Identifier for this particular application in the audit trail logs.  This attribute should only be used to override the basic application code when you want to differentiate a section of the code.
     * @return the application code or an empty String if none is set.
     */
    String applicationCode() default "";

    /**
     * The action to write to the log when we audit this method.  Value must be defined.
     * @return the action to write to the logs.
     */
    String action();

    /**
     * Reference name of the resource resolver to use.
     *
     * @return the reference to the resource resolver.  CANNOT be NULL.
     */
    String resourceResolverName() default "default";

    /**
     * Reference name of the action resolver to use.
     *
     * @return the reference to the action resolver.  CANNOT be NULL.
     */
    String actionResolverName() default "default";

    /**
     * The optional message element can be used to set a message .
     *
     * @return The optional message specified for this annotation.
     */
    String message() default "";

    /**
     * Whether or not the tag and message elements should support Java Expression Language syntax. Setting this to true
     * enables the tag name to be dynamic with respect to the arguments passed to the method being profiled, the
     * return value or exception thrown from the method (if any), and the object on which the method is being called.
     * An Expression Language expression is delimited with curly brackets, and arguments are accessed using the
     * following variable names:
     * <p>
     * <ul>
     * <li>$0, $1, $2, $3, etc. - the parameters passed to the method in declaration order
     * <li>$this - the object whose method is being called - when a static class method is profiled, this
     * will always be null
     * <li>$return - the return value from the method, which will be null if the method has a void return type, or an
     * exception was thrown during method execution
     * <li>$exception - the value of any Throwable thrown by the method - will be null if the method returns normally
     * </ul>
     * <p>
     * For example, suppose you want to profile the <tt>doGet()</tt> method of a servlet, with the tag name dependent
     * on the name of the servlet AND the path info (as returned by getPathInfo()) of the request.
     * You could create the following annotation:
     *
     * <pre>
     * &#064;Profiled(tag = "servlet{$this.servletName}_{$0.pathInfo}", el = true)
     * protected void doGet(HttpServletRequest req, HttpServletResponse res) {
     * ...
     * }
     * </pre>
     *
     * If the doGet() method is called with a request whose getPathInfo() method returns "/sub/path", and the servlet's
     * name if "main", then the tag used when logging a StopWatch will be "servletMain_/sub/path".
     *
     * @return True if expression language support should be enabled, false to disable support - defaults to true.
     * @see <a href="http://commons.apache.org/jexl/">Apache Commons JEXL</a>
     */
    boolean el() default true;

    /**
     * The spring bean name of the logger 
     *
     * @return The logger name
     */
    String loggerBean() default "";
}

maven引入 包

<inspektr.version>1.0.7.GA</inspektr.version>
<dependency>
    <groupId>com.github.inspektr</groupId>
     <artifactId>inspektr-audit</artifactId>
     <version>${inspektr.version}</version>
 </dependency>

 <dependency>
     <groupId>com.github.inspektr</groupId>
     <artifactId>inspektr-common</artifactId>
     <version>${inspektr.version}</version>
 </dependency>

 <dependency>
     <groupId>com.github.inspektr</groupId>
     <artifactId>inspektr-support-spring</artifactId>
     <version>${inspektr.version}</version>
 </dependency>

spring配置：

     <bean id="auditTrailManagementAspect" class="com.fpx.log.audit.AuditTrailManagementAspect">
        <constructor-arg index="0">
            <map>
                <entry key="default">
                    <bean class="com.fpx.common.log.audit.SDOAuditMixResourceResolver" />
                </entry>
                <entry key="parameter">
                    <bean class="com.fpx.common.log.audit.SDOParameterAuditStringResourceResolver"></bean>
                </entry>
            </map>
        </constructor-arg>
        <property name="auditTrailManagers">
            <list>
                <bean class="com.github.inspektr.audit.support.Slf4jLoggingAuditTrailManager">
                    <property name="useSingleLine" value="true" />
                </bean>
            </list>
        </property>
    </bean>

Resovler实现com.github.inspektr.audit.spi.AuditResourceResolver
Action实现com.github.inspektr.audit.spi.AuditActionResolver

public abstract class AbstractAuditMixResourceResolver implements AuditResourceResolver {

    private int returnMaxSize = 1024;

    public final String[] resolveFrom(final JoinPoint joinPoint, final Object retVal, Audit audit) {
        String[] results = new String[2];
        if (audit != null && StringUtils.isNotBlank(audit.message())) {
            results[0] = "params:" + audit.message();
        } else {
            String params = createResource(joinPoint.getArgs());
            results[0] = "params:" + params;
        }
        if (retVal != null) {
            String result = getResult(retVal);
            if (getReturnMaxSize() > 0 && result.length() > getReturnMaxSize()) {
                result = result.substring(0, getReturnMaxSize());
            }
            results[1] = "result:" + result;
        }
        return results;
    }

    public final String[] resolveFrom(final JoinPoint joinPoint, final Exception e, Audit audit) {
        Map<String, String> map = new HashMap<String, String>();
        if (audit != null && StringUtils.isNotBlank(audit.message())) {
            map.put("params", audit.message());
        } else {
            String params = createResource(joinPoint.getArgs());
            map.put("params", params);
        }
        map.put("result", getResult(e.getMessage()));
        return new String[] { JsonUtil.toJson(map) };
    }

    private String getResult(final Object retVal) {
        if (retVal instanceof String) {
            return StringUtils.replaceBlank(retVal.toString());
        } else {
            return JsonUtil.toJson(retVal);
        }
    }

    @Override
    public String[] resolveFrom(JoinPoint target, Object returnValue) {
        return resolveFrom(target, returnValue, null);
    }

    @Override
    public String[] resolveFrom(JoinPoint target, Exception exception) {
        return resolveFrom(target, exception, null);
    }

    protected abstract String createResource(final Object[] args);

    protected int getReturnMaxSize() {
        return returnMaxSize;
    };
}
public class SDOAuditMixResourceResolver extends AbstractAuditMixResourceResolver {

    protected String createResource(final Object[] args) {
        if (args == null) {
            return null;
        }
        StringBuilder builder = new StringBuilder();
        for (Object object : args) {
            if (object instanceof DataObject) {
                builder.append(object.toString()).append(",");
            } else if (object instanceof String) {
                builder.append(StringUtils.replaceBlank(object.toString())).append(",");
            } else {
                builder.append(JsonUtil.toJson(object)).append(",");
            }
        }
        return builder.toString();
    }
}

• Perf4J 是一个新的开放源码的性能记录，监测和分析库
  maven引入包

<perf4j.version>0.9.14</perf4j.version>
<dependency>
   <groupId>org.perf4j</groupId>
    <artifactId>perf4j</artifactId>
    <version>${perf4j.version}</version>
    <classifier>log4jonly</classifier>
    <scope>compile</scope>
</dependency>

@Audit(action = "handle")
    @Profiled(logger = "com.syncomponents.message.JSONMessageHandler")
    public Object handle(String arg0) {

@Profiled 支持一些定制，在此记录几种@Profiled 写法：

1、直接使用
java代码：

@Profiled 

由此产生的日志语句形如：

2013-12-07 15:17:23,734 [main] INFO org.perf4j.TimingLogger - start[开始时间] time[执行耗时] tag[方法名]   

2、带logger属性
打印日志时标识具体的类
java代码：

@Profiled(logger = "com.fpx.common.log.LogServiceImpl")  

由此产生的日志如：

2013-12-07 15:17:23,734 [main] INFO com.fpx.common.log.LogServiceImpl - start[开始时间] time[执行耗时] tag[方法名] 

3、带tag属性
当方法有参数时，可以通过{$x}输出参数值，当参数为一个对象时，可以通过{$x.属性}的方式法输出对象的属性值； tag标识支持JEXL表达式。

java代码：

@Profiled(tag = "test({$0},{$1},{$2})")  

由此产生的日志如：

2013-12-07 15:17:23,734 [main] INFO org.perf4j.TimingLogger - start[开始时间] time[执行耗时] tag[test(a,b,c)] 

4、带message属性
message的作用即可以在输出的内容后加上任何自定义的内容
java代码：

@Profiled(massage= "测试")  

由此产生的日志如：

2013-12-07 15:17:23,734 [main] INFO org.perf4j.TimingLogger - start[开始时间] time[执行耗时] tag[方法名] message[测试]  

5、带logFailuresSeparately属性
java代码：

 @Profiled(logFailuresSeparately=true）

由此产生的日志如

2013-12-07 15:17:23,734 [main] INFO org.perf4j.TimingLogger - start[开始时间] time[执行耗时] tag[方法名.failure] 

• 测试示例

public class LogServiceImpl implements LogService {

    private final static Logger logger = LoggerFactory.getLogger(LogServiceImpl.class);

    @Override
    @Audit(action = "sayHello")
    @BeanLogger
    @Profiled(message = "test" ,tag="sayHello({$0})", logger="com.fpx.common.log.LogServiceImpl")
    public void sayHello(String str) {
       System.out.println("hello " + str);
    }

参考：
https://github.com/dima767/inspektr