企业官网建设流程全解析

一个 logback 配置踩坑：唯一索引冲突的 warn 日志去哪了？

生产环境排查重复消费问题，明明代码里catch住了异常并打了log.warn，却在日志文件里死活找不到。控制台输出又因容器化部署而丢失，问题久久无法定位。本文记录一次真实排查过程，根因出在 logback 的root logger与BIZ logger配置差异上。

一、问题背景

Kafka 消费者接收设备事件消息后，需要落库到本地device_event_message表。该表的msg_service_business_id字段上有唯一索引，用于防止 Kafka 重复消费导致的数据重复。

代码逻辑很标准：try里执行insert，catch (Exception e)里log.warn打印日志并吞掉异常，不阻断后续推送流程。

@Service@Slf4jpublicclassBizMsgServiceImpl{@KafkaListener(topics="${kafka.consumer.deviceEventTopic}",...)publicvoidkafkaDeviceEventListen(ConsumerRecord<String,String>record){// ... 解析事件 ...StringmsgServiceBusinessId=event.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{DeviceEventMessagePOpo=newDeviceEventMessagePO();// ... set 各字段 ...deviceEventMessageMapper.insert(po);}catch(Exceptione){log.warn("保存设备事件到本地表失败 businessId={}",businessId,e);}}}

二、问题现象

线上一段时间后，用户反馈偶发重复推送。排查时翻遍warn.log、error.log文件，没有找到任何保存设备事件到本地表失败的日志。

但数据库里又能查到唯一索引冲突的痕迹（或通过其他途径确认确实发生了重复消费）。于是陷入"明明打了日志却找不到"的困境。

三、根因分析

3.1 第一反应：日志级别？

第一反应是怀疑log.warn级别在生产环境被调高过滤了。但查看logback-spring.xml：

<rootlevel="INFO"><appender-refref="STDOUT"/><appender-refref="ASYNC_INFO"/><appender-refref="ASYNC_ERROR"/></root>

root level="INFO"，WARN 级别高于 INFO，级别上不会被过滤。这条路走不通。

3.2 第二反应：异常没抛出？

怀疑insert违反唯一约束时没有抛异常。但 MyBatis-Plus 的BaseMapper.insert执行的是标准INSERT INTO，MySQL 唯一索引冲突会立即抛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！ --><rootlevel="INFO"><appender-refref="STDOUT"/><appender-refref="ASYNC_INFO"/><appender-refref="ASYNC_ERROR"/></root><!-- BIZ logger：挂了 ASYNC_WARN --><loggername="BIZ"level="DEBUG"additivity="false"><appender-refref="STDOUT"/><appender-refref="ASYNC_INFO"/><appender-refref="ASYNC_DEBUG"/><appender-refref="ASYNC_WARN"/><appender-refref="ASYNC_ERROR"/></logger>

再看各文件 appender 的 filter 配置——用的是LevelFilter精确匹配：

<appendername="WARN"class="ch.qos.logback.core.rolling.RollingFileAppender"><filterclass="ch.qos.logback.classic.filter.LevelFilter"><level>WARN</level><onMatch>ACCEPT</onMatch><onMismatch>DENY</onMismatch><!-- 非 WARN 一律拒绝 --></filter><file>${logPath}/log/warn.log</file>...</appender><appendername="INFO"class="ch.qos.logback.core.rolling.RollingFileAppender"><filterclass="ch.qos.logback.classic.filter.LevelFilter"><level>INFO</level><onMatch>ACCEPT</onMatch><onMismatch>DENY</onMismatch><!-- WARN 会被拒绝，不进 info.log --></filter>...</appender>

3.4 两个 logger 的行为差异

关键在于代码里用了哪个 logger：

// LogUtils.javapublicinterfaceLogUtils{LoggerBIZ=LoggerFactory.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.log（INFO appender 的 LevelFilter 精确匹配 INFO，WARN 被 DENY）
• ❌ 不写入error.log（同理）
• ✅ 只输出到控制台 STDOUT

而生产环境是 Docker 容器部署，控制台日志不落盘、易丢失，排查时只看文件日志，自然就"找不到日志"了。

3.5 一次完整的调用链对照

@KafkaListener(...)publicvoidkafkaDeviceEventListen(ConsumerRecord<String,String>record){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{DeviceEventMessagePOpo=newDeviceEventMessagePO();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.dao，mybatis-plus-boot-starter会传递引入spring-tx，可放心使用。
• 对唯一索引冲突这种预期场景不打印异常堆栈（避免日志噪音，只打关键字段）；对其他未知异常打印完整堆栈，方便排查。

4.2 方案二：给 root logger 补上 ASYNC_WARN

从 logback 配置层面兜底，让所有走 root 的 warn 日志都能落盘：

<rootlevel="INFO"><appender-refref="STDOUT"/><appender-refref="ASYNC_INFO"/><appender-refref="ASYNC_WARN"/><!-- 补上这一行 --><appender-refref="ASYNC_ERROR"/></root>

建议两个方案都做：方案一统一编码规范，方案二兜底防止其他类再踩坑。

4.3 不推荐的写法

// ❌ 用 @Slf4j 的 log，走 root logger，warn 不落盘log.warn("保存设备事件到本地表失败 businessId={}",businessId,e);// ❌ 异常被吞但无任何日志}catch(Exceptione){// 啥也不干}

五、延伸：LevelFilter vs ThresholdFilter

这次踩坑还暴露一个易混淆点——LevelFilter与ThresholdFilter的区别：

本项目用的是LevelFilter精确匹配，所以info.log里只有 INFO，warn.log里只有 WARN。这种"按级别分文件"的设计本身没问题，但前提是logger 必须挂载对应的 appender，否则该级别的日志就无处可去。

六、总结与避坑清单

1. 同一个类里不要混用log（@Slf4j）和LogUtils.BIZ：二者走不同 logger 配置，行为差异巨大。统一用业务约定的 logger（本项目是LogUtils.BIZ）。
2. 改 logback 配置后，确认 root logger 挂载了所有需要的级别 appender：尤其是ASYNC_WARN，否则所有走 root 的 warn 日志只在控制台，不落盘。
3. 生产环境务必保留容器控制台日志：用docker logs或挂载 volume 收集 stdout，作为文件日志的兜底。
4. 区分"预期异常"与"未知异常"：唯一索引冲突是可预期的，单独 catch 并精简日志（不打堆栈）；其他异常打印完整堆栈。这样既不淹没真正的问题，又不丢失排查线索。
5. catch 块的日志要带足够上下文：本次修复补充了deviceSn、eventType、occurTime等字段，便于从日志直接定位是哪台设备、哪类事件重复。

一句话避坑：log.warn不一定写进warn.log——取决于你用的是哪个 logger、它挂了哪些 appender。