前言
前一段时间，遇到了一个MySQL唯一索引的问题，印象挺深刻的，拿出来给大家分享一下，希望对你会有所帮助。
1 案发现场
有一天早上，我看到Sentry报警邮件中，有一封关于唯一索引异常的，正好是我提供的某个接口报出来的。
邮件中包含了trace_id、服务名称、时间、环境信息，还有部分异常信息等等。
我赶紧查看了一下Grafana上的日志。
由于有trace_id，我很快定位到当时把异常的错误日志，日志信息大概是这样的：
Duplicate entry '88410864388751900-588375359938909268-efaba6610049ff2f5d43cd9300' for key 'unx_spu_brand_hash';
...此外，日志中还打印了BusinessException是商品添加失败，请稍后重试。
我们在设计表时，其实是在product_unique_record表中增加了spu_id、brand_id和hash三个字段作为唯一索引。
product_unique_record表其实是product表的防重表。
当时没有在product表中直接加唯一索引，而单独建了一张防重表是有原因的：
- product表有逻辑删除的功能，如果建了唯一索引逻辑删除会有问题。
- product表的数据经常会调整，调整之后可能会存在重复的数据，但重复的数据又不能立刻删除，需要先把依赖这些重复数据的业务数据删除之后，才能删除product表的数据，否则业务上可能会存在问题。
但是这种防重表竟然出现了Duplicate entry的问题，这就有点蹊跷了。
因为保存数据的代码大概是这样的：
@Transactional
public Product insertProduct(Product product) {
Product oldProduct = productMapper.queryCondition(product.getSpuId(),product.getBrandId(), product.getHash());
if(oldProduct != null) {
product.setId(oldProduct.getId());
return product;
}
ProductUniqueRecord productUniqueRecord = createProductUniqueRecord(product);
try {
productUniqueRecordMapper.insert(productUniqueRecord);
productMapper.insert(product);
} catch(DuplicateKeyException e) {
log.info(e.getMessage(), e);
oldProduct = productMapper.queryCondition(product.getSpuId(),product.getBrandId(), product.getHash());
if(oldProduct == null) {
throw new BusinessException("商品添加失败，请稍后重试");
}
product.setId(oldProduct.getId());
}
return product;
}这段代码的主要逻辑是：
- 先从Product表中根据spuId、brandId和hash字段查一下，数据是否存在，如果存在则赋值id，直接返回。
- 然后往ProductUniqueRecord表和Product表中插入数据，如果抛了DuplicateKeyException异常，说明数据已存在，则再根据用spuId、brandId和hash值，从Product表中查一下数据是否存在（正常情况下数据是存在的）。
- 如果再次查数据还是不存在，则抛一个BusinessException。
- 如果再次查数据已存在，则赋值id，最后返回数据。
而insertProduct方法，外层加了@Transactional注解，声明了事务的，也就是说ProductUniqueRecord和Product插入数据的操作是原子操作，要么同时成功，要么同时失败。
而生成环境，却报了一个商品添加失败，请稍后重试的BusinessException，这就非常奇怪了。
那么，为什么会报这个异常呢？
2 初步分析问题
上面的这段代码，在插入数据之前，先根据三个唯一索引字段查询了Product表，当时Product不存在该数据。
然后往ProductUniqueRecord表中插入数据的时候，抛了DuplicateKeyException的异常，说明在ProductUniqueRecord表中三个唯一索引字段的数据当时是存在的。
而代码中通过try/catch捕获了该异常。
接下来，正常情况下，再根据三个唯一索引字段查询了Product表，理论上是能够查询到数据的。
但实际情况是：没有查到数据。
莫非数据库唯一索引抽风了？
那么，到底是什么原因呢？
难道是插入的数据当时正好被删除了？
有点不太可能，人工没有那么快的速度，正好在调用insertProduct方法的过程中把数据删了。
有没有可能是事务回滚了，导致这条数据没了？
但是也不对呀。
当前事务能走到抛BusinessException的这行代码，说明前面的代码逻辑都正常执行了，当前事务根本不会回滚。
有没有可能是当时存在并发操作，其他的事务回滚了，导致那条数据没了呢？
但这种想法也不对。
生成环境配置的数据库隔离级别是已提交读，也就是说，在不同的事务之间，如果事务不提交，是不能读取到其他事务影响的数据的。
如果事务提交了，说明操作已经成功了，就不存在回滚问题了。
那么，到底是什么原因呢？
3 深入分析
接下来，我还发现一个更奇怪的问题。
服务器的日志中打印的Duplicate entry '88410864388751900-588375359938909268-efaba6610049ff2f5d43cd9300'，但这条数据在ProductUniqueRecord表中实际上是不存在的。
我们这边为了减少服务器的日志量，没有记录生产环境insert语句的相关参数，只记录了异常日志，给我们定位问题增加了一些难度。
我当时认为既然数据库报了这个Duplicate entry的问题，说明这条数据曾经存在过。
于是找DBA查了一下MySQL的binlog日志，惊奇的发现，竟然没有查到这条记录的日志。
那条数据根本没有保存到数据库当中过，为什么会报Duplicate entry的异常呢？
莫非MySQL的唯一索引抽风了，出现了bug？我当时真的是这样想的。
为了验证数据库有没有抽风。
我将当时生产环境执行的SQL语句拿到测试环境执行了一下，竟然执行成功了。
说明数据库还真的没有抽风，冤枉他了。
然后，在不经意的某个瞬间，大脑中闪过某个想法，用修改时间的范围查一下，看看最近一天插入的数据，跟手动插入的这个条数据，有没有什么差异。
惊喜的发现一个现象，收到插入的那条数据中的hash值是efaba6610049ff2f5d43cd9300，只有 26 个字符，而其他的hash值是固定长度 32 个字符，比如：efaba6610049ff2f5d43cd930024erf3。
于是我用下面的这条sql语句：
select * from product_unique_record
where spu_id=88410864388751900 and brand_id=588375359938909268 and hash like 'efaba6610049ff2f5d43cd9300%'；找到了3条数据。
这个问题很清晰了，抛出Duplicate entry时，日志中打印的信息是不完整的，hash原本是32位的，被截取了6位。
顺着这个思路，继续往下面分析。
我提出了一个假设：有没有可能是Product表和ProductUniqueRecord表数据不一致导致的这个问题？
虽说这两张表的操作是加了事务的原子操作，不会产生数据不一致的问题。
4 查到原因了
我接下来，分析了那3条数据。
发现其中有1条数据，在Product表中已经被逻辑删除了。
再回头看看之前的那段代码逻辑：
@Transactional
public Product insertProduct(Product product) {
Product oldProduct = productMapper.queryCondition(product.getSpuId(),product.getBrandId(), product.getHash());
if(oldProduct != null) {
product.setId(oldProduct.getId());
return product;
}
ProductUniqueRecord productUniqueRecord = createProductUniqueRecord(product);
try {
productUniqueRecordMapper.insert(productUniqueRecord);
productMapper.insert(product);
} catch(DuplicateKeyException e) {
log.info(e.getMessage(), e);
oldProduct = productMapper.queryCondition(product.getSpuId(),product.getBrandId(), product.getHash());
if(oldProduct == null) {
throw new BusinessException("商品添加失败，请稍后重试");
}
product.setId(oldProduct.getId());
}
return product;
}Product表中没有那条数据，然后程序接下来，往ProductUniqueRecord表中插入数据，但此时由于ProductUniqueRecord表中该数据已存在，所以才会报Duplicate entry异常。
为什么会出现Product和ProductUniqueRecord这两张表的数据不一致的情况呢？
几天之前，业务方调用创建商品接口时，传入了错误的参数，导致程序走了重新构建商品的逻辑。这个逻辑会先删除商品，然后重新创建。
但这个代码已经很久了，删除操作中，只删除了Product表的数据，没有删除ProductUniqueRecord表的数据。
而这两天，有用户刚好创建了已删除的商品，才会出现这个问题。
虽说之前的那个bug已经修复了，但当时数据还没来得及处理，才会出现两张表数据不一致的情况。
很多时候，bug是环环相扣的。
如果不是业务调用方出现了bug，传错了参数，不会走到重新构建商品的逻辑，而这个逻辑有一个bug，没有删除ProductUniqueRecord表的数据，如果不是这个表的数据没有删除，又不会出现Duplicate entry异常。
因此强烈建议大家，如果出现了线上bug导致的数据问题时，一定要及时修复异常数据，不然说不定哪天就会出现另外一个莫名其妙的bug，会把自己坑了。
此外，数据库出现了Duplicate entry异常，程序在打印异常日志时，自动截取了部分字符串，增加了一些排查问题的难度，大家后面可以注意一下这个问题。
