[转自Oracle官方中文博客]sqlplus 登录时快时慢问题诊断

发布时间：2020-12-12 15:26:30 所属栏目：百科来源：网络整理

导读：本文转自: https://blogs.oracle.com/Database4CN/entry/sqlplus_%E7%99%BB%E5%BD%95%E6%97%B6%E5%BF%AB%E6%97%B6%E6%85%A2%E9%97%AE%E9%A2%98%E8%AF%8A%E6%96%AD 客户反映前端系统反映很慢，自己通过sqlplus登录发现时而正常时而卡顿，登录之后有没有明显症

本文转自:

https://blogs.oracle.com/Database4CN/entry/sqlplus_%E7%99%BB%E5%BD%95%E6%97%B6%E5%BF%AB%E6%97%B6%E6%85%A2%E9%97%AE%E9%A2%98%E8%AF%8A%E6%96%AD

客户反映前端系统反映很慢，自己通过sqlplus登录发现时而正常时而卡顿，登录之后有没有明显症状，需要诊断原因。
因为客户反映登录之后并没有异常，所以先不怀疑是db端出现了性能问题，必须先从客户端程序下手，对于诊断登录问
题，需要调查登录阶段时间都花费在了那些调用上，于是需要可以提供strace 输出:
strace -f -ttt -o sqlplus.trc sqlplus / as sysdba

收集信息如下:

+ sqlplus.trc


11114 1468996741.620272 execve("/u01/app/oracle/product/11.2.0/bin/sqlplus",["sqlplus","system/spring"],[/* 29 vars */]) = 0
<skipping>...............
11114 1468996741.849734 read(11,<unfinished ...>
11115 1468996741.849800 getrusage(RUSAGE_SELF,{ru_utime={0,8998},ru_stime={0,28995},...}) = 0
<skipping>.....too much getrusage here 
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_22222_1.aud",O_RDWR|O_CREAT|O_EXCL,0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11112_1.aud",0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11113_1.aud",0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11114_1.aud",0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11115_1.aud",0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11116_1.aud",0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11117_1.aud",0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11118_1.aud",0660) = -1 EEXIST (File exists)
<skipping>.....too much open here
11115 1468996743.559319 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11115_122.aud",0660) = 8    <<<1.7s
<skipping>....
11114 1468996743.579234 read(0,"exitn",1024) = 5   
11114 1468996747.659642 write(10,"r63t10",13 <unfinished ...>  <<<4s elapsed
11115 1468996747.659687 <... read resumed> "r63t10",8208) = 13
11114 1468996747.659702 <... write resumed> ) = 13

首先分析第一个trace文件，根据时间戳查找花费时间最多的地方，的确能发现一处时间明显变化地方，就是 read函数
居然花费了4s，非常可疑，经过自己测试发现原来read函数时间就是sqlplus显示登录之后的提示符到最后客户输入exit
命令的时间差，若是是正常情况，剩下并没有发现其他时间戳有明显跳变情况，因为整个trace文件非常大，所以只能一
点点从头阅读，忽然发现trace文件中间有大量的/u01/app/oracle/admin/orcl/adump/orcl_ora_nnn_1.aud出现，一共有
上百个文件，所有文件读完花费了1.7s，问题原因就发生在了这里，这些文件是审计文件可以随时备份删除。于是让客
户理这些文件之后再次登录，明显好转。至此问题解决，至于客户反映时快时慢是因为客户是RAC系统，而另外一个实
例目录下并没有这些文件，所以有时候登录tns形式到第二个实例就没有这个问题。

（编辑：李大同）

【声明】本站内容均来自网络，其相关言论仅代表作者个人观点，不代表本站立场。若无意侵犯到您的权利，请及时与联系站长删除相关内容!