记一次因为共享缓存导致流水号重复的问题排查过程
背景:
在开发日终应用或者跑批应用的时候,进行每天凌晨跑批或者全天跑批多次进行表数据清理的时候,每次清理都会登记操作明细到日志表,流水号是根据Oracle号段模式获取1000个流水号段放内存里,不够用再从数据库重新获取一批。跑批应用是连接了多个数据源的(TDSQL 9个分库),每执行完一个分库的清理任务再重新执行下一个分库的。任务调度平台每次到了启动时间就会部署实例,然后再销毁实例。
问题来了:写操作日志的时候,有些分库的error日志会报insert唯一键冲突,但是这个获取流水号的方法是每个分库都独立的,从Oracle的递增序列不断增加的,每个分库获取的一批流水号然后再插入每个分库的日志表理论上是不会重复的,那为什么会出现这样的情况呢?而且这个DuplicateKeyException还是偶发的,并不是每次跑批的时候都会出现,有时候01分库报错,有时候02分库报错,01分库好好的没问题.....
排查思路:
1、初步怀疑是平台部署实例的时候没有销毁掉,而是复用了上一次部署的内存,导致内存里还残留上次缓存的流水号没用完继续用,经咨询发现平台的机制是会销毁重新部署的
2、可能是获取流水号的方法逻辑有问题,排查了一遍代码没发现异常,而且这套流水号方法很多应用使用了很多年没出现过问题;
3、查看日志平台,怀疑是分库的日志显示错乱了,01分库出现的报错日志显示到了02分库上,导致毫无规律可言,经咨询相关平台的同事排除这一可能了
4、比较冲突的流水号以及日志表的流水号规律,发现不是连续的,比如:01分库上午使用了1,2,3;然后02分库的流水号理论上应该也是从1,2,3开始的,但是事实上却不是如此,而是从4,5,6开始;下午执行的时候,02分库应该是从上午的1,2,3开始递增使用4,5,6才对,但是居然又使用了1,2,3
结合任务调度平台多数据源任务的处理机制:每次部署都共享一块内存空间,执行完全部分库任务才会销毁这份内存资源,还有流水号申请一批存放内存的逻辑找到问题归因所在:
结论:
在开发日终应用或者跑批应用的时候要特别注意,对于分库任务来说,是会共享实例内存的,因此一定要注意内存或缓存使用的场景,很有可能处理异常。以调框架里ISequenceService.getSequence来生成流水号举例:
1)第一次跑批:09分库的任务先发现缓存流水号为空,就会从09分库申请一段流水(1-1000),并放到缓存中使用,若此时97分库的任务也需要使用流水号,发现缓存中有流水号了,就直接使用缓存中的流水号并且同步到数据库,并没有从97分库申请流水。
2)第二次跑批:97分库的任务先发现缓存流水号为空,就会从97分库申请一段流水(1-1000),并放到缓存中使用,注意本次使用的流水在第一次跑批中已经使用过,如果作为唯一键插入分库中,就会出现唯一键冲突。
启示:
跑批或日终应用,一定不能使用内存或缓存进行分库级别的处理,否则会分库任务间的处理会互相干扰,因为单次跑批,所有分库任务都是共享实例内存的!尤其注意获取交易流水号的时候影响甚大!