原创作品,出自 “深蓝的blog” 博客,欢迎转载,转载时请务必注明出处,否则有权追究版权法律责任。
深蓝的blog:http://blog.youkuaiyun.com/huangyanlong/article/details/46453067
应用系统调优过程小记——索引
声明:
本文不涉及任何企业业务逻辑、业务框架及行业内技术细节,只涉及到部分开发字段名称保留,只是单纯的围绕oracle做一次技术讨论、分享,不会泄露任何企业核心机密,特此说明。
背景介绍:
接到客户反馈现象:某市某信息管理信息系统,部分功能项响应缓慢,希望我们给予解决。
一、操作中发现响应时长问题
(1)、功能项中列表界面响应时长5s左右
(2)、功能项中单条信息界面响应时长3s左右
点击单条记录信息,响应达到接近3s。
二、调优过程记录
(1)、功能项中列表界面响应时长调优
以一小时为单位生成ADDM报告,锁定一项关注点,如下:
摘自报告:
ADDM报告中的建议:
建议案 3: SQL 优化
估计的收益为 .04 个活动会话, 占总活动的 11.11\%。
--------------------------------
操作
对 SELECT 语句 (SQL_ID 为 "5q54sctfu8t9k") 运行 SQL 优化指导。
相关对象
SQL_ID 为 5q54sctfu8t9k 的 SQL 语句。
SELECT t.*,
(select name from server where server = t.server) as
serverName,c.caseName as submCaseName,
(select dic_name from dictionary where dic_value = c.category and
dic_group ='caseType')as submCategoryName,
(select cunit_name from COMMISSIONEDUNIT c where
c.cunit_id=t.departmentcode) as cUnitName,
(select u.name from usr u where u.id=t.authorizedperson)as
authorizedPersonName,
(select dic_name from dictionary d where d.dic_value = t.SECTION
and (d.dic_group = 'FISection' or d.dic_group = 'PSection' or
d.dic_group = 'FTSection' or d.dic_group = 'RSection')
) as sectionName
FROM submission t left join case c on t.caseid=c.caseid
WHERE t.state=0
and t.submcode = :1
and t.server = :2
and t.flag = :3
order by t.CREATEDATE
原理
SQL 在 CPU, I/O 和集群等待上花费的时间占其数据库时间的 100%。这部分数据库
时间可通过 SQL 优化指导进行改善。
原理
此 SQL 的数据库时间由以下部分构成: SQL 执行占 100%, 语法分析占 0%, PL/SQL
执行占 0%, Java 执行占 0%。
原理
SQL_ID 为 "5q54sctfu8t9k" 的 SQL 语句执行了 3913 次, 每次执行平均用时 0.03
6 秒。
对addm报告中的建议持怀疑态度,继续查看tomcat信息。
再次结合系统响应时间。
系统响应时间:5s多
尝试在tomcat中获取响应5s的日志记录。
通过tomcat捕获日志
数字:2,4,14,
2015-06-09 10:58:35,468 [catalina-exec-1640] INFO [jdbc.sqlonly] - select submId submId,server as server,serverName as serverName,caseId caseId,submCaseName as
submCaseName,cUnitName as cUnitName, sectionName sectionName,submCode submCode,acceptCode acceptCode,serialNo
serialNo, commissionCode commissionCode,submName submName,section section,departmentCode departmentCode,
departmentPhone departmentPhone,address address,postNo postNo,faxNo faxNo,garrison garrison,
submittedBy submittedBy,contact contact,credentialType credentialType,credentialNumber credentialNumber,
position position,submittedByOther submittedByOther,otherContact otherContact,otherCredentialType
otherCredentialType, otherCredentialNumber otherCredentialNumber,otherPosition otherPosition,submitDate
submitDate,requestProject requestProject, submSample submSample,oriConclusion oriConclusion,comments
comments,submState submState, flag flag,createdBy createdBy,submitDate submidDate,caseBrief
caseBrief,state state,SLSJ SLSJ, investigationCode as investigationCode,authorizedPersonName
authorizedPersonName,SUBM_TIMEOUT(submid) submTimeOut, noAcceptCode noAcceptCode,QQIdenName
QQIdenName,agreedMatter agreedMatter,archiveCode archiveCode,checkerName checkerName, orderDate
orderDate from ( SELECT s.*, ROWNUM RN FROM ( SELECT t.*,(select name from server where server
= t.server) as serverName,c.caseName as submCaseName, (select cunit_name from COMMISSIONEDUNIT
c where c.cunit_id=t.departmentcode) as cUnitName, (select u.name from usr u where u.id=t.authorizedperson)as
authorizedPersonName, (select u.name from usr u where u.id=t.checker)as checkerName, (select
dic_name from dictionary d where d.dic_value = t.SECTION and (d.dic_group = 'FISection' or
d.dic_group = 'PSection' or d.dic_group = 'FTSection' or d.dic_group = 'RSection') ) as sectionName
FROM submission t left join case c on t.caseid=c.caseid left join usr u on t.slr=u.id WHERE
1=1 and t.flag='0' and t.state=0 and t.server = 120000000000 and submcode in (select su.submcode
from submission su where su.state='0' and su.submcode = submcode and su.submstate='0400' and
su.server = 120000000000) and t.section in ( '2' , '4' , '14' ) order by t.isOldData,t.CREATEDATE
desc ) s WHERE ROWNUM <= 40 ) a WHERE RN > 0
2015-06-09 10:58:36,248 [catalina-exec-1635] INFO [jdbc.sqlonly] - select tg.*,(select name from usr where id = tg.ANALYSTASSIGNED)as assigenedName,(select name
from usr where id = tg.ANALYSTASSOCIATE)as associateName,(select name from usr where id = tg.analystThird)as
analystThirdName from testgroup tg where tg.testGroupId = 515396092345569
2015-06-09 10:58:36,248 [catalina-exec-1635] INFO [jdbc.sqlonly] - select ts.* ,(select sampleAcceptCode from sample s where s.SAMPLEID= ts.sampleid) as sampleAcceptCode
from testsample ts where 1=1 and ts.state <> 1 and ts.state is not null and ts.testGroupId
= 515396092345569
2015-06-09 10:58:36,264 [catalina-exec-1635] INFO [jdbc.sqlonly] - select t.* from usr t where t.id = 515396075524904
2015-06-09 10:58:36,264 [catalina-exec-1635] INFO [jdbc.sqlonly] - select t.* from usr t where t.id = 3474691
2015-06-09 10:58:36,264 [catalina-exec-1635] INFO [jdbc.sqlonly] - select t.*,(select name from usr where id = (select tg.analystAssigned from testGroup tg where
tg.testGroupId = t.testGroupId))as testOrName from test t where 1=1 and t.testgroupid = 515396092345569
and t.id =(select max(id) from test te where te.testgroupid=515396092345569)
2015-06-09 10:58:36,279 [catalina-exec-1635] INFO [jdbc.sqlonly] - select * from protocol WHERE id in ( '120' )
2015-06-09 10:58:36,295 [catalina-exec-1635] INFO [jdbc.sqlonly] - select * from device WHERE id in ( '' )
2015-06-09 10:58:36,295 [catalina-exec-1635] INFO [jdbc.sqlonly] - select * from testmember WHERE testGroupId = 515396092345569
2015-06-09 10:58:36,295 [catalina-exec-1635] INFO [jdbc.sqlonly] - SELECT ID AS id, DIC_NAME AS dicName, DIC_VALUE AS dicValue, DIC_GROUP AS dicGroup, DIC_SUPER_ID
AS dicSuperId, DIC_TYPE AS dicType, DIC_ORDER AS dicOrder, DIC_STATE AS dicState, DIC_ALIAS_NAME
AS dicAliasName FROM DICTIONARY WHERE DIC_STATE = '1' AND DIC_TYPE = '1' AND DIC_GROUP = 'tech'
ORDER BY DIC_ORDER
2015-06-09 10:58:36,295 [catalina-exec-1635] INFO [jdbc.sqlonly] - select s.*,(select MEMBERNAME from member m where m.memberid=s.targetid) as targetName from
sample s where 1=1 and state=0 and s.sampleId = 515396092300846
2015-06-09 10:58:36,295 [catalina-exec-1635] INFO [jdbc.sqlonly] - select s.*,(select MEMBERNAME from member m where m.memberid=s.targetid) as targetName from
sample s where 1=1 and state=0 and s.sampleId = 515396092300847
2015-06-09 10:58:36,357 [catalina-exec-1647] INFO [jdbc.sqlonly] - select c.*,c.type as caseType,(select dic_name from dictionary where dic_value = c.category
and dic_group ='caseType')as categoryName from case c where caseId=515396092342084
2015-06-09 10:58:36,357 [catalina-exec-1647] INFO [jdbc.sqlonly] - select s.*,(select MEMBERNAME from member m where m.memberid=s.targetid) as targetName from
sample s where 1=1 and state=0 and acceptState !='0' and s.submissionid = 515396092342084 and
flag = '0' order by s.sampleAcceptCode , s.sampleCode
2015-06-09 10:58:36,685 [catalina-exec-1626] INFO [jdbc.sqlonly] - select identifyId,server,code,submId,introduction,path,bookClassify bookClassify, (select u.name
from usr u where u.id=authorizedperson) as authorizedPersonName, (select u.name from usr u
where u.id=reChecker) as reCheckerName, checkOut,argument,result,identifyState,testOr,reChecker,reCheckTime,
authorizedPerson,signTime, auditor,auditTime,createdBy,createDate,bookType, content contents,testGroups
testGroups,currYear currYear,signed signed from IDENTIFYBOOK where identifyId = 515396092345575
2015-06-09 10:58:36,685 [catalina-exec-1626] INFO [jdbc.sqlonly] - select s.*,ca.caseName as submCaseName, (select cunit_name from COMMISSIONEDUNIT c where c.cunit_id=s.departmentcode)
as cUnitName, (select se.name from server se where se.server=s.server) as serverName, (select
u.name from usr u where u.id=s.authorizedperson)as authorizedPersonName, (select u.name from
usr u where u.id=s.rechecker)as recheckerName, (select u.name from usr u where u.id=s.checker)as
checkerName, (select u.name from usr u where u.id=s.createdBy)as createdByName, (select dic_name
from dictionary d where d.dic_value = s.SECTION and (d.dic_group = 'FISection' or d.dic_group
= 'PSection' or d.dic_group = 'FTSection' or d.dic_group = 'RSection') ) as sectionName, (select
cir.operator from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0400'
and cir.operatetime = (select max(cir.operatetime) from CIRCULATION cir where cir.operatetype
= '0100' and cir.operatestep = '0400' and cir.objectid = s.submId) and cir.objectid = s.submId)
as receiveName, (select name from usr where id =((select cir.operator from CIRCULATION cir
where cir.operatetype = '0100' and cir.operatestep = '0400' and cir.operatetime = (select max(cir.operatetime)
from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0400' and cir.objectid
= s.submId) and cir.objectid = s.submId)))as receiveByName, (select cir.operateopinion from
CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0500' and cir.operatetime
= (select max(cir.operatetime) from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep
= '0500' and cir.objectid = s.submId ) and cir.objectid = s.submId) as receiveOpinion, (select
cir.operatetime from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0400'
and cir.operatetime = (select max(cir.operatetime) from CIRCULATION cir where cir.operatetype
= '0100' and cir.operatestep = '0400' and cir.objectid = s.submId ) and cir.objectid = s.submId)
as receiveTime, (select cir.operateopinion from CIRCULATION cir where cir.operatetype = '0100'
and cir.operatestep = '0800' and cir.operatetime = (select max(cir.operatetime) from CIRCULATION
cir where cir.operatetype = '0100' and cir.operatestep = '0800' and cir.objectid = s.submId
) and cir.objectid = s.submId) as approvalOpinion from submission s left join case ca on s.caseid=ca.caseid
where s.submId=515396092300845 and s.state=0
2015-06-09 10:58:37,512 [catalina-exec-1647] INFO [jdbc.sqlonly] - select s.*,(select MEMBERNAME from member m where m.memberid=s.targetid) as targetName from
sample s where 1=1 and state=0 and acceptState !='0' and s.submissionid = 515396092342084 and
flag = '1' order by s.sampleAcceptCode , s.sampleCode
2015-06-09 10:58:37,621 [catalina-exec-1626] INFO [jdbc.sqlonly] - select tem_id temId,tem_server temServer,tem_test_type temTestType, tem_name temName,tem_section
temSection, tem_test_type temTestType,tem_content temContents,tem_type temType,tem_order temOrder,createdBy
createdBy,createDate createDate from booktemplate b WHERE b.tem_server = 120000000000 and b.tem_section
= '10' and b.tem_type = '1900'
2015-06-09 10:58:39,664 [catalina-exec-1621] INFO [jdbc.sqlonly] - select s.*,ca.caseName as submCaseName, (select cunit_name from COMMISSIONEDUNIT c where c.cunit_id=s.departmentcode)
as cUnitName, (select se.name from server se where se.server=s.server) as serverName, (select
u.name from usr u where u.id=s.authorizedperson)as authorizedPersonName, (select u.name from
usr u where u.id=s.rechecker)as recheckerName, (select u.name from usr u where u.id=s.checker)as
checkerName, (select u.name from usr u where u.id=s.createdBy)as createdByName, (select dic_name
from dictionary d where d.dic_value = s.SECTION and (d.dic_group = 'FISection' or d.dic_group
= 'PSection' or d.dic_group = 'FTSection' or d.dic_group = 'RSection') ) as sectionName, (select
cir.operator from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0400'
and cir.operatetime = (select max(cir.operatetime) from CIRCULATION cir where cir.operatetype
= '0100' and cir.operatestep = '0400' and cir.objectid = s.submId) and cir.objectid = s.submId)
as receiveName, (select name from usr where id =((select cir.operator from CIRCULATION cir
where cir.operatetype = '0100' and cir.operatestep = '0400' and cir.operatetime = (select max(cir.operatetime)
from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0400' and cir.objectid
= s.submId) and cir.objectid = s.submId)))as receiveByName, (select cir.operateopinion from
CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0500' and cir.operatetime
= (select max(cir.operatetime) from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep
= '0500' and cir.objectid = s.submId ) and cir.objectid = s.submId) as receiveOpinion, (select
cir.operatetime from CIRCULATION cir where cir.operatetype = '0100' and cir.operatestep = '0400'
and cir.operatetime = (select max(cir.operatetime) from CIRCULATION cir where cir.operatetype
= '0100' and cir.operatestep = '0400' and cir.objectid = s.submId ) and cir.objectid = s.submId)
as receiveTime, (select cir.operateopinion from CIRCULATION cir where cir.operatetype = '0100'
and cir.operatestep = '0800' and cir.operatetime = (select max(cir.operatetime) from CIRCULATION
cir where cir.operatetype = '0100' and cir.operatestep = '0800' and cir.objectid = s.submId
) and cir.objectid = s.submId) as approvalOpinion from submission s left join case ca on s.caseid=ca.caseid
where s.submId=515396092342084 and s.state=0
2015-06-09 10:58:48,946 [catalina-exec-1626] INFO [jdbc.sqlonly] - select identifyId,server,code,submId,introduction,path,bookClassify bookClassify, (select u.name
from usr u where u.id=authorizedperson) as authorizedPersonName, (select u.name from usr u
where u.id=reChecker) as reCheckerName, checkOut,argument,result,identifyState,testOr,reChecker,reCheckTime,
authorizedPerson,signTime, auditor,auditTime,createdBy,createDate,bookType, content contents,testGroups
testGroups,currYear currYear,signed signed from IDENTIFYBOOK where identifyId = 515396081737766
2015-06-09 10:58:48,915 [catalina-exec-1641] INFO [jdbc.sqlonly] - SELECT ID AS id, DIC_NAME AS dicName, DIC_VALUE AS dicValue, DIC_GROUP AS dicGroup, DIC_SUPER_ID
AS dicSuperId, DIC_TYPE AS dicType, DIC_ORDER AS dicOrder, DIC_STATE AS dicState FROM DICTIONARY