背景

事情的情况大致是这样的。一个扣减库存的业务上线以后，隔几天会报一次错，错误内容如下：

ERROR - exception: UncategorizedSQLException,"detail":"org.springframework.jdbc.UncategorizedSQLException:
### Error updating database.  Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLQueryInterruptedException: Query execution was interrupted
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: UPDATE a SET stock = stock - ? WHERE id = ? and stock >= ?
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLQueryInterruptedException: Query execution was interrupted
; uncategorized SQLException for SQL []; SQL state [70100]; error code [1317]; Query execution was interrupted; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLQueryInterruptedException: Query execution was interrupted
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:84)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
at org.mybatis.spring.MyBatisExceptionTranslator.translateExceptionIfPossible(MyBatisExceptionTranslator.java:73)
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:446)
at com.sun.proxy.$Proxy64.update(null:-1)
at org.mybatis.spring.SqlSessionTemplate.update(SqlSessionTemplate.java:294)
at org.apache.ibatis.binding.MapperMethod.execute(MapperMethod.java:62)
at org.apache.ibatis.binding.MapperProxy.invoke(MapperProxy.java:59)

这块业务之前一直都是正常的，迁移以后做的唯一大的改动就是加了java事务注解，所以怀疑是否和事务有关。

排查过程

首先现寻找报错的关键信息，第一个看到的是UncategorizedSQLException。查看这个类的源代码，说明如下：

/**
 * Exception thrown when we can't classify a SQLException into
 * one of our generic data access exceptions.
 *
 * @author Rod Johnson
 * @author Juergen Hoeller
 */

可以看到，这个类是Spring无法归类的一个SQL异常，所以从这个异常我们是看不出什么内容的，继续往下。

MySQLQueryInterruptedException: Query execution was interrupted

发现这个执行是超时被kill了。一般来讲，我们公司dba设置的mysql超时时间是500ms。是否是因为数据量太大，没有走到索引，才导致update操作执行时间太长被kill了呢？看一下update语句里

UPDATE a SET stock = stock - ? WHERE id = ? and stock >= ?

马上排除了这个可能性。因为where条件里有id查询，必定会走主键索引，不可能没有走到索引。那会是什么原因呢？
上面我们提到，这个业务操作里是开启了事务的，还原一下大体的执行情况。

start transaction;
UPDATE a SET stock = stock - 1 WHERE id = 100 and stock >= 1;
INSERT INTO a (num) values (1);
commit;

查了一下当时的日志，发现1秒内有大约200条请求对一条记录做更新库存的操作。
线索渐渐清晰起来了，事故现场大致应该是这样的：

T1	T2
begin	begin
UPDATE a SET stock = stock - 1 WHERE id = 100 and stock >= 1;
	UPDATE a SET stock = stock - 1 WHERE id = 100 and stock >= 1;
	INSERT INTO a (num) values (1);
	T2执行完成，1 rows affected
T1 Query execution was interrupted

结论

由于开启了事务，在高并发地对一条记录进行更新的情况下，多个请求会进入排队系统。由于锁的竞争是不公平的，当多个事务同时对一条记录进行更新时，极端情况下，就可能会出现一个更新操作进去排队系统以后，一直拿不到锁，超过500ms被kill了。

细节分析

以上的业务操作，update会先申请行锁，拿到行锁以后进行更新，更新完以后会执行插入操作。那么在插入操作的时候是否需要申请锁呢？
答案是肯定的，不过这里的插入操作使用的是自增锁。那自增锁是什么级别的锁呢？
如果存在自增字段，MySQL会维护一个自增锁，和自增锁相关的一个参数为（5.1.22版本之后加入）
innodb_autoinc_lock_mode：可以设定3个值，0，1，2

0：traditonal （每次都会产生表锁）
1：consecutive （会产生一个轻量锁，simple insert会获得批量的锁，保证连续插入）
2：interleaved （不会锁表，来一个处理一个，并发最高）

Myisam引擎均为traditional，InnoDB默认为1，轻量锁。所以在InnoDB的情况下，这里的insert操作的性能比update操作更高。

优化

有了以上结论以后，那如何优化呢？
最简单的方案就是减少持有锁的时间，处理方式非常简单，将更新操作放到最后执行，从而缩短更新锁的持有时间，避免类似的超时问题。

start transaction;
INSERT INTO a (num) values (1);
UPDATE a SET stock = stock - 1 WHERE id = 100 and stock >= 1;
commit;

参考资料：
业务优化案例一则
mysql并发insert死锁问题——gap、插入意向锁冲突
InnoDB并发插入，居然使用意向锁？
MySQL自增锁