一个 logback 配置踩坑唯一索引冲突的 warn 日志去哪了生产环境排查重复消费问题明明代码里catch住了异常并打了log.warn却在日志文件里死活找不到。控制台输出又因容器化部署而丢失问题久久无法定位。本文记录一次真实排查过程根因出在 logback 的root logger与BIZ logger配置差异上。一、问题背景Kafka 消费者接收设备事件消息后需要落库到本地device_event_message表。该表的msg_service_business_id字段上有唯一索引用于防止 Kafka 重复消费导致的数据重复。代码逻辑很标准try里执行insertcatch (Exception e)里log.warn打印日志并吞掉异常不阻断后续推送流程。ServiceSlf4jpublicclassBizMsgServiceImpl{KafkaListener(topics${kafka.consumer.deviceEventTopic},...)publicvoidkafkaDeviceEventListen(ConsumerRecordString,Stringrecord){// ... 解析事件 ...StringmsgServiceBusinessIdevent.getDeviceId()_event.getDeviceSn()_event.getOccurTime();// 保存到本地设备事件表saveDeviceEventMessage(event,containerId,msgServiceBusinessId);// ... 后续推送消息中心 ...LogUtils.BIZ.info(发送设备事件消息 {},Collections.singletonList(msgInfoReqDTO));msgInfoService.savaMsgInfoPOS(Collections.singletonList(msgInfoReqDTO));}/** * 将Kafka设备事件保存到本地设备事件表 * business_id 存在唯一索引重复事件插入失败时仅告警不阻断 */privatevoidsaveDeviceEventMessage(DeviceEventEntityevent,StringcontainerId,StringbusinessId){try{DeviceEventMessagePOponewDeviceEventMessagePO();// ... set 各字段 ...deviceEventMessageMapper.insert(po);}catch(Exceptione){log.warn(保存设备事件到本地表失败 businessId{},businessId,e);}}}二、问题现象线上一段时间后用户反馈偶发重复推送。排查时翻遍warn.log、error.log文件没有找到任何保存设备事件到本地表失败的日志。但数据库里又能查到唯一索引冲突的痕迹或通过其他途径确认确实发生了重复消费。于是陷入明明打了日志却找不到的困境。三、根因分析3.1 第一反应日志级别第一反应是怀疑log.warn级别在生产环境被调高过滤了。但查看logback-spring.xmlrootlevelINFOappender-refrefSTDOUT/appender-refrefASYNC_INFO/appender-refrefASYNC_ERROR//rootroot levelINFOWARN 级别高于 INFO级别上不会被过滤。这条路走不通。3.2 第二反应异常没抛出怀疑insert违反唯一约束时没有抛异常。但 MyBatis-Plus 的BaseMapper.insert执行的是标准INSERT INTOMySQL 唯一索引冲突会立即抛SQLException经 MyBatis 包装为PersistenceException再经 Spring 包装为DuplicateKeyException。这些异常都会被catch (Exception e)捕获。而且即使不抛异常log.warn这行代码至少会被执行除非异常发生在catch之前。所以异常没抛出也不是根因。3.3 真相root logger 没有 ASYNC_WARN仔细对比logback-spring.xml中root logger和BIZ logger的 appender 配置!-- root logger只挂了 STDOUT、ASYNC_INFO、ASYNC_ERROR没有 ASYNC_WARN --rootlevelINFOappender-refrefSTDOUT/appender-refrefASYNC_INFO/appender-refrefASYNC_ERROR//root!-- BIZ logger挂了 ASYNC_WARN --loggernameBIZlevelDEBUGadditivityfalseappender-refrefSTDOUT/appender-refrefASYNC_INFO/appender-refrefASYNC_DEBUG/appender-refrefASYNC_WARN/appender-refrefASYNC_ERROR//logger再看各文件 appender 的 filter 配置——用的是LevelFilter精确匹配appendernameWARNclassch.qos.logback.core.rolling.RollingFileAppenderfilterclassch.qos.logback.classic.filter.LevelFilterlevelWARN/levelonMatchACCEPT/onMatchonMismatchDENY/onMismatch!-- 非 WARN 一律拒绝 --/filterfile${logPath}/log/warn.log/file.../appenderappendernameINFOclassch.qos.logback.core.rolling.RollingFileAppenderfilterclassch.qos.logback.classic.filter.LevelFilterlevelINFO/levelonMatchACCEPT/onMatchonMismatchDENY/onMismatch!-- WARN 会被拒绝不进 info.log --/filter.../appender3.4 两个 logger 的行为差异关键在于代码里用了哪个 logger调用方式logger 名称走的 logger 配置warn.loginfo.log控制台 STDOUTlog.warn(...)Slf4j注入com.dsa.hems.msg.service.BizMsgServiceImplroot❌ 不写入❌ LevelFilter 拒绝 WARN✅但容器易丢失LogUtils.BIZ.warn(...)BIZBIZ logger✅ 写入❌✅// LogUtils.javapublicinterfaceLogUtils{LoggerBIZLoggerFactory.getLogger(BIZ);}saveDeviceEventMessage用的是log.warn走 root logger而同一个 KafkaListener 方法里其他业务日志用的都是LogUtils.BIZ.info走 BIZ logger。root logger 没有挂载ASYNC_WARNappender所以log.warn的输出❌ 不写入warn.log只有 BIZ logger 才挂了 ASYNC_WARN❌ 不写入info.logINFO appender 的 LevelFilter 精确匹配 INFOWARN 被 DENY❌ 不写入error.log同理✅ 只输出到控制台 STDOUT而生产环境是 Docker 容器部署控制台日志不落盘、易丢失排查时只看文件日志自然就找不到日志了。3.5 一次完整的调用链对照KafkaListener(...)publicvoidkafkaDeviceEventListen(ConsumerRecordString,Stringrecord){LogUtils.BIZ.info(监听到设备事件消息 {} ,value);// ✅ 走 BIZ写 info.log// ...saveDeviceEventMessage(...);// ⚠️ 内部用 log.warn走 root// ...LogUtils.BIZ.info(发送设备事件消息 {},...);// ✅ 走 BIZ写 info.log}privatevoidsaveDeviceEventMessage(...){try{deviceEventMessageMapper.insert(po);}catch(Exceptione){log.warn(保存设备事件到本地表失败 ...,e);// ❌ 走 root不写任何文件}}同一个方法里BIZ logger 和Slf4j的log混用正是这次踩坑的直接原因。四、解决方案4.1 方案一推荐统一使用 BIZ logger把log.warn改成LogUtils.BIZ.warn与同方法其他日志保持一致privatevoidsaveDeviceEventMessage(DeviceEventEntityevent,StringcontainerId,StringbusinessId){try{DeviceEventMessagePOponewDeviceEventMessagePO();po.setMsgServiceBusinessId(businessId);// ... set 各字段 ...deviceEventMessageMapper.insert(po);}catch(DuplicateKeyExceptione){// 唯一索引冲突Kafka重复消费或同businessId事件重复推送属于预期场景仅告警不阻断LogUtils.BIZ.warn(设备事件重复插入(唯一索引冲突), businessId{}, deviceSn{}, eventType{}, occurTime{},businessId,event.getDeviceSn(),event.getEventType(),event.getOccurTime());}catch(Exceptione){LogUtils.BIZ.warn(保存设备事件到本地表失败, businessId{}, deviceSn{}, eventType{},businessId,event.getDeviceSn(),event.getEventType(),e);}}补充说明DuplicateKeyException来自org.springframework.daomybatis-plus-boot-starter会传递引入spring-tx可放心使用。对唯一索引冲突这种预期场景不打印异常堆栈避免日志噪音只打关键字段对其他未知异常打印完整堆栈方便排查。4.2 方案二给 root logger 补上 ASYNC_WARN从 logback 配置层面兜底让所有走 root 的 warn 日志都能落盘rootlevelINFOappender-refrefSTDOUT/appender-refrefASYNC_INFO/appender-refrefASYNC_WARN/!-- 补上这一行 --appender-refrefASYNC_ERROR//root建议两个方案都做方案一统一编码规范方案二兜底防止其他类再踩坑。4.3 不推荐的写法// ❌ 用 Slf4j 的 log走 root loggerwarn 不落盘log.warn(保存设备事件到本地表失败 businessId{},businessId,e);// ❌ 异常被吞但无任何日志}catch(Exceptione){// 啥也不干}五、延伸LevelFilter vs ThresholdFilter这次踩坑还暴露一个易混淆点——LevelFilter与ThresholdFilter的区别过滤器行为WARN 日志能否进入 INFO appenderLevelFilteronMatchACCEPT, onMismatchDENY精确匹配指定级别其他一律 DENY❌ 不会WARN ≠ INFOThresholdFilterlevelINFO大于等于指定级别都通过✅ 会WARN ≥ INFO本项目用的是LevelFilter精确匹配所以info.log里只有 INFOwarn.log里只有 WARN。这种按级别分文件的设计本身没问题但前提是logger 必须挂载对应的 appender否则该级别的日志就无处可去。六、总结与避坑清单同一个类里不要混用logSlf4j和LogUtils.BIZ二者走不同 logger 配置行为差异巨大。统一用业务约定的 logger本项目是LogUtils.BIZ。改 logback 配置后确认 root logger 挂载了所有需要的级别 appender尤其是ASYNC_WARN否则所有走 root 的 warn 日志只在控制台不落盘。生产环境务必保留容器控制台日志用docker logs或挂载 volume 收集 stdout作为文件日志的兜底。区分预期异常与未知异常唯一索引冲突是可预期的单独 catch 并精简日志不打堆栈其他异常打印完整堆栈。这样既不淹没真正的问题又不丢失排查线索。catch 块的日志要带足够上下文本次修复补充了deviceSn、eventType、occurTime等字段便于从日志直接定位是哪台设备、哪类事件重复。一句话避坑log.warn不一定写进warn.log——取决于你用的是哪个 logger、它挂了哪些 appender。