业务背景
今天突然接到一个需求是这样的，需要记录用户的操作记录。有已经存在的技术方案是这样的：
operation log.png
其实redis换成消息中间件也是同样的道理。为了记录业务日志，提高了系统的复杂度，有点得不偿失。
解决方案
方案1：自定义注解，在业务Action上记录参数。
方案2：自定义日志框架对应的Appender，直接输出到目标数据库。
选区方案2的原因有以下几点：
- 很少的代码量，简单修改日志配置即可；
- 和业务完全松耦合；
- 通过包路径细粒度区分日志类型；
- 主流的日志框架支持日志输出到多目标源且支持自定义。
自定义Appender
关于日志的基本使用配置，可以参考之前写过的一篇文章log4j2 sl4j 实践或官方文档。其实之前的这篇实践文章有一些不足之处，slf4j（simple log facade for java）采用了门面设计模式，分别装饰了主流的日志实现，包括log4j,log4j2,logback等。
接下来的示例代码以logback为例，关于log4j或者其他更多实现大同小异。
MongoDBAppender.java
/**
* 这个bean不托管给Spring
*/
@Slf4j
public class MongoDBAppender extends UnsynchronizedAppenderBase<ILoggingEvent> {
// spring data mongodb
private MongoTemplate mongoTemplate;
//thread pool
private Executor asyncExecutor;
@Override
protected void append(ILoggingEvent eventObject) {
if (mongoTemplate == null || asyncExecutor == null) {
initMongoAndThreadPool();
}
if (mongoTemplate != null && asyncExecutor != null) {
asyncExecutor.execute(() -> {
try {
if (mongoTemplate != null) {
MixcLoggerEntity doc = new MixcLoggerEntity();
doc.setTime(DateFormatUtils.format(eventObject.getTimeStamp(), "yyyy-MM-dd HH:mm:ss"));
doc.setLevel(eventObject.getLevel().toString());
doc.setLogger(eventObject.getLoggerName());
doc.setThread(eventObject.getThreadName());
doc.setCurThread(Thread.currentThread().getName());
doc.setMessage(eventObject.getFormattedMessage());
mongoTemplate.insert(doc);
}
} catch (Exception e) {
log.error("save operation error:{}", e);
}
});
}
}
private void initMongoAndThreadPool() {
mongoTemplate = ApplicationContextProvider.getBean(MongoTemplate.class);
asyncExecutor = ApplicationContextProvider.getBean("asyncExecutor", Executor.class);
}
}
logback.xml
<appender name="mongoDB" class="******.log.MongoDBAppender"/>
<!-- additivity:true 表示上抛到root级别的appender -->
<logger name="******.WebLogAspect" level="DEBUG" additivity="true">
<appender-ref ref="mongoDB"/>
</logger>
好了，已经可以实现把WebLogAspect类的日志异步写入mongodb数据库。
为什么是WebLogAspect这个类？
因为自定义了aop的切面类，把所有的Controller方法作为切入点，打印每个action的请求参数等等。
WebLogAspect
@Aspect
@Component
public class WebLogAspect {
private final static Logger logger = LoggerFactory.getLogger(WebLogAspect.class);
/**
* 以 controller 包下定义的所有请求为切入点
*/
@Pointcut("execution(省略*****.admin.controller..*.*(..))")
public void webLog() {
}
/**
* 在切点之前织入
*
* @param joinPoint
* @throws Throwable
*/
@Before("webLog()")
public void doBefore(JoinPoint joinPoint) {
// 开始打印请求日志
ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes();
HttpServletRequest request = attributes.getRequest();
// 打印请求相关参数
logger.info("========================================== Start ==========================================");
logger.info("URL : {}", request.getRequestURL());
logger.info("HTTP Method : {}", request.getMethod());
logger.info("Class Method : {}.{}", joinPoint.getSignature().getDeclaringTypeName(), joinPoint.getSignature().getName());
logger.info("IP : {}", request.getHeader("x-forwarded-for"));
logger.info("Request Args : {}", JSONObject.toJSONString(filterArgs(joinPoint.getArgs())));
}
/**
* 在切点之后织入
*
* @throws Throwable
*/
@After("webLog()")
public void doAfter() {
logger.info("=========================================== End ===========================================");
// 每个请求之间空一行
logger.info("");
}
/**
* 环绕
*
* @param proceedingJoinPoint
* @return
* @throws Throwable
*/
@Around("webLog()")
public Object doAround(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
long startTime = System.currentTimeMillis();
Object result = proceedingJoinPoint.proceed();
logger.info("Response Result : {}", JSONObject.toJSONString(result));
logger.info("Time-Total : {} ms", System.currentTimeMillis() - startTime);
return result;
}
/**
* 过滤无法序列化的参数类型
* @param args
* @return
*/
private Object[] filterArgs(Object[] args) {
Object[] results = new Object[args.length];
for (int i = 0; i < args.length; i++) {
if (args[i] instanceof ServletRequest || args[i] instanceof ServletResponse || args[i] instanceof MultipartFile) {
//ServletRequest不能序列化，从入参里排除，否则报异常
continue;
}
results[i] = args[i];
}
return results;
}
}
所以，对于我们的操作日志记录非常简单。
踩坑总结
自定义filter为什么继承UnsynchronizedAppenderBase？
其实也可以继承其他类。容易误解为继承重写append方法就是异步的执行日志，事实并非如此。
Similar to AppenderBase except that derived appenders need to handle thread synchronization on their own.
和AppenderBase类似，除了需要派生类自己处理线程同步问题（改成异步）。
所以，你继承AppenderBase 和继承UnsynchronizedAppenderBase没什么本质的区别。只是通过名字来约束。同时UnsynchronizedAppenderBase有一个派生类AsyncAppender也是自己实现了异步记录日志。
Appenders官方文档还有更多的内容值得一看，刚刚过了一遍，列几点收获？
- 如果你在自定义的append()里面打印log会发生什么，对，没错，是无限的递归调用，会导致内存溢出。可以根据代码或者包的隔离来解决
- consoleAppender支持开启控制台字体颜色，查日志的时候可以小小娱乐一下
- 官方原生支持很多appender，很多可以直接用在我们的业务当中。比如：smtpAppender，可以用来发异常邮件或者通知。
更大的日志体量一定是依赖ELK来存储和检索。其实自己处理日志收集也需要借鉴apperder的解决方案，异步，批量传输。
