1 问题描述
未签收的订单十五天之后自动签收：总共2个步骤： step1 在乐购系统中批量更新未签收订单的状态，step2: 通过RPC修改订单系统的订单状态， step1和step2放到一个事务中。然后发现step2 订单DB状态修改成功，但是step1 乐购db的订单状态并未修改。
2 排查过程
- 怀疑是程序的问题，检查乐购系统的执行日志，发现所有日志执行成功，db的插入和更新操作日志以及事务日志，都显示执行正确；【正常】
- 怀疑是DB执行的问题，检查DB的binglog日志，发现没有事务执行的任何记录，那数据到底是提交到哪里去了呢？ 乐购系统的日志明明是显示执行成功的啊。于是怀疑当时db执行可能有错误再检查db的errorlog发现也没有任何db执行错误信息；【正常】
- 怀疑是db的配置问题，因为我们当时在dev和qa环境下都测试成功，就是boss环境发生这样的奇怪问题。于是检查dev，qa和boss环境的所有配置，包括：
bulk_insert_buffer_size 批量插入buffer大小，innodb_flush_log_at_trx_commit 事务提交的日志级别，lock timewait锁等待时间，注意这个参数很重要。默认是5分钟吧，我们设置的是365天！！【不正常】 - 发现这三个环境没有db配置没有任何差别，唯一不同的是线上db做了主从配置。难道主从配置会影响到事务提交的级别，这个也有可能，因为db主从同步会写binglog日志，而binglog又是事务执行必须日志（还有redolog），于是google db主从同步对事务的影响，没发现任何信息；【正常】
- 这时再重现梳理思路，那就是剩下2种可能：
- 乐购系统的数据根本就没有提交到db，由于网络问题什么的，如果这种问题的话，spring+mybatis会有错误日志，db超超时问题的（当时准备不行再用tcpdump验证下3306端口，但是这个问题只能在boss环境出现，没办法tcpdump）；【正常】
- 数据已经到达db了，由于db自身的问题或约束而没有执行。对，是不是db有啥约束，google之后发现确实有一个参数：
max_allowed_packet 这个参数对事务批量提交时数据大小有限制，我们设置的是16m， 难道我们boss环境下事务一次提交的数据超过这个了，检查了提交记录数据，打开128k 字节，远远小于16m。排除这个参数。【正常】
- 查看INNODB状态日志：【不正常，DB死锁】
SHOW ENGINE INNODB STATUS LATEST DETECTED DEADLOCK
2015-10-20 16:26:11 7fe0a6aa0700
*** (1) TRANSACTION:
TRANSACTION 47995200, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 360, 2 row lock(s)
MySQL thread id 1175573, OS thread handle 0x7fe0a5fa3700, query id 74660997 10.XXX dev Searching rows for update
UPDATE tableXX
SET
status = 1,success_at = now(),
update_at = now()
WHERE refund_no = 'XXX'
AND status != 1
3 解决问题
- 修改db中的 lock timewait锁等待时间，线上数据即使死锁也可以快速释放锁；
- 修改程序，把step2 rpc调用修改为异步执行，注意这样修改导致事务实际上无效了；
4 总结问题
这里我们也检查了我们的程序确实也有问题，一个事务包括在step1和step2中，而step2采用rpc调用时间特别长(>2分钟)，这样导致step1中事务无法及时提交，这个过程中db一直等待commit，而线上数据肯定也会实时更新db，很容易发生死锁。
又是DB死锁问题，难道事务中db这么容易死锁，这里推荐一篇阿里大牛的写的一篇文章，http://hedengcheng.com/?p=844。彻底分析了使用事务中mysql死锁的问题，原来是页面死锁的问题，不是事务死锁引起的。
还有一个风险就是DB死锁时，mybatis+spring竟然没有感知。。日志打印出来全是成功，太坑了。
