前言
在代码中编写日志是日常开发中的基本要求，记录日志一方面是方便日后通过日志能够查找问题原因，另一方面也可以用于后续的审计工作。我以前对团队编写日志的要求是，通过打印的日志就可以看出整个代码的业务逻辑，所以我们团队的代码可以做到没有注释，通过代码中的日志就可以了解到整个代码的业务逻辑。这样要求的好处是看日志查问题的时候，通过看日志就知道代码的处理逻辑，而不用再翻出代码来看业务处理逻辑了。我相信很多同学都有类似的感受，就是在查日志的时候发现日志的信息都非常的混乱，查起问题来别提多别扭了，如果日志都按业务逻辑记录好了那就不会存在这样的问题。
1. 日志要求
我们在代码中记录日志从大类上区分，一般有两种，一种是所有交易都记录的系统基础日志，日志中会包含系统时间、请求返回报文、用户名等等信息；还有一种是业务相关的逻辑日志。
1.1 日志分级
我们先来说下大家记录的最多的业务逻辑日志，记录逻辑日志我们一般都会对日志进行分级error、info、debug这些级别，因为日志记录的太详细就会影响到服务器性能，所以一般我们在生产上只会打开info级别的，有的交易量比较大的系统甚至只打开error级别的日志。
1.2 逻辑日志记录
开头说了对于info或者debug级别的日志，需要能够在代码中明确写出，在每个代码分支的地方都记录分支条件的日志，这样当出现问题后通过查看日志就能够知道为什么走到的错误的分支，直接看日志就知道出异常时候每一步关键参数的值，如果逻辑日志记录的完整的话，查问题甚至都不需要在ide中进行debug。
例：在每个分支都记录逻辑日志，这样方便在日志中查找到问题根因
private boolean initEngine(){
logger.info("init all engines begin: ");
Map<String, IEngine> engines = commonEngineFactory.getAllEngines();
Map<String, IEngine> customEngines = customEngineFactory.getAllEngines();
if(customEngines == null && engines == null){
logger.info("customEngines == null && engines == null.");
return false;
}else if(customEngines != null) {
engines.putAll(customEngines);
}
CloudAppContext.getInstance().setEngineMap(engines);
logger.info("init engines = " + engines);
return true;
}
1.3 切面纪录系统日志
对于系统日志我们一般采取的是通过切面进行日志记录，这样可以最大限度的减少日志对系统逻辑的影响，再通过自定义注解可以在需要加系统日志的逻辑类方法前面加上系统切面注解就可以。下面的章节我们详细讲解下如何实现切面日志。
2. 切面日志实现
为了实现上面说到的切面日志，需要实现下面几个东西，首先要定义一个自定义环绕注解，第二要定义一个Aspect类来重写环绕注解方法，最后还要自定义一个写日志接口，并实现这个接口。下面分别介绍下具体实现方式。
实现完注解切面日志相关类后，可以在相关业务类的逻辑方法前加上方法环绕注解@SysLog，这样就实现了环绕注解，对业务逻辑代码完全没有侵入性。
/**
* 保存配置
*/
@SysLog("保存配置")
@RequestMapping("/save")
public ResponseBean save(@RequestBody SysConfigEntity config){
ValidatorUtils.validateEntity(config);
sysConfigService.save(config);
return ResponseBean.ok();
}
2.1 环绕注解
自定义一个SysLog的注解类，方便在其他逻辑类里使用，这样逻辑代码就不用在逻辑代码中加入这种通用系统日志，在逻辑代码中将只存在业务日志。
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
@Documented
public @interface SysLog {
String value() default "";
}
在切面类中重写环绕注解，around方法的point入参就是需要进行代理的业务类的切入点，调用point.proceed（）就会代理调用加了@SysLog注解的业务方法，在这个业务方法前后我们可以加上我们要记录的任何系统日志信息。
@Around("logPointCut()")
public Object around(ProceedingJoinPoint point) throws Throwable {
long beginTime = System.currentTimeMillis();
//执行业务逻辑方法
Object result = point.proceed();
//执行时长(毫秒)
long time = System.currentTimeMillis() - beginTime;
//保存日志
saveSysLog(point, time);
return result;
}
2.2 日志切面
上面定义了自定义注解，为了实现切面日志，当然需要定义一个切面类，不然系统是无法知道在哪里形成切面，并在切面之前还是之后进行切面方法操作，Aspect的底层实现，其实就是一个动态代理，jvm启动的时候会找寻到相关切面注解，然后在业务类的基础上又定义了一个包含切面相关方法的动态代理类，在执行的时候会先调用到这个动态代理类，执行切面中的方法，再执行业务逻辑方法。
@Aspect
@Component
public class SysLogAspect {
@Autowired
private SysLogService sysLogService;
//定义切入点Pointcut
@Pointcut("@annotation(com.monkey01.log.aspect.SysLog)")
public void logPointCut() {
}
@Around("logPointCut()")
public Object around(ProceedingJoinPoint point) throws Throwable {
long beginTime = System.currentTimeMillis();
//执行业务逻辑方法
Object result = point.proceed();
//执行时长(毫秒)
long time = System.currentTimeMillis() - beginTime;
//保存日志
saveSysLog(point, time);
return result;
}
private void saveSysLog(ProceedingJoinPoint joinPoint, long time) {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();
Method method = signature.getMethod();
SysLogEntity sysLog = new SysLogEntity();
SysLog syslog = method.getAnnotation(SysLog.class);
if(syslog != null){
//注解上的描述
sysLog.setOperation(syslog.value());
}
//请求的方法名
String className = joinPoint.getTarget().getClass().getName();
String methodName = signature.getName();
sysLog.setMethod(className + "." + methodName + "()");
//请求的参数
Object[] args = joinPoint.getArgs();
try{
String params = new Gson().toJson(args[0]);
sysLog.setParams(params);
}catch (Exception e){
}
sysLog.setTime(time);
sysLog.setCreateDate(new Date());
//保存系统日志
sysLogService.save(sysLog);
}
}
定义一个系统日志实体类，方便日后对系统日志统一格式化。
public class SysLogEntity implements Serializable {
private static final long serialVersionUID = 1L;
private Long id;
//用户名
private String username;
//用户操作
private String operation;
//请求方法
private String method;
//请求参数
private String params;
//执行时长(毫秒)
private Long time;
//IP地址
private String ip;
//创建时间
private Date createDate;
/**
* 设置：
*/
public void setId(Long id) {
this.id = id;
}
/**
* 获取：
*/
public Long getId() {
return id;
}
/**
* 设置：用户名
*/
public void setUsername(String username) {
this.username = username;
}
/**
* 获取：用户名
*/
public String getUsername() {
return username;
}
/**
* 设置：用户操作
*/
public void setOperation(String operation) {
this.operation = operation;
}
/**
* 获取：用户操作
*/
public String getOperation() {
return operation;
}
/**
* 设置：请求方法
*/
public void setMethod(String method) {
this.method = method;
}
/**
* 获取：请求方法
*/
public String getMethod() {
return method;
}
/**
* 设置：请求参数
*/
public void setParams(String params) {
this.params = params;
}
/**
* 获取：请求参数
*/
public String getParams() {
return params;
}
/**
* 设置：IP地址
*/
public void setIp(String ip) {
this.ip = ip;
}
/**
* 获取：IP地址
*/
public String getIp() {
return ip;
}
/**
* 设置：创建时间
*/
public void setCreateDate(Date createDate) {
this.createDate = createDate;
}
/**
* 获取：创建时间
*/
public Date getCreateDate() {
return createDate;
}
public Long getTime() {
return time;
}
public void setTime(Long time) {
this.time = time;
}
@Override
public String toString() {
return "SysLogEntity{" +
"id=" + id +
", username='" + username + '\'' +
", operation='" + operation + '\'' +
", method='" + method + '\'' +
", params='" + params + '\'' +
", time=" + time +
", ip='" + ip + '\'' +
", createDate=" + createDate +
'}';
}
}
2.3 日志服务封装
很多人会问上面注解和切面类都写好了不就可以直接使用了吗？但是我们要知道写日志的具体实现和方式可能会不断改变，例如之前我们都是使用log4j突然架构师说logback性能更好，要全换了，或者是我们原来都是记录本地文件日志，突然有要求都发送到中央日志中心，是不是一下就懵逼了，所以我们要定义一个写日志的服务接口，在所有要调用业务日志系统日志写入的地方都调用这个接口实现，而不是直接调用具体的日志实现，做一个接口隔离，这样后面的实现我们可以很轻松的随意改变而不会影响到业务逻辑代码。
@Service
public interface SysLogService {
void save(SysLogEntity sysLog);
}
这个实现可以是简单的直接本地打印，也可以是写数据库，也可以是调用logback这些写本地文件，甚至是直接网络发送到中央日志中心。
@Service("sysLogService")
public class SysLogServiceImpl implements SysLogService {
@Override
public void save(SysLogEntity sysLog){
// sysLogDao.saveSysLog(sysLog);
System.out.println(sysLog);
}
}
3. 提高日志性能
3.1 设置缓存并异步写日志
log4j缓存配置，因为磁盘1个block为8k，配置为达到8k写一次日志文件。
<appender name="monitorAppender"
class="org.apache.log4j.DailyRollingFileAppender">
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%m%n" />
</layout>
<param name="DatePattern" value="'.'yyyy-MM-dd-HH" />
<param name="File" value="mtlogs/mt_log.txt" />
<param name="BufferedIO" value="true" />
<!-- 8K为一个写单元 -->
<param name="BufferSize" value="8192" />
</appender>
<appender name="ASYNCOUT" class="org.apache.log4j.AsyncAppender">
<param name="BufferSize" value="512" />
<appender-ref ref="DRFOUT" />
</appender>
logback设置异步队列
<appender name ="ASYNC" class= "ch.qos.logback.classic.AsyncAppender">
<!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志 -->
<discardingThreshold >0</discardingThreshold>
<!-- 更改默认的队列的深度,该值会影响性能.默认值为256 -->
<queueSize>512</queueSize>
<!-- 添加附加的appender,最多只能添加一个 -->
<appender-ref ref ="FILE"/>
</appender>
log4j和logback异步记录日志的原理基本是一样的，都是采用了异步队列的方式，先将要记录的日志直接poush到本地的BlockingQueue中，当queue中的日志量达到设置的buffer阈值的时候再启动一个异步线程获取queue中待写入的日志去写本地文件。因为磁盘io的成本是非常高的，所以每次异步写日志的时候，最好是磁盘block的整数倍，这样能够充分利用磁盘IO，不会造成写资源浪费。
3.2 异步发送网络日志
本地日志是一种方式，但是最近几年，大部分互联网公司都在公司内部建立中央集群日志类似ELK之类。这类中央日志的好处有很多，一个是方便集群量比较大的系统去查日志，现在互联网系统大部分都有很多集群节点，笔者之前做过一个移动端应用服务系统，有36个节点，当有这么多节点的时候，最痛苦的有两件事，一件事是上每个节点查询日志，还有一件是版本部署，多节点日志查询可以通过中央日志系统来解决，多节点版本部署可以通过docker之类的容器化技术或者自动化部署来解决；中央日志第二个好处是减少每个内部系统的日志压力，每个系统不用写到本地日志文件，占用本地磁盘空间，拖慢交易。
通过异步发送网络日志一般来说能够大幅提高日志性能，系统只需要每次将要写的日志发送到队列中，再从队列取出日志批量发送到中央日志系统。
上面介绍了下我们写日志比较好的实践，希望大家能够应用到自己的项目中，降低日志对系统逻辑代码的耦合性。
