wiki

用户工具

站点工具

您的足迹: • 线程池 • 实现log4j打日志带uuid
分享:技术:log4j:实现log4j打日志带uuid

这是本文档旧的修订版！

目录

实现log4j打日志带uuid(同一个请求线程同一个uuid)

实现思路

  1. 新建Logger子类BaseUuidLogger，重写debug，info等方法；在ThreadLocal中获取同一个uuid；打印日志前带上这个uuid
  2. spring能管理到的类(@controller,@service)，使用aop切面，扫描Logger变量强制设置成BaseUuidLogger
  3. spring管理不到的类，比如util工具类，使用BaseUuidLoggerUtils.getBaseUuidLogger()赋值给Logger变量

具体步骤

BaseUuidLogger.java

由于使用BaseUuidLogger重写debug，info后的方法打印日志，log4j打印出来的类和行号都是BaseUuidLogger类的信息，而我们希望log4j打印出调用BaseUuidLogger的堆栈前面一个类的类名和行号信息。

所以，修改log4j配置文件把log4j捕获的类型和行号删除，然后，在BaseUuidLogger中重写的debug，info等方法打印日志前带上ThreadLocal中获取的同一个uuid之前再带上调用BaseUuidLogger的堆栈前面一个类的类名和行号信息。

BaseUuidLogger.java
package com.shhxzq.fin.lifeapp.model.base;
 
import java.util.UUID;
 
import org.apache.commons.lang.StringUtils;
import org.apache.log4j.Logger;
 
/**
 * 基础日志操作类-同一个线程的uuid是一样的
 * 
 * @author Gxx
 */
public class BaseUuidLogger extends Logger {
 
	/**
	 * 通过匿名内部类覆盖ThreadLocal的initialValue()方法，指定初始值
	 * 使得同一个线程的uuid是一样的
	 */
	private static ThreadLocal<String> uuid = new ThreadLocal<String>() {
		/**
		 * 初始值
		 */
		public String initialValue() {
			return "[uuid:" + UUID.randomUUID().toString() + "] : ";
		}
	};
 
	/**
	 * 空参数构造函数
	 */
	public BaseUuidLogger() {
		super(StringUtils.EMPTY);
	}
 
	/**
	 * 构造方法
	 * 
	 * @param name
	 */
	protected BaseUuidLogger(String name) {
		super(name);
	}
 
	@Override
	public void trace(Object message) {
		message = getStackString() + uuid.get() + message;
		super.trace(message);
	}
 
	@Override
	public void debug(Object message) {
		message = getStackString() + uuid.get() + message;
		super.debug(message);
	}
 
	@Override
	public void error(Object message) {
		message = getStackString() + uuid.get() + message;
		super.error(message);
	}
 
	@Override
	public void error(Object message, Throwable t) {
		message = getStackString() + uuid.get() + message;
		super.error(message, t);
	}
 
	@Override
	public void fatal(Object message) {
		message = getStackString() + uuid.get() + message;
		super.fatal(message);
	}
 
	@Override
	public void fatal(Object message, Throwable t) {
		message = getStackString() + uuid.get() + message;
		super.fatal(message, t);
	}
 
	@Override
	public void info(Object message) {
		message = getStackString() + uuid.get() + message;
		super.info(message);
	}
 
	@Override
	public void warn(Object message) {
		message = getStackString() + uuid.get() + message;
		super.warn(message);
	}
 
	/**
	 * 获取堆栈信息
	 * @param stackElements
	 * @return
	 */
	private String getStackString() {
		StackTraceElement[] stackElements = new Throwable().getStackTrace();
		if (stackElements != null && stackElements.length > 2) {
			return "[" + stackElements[2].getClassName()+ ".java:" 
					+ stackElements[2].getMethodName() + "():" 
					+ stackElements[2].getLineNumber() + "]";
 
        }
		return StringUtils.EMPTY;
	}
}

log4j.xml

[%C:%L]指的是[类名:行号]，因为同一个线程请求打印出同一个uuid，所以把%t(指的是线程名)也去掉了。

log4j.xml
    <appender name="ELP-ALL" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="file" value="${la.log4j.dir}/lifeapp.log" />
        <param name="append" value="true" />
        <param name="datePattern" value="'_'yyyy-MM-dd" />
        <param name="encoding" value="UTF-8" />
        <layout class="org.apache.log4j.PatternLayout">
            ==
            <param name="ConversionPattern" value="%d %t [%C:%L] %-5p : %m%n" />
            修改前<->修改后
            <param name="ConversionPattern" value="%d %-5p %m%n" />
            ==
        </layout>
    </appender>
 
    <appender name="ELP-ERROR" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="file" value="${la.log4j.dir}/lifeapp-error.log" />
        <param name="append" value="true" />
        <param name="datePattern" value="'_'yyyy-MM-dd" />
        <param name="threshold" value="ERROR" />
        <param name="encoding" value="UTF-8" />
        <layout class="org.apache.log4j.PatternLayout">
            ==
            <param name="ConversionPattern" value="%d %t [%C:%L] %-5p : %m%n" />
            修改前<->修改后
            <param name="ConversionPattern" value="%d %-5p %m%n" />
            ==
        </layout>
    </appender>

application-context.xml

配置AOP切面，可以扫描到指定路径下所有@Service注解的服务类

application-context.xml
	<!-- 服务层AOP begin -->
	<bean id="serviceAop" class="com.shhxzq.fin.lifeapp.biz.utils.ServiceAop" />
	<aop:config>
		<aop:aspect id="serviceAspect" ref="serviceAop">
			<aop:pointcut id="target" expression="execution(* com.shhxzq.fin.lifeapp..*.*(..))" />
			<aop:around method="around" pointcut-ref="target" />
		</aop:aspect>
	</aop:config>
	<!-- 服务层AOP end -->

spring-mvc.xml

要让AOP扫描到@Controller注解的控制器类(虽然是spring管理，但是AOP默认扫描不到)，必须加一行配置

spring-mvc.xml
	<!-- 扫描控制器类 -->
	<context:component-scan base-package="com.shhxzq.fin.lifeapp" />
 
	<!-- 让aop可以切面到controller -->
	<aop:aspectj-autoproxy proxy-target-class="true"/>

ServiceAop.java

扫面到切面指向的类和方法时候，程序会进入切面类的实现逻辑：通过反射扫描当前执行对象的Logger类型成员变量，new一个BaseUuidLogger子类对象，把这个Logger类型成员变量的所有属性拷贝赋值给BaseUuidLogger，再反射强制set给这个Logger类型成员变量。

ServiceAop.java
package com.shhxzq.fin.lifeapp.biz.utils;
 
import java.lang.reflect.Field;
import java.lang.reflect.Method;
import java.text.MessageFormat;
 
import org.apache.log4j.Logger;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.Signature;
import org.aspectj.lang.reflect.MethodSignature;
 
import com.shhxzq.fin.lifeapp.model.base.BaseUuidLogger;
import com.shhxzq.fin.lifeapp.model.base.BusinessException;
import com.shhxzq.fin.lifeapp.model.base.Log;
import com.shhxzq.fin.lifeapp.model.base.LogMethodTime;
 
/**
 * 服务层AOP
 * @author Gxx
 */
public class ServiceAop {
 
	/**
	 * 日志记录器
	 */
	Logger logger = BaseUuidLoggerUtils.getBaseUuidLogger();
 
	/**
	 * 方法前后操作
	 * @param pjp
	 * @return
	 * @throws Exception
	 */
	public Object around(ProceedingJoinPoint pjp) throws Throwable {
		/**
		 * 获取切面方法
		 */
		Signature sig = pjp.getSignature();
		MethodSignature msig = null;
		if (!(sig instanceof MethodSignature)) {
			throw new IllegalArgumentException("该注解只能用于方法");
		}
		msig = (MethodSignature) sig;
		Object target = pjp.getTarget();
		Method currentMethod = target.getClass().getMethod(msig.getName(), msig.getParameterTypes());
 
		/**
		 * 判断是否有Logger对象，有则强制设置为BaseUuidLogger
		 */
		Field[] files = target.getClass().getDeclaredFields();
		for(Field field : files) {
			if(field.getType() == Logger.class) {
				/**
				 * 私有变量必须先设置Accessible为true
				 */
	            field.setAccessible(true);
				/**
				 * 判断是否第一次赋值
				 */
				if(!(field.get(target) instanceof BaseUuidLogger)) {
					/**
					 * 创建基础日志操作实体-同一个线程的uuid是一样的
					 */
					BaseUuidLogger uuidLogger = new BaseUuidLogger();
					/**
					 * 拷贝属性-父类向子类拷贝(两层父类)
					 */
					BeanUtils.copyPropertiesLevel2(uuidLogger, field.get(target));
					/**
					 * 覆盖设置Logger对象
					 */
		            field.set(target, uuidLogger);
				}
			}
		}
 
		/**
		 * 判断是否加注解@Log和@LogMethodTime
		 */
		boolean isLog = currentMethod.isAnnotationPresent(Log.class);
		boolean isLogMethodTime = currentMethod.isAnnotationPresent(LogMethodTime.class);
 
		/**
		 * 类.方法 名字
		 */
		String targetName = pjp.getTarget().getClass().getName() + "." + pjp.getSignature().getName();
 
		/**
		 * 注解@Log或@LogMethodTime，只要配置一个就打日志
		 */
		if(isLog || isLogMethodTime) {
			String request = BeAopUtil.getStringFromRequest(pjp.getArgs());
			String requestMsg = "log - {0} request - {1}";
			logger.info(MessageFormat.format(requestMsg, new Object[] { targetName, request }));
		}
 
		/**
		 * 开始时间
		 */
		long begin = DateUtils.getNow().getTime();
 
		Object result = null;
		try {
			/**
			 * 执行方法
			 */
			result = pjp.proceed();
		} catch (BusinessException t) {
			logger.error(targetName + " exception occure!reason:" + t.getMessage());
			throw t;
		} catch (Throwable t) {
			logger.error(targetName + " exception occure!", t);
			throw t;
		} finally {
			/**
			 * 注解@LogMethodTime才计算计算时间
			 */
			if(isLogMethodTime) {
				long end = DateUtils.getNow().getTime();
				logger.info(targetName + " use time : " + (end - begin) / 1000.0 + "s");
			}
		}
 
		/**
		 * 注解@Log或@LogMethodTime，只要配置一个就打日志
		 */
		if(isLog || isLogMethodTime) {
			Object response = BeAopUtil.getStringFromResponse(result);
			String responseMsg = "log - {0} response - {1}";
			logger.info(MessageFormat.format(responseMsg, new Object[] { targetName, response }));
		}
		return result;
	}
}

BeanUtils.java

一般采用org.apache.commons.beanutils.BeanUtils.java:copyProperties(Object dest, Object orig)来拷贝两个对象的相同属性，但是这个类不能拷贝private，protected以及父类的所有属性，所以这里使用反射机制新写一个Bean工具类。

BeanUtils.java
package com.shhxzq.fin.lifeapp.biz.utils;
 
import java.lang.reflect.Field;
import java.lang.reflect.Modifier;
 
/** 
 * Bean工具类
 * @author Gxx
 */
public class BeanUtils {
	/**
	 * 拷贝属性-父类向子类拷贝(一层父类)
	 * @param dest
	 * @param origin
	 * @throws Exception
	 */
	public static void copyPropertiesLevel1(Object dest, Object origin) throws Exception {
		if (!(dest.getClass().getSuperclass() == origin.getClass())) {
			throw new Exception("dest不是origin的子类");
		}
		/**
		 * 第一层父类
		 */
		Class fatherClass = origin.getClass();
		Field ff[] = fatherClass.getDeclaredFields();
		for (int i = 0; i < ff.length; i++) {
			Field f = ff[i];
 
			// 私有变量必须先设置Accessible为true
			f.setAccessible(true);
 
			// 修改final属性
			Field modifiersField = Field.class.getDeclaredField("modifiers");
			modifiersField.setAccessible(true);
			modifiersField.setInt(f, f.getModifiers() & ~Modifier.FINAL);
 
			f.set(dest, f.get(origin));
		}
	}
 
	/**
	 * 拷贝属性-父类向子类拷贝(两层父类)
	 * @param dest
	 * @param origin
	 * @throws Exception
	 */
	public static void copyPropertiesLevel2(Object dest, Object origin) throws Exception {
		if (!(dest.getClass().getSuperclass() == origin.getClass())) {
			throw new Exception("dest不是origin的子类");
		}
		/**
		 * 第一层父类
		 */
		Class fatherClass = origin.getClass();
		Field ff[] = fatherClass.getDeclaredFields();
		for (int i = 0; i < ff.length; i++) {
			Field f = ff[i];
 
			// 私有变量必须先设置Accessible为true
			f.setAccessible(true);
 
			// 修改final属性
			Field modifiersField = Field.class.getDeclaredField("modifiers");
			modifiersField.setAccessible(true);
			modifiersField.setInt(f, f.getModifiers() & ~Modifier.FINAL);
 
			f.set(dest, f.get(origin));
		}
 
		/**
		 * 第二层父类
		 */
		fatherClass = origin.getClass().getSuperclass();
		ff = fatherClass.getDeclaredFields();
		for (int i = 0; i < ff.length; i++) {
			Field f = ff[i];
 
			// 私有变量必须先设置Accessible为true
			f.setAccessible(true);
 
			// 修改final属性
			Field modifiersField = Field.class.getDeclaredField("modifiers");
			modifiersField.setAccessible(true);
			modifiersField.setInt(f, f.getModifiers() & ~Modifier.FINAL);
 
			f.set(dest, f.get(origin));
		}
	}
}

BaseUuidLoggerUtils.java

前面配置AOP，那么AOP扫描到的@Service和@Controller自动Logger类型成员变量会变成BaseUuidLogger对象；那脱离了spring管理的其它类就只能还一种方法，使用这个工具类手动获取BaseUuidLogger对象。

BaseUuidLoggerUtils.java
package com.shhxzq.fin.lifeapp.biz.utils;
 
import org.apache.log4j.Logger;
 
import com.shhxzq.fin.lifeapp.model.base.BaseUuidLogger;
 
/** 
 * 基础日志输出工具类-同一个线程的uuid是一样的
 * @author Gxx
 */
public class BaseUuidLoggerUtils {
	/**
	 * 日志记录器
	 */
	static Logger logger = Logger.getLogger(BaseUuidLoggerUtils.class);
 
	/**
	 * 或者基础日志操作实体-同一个线程的uuid是一样的
	 * @return
	 */
	public static BaseUuidLogger getBaseUuidLogger() {
		BaseUuidLogger baseUuidLogger = new BaseUuidLogger();
		try {
			BeanUtils.copyPropertiesLevel2(baseUuidLogger, Logger.getLogger(BaseUuidLoggerUtils.class));
		} catch (Exception e) {
			logger.error("拷贝属性异常", e);
		}
		return baseUuidLogger;
	}
}

用法1

spring能管理到的类(@controller,@service)，使用aop切面，扫描Logger变量强制设置成BaseUuidLogger

LaCreditServiceImpl.java
/**
 * 信用卡服务接口实现类
 *
 * @author Gxx
 */
@Service("laCreditService")
public class LaCreditServiceImpl implements LaCreditService {
    /**
     * 日志处理器
     */
    private Logger logger = Logger.getLogger(LaCreditServiceImpl.class);
 
    ...
}
CreditController.java
/**
 * 信用卡相关接口
 * @author Gxx
 */
@Controller
@RequestMapping("/lifeapp/credit/")
public class CreditController {
 
	/**
	 * 日志处理器
	 */
	private final Logger logger = Logger.getLogger(CreditController.class);
 
    ...
}

用法2

spring管理不到的类，比如util工具类，使用BaseUuidLoggerUtils.getBaseUuidLogger()赋值给Logger变量

HawkeyeUtil.java
/**
 * 监控工具类
 *
 * @author Gxx
 * @since 2016/12/2
 */
public class HawkeyeUtil {
 
    /**
     * 日志处理器
     */
    private static Logger logger = BaseUuidLoggerUtils.getBaseUuidLogger();
 
    ...
}

打印效果

2016-12-24 09:28:46,503 INFO [com.shhxzq.fin.lifeapp.biz.utils.ServiceAop.java:around():93][uuid:f9ca7f9e-3d01-4fb3-be1e-30866c598f35] : log - com.shhxzq.fin.lifeapp.biz.impl.credit.LaCreditServiceImpl.queryShowCreditMenu request - {"acceptMode":"Mobile","custNo":"0000045412","deviceId":"BiHo7J4ppFXL8vAmQ3WZ7M"}
2016-12-24 09:28:46,503 INFO [com.shhxzq.fin.lifeapp.remote.impl.SafeCenterServiceImpl.java:checkShowCreditMenu():63][uuid:f9ca7f9e-3d01-4fb3-be1e-30866c598f35] : 判断用户是否可见信用卡服务请求:BeidouRiskQueryDO{appName='LIFEAPP', dataMap={}, moduleType=101, isMeetBreak=true, memberId='0000045412', deviceId='BiHo7J4ppFXL8vAmQ3WZ7M', ip='null', weixin='null'}
2016-12-24 09:28:46,505 INFO [com.shhxzq.fin.lifeapp.remote.impl.SafeCenterServiceImpl.java:checkShowCreditMenu():78][uuid:f9ca7f9e-3d01-4fb3-be1e-30866c598f35] : 判断用户能否还款返回:AccessStatus=[0],Reason=[null]
2016-12-24 09:28:46,506 INFO [com.shhxzq.fin.lifeapp.biz.utils.ServiceAop.java:around():120][uuid:f9ca7f9e-3d01-4fb3-be1e-30866c598f35] : com.shhxzq.fin.lifeapp.biz.impl.credit.LaCreditServiceImpl.queryShowCreditMenu use time : 0.003s
2016-12-24 09:28:46,506 INFO [com.shhxzq.fin.lifeapp.biz.utils.ServiceAop.java:around():130][uuid:f9ca7f9e-3d01-4fb3-be1e-30866c598f35] : log - com.shhxzq.fin.lifeapp.biz.impl.credit.LaCreditServiceImpl.queryShowCreditMenu response - true

根据uuid 

grep 'f9ca7f9e-3d01-4fb3-be1e-30866c598f35' lifeapp.log --color

可以查到日志中同一次请求的所有日志

[待探讨方式1]ASM字节码技术

lifeapp项目运行，自动解压log4j.jar，拿到Logger.class(或者父类)，使用ASM字节码技术框架，修改debug，info等方法(或者修改这些方法统一调后面的某个方法)，在打印信息之前带上uuid(在ThreadLocal中获取同一个uuid)。

用法

和原始的Logger对象用法一样

HawkeyeUtil.java
/**
 * 监控工具类
 *
 * @author Gxx
 * @since 2016/12/2
 */
public class HawkeyeUtil {
 
    /**
     * 日志处理器
     */
    private static Logger logger = Logger.getLogger(HawkeyeUtil.class);
 
    ...
}

[待探讨方式2]修改Log4j源码

拿出Log4j源码，修改debug，info等方法(或者修改这些方法统一调后面的某个方法)，在打印信息之前带上uuid(在ThreadLocal中获取同一个uuid)。

用法

和原始的Logger对象用法一样

HawkeyeUtil.java
/**
 * 监控工具类
 *
 * @author Gxx
 * @since 2016/12/2
 */
public class HawkeyeUtil {
 
    /**
     * 日志处理器
     */
    private static Logger logger = Logger.getLogger(HawkeyeUtil.class);
 
    ...
}
分享/技术/log4j/实现log4j打日志带uuid.1482544073.txt.gz · 最后更改: 2016/12/24 09:47 由 gxx

页面工具

除额外注明的地方外，本维基上的内容按下列许可协议发布： CC Attribution-Share Alike 3.0 Unported
CC Attribution-Share Alike 3.0 Unported Donate Powered by PHP Valid HTML5 Valid CSS Driven by DokuWiki