系统优化实践记录—日志

系统优化实践记录—日志

在决定使用该开源项目后，首先熟悉了项目的架构，然后在阅读源码的过程中，发现日志打印十分不规范，同时对日志的使用也很差，于是，我利用jmeter和jvisualvm在windows机器上进行了简单的测试。发现写日志的时间占据了整个系统执行时间（CPU）时间的40%多，于是，首先便是对日志的重构。

PS：这里主要用jmeter进行压力测试，用jvisualvm监控java程序的方法在cpu的总执行时间。两个工具的使用网上资料十分多，这里不再赘述。利用阿里开源的tprofiler可以在linux上对系统监控，观察线程执行情况和Java程序方法执行时间占cpu总的执行时间。

在一个系统中，日志十分重要的，我们往往需要通过日志去分析生产问题等，那么如何在系统中使用好日志呢？

一 、按环境使用日志级别

在系统的开发中，一般都会分开发（env），测试（stg），生产（prd）三个环境，在使用日志时我们主要会使用到日志的DEBUG，INFO，WARN，ERROR这四个级别。

1. DEBUG：最基础的日志级别，一般在开发和测试时使用该级别，打印最基本的系统信息及功能信息，比如在mq系统中，每次发送一条消息，应该用debug级别打印出来，方便调试。

2. INFO：比DEBUG高一级，一般在生产使用，打印最基本的系统信息和必要的功能信息，例如：在mq系统中，如果每发一条消息都打印一次，那么在消息量很大时日志会耗费非常多的io和cpu执行时间，在mqtt中，用info打印连接信息，订阅信息等日志

3. WARN：打印系统一般错误信息，客户端异常操作信息，例如校验失败等信息

4. ERROR：打印系统异常。

在开发环境使用DEBUG级别，在测试环境使用DEBUG和INFO级别，在生产环境使用INFO级别。级别越低，打印的日志越多，信息越详细，相应的系统在处理日志方面需要牺牲更多的性能。

能越少打印就少打印，不要重复打印日志。

二、日志分类

在打印日志时，可以按功能区分来打印日志，方便对日志的查看，例如就mqtt来说。有：连接，发布消息，订阅，集群，存储等功能，那么打印日志时，就可以分别将相应的逻辑的日志打印到相应的日志文件里。比如connect.log，publish.log等。对于异常信息也可以打印到专门的异常日志文件中，例如connect_error.log等。同时，日志是滚动打印的，可以按日志大小，也可以按时间，方便查看。

三、使用LoggerName而不是class

在使用日志时，下面是很常见的用法。我们使用的开源项目也全是这种打印

private static final Logger LOG = LoggerFactory.getLogger(Server.class);

这里Server是启动类，mqtt的启动日志放在mqtt.log中，所以最好用下列方式

private static final Logger LOG = LoggerFactory.getLogger("mqtt.log");

可以直接将该类的日志输出到mqtt.log，满足第二点日志分类，不用每次都要获取该类的字节码。

四、不要打印多余的日志信息

在打印日志时，不需要重复打印某个日志信息，例如mqtt的连接，在连接进来时打印一条信息。在处理期间，如果不出现异常，是不需要再打印多余的信息的，在一条日志中我们最好打印出所有可能有用的信息。例如类名，方法名，执行线程名等，而不是将信息分开记录。

五、在日志中，不要使用“+”拼接，而是使用{}

例如如下对一段日志的打印：

LOG.debug("Starting Mqtt server. Configuration file path="+configFile.getAbsolutePath());
LOG.debug("Starting Mqtt server. Configuration file path={}", configFile.getAbsolutePath());

它们的区别是：第一段无论如何都会对这段字符串进行拼接，而第二条只会在执行debug级别时才去拼接。而在生产上我们是不打印debug日志的，所以拼接是多余的操作。