Java日志最佳实践(游戏项目)
窥一斑而知全豹(阿里、唯品会)
阿里日志规约
1. 【强制】应用中不可直接使用日志系统 （Log 4 j 、 Logback） 中的 API ，而应依赖使用日志框架
SLF 4 J 中的 API ，使用门面模式的日志框架，有利于维护和各个类的日志处理方式统一。
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
private static final Logger logger = LoggerFactory.getLogger(Abc.class);
2. 【强制】日志文件推荐至少保存 15 天，因为有些异常具备以“周”为频次发生的特点。
3. 【强制】应用中的扩展日志 （ 如打点、临时监控、访问日志等 ） 命名方式：
appName _ logType _ logName . log 。 logType :日志类型，推荐分类有
stats / desc / monitor / visit 等 ；logName :日志描述。这种命名的好处：通过文件名就可知
道日志文件属于什么应用，什么类型，什么目的，也有利于归类查找。
正例： mppserver 应用中单独监控时区转换异常，如：
mppserver _ monitor _ timeZoneConvert . log
说明：推荐对日志进行分类，如将错误日志和业务日志分开存放，便于开发人员查看，也便于通过日志对系统进行及时监控。
4. 【强制】对 trace / debug / info 级别的日志输出，必须使用条件输出形式或者使用占位符的方
式。
说明： logger . debug( " Processing trade with id : " + id + " and symbol : " + symbol);
如果日志级别是 warn ，上述日志不会打印，但是会执行字符串拼接操作，如果 symbol 是对象，
会执行 toString() 方法，浪费了系统资源，执行了上述操作，最终日志却没有打印。
正例： （ 条件 ）
if (logger.isDebugEnabled()) {
logger.debug("Processing trade with id: " + id + " and symbol: " + symbol);
}
正例： （ 占位符 ）
logger.debug("Processing trade with id: {} and symbol : {} ", id, symbol);
5. 【强制】避免重复打印日志，浪费磁盘空间，务必在 log 4 j . xml 中设置 additivity = false 。
正例： <logger name="com.taobao.dubbo.config" additivity="false">
6. 【强制】异常信息应该包括两类信息：案发现场信息和异常堆栈信息。如果不处理，那么通过
关键字 throws 往上抛出。
正例： logger.error(各类参数或者对象 toString + "_" + e.getMessage(), e);
7. 【推荐】谨慎地记录日志。生产环境禁止输出 debug 日志 ； 有选择地输出 info 日志 ； 如果使
用 warn 来记录刚上线时的业务行为信息，一定要注意日志输出量的问题，避免把服务器磁盘撑爆，并记得及时删除这些观察日志。说明：大量地输出无效日志，不利于系统性能提升，也不利于快速定位错误点。记录日志时请
思考：这些日志真的有人看吗？看到这条日志你能做什么？能不能给问题排查带来好处？
8. 【参考】可以使用 warn 日志级别来记录用户输入参数错误的情况，避免用户投诉时，无所适从。注意日志输出的级别， error 级别只记录系统逻辑出错、异常等重要的错误信息。如非必要，请不要在此场景打出 error 级别。
唯品会日志日志规约
Rule 1. 【强制】应用中不可直接使用日志库（Log4j、Logback）中的API，而应使用日志框架SLF4J中的API
使用门面模式的日志框架，有利于维护各个类的日志处理方式统一。
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
private static Logger logger = LoggerFactory.getLogger(Foo.class);
Rule 2. 【推荐】对不确定会否输出的日志，采用占位符或条件判断
//WRONG
logger.debug("Processing trade with id: " + id + " symbol: " + symbol);
如果日志级别是info，上述日志不会打印，但是会执行1)字符串拼接操作，2)如果symbol是对象，还会执行toString()方法，浪费了系统资源，最终日志却没有打印。
//RIGHT
logger.debug("Processing trade with id: {} symbol : {} ", id, symbol);
但如果symbol.getMessage()本身是个消耗较大的动作，占位符在此时并没有帮助，须要改为条件判断方式来完全避免它的执行。
//WRONG
logger.debug("Processing trade with id: {} symbol : {} ", id, symbol.getMessage());
//RIGHT
if (logger.isDebugEnabled()) {
logger.debug("Processing trade with id: " + id + " symbol: " + symbol.getMessage());
}
Rule 3. 【推荐】对确定输出，而且频繁输出的日志，采用直接拼装字符串的方式
如果这是一条WARN，ERROR级别的日志，或者确定输出的INFO级别的业务日志，直接字符串拼接，比使用占位符替换，更加高效。
Slf4j的占位符并没有魔术，每次输出日志都要进行占位符的查找，字符串的切割与重新拼接。
//RIGHT
logger.info("I am a business log with id: " + id + " symbol: " + symbol);
//RIGHT
logger.warn("Processing trade with id: " + id + " symbol: " + symbol);
Rule 4. 【推荐】尽量使用异步日志
低延时的应用，使用异步输出的形式(以AsyncAppender串接真正的Appender)，可减少IO造成的停顿。
需要正确配置异步队列长度及队列满的行为，是丢弃还是等待可用，业务上允许丢弃的尽量选丢弃。
Rule 5. 【强制】禁止使用性能很低的System.out()打印日志信息
同理也禁止e.printStackTrace();
例外: 应用启动和关闭时，担心日志框架还未初始化或已关闭。
Sonar-106: Standard outputs should not be used directly to log anything
Sonar-1148: Throwable.printStackTrace(...) should not be called
Rule 6. 【强制】禁止配置日志框架输出日志打印处的类名，方法名及行号的信息
日志框架在每次打印时，通过主动获得当前线程的StackTrace来获取上述信息的消耗非常大，尽量通过Logger名本身给出足够信息。
Rule 7. 【推荐】谨慎地记录日志，避免大量输出无效日志，信息不全的日志
大量地输出无效日志，不利于系统性能，也不利于快速定位错误点。
记录日志时请思考：这些日志真的有人看吗？看到这条日志你能做什么？能不能给问题排查带来好处？
Rule 8. 【推荐】使用warn级别而不是error级别，记录外部输入参数错误的情况
如非必要，请不在此场景打印error级别日志，避免频繁报警。
error级别只记录系统逻辑出错、异常或重要的错误信息。
记录日志的目的和原则
- 目的
- 原则
- 这些日志真的有人看吗？
- 看到这条日志你能做什么？
- 能不能给问题排查带来好处？
- 不多不少
最佳日志实践(游戏项目)
- 统一管理SLF4J#Logger
- 封装统一的Logs接口，通过此接口获取Logger
- 使用时通常可结合"import static"
- 没有必要每一个class内都声明一个Logger
- 注：当前日志实现是logback
- Logger分类
- system
- 系统日志、包括系统启停(info)、系统运行监控日志等(debug、每分钟)
- 通过该日志可以知道系统是否顺利启动、开启debug日志后可以知晓当前系统整体状态
- persistence
- 持久化日志，主要是mongo/redis的数据存储、加载日志，较重要
- 通过该日志可以知道如一个玩家数据的序列化时间，整体一个调度周期的序列化时间，加载一个玩家数据的时间，回档的判断等
- net
- 网络层日志，主要包括request/response/notify等（通常这部分是debug日志，在上线前期打开，后期随着版本稳定可以关闭），也包括自定义网络层的一些日志
- 通常查询线上bug现在业务日志查询，如果需要上下文的request/response等详细信息可去net日志查询
- business
- 业务日志，主要包括各业务模块自己的一些日志打印，如方法如参的检查，业务操作的记录等。这个日志是通常排查问题经常用到的
- 如果有比较大或者比较大的业务模块，日志比较多需要经常查看的话，可以单独出来一个模块日志
- schedule
- 定时调度日志，目前主要包括quartz的相关日志。在查询定时任务相关的bug时，此日志比较重要
- devops
- 包括游戏与外部运维、运营、三方sdk交互的日志，如gm、推送、global等
- robot
- third
- 三方依赖库日志，包括revenant框架的日志和部分比较重要的三方库日志
- 注：1. 需要使用slf4j 2. thrid logger是基于"package name"
- error
- 错误日志单独一个文件，主要是一些重要的错误和异常
- 注：并没有一个单独的这样logger，而是各个模块logger的error除了追到自己的文件外，还要统一汇总到error.log
- 日志格式规范
- 禁用的conversion specifier(logback)
- C/class、F/file、L/line、M/method、caller
- its use should be avoided unless execution speed is not an issue
- logback.xml#推荐pattern
- 必须字段：d、t、p、m 可选字段：c
- %d{HH:mm:ss.SSS} [%t] %-5p %c{0} - %m%n
- 这个输出了logger，主要用于三方库的logger
- %d{HH:mm:ss.SSS} [%t] %-5p - %m%n
- msg
- 必选项2：class.method (用来定位，相当于手动实现了"class.method")
- 必选项2：如果是玩家相关的日志，最好记录rid(用来定位会话标识)
- 这有另外一个很重要的作用是可以写过滤器，过滤输出某个指定出错玩家的debug日志
- 必选项2：精炼内容
- 记录日志的时候需要考虑当线上出现问题的时候，我记录的日志内容是否能对我排查问题起到作用？是否会出现该记录的没有记录？
- 需要review是否通顺，别人是否可以看懂，能否提供真正有意义的信息
- 日志级别
- 只使用debug、info、warn、error四个级别
- error-当系统出现较严重的问题时会经常去错误日志查看
- 较重要的异常(注：并非所有异常都记录error，有些可能为warn)
- 较重要的错误信息(注：逻辑参数检查不通过这种不是error)
- warn
- 主要用来记录如handler参数校验不通过
- 用来记录部分不重要的异常、非正常的条件分支(业务流程预期不符)
- info-通常来说优先根据info日志可初步定位
- 主要包括如系统状态变化日志
- 业务流程的核心处理、关键动作
- 业务流程的状态变化
- debug
- 通常上线前期debug日志会打开，后随着稳定会关闭debug
- 当出现bug时或者棘手的问题时，需要动态的开启debug
- 如果只是某个玩家出现问题，那么开启debug日志量会非常大，所以需要有基于rid判断的日志过滤器(RidFilter extends Filter<ILoggingEvent>)
- 日志性能
- 推荐使用AsyncAppender
- 避免阻塞业务逻辑线程
- queueSize和discardingThreshold都要设置，即允许丢失日志，否则队列满会造成业务线程阻塞
- 优先使用{}占位符进行参数格式化，除非参数调用消耗较大需要增加isEnabled条件判断
- 避免使用代价较大caller data(C/F/L/M)
- 再向进一步提升性能的话，可考虑log4j2(Asynchronous Loggers based on the LMAX Disruptor library)
- 日志细节
- 个人不建议用一个工具类来再包装一层debug/info/warn/error方法
- 这种实现通常只能声明一个logger，无法控制多个模块的level
- 行号不准确，需要通过具体的logger传入'fqcn'实现
- 记录日志一定不能抛出异常
- 可能会影响业务逻辑，需要check日志格式化参数调用是否可能抛出异常
- 记录异常要用规范的格式
- log.error("filter error:",e) // 这个是正确的方式
- log.error("filter error:{}",e) // 这个是错误的方式
- 其实只要看org.slf4j.Logger接口的api就了解了#error(String msg, Throwable t)
- 建议使用SiftingAppender，避免logback内声明过多的appender
- 如果需要配合AsyncAppender使用，则外部只需要声明一个该Appender即可，然后其appender-ref指向sift(SiftingAppender admits one and only one nested appender)
- 线上记录日志避免使用System.out、System.err、e.printStackTrace()
- 不用担心日志框架没有启动，这个日志框架内部会使用标准输出打印
- 所以程序启动时刻的标准输出和标准错误不能丢（即不能重定向到/dev/null），另外一个原因是一些三方日志没有使用slf4j，也可能会直接向控制台写日志
- 如果使用nohup启动程序，建议将标准输出和标准错误都重定向到/dev/null,否则nohup默认的重定向文件nohup.out会越来越大
- >/dev/null 2>&1
- 不过当日志框架未初始化时就报错的还是，则还是需要修改启动脚本输出stdout和stderr
- 所以优先建议使用python启动程序(使用sh库)
- 一些重要的错误可以和报警系统关联起来
- 一些较重要的系统信息建议接入监控系统
- 如通过grafana这种图表化的形式直接的看到系统信息的变化曲线
- 线上可根据需要动态的调整各个logger的level
- 可直接修改logback.xml
- 可通过'脚本化'的方式获取到对应的logger调用setLevel即可(需要转为对应实际的logger如ch.qos.logback.classic.Logger)
- 要考虑日志文件的大小
- 日志太大，则很难grep
- 所以要通过线上测试酌情考虑根据文件大小滚动文件
- 日志的maxHistory建议为15天
参考
- 最佳日志实践（v2.0）
- 优秀日志实践准则
- 唯品会日志规约
- 阿里巴巴Java开发手册#日志规约
- slf4j faq
- logback layouts
- logback filters
- Apache Log4j 2
- log4j日志封装说明
- Java日志性能那些事
- Java日志的一些细节
- Logback SiftAppender
- 提升logback的性能
- SiftAppender的问题
网友评论