189 8069 5689

sqlplus登录时快时慢的问题分析

sqlplus 登录时快时慢的问题分析,相信很多没有经验的人对此束手无策,为此本文总结了问题出现的原因和解决方法,通过这篇文章希望你能解决这个问题。

网站建设哪家好,找成都创新互联!专注于网页设计、网站建设、微信开发、成都小程序开发、集团企业网站建设等服务项目。为回馈新老客户创新互联还提供了浦东免费建站欢迎大家使用!

客户反映前端系统反映很慢,自己通过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
...............
11114 1468996741.849734 read(11, 
11115 1468996741.849800 getrusage(RUSAGE_SELF, {ru_utime={0, 8998}, ru_stime={0, 28995}, ...}) = 0
.....too much getrusage here 
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11111_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", O_RDWR|O_CREAT|O_EXCL, 0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11113_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_11114_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_11115_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_11116_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_11117_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_11118_1.aud", O_RDWR|O_CREAT|O_EXCL, 0660) = -1 EEXIST (File exists)
.....too much open here
11115 1468996743.559319 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11115_122.aud", O_RDWR|O_CREAT|O_EXCL, 0660) = 8    <<<1.7s
....
11114 1468996743.579234 read(0, "exit\n", 1024) = 5   
11114 1468996747.659642 write(10, "\0\r\0\0\6\0\0\0\0\0\3\t\10", 13   <<<4s elapsed
11115 1468996747.659687 <... read resumed> "\0\r\0\0\6\0\0\0\0\0\3\t\10", 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形式到第二个实例就没有这个问题。

sqlplus 登录时快时慢问题诊断

By: Bin Mao

客户反映前端系统反映很慢,自己通过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
...............
11114 1468996741.849734 read(11, 
11115 1468996741.849800 getrusage(RUSAGE_SELF, {ru_utime={0, 8998}, ru_stime={0, 28995}, ...}) = 0
.....too much getrusage here 
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11111_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", O_RDWR|O_CREAT|O_EXCL, 0660) = -1 EEXIST (File exists)
11115 1468996741.871284 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11113_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_11114_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_11115_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_11116_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_11117_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_11118_1.aud", O_RDWR|O_CREAT|O_EXCL, 0660) = -1 EEXIST (File exists)
.....too much open here
11115 1468996743.559319 open("/u01/app/oracle/admin/orcl/adump/orcl_ora_11115_122.aud", O_RDWR|O_CREAT|O_EXCL, 0660) = 8    <<<1.7s
....
11114 1468996743.579234 read(0, "exit\n", 1024) = 5   
11114 1468996747.659642 write(10, "\0\r\0\0\6\0\0\0\0\0\3\t\10", 13   <<<4s elapsed
11115 1468996747.659687 <... read resumed> "\0\r\0\0\6\0\0\0\0\0\3\t\10", 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形式到第二个实例就没有这个问题。

看完上述内容,你们掌握sqlplus 登录时快时慢的问题分析的方法了吗?如果还想学到更多技能或想了解更多相关内容,欢迎关注创新互联行业资讯频道,感谢各位的阅读!


文章题目:sqlplus登录时快时慢的问题分析
当前路径:http://cdxtjz.cn/article/jsgipd.html

其他资讯