问题记录01

问题描述： 数据入库前查库，没查到，但做insert时异常了，表示数据已存在？ 

数据库：单体，没有主从关系

web：单体，不存在任务冲突

使用到了线程池,  但每个线程执行任务都是唯一的，根据唯一单号去执行的，也不存在任务重复并发执行。（每个任务都有不同的随机休眠时间）

频率：偶发情况，但出现类似的情况有点多。

------------------------------------------------------------------------------------------------------------------------

错误日志

# 错误日志，时间：
15:22:41.536 [threadPoolTaskExecutor-4] ERROR c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$batchUpdateItemDetailInfoByApi$7,367] - 查详情API接口线程异常 threadName=threadPoolTaskExecutor-4,inquiryCode=EP240723-230

#关键异常信息
Duplicate entry 'EP240723-230-3876255-2' for key 'dhc_item_detail_sub_unique'

info日志

# info 日志：

15:22:41.287 [threadPoolTaskExecutor-4] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$batchUpdateItemDetailInfoByApi$7,361] - ItemDetailInfo sleep=7436 
线程启动：threadPoolTaskExecutor-4,EP240723-230
15:22:41.510 [threadPoolTaskExecutor-4] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [extracted,410] - selectPieceCodeSubListByInquiryCode->inquiryCode=EP240723-230,pieceCodeList=[]              

# 这里的空数组，表示没有查到数据, 应该做新增操作。
15:22:41.522 [threadPoolTaskExecutor-4] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$extracted$8,449] - threadName=threadPoolTaskExecutor-4,inquiryCode=EP240723-230...insert...DhcItemDetailSub...pieceCode=3876255-2

# 从日志和时间点上看,在这里现唯一键冲突的异常了，没看到线程结束的日志。

# 下面都是其他线程启动日志了

15:22:45.522 [threadPoolTaskExecutor-3] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$batchUpdateItemDetailInfoByApi$7,361] - ItemDetailInfo sleep=50247 
线程启动：threadPoolTaskExecutor-3,EP240723-203

..

..

..

# 再到 EP240723-230 下一次执行的日志

15:25:56.994 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$batchUpdateItemDetailInfoByApi$7,365] - ItemDetailInfo sleep=40315 线程结束：threadPoolTaskExecutor-7,EP230921-229
15:26:04.739 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$batchUpdateItemDetailInfoByApi$7,361] - ItemDetailInfo sleep=7745 线程启动：threadPoolTaskExecutor-7,EP240723-230
15:26:05.109 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [extracted,410] - selectPieceCodeSubListByInquiryCode->inquiryCode=EP240723-230,pieceCodeList=["3876255-2"]

# 这里查到数据了，下面进行了更新操作。
15:26:05.119 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$extracted$8,445] - threadName=threadPoolTaskExecutor-7,inquiryCode=EP240723-230...update...DhcItemDetailSub...pieceCode=3876255-2
15:26:05.130 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$extracted$8,445] - threadName=threadPoolTaskExecutor-7,inquiryCode=EP240723-230...update...DhcItemDetailSub...pieceCode=3876255-2
15:26:05.136 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [extracted,462] - threadName=threadPoolTaskExecutor-7,inquiryCode=EP240723-230,更新完毕！
15:26:05.136 [threadPoolTaskExecutor-7] INFO  c.r.w.d.s.i.DhcCustomServiceImpl - [lambda$batchUpdateItemDetailInfoByApi$7,365] - ItemDetailInfo sleep=7745 线程结束：threadPoolTaskExecutor-7,EP240723-230

数据库入库详情： 入库时间是 2024-07-23 15:22:41 。

数据入库的时间与错误日志的时间接近。 问题就在这，入库前我select查询过,没有3876255-2数据，代码才做的insert操作，结果与数据库中唯一键异常了，很奇怪！

如果重复执行, 按理说日志里面应该能记录。 入库时间也不会相差如此接近。

目前猜测，可能是使用的开源框架中存在重复请求数据库的操作，排查中