最近碰到了一個oracle bug，但是我感覺還是有些運氣的成分，雖然錯誤日誌和bug描述吻合，版本也完全對應，現在有幾個問題在我腦海中翻騰，就是這個問題是不是一個特例，是不是一些額外的原因導致的，於是我翻出了日誌重新來看。 這是一個一主兩備的環境，一個本地災備，一個異地災備，資料庫版本是10.2.0.4.0，單例項 資料庫日誌如下： Redo Shipping Client Connected as PUBLIC -- Connected User is Valid RFS[8]: Assigned to RFS process 17656 RFS[8]: Identified database type as 'physical standby' RFS[8]: Archived Log: '/U01/app/oracle/flash_recovery_area/Stest2/archivelog/2016_03_21/o1_mf_1_8080_cgxw8n7l_.arc' Mon Mar 21 02:51:34 2016 ksvcreate: Process(m000) creation failed Mon Mar 21 02:52:34 2016 ksvcreate: Process(m000) creation failed Mon Mar 21 02:53:34 2016 ksvcreate: Process(m000) creation failed

為什麼是在2:50開始會報出這個錯誤，也是有一定的觸發條件，那就是每天的2:50會開啟一個查詢視窗，然後在幾個小時後關閉視窗，想來11g是該有多幸福啊。 上面的錯誤日誌就是在crontab中設定的資料庫狀態從read-only和online之間不斷的切換報出的。 看到這些日誌，感覺有幾個疑點。 1）為什麼2:50開始就會報出這個錯誤，是否和應用的查詢有關，有效能不良的sql語句導致 2）對於應用，是否開啟了大批量的查詢session，導致系統的程序資源不足 3）是否是系統層面的資源使用緊張導致 4）10gR2的環境其實還有一套，但是那套備庫環境印象中卻沒有類似的錯誤日誌 5）問題能夠重現 6）問題的解決方案 對於這幾個問題，相信弄明白了，自己說服自己了最重要。 首先第一個問題，是否和應用的查詢有關，是否有效能不良的sql語句導致。因為是10g的備庫，所以ash的資訊這塊還是不獨立的，如果需要監控只能自己 定製監控了。當然這種活自己也是駕輕就熟，但是先可以放一放，我的設想是如果沒有sql語句的問題，先看看後面的幾個問題。 然後第二個問題，是否有大批量的查詢導致的session溢位 檢視最新的一部分日誌，發現了下面的情況 [@test.cyou.com bdump]$ ls -lrt|tail -20 -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p012_17123.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p011_17121.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p010_17119.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p009_17117.trc -rw-r----- 1 oracle oinstall 909 Mar 21 02:50 test_p008_17115.trc -rw-r----- 1 oracle oinstall 908 Mar 21 02:50 test_p007_17113.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p006_17111.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p005_17109.trc -rw-r----- 1 oracle oinstall 912 Mar 21 02:50 test_p004_17107.trc -rw-r----- 1 oracle oinstall 912 Mar 21 02:50 test_p003_17105.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p002_17103.trc -rw-r----- 1 oracle oinstall 909 Mar 21 02:50 test_p001_17101.trc -rw-r----- 1 oracle oinstall 911 Mar 21 02:50 test_p000_17099.trc -rw-r----- 1 oracle oinstall 3002 Mar 21 02:50 test_mrp0_17097.trc -rw-r----- 1 oracle oinstall 57547 Mar 21 06:29 test_mmon_338.trc -rw-r----- 1 oracle oinstall 3236 Mar 21 06:30 test_rsm0_391.trc -rw-r----- 1 oracle oinstall 2475 Mar 21 06:30 test_dmon_342.trc -rw-r----- 1 oracle oinstall 2013 Mar 21 19:42 test_mrp0_3136.trc -rw-r----- 1 oracle oinstall 367817 Mar 21 19:42 alert_test.log -rw-r----- 1 oracle oinstall 567898962 Mar 21 21:29 drctest.log 裡面的亮點在於出現了大量的p00x的程序，這些都是一些和並行相關的程序。但是為什麼要並行呢。自己一個直接的聯想是可能啟用並行的一些操作，比如並行 查詢，如果session數足夠多，可能就會丟擲資源使用的問題了。當然，因為沒有任何監控，目前這是一個猜想，當然也可以間接從zabbix的監控中看 出確實沒有程序的急劇提升 抓取其中的一個日誌來看看。 /U01/app/oracle/admin/test/bdump/test_p000_12950.trc Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /U01/app/oracle/product/10.2 System name: Linux Node name: test.cyou.com Release: 2.6.18-128.el5 Version: #1 SMP Wed Dec 17 11:41:38 EST 2008 Machine: x86_64 Instance name: test Redo thread mounted by this instance: 1 Oracle process number: 23 Unix process pid: 12950, image: [email protected] (P000) *** 2016-03-20 02:50:01.953 *** SERVICE NAME:() 2016-03-20 02:50:01.952 *** SESSION ID:(2956.3620) 2016-03-20 02:50:01.952 Slave exiting with ORA-10388 exception KCBR: Number of read descriptors = 1024 KCBR: Media recovery blocks read (ASYNC) = 1328 KCBR: Redo cache copies/changes = 16458/16458 KCBR: Influx buffers flushed = 8 times KCBR: Reads = 119 reap (110 no-op, 0 one), 30 all 如果認為還不足以論證或者先不太明白，可以先放一放。 第三個問題，系統層面的資源是否緊張。這個可以從zabbix看出，無論io，cpu，cache，swap都沒有出現任何緊張的情況 Tasks: 216 total, 1 running, 214 sleeping, 0 stopped, 1 zombie Cpu(s): 0.4%us, 0.0%sy, 0.0%ni, 99.6%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 65996408k total, 39600240k used, 26396168k free, 1014300k buffers Swap: 8385920k total, 232k used, 8385688k free, 37149992k cached 從目前的情況來看，資源的情況還是比較富足的。 那麼第四個問題10gR2的環境還有一套，為什麼沒有類似的錯誤，經過驗證，發現那套環境是10.2.0.5.0的環境，而一個相關的bug是5583049， mos中的描述很清晰。問題發生在10.2.0.4的版本中，在其它的平臺會有一些差別。

Patch 5583049: 'KSVCREATE: PROCESS(M000) CREATION FAILED' AFTER STANDBY OPEN RO MULTIPLE TIMES
Last Updated     18-Jul-2009 06:33 (6+ years ago)   Size     23.5 KB              
Product     Oracle Database - Enterprise Edition     
Release     Oracle 10.2.0.4                        Classification     General    
Platform     Linux x86-64                           Patch Tag       

所以這個問題在10.2.0.5，經過驗證是不存在的。 然後第5個問題，那就來複現一些，復現的過程如果順利會解釋清楚第一個和第二個問題的可能性 驗證很簡單，就是把備庫置為read-only狀態 DGMGRL> edit database speak4 set state='read-only'; Succeeded. 然後檢視日誌，發現問題竟然能夠馬上覆現，而且很有規律，是一分鐘會出現一次，從目前的青年卡來看，和應用的sql導致的影響不大了。 對於資料庫層面的資源使用，可以參考下面的查詢結果。 SQL> select * from v$resource_limit; RESOURCE_NAME CURRENT_UTILIZATION MAX_UTILIZATION INITIAL_ALLOCATION LIMIT_VALUE ----------------------- ------------------- --------------- -------------------- -------------------- processes 36 41 1000 1000 sessions 27 46 3000 3000 enqueue_locks 29 93 32860 32860 enqueue_resources 29 29 13420 UNLIMITED 發現session數還遠遠未達到，所以這個可能性極低。 所以這個問題基本能夠看出確實復現了問題，那麼怎麼進一步驗證呢，我們可以開啟另外一個備庫來，驗證一下，切換兩次之後，也看到了同樣的錯誤。 通過上面的各種測試已經能夠充分能夠驗證問題所在了。 好了最後一個問題，那就是如何解決，官方提供了兩種方案。 一種是重啟，另外一種是設定關閉sga自動管理，並設定statistics=basic 這種方案還是根據具體的情況來選用。為什麼設定statistics=basic需要關閉sga的自動管理呢。 SQL> alter system set statistics_level=basic; alter system set statistics_level=basic * ERROR at line 1: ORA-02097: parameter cannot be modified because specified value is invalid ORA-00830: cannot set statistics_level to BASIC with auto-tune SGA enabled 這個錯誤已經很明顯說明了這種依賴。 當然自己還是認真測了論證了一番，發現確實如此，重新切換read-only,online就再沒有這個問題了。 通過這個小的案例可以看出，其實一個很細小的問題還是需要投入一些認真的測試，不能簡單認為是一個bug就草率了事,自己說服了自己，處理問題才會更加從容不迫。