日志刷屏通常不是日志框架本身的问题,而是两个环节没做好:级别过滤没有按包路径精确控制,以及日志写入与业务线程同步执行。比如在支付回调模块中,一条交易可能触发十几条INFO日志,业务高峰时控制台滚动速度远超肉眼可读范围,文件半天就能写满几个GB。要解决这个问题,单纯调高全局级别会让关键链路失去追踪信息,盲目关闭日志又不利于排查。正确做法是分层控制级别,再把落盘动作从业务线程中剥离。

一、日志级别过滤:按包路径精确控制
日志级别从高到低通常为ERROR、WARN、INFO、DEBUG、TRACE。级别控制的核心不是全局一刀切,而是按包路径为不同模块设置不同阈值。很多刷屏问题来自root级别被设置为DEBUG或INFO,导致框架包、连接池、消息队列客户端也以INFO或DEBUG级别输出。Spring容器启动时会打印大量初始化细节,MyBatis、Netty等组件同样如此。
在生产环境,合理的默认策略是:自有业务包保持INFO,第三方包和框架至少设置为WARN,核心交易链路可以单独提升到DEBUG以应对线上排查。Logback的logger继承机制可以实现这一点:子logger默认继承父logger的级别和appender,设置additivity="false"可以阻止日志向父级重复传递,避免同一行日志被打印两次。
<configuration>
<root level="WARN">
<appender-ref ref="CONSOLE"/>
</root>
<logger name="com.example.order" level="INFO" additivity="false">
<appender-ref ref="CONSOLE"/>
</logger>
<logger name="org.springframework" level="WARN"/>
<logger name="com.zaxxer.hikari" level="WARN"/>
</configuration>
这段配置先把全局级别收紧到WARN,再单独放开订单模块。这样第三方组件的INFO通知不会进入控制台,而业务关键日志仍然保留。另一个容易忽视的点是循环体内的日志:如果在一个遍历5000条记录的循环里打印INFO,即使级别为INFO也会造成刷屏。此时应把循环细节降到DEBUG,并在打印前调用logger.isDebugEnabled()判断,避免无谓的字符串拼接和参数装箱。
更推荐使用参数化日志。例如logger.debug("处理订单编号:{}", orderNo);,框架只有在级别满足时才会执行字符串拼接。不要在循环里写logger.info("订单明细:" + detail.toString());,因为即使INFO被关闭,字符串拼接也会执行,造成额外CPU和内存开销。
二、异步写入:用队列解耦日志IO
同步Appender的代价在于:每调用一次logger.info,业务线程都可能等待文件写入或网络传输完成后才能继续。对于本地磁盘写入,虽然操作系统有页缓存,但高频写入仍会让业务线程出现明显的IO等待。异步写入的思路是引入一个内存队列,业务线程只负责把日志事件放入队列,由后台消费者线程批量或逐个落盘。
Logback提供了<appender>的异步实现ch.qos.logback.classic.AsyncAppender。配置时先定义普通文件Appender,再把它挂到异步Appender下面。核心参数包括queueSize、discardingThreshold和neverBlock。队列默认容量只有256个事件,瞬时高并发下很容易打满。
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/app.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
<fileNamePattern>logs/app.%d{yyyy-MM-dd}.log</fileNamePattern>
<maxHistory>7</maxHistory>
</rollingPolicy>
<encoder>
<pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>1024</queueSize>
<discardingThreshold>0</discardingThreshold>
<neverBlock>false</neverBlock>
<appender-ref ref="FILE"/>
</appender>
这里把队列扩容到1024,并设置discardingThreshold为0,表示不丢弃任何级别的日志。但业务线程可能因为队列满而被阻塞,因此neverBlock设为false。如果更加看重接口响应时间,可以设置neverBlock=true,让业务线程在队列满时直接丢弃日志事件,避免阻塞,但会牺牲日志完整性。
队列容量不是越大越好。容量过小会导致频繁装满,容量过大则内存占用上升,极端情况下,如果磁盘写入速度长期跟不上产生速度,队列会持续堆积,进而触发频繁GC或OOM。一个折中方案是:生产环境将queueSize设为512到2048之间,保留discardingThreshold为20%,但仅丢弃DEBUG和TRACE级别日志,保证INFO以上事件尽量保留。Logback在队列剩余容量低于阈值时会先丢弃低级别日志,这种策略比直接阻塞更符合互联网服务对可用性的要求。
如果使用Log4j2,还可以选择基于LMAX Disruptor的AsyncLogger,吞吐量比Logback的ArrayBlockingQueue方案更高。但无论哪种实现,异步写入都不能消除磁盘IO总量,只是把IO成本转移到后台线程。因此仍然需要配合滚动策略、日志压缩和合理的保留天数,避免磁盘被写满。
三、完整配置与压测验证
将级别过滤和异步写入组合起来,可以得到一个比较完整的Logback配置。下面示例区分了控制台和文件输出:控制台保留给开发环境,文件走异步通道,第三方组件维持WARN,订单模块保持INFO,SQL日志单独限制到DEBUG。
<configuration>
<property name="LOG_PATH" value="logs/app"/>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{40} - %msg%n</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>${LOG_PATH}.log</file>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${LOG_PATH}.%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>14</maxHistory>
<totalSizeCap>5GB</totalSizeCap>
</rollingPolicy>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
</encoder>
</appender>
<appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
<queueSize>2048</queueSize>
<discardingThreshold>20</discardingThreshold>
<neverBlock>true</neverBlock>
<appender-ref ref="FILE"/>
</appender>
<root level="WARN">
<appender-ref ref="CONSOLE"/>
<appender-ref ref="ASYNC_FILE"/>
</root>
<logger name="com.example.order" level="INFO" additivity="false">
<appender-ref ref="ASYNC_FILE"/>
</logger>
<logger name="com.example.sql" level="DEBUG" additivity="false">
<appender-ref ref="ASYNC_FILE"/>
</logger>
</configuration>
这段配置里,ASYNC_FILE的neverBlock设置为true,优先保证接口不因日志阻塞。20%的丢弃阈值只会在队列接近打满时触发,而且按照级别从低到高丢弃,因此ERROR和WARN仍大概率保留。实际项目中是否允许丢日志,需要和业务方确认。如果必须有完整审计日志,可改用neverBlock=false,并适当调大队列容量。
验证时可以用一段简单的Java代码模拟高频日志输出,对比同步和异步两种配置下的耗时和CPU使用。测试逻辑并不复杂:循环调用5000次logger.info,分别记录总耗时。同步模式下,耗时通常会随文件大小增长而上升;异步模式下,业务线程耗时会显著下降,但后台消费线程的CPU占用会升高。观察指标时要同时看接口响应时间、日志文件增长速率和JVM内存曲线,避免只看到响应变快就认为调优完成。
public class LogPressureTest {
private static final Logger logger = LoggerFactory.getLogger(LogPressureTest.class);
public static void main(String[] args) {
long start = System.currentTimeMillis();
for (int i = 0; i < 5000; i++) {
logger.info("订单处理完成,订单号:{},当前序号:{}", "ORDER-" + i, i);
}
long cost = System.currentTimeMillis() - start;
System.out.println("5000条日志写入耗时:" + cost + " ms");
}
}
上述代码没有使用System.out.println代替日志输出,因此测试结果能反映日志框架的真实开销。如果需要进一步观察线程状态,可以用jstack查看业务线程是否阻塞在ArrayBlockingQueue.put上,或者用jstat -gcutil观察异步队列对新生代内存的影响。
最后需要注意,异步写入不是银弹。单线程批处理任务、低并发后台服务如果盲目开启异步,可能只是把简单问题复杂化。异步Appender还会带来日志顺序问题,因为多个业务线程并发入队时,事件的相对顺序无法完全保证。如果日志之间有严格的先后依赖,建议在日志中携带全局traceId或时间戳,而不是依赖写入顺序排查问题。至此,通过按包路径细化级别,再加上合理的异步队列参数,日志刷屏基本可以得到控制。