背景

某项目一个查询界面,在没有人访问情况下,接口返回时间在3s+,压测50并发平均响应时间在8s+

在没有高并发情况下,出现接口慢大概率是SQL查询效率慢问题。

排查

Arthas trace命令可以观察方法执行时间,并且记录调用其他方法所用的时间,找到接口的代码,trace其调用方法(一般在service层进行观察)

[arthas@15098]$ trace com.definesys.dportal_auth.modular.service.impl.QmsQuestionnaireService queryQuestList
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 120 ms, listenerId: 9
<code>---ts=2021-08-10 13:50:34;thread_name=http-nio-8081-exec-13;id=24;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@56fcc3e8
    </code>---[2683.928449ms] com.definesys.dportal_auth.modular.service.impl.QmsQuestionnaireService:queryQuestList()
        +---[0.064004ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getUserCode() #80
        +---[2304.307611ms] com.definesys.dportal_auth.modular.service.impl.QmsQuestionnaireService:getCodeList() #95
        +---[0.004481ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getUserCode() #82
        +---[1.757941ms] com.definesys.dportal_auth.modular.dao.AuthEmployeesDAO:getQuestionnaireByEmpCode() #95
        +---[0.011119ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getTag() #89
        +---[0.004484ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getTag() #92
        +---[0.004352ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getUserCode() #94
        +---[0.007855ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getPage() #96
        +---[0.005728ms] com.definesys.dportal_auth.modular.pojo.dto.QueryQuestListInputDto:getPageSize() #95
        <code>---[377.375624ms] com.definesys.dportal_auth.modular.dao.QmsQuestionnaireDAO:queryNotFilledQuestList() #94

注意到方法getCodeList占用了大部分时间

[2304.307611ms] com.definesys.dportal_auth.modular.service.impl.QmsQuestionnaireService:getCodeList() #95

我们继续观察getCodeList方法

[arthas@15098]$ trace com.definesys.dportal_auth.modular.service.impl.QmsQuestionnaireService getCodeList
Press Q or Ctrl+C to abort.
Affect(class count: 1 , method count: 1) cost in 105 ms, listenerId: 4
</code>---ts=2021-08-10 13:23:09;thread_name=http-nio-8081-exec-51;id=a8;is_daemon=true;priority=5;TCCL=org.springframework.boot.context.embedded.tomcat.TomcatEmbeddedWebappClassLoader@56fcc3e8
    <code>---[2845.567052ms] com.definesys.dportal_auth.modular.service.impl.QmsQuestionnaireService:getCodeList()
        +---[2842.804586ms] com.definesys.dportal_auth.modular.service.impl.BaseService:queryAuthorizeListByTableAndAccountCode() #170
        </code>---[2.479209ms] com.definesys.dportal_auth.modular.dao.QmsQuestionnaireDAO:queryNoAuth() #173

同样我们继续观察queryAuthorizeListByTableAndAccountCode方法,该方法进行了两次sql查询,sql如下

select questionnaire_code as AUTH_COLUMN_ID
from qms_questionnaire_relation_t
where authorization_type = 'GROUP'
  and authorization_code in (select group_id
                             from auth_group_relation_t
                             where relation_type = 'ORG'
                               and relation_code in ('')
                             UNION
                             select group_id
                             from auth_group_relation_t
                             where relation_type = 'ROLE'
                               and relation_code in
                                   (select role_code from auth_role_relation_t where employee_code = '999')
                             UNION
                             select group_id
                             from auth_group_relation_t
                             where relation_type = 'USER'
                               and relation_code = '999')
  • qms_questionnaire_relation_t数据量44行
  • auth_group_relation_t数据量8w行左右

在数据库工具中执行该sql大概需要2.3s时间,也就是说大部分时间是花在了该sql上,因为qms_questionnaire_relation_t数据量才44,基本对性能构不成影响,大概率是表auth_group_relation_t出问题,我们在该表上没有看到字段relation_code的索引,但查询条件relation_code = '999'中,有用该字段进行查询,表加上字段relation_code的索引问题解决,查询降到毫秒级,接口响应速度在1s以下,重新压测,压测结果正常

结论

在没有高并发的情况下,接口速度慢,大概率是sql性能问题,sql性能问题大概率是索引没加。

Trackback

no comment untill now

Add your comment now