有一天接到了同事的一個電話,說是有一個資料庫無法訪問了,希望我幫一下忙,連接過去查看,發現是一個看似很簡單的ORA錯誤,如下。
$ sqlplus / as sysdbaCopyright (c) 1982, 2011, Oracle. All rights reserved.
ERROR:ORA-09817: Write to audit file failed.Linux-x86_64 Error: 28: No space left
Additional information: 12
ORA-01075: you are currently logged
這種問題想必大家都或多或少碰到過,從錯誤日誌來看還是因為審計日誌寫不進去了;
再進一步來說,就是磁碟空間不足了。
通過df -h的結果足以說明,磁碟空間確實是不足了,如下。
Filesystem Size Used Avail Use% Mounted
/dev/sda7 5.9G 633M 4.9G 12% /
.../dev/sdb1 3.1T 3.0T 0 100% /data
注意:如果資料庫因為磁碟空間無法登錄,查看不了審計日誌的路徑,可以通過$ORACLE_ HOME/dbs下的參數文件來查找審計日誌的路徑。
臨時解決方法
要解決這個問題,就需要清理磁碟空間,發現有一個大約100MB的臨時文件,可以先挪到其他的目錄下,然後再次嘗試TNS連接就沒有問題了。
問題似乎已經得到初步解決。但是過了不到一分鐘,再次嘗試,發現又無法登錄。查看磁碟空間,空間已經用完了,於是又做了一些磁碟空間的清理,問題的處理才暫時告一段落。
問題反思
這樣一來,我們需要分析問題的原因。空間問題導致的資料庫無法登錄是不應該犯的錯誤。因為查看前幾天的巡檢結果,看到還剩下很多的空間。按照一個閾值來參考,還是夠用的。
那就說明資料庫層面還是有一些異常的地方,於是得到了如圖所示的報告。這個報告能夠看出一個資料庫的負載情況,能夠看到在一個小時內redo的切換頻率。橫軸上方是時間,顯示的是每個小時的歸檔切換頻率,縱軸是日期。
可以看到在問題發生的時間段內(用框圖標註出來的部分),redo切換頻率極高,資料庫負載是在近兩天才升上去的,但是資料庫redo切換如此頻繁,是否在應用層面有一些大的變更目前還沒有相關的通知,而導致空間問題就這樣累計了下來,結果到第二天歸檔時一下子撐滿了磁碟空間才發現問題。
為證實上面的想法還需要協同其他部門進一步確認,在此不作贅述。但是對於DBA來說,確實需要檢查資料庫層面的一些數據變化情況,而隨時做出響應。
因為目前的環境使用Data Guard的架構,歸檔數據傳輸到備庫的頻率還是很高的,所以對於歸檔的保留也就採用了一些處理。目前的歸檔保留時間是2天,考慮到這些天內歸檔切換頻率極高,很可能備庫的空間也會佔滿。所以簡單地修改了一下crontab中歸檔的刪除策略很有必要。
注意:歸檔路徑最好是放在fast_recovery_area_dest下,在11g備庫中,會有一個空間閾值,超過了80%會自動刪除閃回區下的文件,這是11g的一個新特性。
對於這個問題的反思如下:
(1)對於歸檔的刪除,最好能夠做些前瞻性的處理,比如,對於歸檔產生較多,但是又不希望直接刪除歸檔的情況,可以對歸檔進行定時壓縮和定時刪除(定時刪除的文檔須是過期的),這樣既節省了空間又可保留儘可能多的歸檔。
(2)資料庫級的變更和應用關係極為緊密,如果有什麼大的變更或者批量處理還是能夠讓DBA知曉,在這個問題上DBA還是需要做到先知先覺。
(3)從資料庫層面進行了分析,在短期內生成了大量的redo,造成了頻繁的日誌切換,導致歸檔佔用了大量的空間,最後無法登錄,因此,我們可以做一些工作來儘可能長時間的保留近期的歸檔;同時我們還可以換一個思路,即查看是什麼操作生成了大量的redo,是否可以減少redo的生成量,達到釜底抽薪的效果。
關於上面的反思第三條,順著這個思路我們詳細講述一下。
從資料庫層面進行分析
一般來說,日誌會記錄儘可能完整的信息,這是做數據恢復的基礎,但謹慎起見,我們先來分析一下再來做決定看看是否可行。
查看資料庫的redo切換頻率,在近幾天內的redo切換頻率極高,基本每個小時日誌切換都在250次左右。對於一個OLTP的系統來說是非常高的負載,這種頻繁的日誌切換我也只在數據遷移的一些場景中碰到過。
但是奇怪的是查看資料庫的DB time,卻發現這個值其實並不高,如下所示,看起來似乎前後矛盾,因為從這一點來看資料庫內的負載變化其實並不是很高。
BEGIN_SNAP END_SNAP SNAPDATE DURATION_MINS DBTIME
---------- ---------- ----------------------- ----------
82560 82561 05 Sep 2019 00:00 30 26
82561 82562 05 Sep 2019 00:30 30 26
82562 82563 05 Sep 2019 01:00 29 29
82563 82564 05 Sep 2019 01:30 30 27
82564 82565 05 Sep 2019 02:00 30 23
82565 82566 05 Sep 2019 02:30 30 23
82566 82567 05 Sep 2019 03:00 30 20
對於這種情況,我們還是抓取一個AWR報告來看看。
在AWR報告中,可以看到瓶頸還是主要在DB CPU和IO相關的等待事件,見下表。
Top 5 Timed Foreground Events表4-1
查看時間模型,可以看到DB CPU和SQL相關的影響各佔了主要的比例。
查看等待事件能夠看到主要都是在CPU的消耗上,進一步分析能夠關注的重點就是SQL語句,Top 1的SQL語句執行情況見下表。
這條語句執行頻率極高,語句也很簡單,但是CPU消耗卻很高,初步懷疑是走了全表掃描。
語句如下:
update sync_id set max_id = :1 where sync_id_type = :2
簡單查看執行計劃,發現確實是走了全表掃描;通常情況下,這種情況首先是需要走索引的,沒有索引可以新建一個索引,但是當筆者看到SQL by Executions這個部分時,發現問題其實不是那麼簡單。
可以看到第2個語句就是剛剛提到的Top 1的SQL,對應的指標很不尋常的,一次執行處理的行數近5 000多行,執行了1萬多次,處理的數據行數近8000萬,見下表。
但是查看表,發現數據其實就是1萬多條,所以這明顯是一個問題。
我們再來進一步分析,一個小表1萬多行的數據,每次執行更新5 000多行,可以斷定數據的分布是不均勻的。因為這個表結構非常簡單,只有兩個欄位,所以還是很好定位的。
簡單查看了一下數據情況,發現數據主要分布在兩個type列值上,基本上佔用了99.99%以上,如下所示。
SQL> select max_id,count(*)from SYNC_ID where SYNC_ID_TYPE='SYNC_LOG_ID' group by max_id;
MAX_ID COUNT(*)
---------- ----------
38 5558
SQL> select max_id,count(*)from SYNC_ID where SYNC_ID_TYPE=SYNC_TEST2_LOG_ID' group by max_id;
MAX_ID COUNT(*)
---------- ----------
108 5577
從數據的分布情況可以看到,表中存在了大量的冗餘數據,而且表中也沒有索引欄位和其他約束;這樣一來,每次更新時只要更新一個欄位值,就會修改5 000多行數據的值;如果執行頻繁,短時間內就會頻繁生成大量的redo。因此從目前的SQL運行情況來看,這條語句應該是造成redo頻繁切換的主要原因。
畢竟是線上環境,需要做一些確認和溝通之後才能夠變更的,目前只是建議,我們還需要驗證測試一下。
驗證測試
測試的思路很簡單,只需把這個表裡的數據導出來,放到其他的測試環境中,然後模擬做頻繁的更新,查看歸檔的頻率即可。
首先把數據導入另外一個測試環境中。其次使用下面的語句進行頻繁更新即可,先更新100萬次,中間可以隨時中斷,於是我寫了下面的腳本。
function test_update
{
sqlplus test/test <<EOF
update sync_id set max_id = 38 where sync_id_type = 'SYNC_LOG_ID';
commit;
EOF
}
for i in
do
test_update
done
在測試開始的時候,歸檔切換頻率是0。
Redo Switch times per hour xxxx-Sep-05 16:02:55
--- -- -- ---- ---- ---- ---- ---- ---- ---- ----
9月5日 0 0 0 0 0 0 0 0運行了不到3分鐘,日誌切換就達到了14次,還是能夠說明問題的。
Redo Switch times per hour xxxx-Sep-05 16:05:20
--- -- - ---- ---- ---- ---- ---- ---- ---- ----
9月5日 14 0 0 0 0 0 0 0
然後我們使用更新的方式來驗證一下。
Redo Switch times per hour xxxx-Sep-05 16:08:04
9月5日 14 0 0 0 0 0 0 0
過了4分鐘,日誌一次都沒有切換。
9月5日 14 0 0 0 0 0 0 0
這就足以說明了我們的推論是正確的
最後就是做進一步的確認,然後在正式的環境中部署,在線上環境清理了冗餘數據之後,這個問題再沒有出現過。