一、问题描述
商城系统今天上线了一个功能,用户在商城中点击商品详情页的去购买按钮时,如果商品是有代金券优惠活动的商品,则会先领券后计算商品金额。 这里面涉及到两步操作:调用领券接口,领券成功后,调用计算接口(计算商品价格接口),计算接口内部会调用代金券查券接口。遇到问题是,发券后,立即调用代金券查询代金券,查询不到刚发的代金券,停几秒中再去查,就可以查到,这种情况大概率会复现。
很奇怪的问题,代金券系统已经很久没有修改过了,线上也未爆出过发了代金券而查询不到的情况。
二、问题排查
一开始以为是数据库主从延迟导致的,把代金券查询接口日志打开,发现dao从库中查询时是可以查到刚发送的券,但是进行规则过滤后,代金券被过滤了,添加详细的日志,发现代金券是被有效期校验给过滤了。
代金券的有效期校验是:当前时间 >= 代金券创建时间 and 当前时间 <= 代金券结束时间
代金券有效期一般都是从发券时间开始,到发券时间+7天,因此当前时间必然<代金券结束时间,那么就是当前时间小于创建时间导致过滤,这就更奇怪了,发券在前,查询在后,查询时,系统时间应该是大于代金券创建时间的,为什么会被过滤呢。
查看数据库记录,发现一个奇怪的问题,代金券createtime居然比updatetime多了1s:
createTime | updateTime |
---|---|
2021-07-01 14:18:42 | 2021-07-01 14:18:41 |
心理隐约感觉找到了方向。继续查看代金系统的日志,发现创建日志打印时间为:2021-07-01 14:18:41.529, 而查询代金券的时间为2021-07-01 14:18:41.611。
这大概就找到问题了,createTime入库时间比系统时间多了1秒,导致2021-07-01 14:18:41.611 < 2021-07-01 14:18:42。那么为什么入库时间会多1秒呢?
查看代金券createTime设值的代码:
setCreateTime(new Date());
取的是当前系统时间,而updateTime其值不是由java代码设置的,而是设置了默认值,也就时入库时,会取mysql current time。
看下createtime和updatetime的sql定义:
`create_time` datetime(0) DEFAULT '0000-00-00 00:00:00' COMMENT '创建时间',
`last_update_time` timestamp(0) DEFAULT CURRENT_TIMESTAMP(0) ON UPDATE CURRENT_TIMESTAMP(0) COMMENT '最后更新时间',
发现两个字段的类型居然不一致,createTime是datetime(0)类型,表示时间会精确到秒,而updateTime是timestamp(0)。
百度一番,发现这居然是mysql的一个bug, 当时间字段类型为datetime时,如果时间毫秒数小于500时,向下舍,如果大于等于500时向上加1秒,也就是:
2021-07-01 14:18:41.400 会存为2021-07-01 14:18:41
2021-07-01 14:18:41.591 会存为2021-07-01 14:18:42
线上之所以一直未爆出这个问题,主要是没有这种领券后,在极短时间(500ms内)就去查券的场景,而商城这个场景是自动发券自动查,间隔时间基本上100ms以内,才爆出这个问题。
三、问题解决
解决办法有3个:
- 查询判断时,取当前时间时,加1s
- 存datetime类型的字段时,对Date类型的值进行处理,将毫秒置为000,比如2021-07-01 14:18:41.400 设置为2021-07-01 14:18:41.000
- 将mysql时间类型改为datetime(3),或者timestamp类型。
推荐第二种,因为第1种并没有解决根本问题,存入的数据本身就是错的,保不齐其他地方也会有日期判断的地方,如果数据存入的就是错的,其他地方判断也会是错的。而第3种需要修改数据库字段类型,公司内对数据量大的表进行修改比较麻烦,而且时间精确到毫秒意义并不大,还会占用更多的空间,不如修改两行代码来的快捷。