導(dǎo)讀：東方龍馬致力數(shù)據(jù)庫(kù) | 中間件領(lǐng)域20余年，積累很多寶貴的業(yè)內(nèi)經(jīng)驗(yàn)和專業(yè)人才，今天由東方龍馬高級(jí)工程師阮文強(qiáng)，向大家講述一次因BUG原因引發(fā)的性能故障分析與處理案例。希望對(duì)你有所幫助。
一般情況下，對(duì)于ORACLE數(shù)據(jù)庫(kù)來說，一說到性能問題，我們都是聯(lián)想到是否SQL執(zhí)行出現(xiàn)了性能問題？是否配置不合理？是否CPU和IO等操作系統(tǒng)資源使用出現(xiàn)問題？但最近我們遇到了一個(gè)由于ORACLE BUG引發(fā)的數(shù)據(jù)庫(kù)性能問題。
背景：用戶反饋有一套系統(tǒng)運(yùn)行很慢，包括所有的操作如一般的登錄、查詢、編輯、報(bào)表輸出都突然變得很慢，開發(fā)人員和運(yùn)維人員都做了相關(guān)的檢查和一般分析，但都沒發(fā)現(xiàn)任何可疑的地方，開發(fā)人員還對(duì)中間件tomcat服務(wù)器進(jìn)行了重啟，運(yùn)維人員也對(duì)ORACLE數(shù)據(jù)庫(kù)服務(wù)重啟。重啟后，系統(tǒng)仍然很慢，最終用戶不斷的抱怨。
根據(jù)技術(shù)人員的反映和之前的操作，我們第一分析就是檢查分析當(dāng)前系統(tǒng)資源使用情況，發(fā)現(xiàn)包括Cpu、IO、內(nèi)存均使用正常，然后開始把焦點(diǎn)放在數(shù)據(jù)庫(kù)本身。
首先，從數(shù)據(jù)庫(kù)中抓取AWR報(bào)告，確認(rèn)一下整體上的性能問題，整體數(shù)據(jù)庫(kù)時(shí)間消耗如下：
Snap Id | Snap Time | Sessions | Cursors/Session | |
Begin Snap: | 21589 | 28-Dec-12 09:00:23 | 107 | 3.9 |
End Snap: | 21590 | 28-Dec-12 10:00:25 | 131 | 4.0 |
Elapsed: | 60.04 (mins) | |||
DB Time: | 532.21 (mins) |
我們可以看到，一共收集了60分鐘的報(bào)告，DB TIME即數(shù)據(jù)庫(kù)實(shí)際運(yùn)行時(shí)間占到了532分鐘，即相當(dāng)于差不多9個(gè)線程核的CPU滿負(fù)載運(yùn)行。根據(jù)我們對(duì)這套系統(tǒng)了解，業(yè)務(wù)量一般不大，數(shù)據(jù)庫(kù)壓力也不大，我們暫時(shí)確認(rèn)是數(shù)據(jù)庫(kù)整體上性能問題，并判斷可能是鎖（包括lock鎖和Latch鎖）資源等待問題，然后進(jìn)一步看等待事件：
Event | Waits | Time(s) | Avg wait (ms) | % DB time | Wait Class |
row cache lock | 5,919 | 27,841 | 4704 | 87.19 | Concurrency |
DB CPU | 754 | 2.36 | |||
cursor: pin S wait on X | 268 | 510 | 1904 | 1.60 | Concurrency |
direct path read | 46,380 | 39 | 1 | 0.12 | User I/O |
log file sync | 9,699 | 12 | 1 | 0.04 | Commit |
參考：row cache lock 解釋：
Row Cache Lock：
When DDLs execute, it must acquire a row cache latch to lock the Data Dictionary information. The shared pool contains a cache of rows from the data dictionary that helps reduce physical I/O to the data dictionary tables. This allows locking of individual data dictionary rows.
我們根據(jù)后臺(tái)等待事件發(fā)現(xiàn)，row cache lock等待事件占了87%以上，占了運(yùn)行時(shí)間27841秒，相當(dāng)于約450分鐘以上，占了所有運(yùn)行時(shí)間的約87%（27841/(532*60)=87.2%）。理論上這個(gè)事件是不能出現(xiàn)在TOP 5事件中的，說明當(dāng)前系統(tǒng)性能差、數(shù)據(jù)庫(kù)運(yùn)行時(shí)間消耗時(shí)間長(zhǎng)都是由row cache lock等待事件引發(fā)起。我們?cè)偃タ凑w時(shí)間使用模型：
Time Model Statistics
Total time in database user-calls (DB Time): 31932.9s
Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
Ordered by % or DB time desc, Statistic name
Statistic Name | Time (s) | % of DB Time |
parse time elapsed | 25,552.00 | 80.02 |
hard parse elapsed time | 24,988.46 | 78.25 |
sql execute elapsed time | 6,906.29 | 21.63 |
根據(jù)時(shí)間模型數(shù)據(jù)，可以看到60分鐘之內(nèi)，用于SQL或PLSQL解釋的時(shí)間就占了80%以上，即25552秒，我們可以推測(cè)出由于與共享池相關(guān)的row cache lock等待事件導(dǎo)致了SQL解釋出現(xiàn)問題，并最終大量的SQL運(yùn)行變成緩慢，從于引發(fā)了系統(tǒng)的整體上性問題。
根據(jù)上面的分析數(shù)據(jù)，我們第一步就是先確認(rèn)數(shù)據(jù)庫(kù)配置是否存在問題，對(duì)于我們認(rèn)為不合理的配置，就是調(diào)整到相對(duì)合理或我們認(rèn)為合理的配置。對(duì)于當(dāng)前的配置數(shù)據(jù)，我們主要對(duì)SGA和相關(guān)的內(nèi)存組件進(jìn)行了調(diào)整，調(diào)整配置如下：
同時(shí)，對(duì)操作系統(tǒng)內(nèi)核的一些參數(shù)據(jù)進(jìn)行了調(diào)整：
通過調(diào)整后，根據(jù)對(duì)數(shù)據(jù)庫(kù)的監(jiān)控，系統(tǒng)性能有一點(diǎn)提升，可沒從實(shí)質(zhì)上解決整體上系統(tǒng)慢的性能問題。
我們繼續(xù)深入分析，通過hanganalyz level 3進(jìn)行跟蹤，得到相關(guān)TRACE文件，關(guān)鍵內(nèi)容如下：
我們發(fā)現(xiàn)，當(dāng)前大量的會(huì)話都是在等待nodenum=349(session id=350)的會(huì)話，然后再看具體會(huì)話TRACE信息，如下：
從上面的信息我們發(fā)現(xiàn)，上面row cache lock 的引發(fā)主要是由于在執(zhí)行常規(guī)SQL語(yǔ)句等待另一個(gè)會(huì)話（SID=350）釋放相關(guān)資源，可我們發(fā)現(xiàn)SID=350的會(huì)話當(dāng)前卻未執(zhí)行任何SQL，而且是空閑等待，這是非常不合理的。
這時(shí)，我們可以初步確認(rèn)：當(dāng)前的性能問題和相關(guān)的SQL執(zhí)行并沒有直接聯(lián)系，很大概率是ORACLE的內(nèi)部運(yùn)行機(jī)制出現(xiàn)問題，即可能是BUG的問題！
我們通過METALINK發(fā)現(xiàn)該問題進(jìn)一步確認(rèn)是BUG方面的問題，如下：
注：具體見METALINK DOC ID：1162566.1
從上面的信息我們發(fā)現(xiàn)，當(dāng)前系統(tǒng)問題與BUG 9776608有一定的符合性：
當(dāng)前版本都是11.2.0.0.1
出現(xiàn)大量row cache lock，而且都是短的大量的row cache lock等待。
通過進(jìn)一步分析系統(tǒng)底層調(diào)用都是ksedsts()+644<- ksdxfstk() +44<- ksdxcb()……等函數(shù)開頭。
根據(jù)文檔要求，該問題可升級(jí)到11.2.0.2以上版本或安裝補(bǔ)丁包patch9776608解決問題。
隨后，我們配合運(yùn)維人員進(jìn)行系統(tǒng)ORACLE數(shù)據(jù)庫(kù)基于PSU補(bǔ)丁升級(jí)：
考慮到當(dāng)前系統(tǒng)最新版本，我們直接把數(shù)據(jù)庫(kù)升級(jí)到11.2.0.3.4版本。
考慮到系統(tǒng)升級(jí)的安全性，我們先對(duì)測(cè)試環(huán)境進(jìn)行PSU補(bǔ)丁的升級(jí)，然后再對(duì)正式環(huán)境進(jìn)行升級(jí)。
完成升級(jí)后，對(duì)系統(tǒng)進(jìn)行監(jiān)控，確認(rèn)性能問題得到徹底解決！
附錄：?jiǎn)栴}解決后前后性能對(duì)比解釋
Snap Id | Snap Time | Sessions | Cursors/Session | |
Begin Snap: | 21828 | 07-Jan-13 09:00:17 | 81 | 2.7 |
End Snap: | 21829 | 07-Jan-13 10:00:26 | 95 | 3.2 |
Elapsed: | 60.15 (mins) | |||
DB Time: | 59.09 (mins) |
我們同樣收集系統(tǒng)相對(duì)壓力比較大的時(shí)間段1小時(shí)的工作日志，DBTIME 只運(yùn)行 59分鐘，為存在性能問題時(shí)間段（之前同一時(shí)間段DBTIME為532分鐘）的10分之一左右。
Event | Waits | Time(s) | Avg wait (ms) | % DB time | Wait Class |
DB CPU | 701 | 19.78 | |||
virtual circuit wait | 51,595 | 37 | 1 | 1.03 | Network |
db file sequential read | 6,676 | 24 | 4 | 0.68 | User I/O |
db file scattered read | 4,163 | 20 | 5 | 0.56 | User I/O |
library cache lock | 9 | 17 | 1895 | 0.48 | Concurrenc |
在TOP 5事件中，不再存在row cache lock等待事件！
Time Model Statistics
Total time in database user-calls (DB Time): 3545.3s
Statistics including the word "background" measure background process time, and so do not contribute to the DB time statistic
Ordered by % or DB time desc, Statistic name
Statistic Name | Time (s) | % of DB Time |
connection management call elapsed time | 2,802.13 | 79.04 |
DB CPU | 701.34 | 19.78 |
sql execute elapsed time | 473.92 | 13.37 |
parse time elapsed | 218.52 | 6.16 |
hard parse elapsed time | 176.29 | 4.97 |
在整個(gè)系統(tǒng)時(shí)間模型中，解釋的時(shí)間僅占到數(shù)據(jù)庫(kù)運(yùn)行時(shí)間的6.16%，比之前的80%以上下降了75%以上。
- 蜜度索驥：以跨模態(tài)檢索技術(shù)助力“企宣”向上生長(zhǎng)
- Automechanika Shanghai 20周年盛會(huì)圓滿收官： 參展商及觀眾人數(shù)再創(chuàng)新高，彰顯行業(yè)強(qiáng)勁增長(zhǎng)態(tài)勢(shì)、 創(chuàng)新成果及全球合作新篇章
- IFA 2025新聞發(fā)布會(huì)在深圳成功舉行，與中國(guó)企業(yè)再鑄輝煌
- 美通社舉辦2024媒體趨勢(shì)沙龍 交流媒體傳播新業(yè)態(tài)
- 歡迎報(bào)名丨“太湖之芯”湖州半導(dǎo)體及光電產(chǎn)業(yè)上海對(duì)接活動(dòng)即將舉行
- 相約—武漢電子展︱賦能中西部電子信息產(chǎn)業(yè)發(fā)展——2025 武漢國(guó)際半導(dǎo)體產(chǎn)業(yè)與電子技術(shù)博覽會(huì)將于5月15日盛大召開
- 智馭時(shí)代 第十六屆虎嘯獎(jiǎng)
- 2024 OpenCloudOS年會(huì)即將啟航，前瞻亮點(diǎn)獨(dú)家揭秘
- 戰(zhàn)略贊助合作 | 全球自助售貨行業(yè)高峰論壇暨全球行業(yè)領(lǐng)袖晚宴：共塑全球自助行業(yè)新格局！
- 數(shù)智領(lǐng)航增長(zhǎng)，金璨獎(jiǎng)獎(jiǎng)項(xiàng)案例邀您與我們一起共同見證
- 迎潮而上！2025 ChinaJoy潮·生活展區(qū)招商盛大開啟
免責(zé)聲明：本網(wǎng)站內(nèi)容主要來自原創(chuàng)、合作伙伴供稿和第三方自媒體作者投稿，凡在本網(wǎng)站出現(xiàn)的信息，均僅供參考。本網(wǎng)站將盡力確保所提供信息的準(zhǔn)確性及可靠性，但不保證有關(guān)資料的準(zhǔn)確性及可靠性，讀者在使用前請(qǐng)進(jìn)一步核實(shí)，并對(duì)任何自主決定的行為負(fù)責(zé)。本網(wǎng)站對(duì)有關(guān)資料所引致的錯(cuò)誤、不確或遺漏，概不負(fù)任何法律責(zé)任。任何單位或個(gè)人認(rèn)為本網(wǎng)站中的網(wǎng)頁(yè)或鏈接內(nèi)容可能涉嫌侵犯其知識(shí)產(chǎn)權(quán)或存在不實(shí)內(nèi)容時(shí)，應(yīng)及時(shí)向本網(wǎng)站提出書面權(quán)利通知或不實(shí)情況說明，并提供身份證明、權(quán)屬證明及詳細(xì)侵權(quán)或不實(shí)情況證明。本網(wǎng)站在收到上述法律文件后，將會(huì)依法盡快聯(lián)系相關(guān)文章源頭核實(shí)，溝通刪除相關(guān)內(nèi)容或斷開相關(guān)鏈接。
