做后端开发的没人离得开日志不管是线上问题排查、接口异常追踪还是日常业务监控日志都是最直接的依据。很多人开发项目都是直接引入starter依赖默认配置直接跑从来不会主动去改日志底层参数。平时本地测试没啥问题一上生产就各种离谱状况日志重复打印、部分异常堆栈丢失、磁盘日志文件爆涨、异步日志丢数据。踩的坑多了慢慢发现大部分线上日志问题都不是代码bug导致的而是日志框架默认配置的隐性缺陷造成的。今天就结合我日常迭代、线上排障的真实经历盘点几个最容易被忽视、网上博文很少讲透的logbackslf4j实战坑内容都是实打实的项目经验没有空话套话。一、最鸡肋的坑默认日志重复输出问题这个问题我敢说百分之六十的Java开发者都遇到过但绝大多数人都不知道根因在哪。现象很简单自定义配置了root日志输出但是控制台、日志文件里每一条业务日志都会打印两遍一遍正常、一遍重复日志文件体积直接翻倍排查问题的时候也眼花缭乱。很多人第一反应是代码写了两次log输出翻遍全局代码根本没有重复调用info、error方法。其实核心原因就两个一是appender没有设置additivityfalse二是root节点和子logger节点的输出流冲突了。简单解释下logback的日志传播机制是向上传递的。如果你针对某个包单独配置了logger输出又在root节点配置了全局输出且没有关闭传递那么这条日志会先被子logger输出一次再向上传递给root节点再输出一次。贴一段很多新手会写错的配置这也是我刚入行时踩过的错误写法logger namecom.xxx.service levelINFO appender-ref refFILE / /logger root levelINFO appender-ref refFILE / appender-ref refCONSOLE / /root上面这段配置百分百会出现日志重复打印。因为com.xxx.service包下的日志输出后会默认向上传递给root双重输出无法避免。正确的写法只需要在自定义logger节点中加上additivityfalse阻断日志向上传递即可。这里提一句网上很多教程只说加这个参数但是没人讲原理。其实这个参数的默认值是true也就是默认开启向上传播这也是官方默认配置最大的一个迷惑点。修正后的配置logger namecom.xxx.service levelINFO additivityfalse appender-ref refFILE / /logger改完之后重启项目重复打印的问题直接解决。我之前接手过一个老项目就是因为这个问题生产环境日志文件每天多十几个G运维天天报警前任开发一直没找到问题白白浪费服务器磁盘资源。二、致命坑异步日志开启后异常堆栈丢失、日志丢包为了提升接口响应速度减少日志同步打印带来的IO阻塞现在大部分项目都会开启logback的异步日志。异步日志的优势很明显把日志打印操作丢到后台线程池不占用业务线程高并发场景下性能提升非常明显。但异步日志也是线上丢日志、丢异常堆栈的重灾区很多生产诡异问题都出自这里。我上个月就碰到一个线上bug用户支付失败后台捕获了异常但是日志文件里只有异常提示文案没有完整堆栈信息根本无法定位报错位置。排查了整整一下午最后才锁定是异步日志队列满了丢弃了部分日志数据。logback的异步appender默认队列容量只有256这个数值在高并发场景下完全不够用。当瞬时请求量暴增日志生成速度远超异步线程的消费速度队列塞满之后新的日志任务会被直接丢弃而且不会抛出任何异常开发者完全感知不到。更坑的一点是默认配置下INFO级别以下的日志会优先被丢弃ERROR异常日志也会随机丢失这就导致线上出问题却没有日志可查。还有一个隐藏问题异步日志如果没有配置includeCallerDatatrue打印的日志会缺失类名、行号、方法名排查问题时只能看到报错信息看不到具体代码位置基本等于废日志。给大家贴一份生产可用的异步日志正确配置避开所有默认坑appender nameASYNC_FILE classch.qos.logback.classic.AsyncAppender appender-ref refFILE/ !-- 开启调用方数据保留类名行号 -- includeCallerDatatrue/includeCallerData !-- 扩容队列容量适配高并发 -- queueSize2048/queueSize !-- 队列剩余容量小于阈值不丢弃error日志 -- neverBlocktrue/neverBlock /appender这里重点说下neverBlock参数很多人搞不懂作用。设置为true时队列满了之后不会阻塞业务线程直接丢弃多余日志设置为false会阻塞业务线程保证日志不丢失但会影响接口性能。生产环境建议按需配置核心支付、订单业务建议关闭丢弃策略宁愿牺牲一点性能也要保证日志完整普通查询、统计接口可以开启丢弃保证接口响应速度。三、极易忽略日志滚动策略不当导致磁盘爆满日志滚动切割是每个项目必备的配置按天切割、按大小切割看似简单实则很多人配置的都不规范。常见错误配置有两个一是只配置按天切割不配置单文件最大容量二是没有设置日志保留天数。我之前碰到过一次线上事故项目上线半年从来没人清理日志服务器磁盘直接被占满所有接口全部报错服务宕机。原因就是老项目的logback配置只写了按天滚动没有配置maxHistory日志文件无限累加半年时间积累了上百G日志。还有一种情况大流量项目单日日志量极大只按天切割的话单个日志文件会达到几十G打开卡顿、检索困难完全没法排查问题。所以生产环境必须配置时间大小双维度滚动切割同时限制日志保留时长自动清理过期日志。标准生产配置如下appender nameFILE classch.qos.logback.core.rolling.RollingFileAppender filelogs/app.log/file rollingPolicy classch.qos.logback.core.rolling.TimeBasedRollingPolicy fileNamePatternlogs/app-%d{yyyy-MM-dd}-%i.log/fileNamePattern !-- 保留7天日志自动清理过期文件 -- maxHistory7/maxHistory !-- 单文件最大2GB超出自动拆分 -- maxFileSize2GB/maxFileSize !-- 总日志容量上限防止磁盘爆满 -- totalSizeCap20GB/totalSizeCap /rollingPolicy /appender这里提醒一句maxHistory的生效规则是跟随滚动时间的按天切割就按天清理按小时切割就按小时清理配置的时候一定要对应上。另外很多人忽略totalSizeCap这个参数是兜底配置就算保留天数没到总容量超出上限也会自动删除最早的日志双重保障磁盘安全。四、依赖冲突slf4j多重绑定日志错乱失效这是依赖层面的经典坑几乎所有做过微服务的开发者都碰到过。现象就是项目启动报错SLF4J: Class path contains multiple SLF4J bindings日志输出错乱有的模块能打日志有的模块完全无日志严重时项目启动失败。根本原因是项目中引入了多个日志实现包比如logback、log4j、slf4j-simple同时存在slf4j无法确定绑定哪个实现导致冲突。最常见的冲突来源是第三方依赖比如老版本的redis、kafka、工具类包会隐性带入其他日志框架。解决办法很简单统一日志依赖排除所有多余的日志实现全局统一使用slf4jlogback。maven统一排除配置直接放到父pom中全局生效dependencyExclusions exclusion groupIdorg.slf4j/groupId artifactIdslf4j-simple/artifactId /exclusion exclusion groupIdorg.slf4j/groupId artifactIdslf4j-log4j12/artifactId /exclusion exclusion groupIdlog4j/groupId artifactIdlog4j/artifactId /exclusion /dependencyExclusions很多人图省事看到冲突报错直接忽略觉得不影响运行。实则隐患极大依赖冲突会导致日志随机丢失线上出问题根本无法溯源属于必须修复的高危问题。五、个人实战总结日志框架看着简单属于项目里最基础的组件但往往就是这种基础组件的隐性坑最容易导致线上重大问题。我总结了几条自己日常开发的日志规范团队内部一直强制执行基本规避了百分之99的日志问题1、所有自定义logger必须手动添加additivityfalse杜绝日志重复输出2、高并发项目必须优化异步日志配置扩容队列、开启调用方数据禁止使用默认参数3、生产环境一律使用时间大小双滚动策略配置过期清理和总容量兜底4、全局统一日志依赖排查所有第三方包的日志冲突不保留多余日志实现5、核心业务异常必须手动打印完整堆栈禁止只打印简单提示文案。其实很多开发都不重视日志配置觉得能打印日志就行。但线上排查问题日志是唯一的抓手日志配置不规范出问题时寸步难行白白浪费大量排障时间。以上就是我多年开发积累的日志框架核心坑点都是实战踩坑总结出来的干货没有任何纸上谈兵。后续碰到新的日志坑点也会持续更新记录。
