溫馨提示×
您好，登錄后才能下訂單哦！
點擊 登錄注冊 即表示同意《億速云用戶服務條款》
您好，登錄后才能下訂單哦！
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_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)
<skipping>.....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
<skipping>....
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 <unfinished ...> <<<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形式到第二個實例就沒有這個問題。
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
<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_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)
<skipping>.....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
<skipping>....
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 <unfinished ...> <<<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 登錄時快時慢的問題分析的方法了嗎？如果還想學到更多技能或想了解更多相關內容，歡迎關注億速云行業資訊頻道，感謝各位的閱讀！
免責聲明：本站發布的內容（圖片、視頻和文字）以原創、轉載和分享為主，文章觀點不代表本網站立場，如果涉及侵權請聯系站長郵箱：is@yisu.com進行舉報，并提供相關證據，一經查實，將立刻刪除涉嫌侵權內容。
