今天定位一个电商网站登录慢的问题。据QA反映测试环境,最近出现登录缓慢。QA反映说B2B用户登录站点很慢,B2C用户登录就很快。
定位第一步:用jstack 抓线程
用B2B用户登录站点,同事服务器上用jstack连续抓取3次thread dump,分析三个thread dump文件,发现是在等待数据库返回数据。
第一线程堆栈出现如下信息:
我们搜索nid “0x7b86” 从第二个堆栈文件,结果如下:
到这里可以断定这个问题与数据库有关了,我们再搜索下第三个线程堆栈,确认下,结果如下图:
从上面三个堆栈,可以看出登录慢的问题出在数据,为了证明数据库的清白我们可以获取oracle数据库的AWR日志看下问题,详细问题可以网上看下怎么获取AWR日志。
我这里获取的AWR日志,是从登录开始到结束这段时间的。也就是在登录前打个点,登录成功后打个点,获取这两个点之间的统计情况并生产AWR日志。
从AWR部分如下图所示:
从上图可以使到问题,为什么我就简单的一个登录功能怎么有些SQL执行了几千次,最大是11814次。这个问题好奇怪。查看具体执行的sql,发现都是从organization这个表中获取数据,为什么一个登录会查询这个表上千次了。于是向DBA求助,DBA开启了oracle数据库的FGA,具体命令如下:
开:
call dbms_fga.add_policy(object_schema=>'your schema name', object_name=>'table name', policy_name=>'FEI_ORGANIZATION', statement_types=>'SELECT, UPDATE, INSERT, DELETE');
关:
call dbms_fga.drop_policy( object_schema=>'your schema name', object_name=>'table name', policy_name=>'FEI_ORGANIZATION');
查审计结果:
SELECT
os_user,
userhost,
timestamp,
object_name,
sql_text,
sql_bind,
statement_type
FROM dba_fga_audit_trail;
查询出的审计结果如下:
红色区域循环执行,导致数据查询organization很多次。结合业务路径,发现B2B user 表上有两个字段organizations 和parentOrganization,登录的时候首先去查找所属的父organization,父找到后,再去查找organizations中的,由于organizations中的子又指向了父organization。由此导致循环查询organization这个表。
由此得出查询有双向关联的两个表的时候,只能是单向,否则会出现循环。