解决web端登录时等待过久并偶尔抛出事务相关异常

﹏ヽ暗。殇╰゛Y 2022-04-23 13:56 29阅读 0赞

## 问题描述 ##

![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70]

## 分析 ##

登录函数中有一个事务，如下：  
![在这里插入图片描述][20190313171051231.png]  
事务里面有一个有可能操作比较耗时的过程：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 1]  
在新增登录日志的时候，获取用户的ip。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 2]  
具体干了啥不重要，重要的是发了一个http请求，并且是串行的，所以这个请求比较耗时的可能是很大的，并且具备不确定性因素。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 3]

## 反思 ##

`TransactionRollbackException`的文档注释为：

*This exception indicates that the transaction associated with processing of the request has been rolled back, or marked to roll back. Thus the requested operation either could not be performed or was not performed because further computation on behalf of the transaction would be fruitless*

可能的过程为：线程1进入事务、然后进行了一次update操作，获得了一个排他锁，然后被卡在了获取ip的那个地方，即此事务持有着排他锁，然后还长时间不结束（50s+），然后线程2也进入了事务，此时在进行update的时候，需要等待线程1释放排它锁，在50秒过后，仍未获取到锁，此时获取锁时间超过了预设，抛出上述异常。

## 解决 ##

规避潜在的耗时操作。**但是由于此服务没人维护，因此通过本地编译，然后拉包替换相应class文件，再上传到服务器的方式进行修改。**

## 复现 ##

查看获取锁的超时阀值：

SHOW VARIABLES LIKE '%timeout%';

输出如下：

+-----------------------------+----------+
    | Variable_name               | Value    |
    +-----------------------------+----------+
    | connect_timeout             | 10       |
    | delayed_insert_timeout      | 300      |
    | have_statement_timeout      | YES      |
    | innodb_flush_log_at_timeout | 1        |
    | innodb_lock_wait_timeout    | 50       |
    | innodb_rollback_on_timeout  | OFF      |
    | interactive_timeout         | 28800    |
    | lock_wait_timeout           | 31536000 |
    | net_read_timeout            | 30       |
    | net_write_timeout           | 60       |
    | rpl_stop_slave_timeout      | 31536000 |
    | slave_net_timeout           | 60       |
    | wait_timeout                | 28800    |
    +-----------------------------+----------+
    13 rows in set (0.01 sec)

代码如下：

// --------------------------Controller------------
      /**
       * 测试web端登录锁表
       */
      @GetMapping("/hotline/test")
      public void testSomeThing() throws InterruptedException {
        
        testService.doSomething();
      }
    // ----------------------------Service----------------
    @Service
    public class TestService {
        
    
      @Autowired
      private BizConfMapper confMapper;
    
      @Transactional(rollbackFor = Exception.class)
      public void doSomething() throws InterruptedException {
        
        // 共享锁
        BizConf conf = confMapper.selectByPrimaryKey(0);
        // 排它锁
        confMapper.updateByPrimaryKey(conf);
        // 等待让下个线程超时，最起码要大于50
        Thread.sleep(60000);
      }
    }

日志输出与项目中出现的错误信息基本一致，如下：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 4]  
在`@Transactional`注解中加入timeout后，报错不一样，但是阔以理解为spring框架为我们抛出了异常。如下：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 5]

## 后记 ##

其中对我理解这种现象有很大帮助的资料为这一张图，它让我明白了锁与事务之间的关系。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 6]  
参考：  
[https://segmentfault.com/a/1190000014133576][https_segmentfault.com_a_1190000014133576]

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70]: /images/20220309/5d45b9678a1b460297ce79005f33430a.png
[20190313171051231.png]: /images/20220309/cd00ebfe4e9f40e68fa876669320d253.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 1]: /images/20220309/a62554c79a574fcfac69651d27ea45a1.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 2]: /images/20220309/7689338bca4048708e56ca1a83b7aa72.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 3]: /images/20220309/4034ff6d17814a47a8cfbe9a2785fb41.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 4]: /images/20220309/a30d303d92a74def8be3b9422cc01fbe.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 5]: /images/20220309/a1e41a4287d04948b5f5b9781a2fb1c2.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L2FzYWhpbm9rYXdh_size_16_color_FFFFFF_t_70 6]: /images/20220309/6c6843ca090b44969d819c356b06454d.png
[https_segmentfault.com_a_1190000014133576]: https://segmentfault.com/a/1190000014133576