自定义realm出现doGetAuthorizationInfo多次重复调用

た入场券 2022-12-13 04:06 258阅读 0赞

> 前言：此次排查的过程，主要是利用debug模式下，深入源码打断点才发现问题所在。

### 一、问题描述： ###

练习shiro认证授权，发现授权方法中相关的sql语句多次重复执行了。于是，各种排查，为什么会有多次重复执行相同的sql查询，这岂不是很影响性能。于是有了下面的排查过程。

### 二、发现问题，截图如下： ###

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

### 三、排查过程 ###

**（过程1）**：肯定是先从shiro的配置文件逐个排查过了，没有任何发现，还是解决不了问题。

**（过程2）**：既然是多次sql语句执行，那考虑到是某个方法重复调用了。于是定位到了下边的这个方法。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 1]  
a）debug模式启动，断点来到上边的`Set<String> roleNames = roleDAO.queryRoleNamesByUsername(username);`。

b）于是从逆向思维出发，是谁调用了`protected AuthorizationInfo doGetAuthorizationInfo(PrincipalCollection principalCollection)`方法。

> 借助调试工具，Step Out (Shift + F8)：步出，从步入的方法内退出到方法调用处，此时方法已执行完毕，只是还没有完成赋值。

![调式工具][20201009175610571.png_pic_center]  
c）借助调式工具，Step Out看看是谁调用了`doGetAuthorizationInfo()`方法。  
来到`AuthorizingRealm`类的`isPermitted(PrincipalCollection principals, String permission)`方法。  
![在这里插入图片描述][202010091803532.png_pic_center]  
d）继续Step Out，来到同类下的`isPermitted(PrincipalCollection principals, Permission permission);`  
![在这里插入图片描述][20201009180031405.png_pic_center]  
e）继续Step Out，来到同类下的`info = this.doGetAuthorizationInfo(principals);`  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 2]  
e）继续Step Out多次…，来到了一个循环do\{\}while()循环，如下。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 3]  
f）到了这一步，多少看出一点猫腻了，这个permission：“sys:c:delete”，就是来自数据库的权限内容。

g）于是好奇重复执行了多少次该sql的执行。  
在`doGetAuthorizationInfo(PrincipalCollection principalCollection)`方法体内定义一个变量，看看到底执行了多少次。  
定义的变量如下：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 4]  
执行结果如下：  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 5]  
发现都是次数1，这就奇怪了，说明都是一个新的对象调用该方法。  
h）接着数了下，一共执行了11次，然后回到数据库，查看有没有什么记录是11次的。发现还是没有，到这里就又觉得没思绪了。

i）最后，想到了前端是用的thymeleaf模板中用到了shiro的授权标签。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 6]  
数了下，恰好是11个，这就跟控制台打印的sql方法执行的个数相符合了。

j）为了确认下，是由于前端这个11个shiro授权标签导致的。继续操作到步骤`e）`来，然后释放掉当前断点，又来到当前断点，这其实是第二次来到相同的地方，现象如下：  
第一次：sys:c:delete  
![在这里插入图片描述][20201009182008270.png_pic_center]  
第二次：sys:c:update  
![在这里插入图片描述][20201009182315100.png_pic_center]  
第三次：sys:c:find  
![在这里插入图片描述][20201009182350748.png_pic_center]  
多次…  
这个过程，permission就跟thymeleaf中shiro授权标签对应上了。  
![在这里插入图片描述][watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 7]

### 四、确定问题所在 ###

至此，可以确定，控制台中打印的sql查询，是由于前端thymeleaf模板中，多次使用的shiro授权标签导致的，这也就印证了为什么`doGetAuthorizationInfo(PrincipalCollection principalCollection)`方法中定义的i变量，重复打印出的结果是1了。

### 五、总结 ###

由于学shiro是通过视频学的，这样容易发现学得不系统，没方法领会到问题的关键所在。即使在排查过程中，百度有回答说是调用`subject.isPermitted()`就会触发`doGetAuthorizationInfo(PrincipalCollection principalCollection)`方法执行，但还是联想不到是自己使用了多个shiro的授权标签，从而多次调用了`doGetAuthorizationInfo(PrincipalCollection principalCollection)`方法。

但更加体会到，掌握debug和深入源码去排查问题方法的重要性，只有亲身体会，才会发觉深入了解源码的重要性。

— end

[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center]: /images/20221123/ed09bdf548c5411aaa86ac977cf35a93.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 1]: /images/20221123/4df4d3c3b71b46a390e18b28d8c31d05.png
[20201009175610571.png_pic_center]: /images/20221123/c9435cf913354c1d96cd8493c86a6f37.png
[202010091803532.png_pic_center]: /images/20221123/57b96f0e44684a5582d326fff253c605.png
[20201009180031405.png_pic_center]: /images/20221123/22e34a1c310542c9b5cb391204776141.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 2]: /images/20221123/469d1bdef74a463bbd4010bc4326c0f4.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 3]: /images/20221123/0914b3c92c78421eb4f173c907b7f11b.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 4]: /images/20221123/07859213cacd416ca96adafd82d03ac3.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 5]: /images/20221123/f8aaff34c8ec4a498ebb4abc5c65ce65.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 6]: /images/20221123/0be99450b4fe4b46b7934584379b4f5c.png
[20201009182008270.png_pic_center]: /images/20221123/bd30a94f1fcd4b4f9b8cfcc98d832746.png
[20201009182315100.png_pic_center]: /images/20221123/bc40aef2321e430e8ba0718a04d9b675.png
[20201009182350748.png_pic_center]: /images/20221123/93ebb0e33a9d4df3adcf8916339fdfc6.png
[watermark_type_ZmFuZ3poZW5naGVpdGk_shadow_10_text_aHR0cHM6Ly9ibG9nLmNzZG4ubmV0L3NneDU2NjY2NjY_size_16_color_FFFFFF_t_70_pic_center 7]: /images/20221123/405004c58a7a4a5a94c3255625a76b7e.png