背景:接手一个历史悠久的微博评论模块,用户本应每小时只能评论1次,但近期突然出现大量重复评论。以下是完整的排查流水账。
一、灵异现象
监控系统报警显示:
- 用户A在09:00:00发表评论
- 09:00:30再次评论成功
- 09:01:15第三次评论成功
但代码中明明有限流逻辑:
// 关键限流代码
public boolean canComment(String userId) {
String commentKey = COMMENT_PREFIX + userId;
String lastCommentTime = cacheService.get(commentKey);
if (缓存为空 || 超过1小时) {
更新缓存时间;
return true;
}
return false;
}
二、菜鸡排查日记
第一阶段:甩锅缓存(30分钟)
- 检查Redis连接:正常
- 手动执行
get comment:testUser
:返回时间戳 - 查看缓存过期时间TTL:确实1小时
第二阶段:怀疑时间差(1小时)
// 在代码中加入调试日志
log.info("当前时间:{}, 缓存时间:{}, 差值:{}",
currentTime, lastTime, elapsedTime);
发现两次有效评论的实际间隔仅30秒,但日志显示时间差计算为3601000ms(刚好1小时)
第三阶段:发现魔鬼细节
仔细检查缓存更新逻辑:
// 原代码
cacheService.add(commentKey, System.currentTimeMillis(), 1, TimeUnit.HOURS);
// 实际CacheUtils实现:
public void add(String key, Object value, long timeout, TimeUnit unit) {
// 注意第三个参数是long类型!
redisTemplate.opsForValue().set(key, value, timeout, unit);
}
突然想起:Hutool的DateUtil与Jakarta的DateTime混用,在创建时间戳时出现时区转换问题!
三、真相大白
根本原因:
DateTime
带时区信息,而System.currentTimeMillis()
是UTC时间- 当使用
new DateTime()
构造对象时,默认使用系统时区(东八区) 导致存储的时间戳比实际大8小时:
// 错误示例: cache存储时间:1698768000000(UTC+8的Unix时间戳) 实际系统时间:1698742800000(UTC时间戳)
- 时间差计算时出现8小时偏差
四、修复方案
// 修改时间获取方式
// 原代码
cacheService.add(commentKey, System.currentTimeMillis(), ...);
// 修改后
long correctTime = DateTime.now().getTime();
cacheService.add(commentKey, correctTime, ...);
后记:这个BUG教会我三个道理:
- 时间处理永远是暗坑之王
- 不要混用不同组件的时间工具
- 看起来人畜无害的代码反而容易翻车
(后来发现是当年赶工时,从其他模块CV代码时没注意时区问题...)
可扩展问题点:
- 如果检查
UserCommentsService.saveOrUpdate
方法,可能发现commentId
用Integer类型溢出问题 userService.selectNicknameByOpenId
如果返回null,会导致comments.name
字段存为cid- 没有事务控制可能导致评论主表和关联表数据不一致