使用arthas 分析一个系统登录慢的问题

场景很简单，就是一个业务系统集成了sso api 参考模式如下

 

 

问题描述

正常接口登录比较快，基本1s 处理完成，但是如果用户不在外部sso api 系统存在的时候登录居然需要10多秒，因为外部sso 接口使用
的比较多理论上是有稳定性保障的（主要是测试了存在的时候都很快。。。。）

解决

开始以为是app 应用的问题（因为sso api 好多系统都在使用，不会这么慢的），但是因为app 是一个外部系统（没有源码）
所以想到的解决方法是使用arthas 工具先黑盒处理下，因为登录一般是auth 或者login 之后的方法，所以先sc auth
结果搜到了相关的class，解决方法就简单了，可以先sm 查看类的方法，或者jad 反编译源码，然后trace 具体方法调用就可以了
具体调用如下

 

Affect(class count: 1 , method count: 2) cost in 316 ms, listenerId: 3

// 账户不存在的调用

`---ts=2021-11-12 15:54:05;thread_name=qtp882699232-28;id=1c;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@6475d174

    `---[15437.677946ms] xmodule.auth.AuthApi:login() // 耗时

        +---[0.044758ms] xmodule.SDK.event.types.PreLoginEvent:<init>() #323

        +---[0.029687ms] xmodule.SDK.inner.IBeans:getEventHub() #325

        +---[15421.256656ms] xmodule.SDK.inner.IEventHub:dispatchEvent() #325  // 此方法一直在等待

        +---[0.034421ms] xmodule.auth.AuthCore:getModel() #332

        +---[0.673894ms] xmodule.SDK.inner.IAuthCore$IAuthModel:checkLoginId() #332

        +---[8.880074ms] xmodule.auth.AuthApi:login() #338

        |   `---[8.772531ms] xmodule.auth.AuthApi:login()

        |       +---[0.047601ms] xmodule.SDK.inner.IBeans:getUserCore() #384

        |       +---[1.094431ms] xmodule.SDK.inner.IUserCore:getAuthUser() #384

        |       +---[0.045898ms] xmodule.SDK.inner.IBeans:getUserCore() #396

        |       +---[3.65757ms] xmodule.SDK.inner.IUserCore:checkUserStatus() #396

        |       +---[0.149839ms] xmodule.SDK.types.UserInfo:getAccount() #399

        |       +---[0.217127ms] xmodule.auth.AuthUtils:checkPassword() #419

        |       +---[0.826517ms] xserver.service.conf.ConfCoreApi:get() #456

        |       +---[0.049946ms] xserver.service.cache.LocalCache:getCache() #466

        |       +---[0.069939ms] xserver.service.cache.XCache:remove() #466

        |       +---[0.072384ms] javax.servlet.http.HttpServletRequest:getHeader() #468

        |       +---[0.169912ms] xmodule.SDK.types.TokenInfo:newToken() #474

        |       +---[0.042228ms] xmodule.auth.AuthCore:getModel() #475

        |       +---[1.312514ms] xmodule.SDK.inner.IAuthCore$IAuthModel:addToken() #475

        |       `---[0.043042ms] xmodule.SDK.types.LoginInfo:<init>() #476

        +---[0.054825ms] xmodule.SDK.event.types.PostLoginEvent:<init>() #348

        +---[0.06122ms] xmodule.SDK.inner.IBeans:getEventHub() #350

        +---[2.377738ms] xmodule.SDK.inner.IEventHub:dispatchEvent() #350

        +---[0.039641ms] xmodule.SDK.inner.IBeans:getUserCore() #353

        +---[2.814368ms] xmodule.SDK.inner.IUserCore:checkUserStatus() #353

        +---[0.049572ms] xmodule.SDK.inner.IBeans:getUserApi() #354

        `---[0.61116ms] xmodule.SDK.inner.IUserApi:setLoginCount() #354

 

//  账户存在的调用

`---ts=2021-11-12 15:55:08;thread_name=qtp882699232-26;id=1a;is_daemon=false;priority=5;TCCL=sun.misc.Launcher$AppClassLoader@6475d174

    `---[1187.807904ms] xmodule.auth.AuthApi:login() // 耗时

        +---[0.038644ms] xmodule.SDK.event.types.PreLoginEvent:<init>() #323

        +---[0.032631ms] xmodule.SDK.inner.IBeans:getEventHub() #325

        +---[1178.416895ms] xmodule.SDK.inner.IEventHub:dispatchEvent() #325 // 此方法还是比较快

        +---[0.053749ms] xmodule.SDK.event.types.PostLoginEvent:<init>() #348

        +---[0.057909ms] xmodule.SDK.inner.IBeans:getEventHub() #350

        +---[3.247777ms] xmodule.SDK.inner.IEventHub:dispatchEvent() #350

        +---[0.069796ms] xmodule.SDK.inner.IBeans:getUserCore() #353

        +---[4.376166ms] xmodule.SDK.inner.IUserCore:checkUserStatus() #353

        +---[0.050942ms] xmodule.SDK.inner.IBeans:getUserApi() #354

        `---[0.871408ms] xmodule.SDK.inner.IUserApi:setLoginCount() #354

 

以上方法中的IEventHub:dispatchEvent 实际上是一个调用外部api时候的一个等待，结果显而易见不存在账户的等待时间比较长
而且通过测试直接调用外部接口也发现的确很慢（10多秒。。。。）

说明

以上是一个简单的基于arthas 分析系统登录接口问题的实践，希望对大家有用