兩條報警資訊的分析（第二篇)(r6筆記第71天)
還是繼續分析報警資訊的關聯，下面兩個看似沒有直接聯絡的報警資訊其實很有關聯。 下面是主庫的報警的資訊，檢視v$dataguard_status得到了最新的錯誤資訊。
############################# [DB監控系統][email protected]_報警 ZABBIX-監控系統: ------------------------------------ 報警內容: DG_issue ------------------------------------ 報警級別: PROBLEM ------------------------------------ 監控專案: dg_issue：2015-09-26 03:52:00.0Log Transport ServicesErrorError 12514 received logging on to the standby2015-09-26 03:52:00.0Log Transport ServicesErrorPING[ARC1]: Heartbeat failed to connect to standby '(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=xxxxx.com)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=sadb2_XPT)(INSTANCE_NAME=adb2)(SERVER=dedicated)))'. Error is 12514.2015-09-26 03:52:02.0Log Transport ServicesErrorError 12514 received logging on to the standby2015-09-26 03:52:02.0Fetch Archive LogErrorFAL[server, ARC1]: Error 12514 creating remote archivelog file '(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=xxxx)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=sadb2_XPT)(INSTANCE_NAME=adb2)(SERVER=dedicated)))' ------------------------------------ 報警時間:2015.09.26-03:53:09
下面是相鄰時間段裡備庫的報警資訊
[DB監控系統][email protected]_報警 ZABBIX-監控系統: ------------------------------------ 報警內容: Free disk space is less than 20% on volume /opt ------------------------------------ 報警級別: PROBLEM ------------------------------------ 監控專案: Free disk space on /opt (percentage)：9.82 % ------------------------------------ 報警時間:2015.09.26-03:28:57
這兩條資訊看似沒有必然的關聯，我們來分析一下原委，看看怎麼解決這個問題。 既然提示備庫有問題，我們來看看備庫的日誌資訊。
Redo Shipping Client Connected as PUBLIC -- Connected User is Valid RFS[1750]: Assigned to RFS process 3676 RFS[1750]: Identified database type as 'physical standby' RFS[1750]: Archived Log: '/U01/app/oracle/admin/adb2/arch/1_7751_782793360.dbf' Sat Sep 26 03:14:46 CST 2015 Stopping background process MMNL Sat Sep 26 03:14:47 CST 2015 Stopping background process MMON Sat Sep 26 03:14:48 CST 2015 SMON: disabling cache recovery Sat Sep 26 03:14:50 CST 2015 Starting background process MMON Sat Sep 26 03:14:50 CST 2015 ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT NODELAY Starting background process MMNL MMON started with pid=11, OS id=20676 Sat Sep 26 03:14:50 CST 2015 Attempt to start background Managed Standby Recovery process (adb2) MMNL started with pid=20, OS id=20678 MRP0 started with pid=21, OS id=20680 Sat Sep 26 03:14:50 CST 2015 MRP0: Background Managed Standby Recovery process started (adb2) Managed Standby Recovery not using Real Time Apply parallel recovery started with 15 processes Sat Sep 26 03:14:56 CST 2015 Waiting for all non-current ORLs to be archived... Media Recovery Log /U01/app/oracle/admin/adb2/arch/1_7751_782793360.dbf Sat Sep 26 03:14:56 CST 2015 Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE THROUGH ALL SWITCHOVER DISCONNECT NODELAY Sat Sep 26 03:14:59 CST 2015 Media Recovery Waiting for thread 1 sequence 7752 Sat Sep 26 03:21:38 CST 2015 Redo Shipping Client Connected as PUBLIC -- Connected User is Valid RFS[1751]: Assigned to RFS process 21848 RFS[1751]: Identified database type as 'physical standby' RFS[1751]: Archived Log: '/U01/app/oracle/admin/adb2/arch/1_7752_782793360.dbf' Sat Sep 26 03:21:39 CST 2015 Media Recovery Log /U01/app/oracle/admin/adb2/arch/1_7752_782793360.dbf Media Recovery Waiting for thread 1 sequence 7753
單純看日誌沒有發現相關的ora錯誤。 檢視備庫的檔案系統資訊。可以看到分割槽/opt的空間目前是正常的，說明在之後空間得到了釋放。
$ df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sda1 5.9G 959M 4.6G 17% /
/dev/sda3 7.5G 6.2G 943M 88% /var
/dev/sda5 12G 2.7G 8.1G 25% /usr
tmpfs 32G 8.0K 32G 1% /dev/shm
/dev/shm 32G 8.0K 32G 1% /tmp
/dev/sda7 495G 352G 118G 75% /opt
好了，問題背景交代完了，我們這個時候就來分析一下，這個問題在最近每天都會存在，時間段固定，可以斷定這是一個scheduler或者crontab之類觸發的。 而資料備份在備庫中，crontab更加現實一些，因為這個庫是10g的庫，還在mount階段。 所以查看了crontab，發現確實在特定的時間段存在一個備份任務。這是一個使用datapump的邏輯備份。 因為這個庫也不算大，但是資料還是比較重要，在有些資料誤刪除的情況下，還可以根據需要做一些對應的資料恢復工作，所以採用了邏輯備份的方式做了一次全備。 檢視base目錄下的空間使用情況，發現備份集的資料比資料庫資料檔案的還要大一些。這個似乎也不太合理。
$ du -sh ./*
182G ./backup_stage
169G ./oracle
12M ./oraInventory
oracle目錄下的檔案如下:
oracle]$ ll
total 12
drwxrwxr-x 3 oracle oinstall 4096 Feb 19 2014 admin
drwxr-xr-x 3 oracle oinstall 4096 May 14 2012 oradata
drwxrwxr-x 5 oracle oinstall 4096 Jul 30 11:08 product檢視之後發現backup_stage下存放的是近兩天的備份內容，也就是近兩天的資料備份都可以根據需要進行恢復。 那麼crontab是怎麼配置的呢? 30 1 * * * . $HOME/.adb2profile;$HOME/dbadmin/scripts/expdpfull.sh 這個重要的指令碼的內容如下：
less $HOME/dbadmin/scripts/expdpfull.sh
#!/bin/bash
. ~oracle/.bash_profile
home=~oracle
export home
lexphome=/U01/app/backup_stage/exp
export lexphome
expfile=${ORACLE_SID}_`date +%Y%m%d`
export expfile
dgmgrl / "edit database sadb2 set state='READ-ONLY'"
if [ $? -ne 0 ]; then
echo "set read-only failed!"
exit 1
fi
sleep 60
exp '/ as sysdba' parfile=$home/dbadmin/scripts/dbexp_full_adb2.par log=$lexphome/${expfile}.log
dgmgrl / "edit database sadb2 set state='ONLINE'"
if [ $? -ne 0 ]; then
echo "set online failed!"
exit 1
fi
find $lexphome/ -name '*.dmp' -mtime +1 -exec rm -f {} ;
所做的工作大體如下，取消備庫的日誌應用，然後把資料庫置為read-only狀態，然後做邏輯備份，備份完成之後把備庫開啟日誌應用，然後刪除前一天的備份。 流程和思路應該看不出什麼問題吧。 但是這個問題仔細琢磨了下，覺得還是哪裡不對勁，但又說不出。最後仔細揣摩了一番，發現這個流程其實還是可以做改進的。 打個比方，磁碟剩餘空間又160G,每天的備份大概是50G,這樣每天備份完成刪除之後就會剩餘60G的空間， 如果按照現有的流程來做，就是下面的形式 開啟邏輯備份 50G, 已有近兩天的備份100G,那麼剩餘空間就是160G-50G*2-50G=10G 如果是這種情況，就會出現空間的緊縮和抖動。使用zabbix檢視近期的空間緊縮情況確實就是這樣的情況
我們可以做這樣一種優化，即開始備份前，刪除前兩天的一個備份，然後開始當天的備份，這樣，備份就始終是兩個，空間使用率反而還會短期擴張。
明白了思路，解決起來就輕鬆很多，可以直接在備份前開始清理前兩天的一個備份。
指令碼內容如下：
less $HOME/dbadmin/scripts/expdpfull.sh
#!/bin/bash
. ~oracle/.bash_profile
home=~oracle
export home
lexphome=/U01/app/backup_stage/exp
export lexphome
expfile=${ORACLE_SID}_`date +%Y%m%d`
export expfile
find $lexphome/ -name '*.dmp' -mtime +1 -exec rm -f {} ;
dgmgrl / "edit database sadb2 set state='READ-ONLY'"
if [ $? -ne 0 ]; then
echo "set read-only failed!"
exit 1
fi
sleep 60
exp '/ as sysdba' parfile=$home/dbadmin/scripts/dbexp_full_adb2.par log=$lexphome/${expfile}.log
dgmgrl / "edit database sadb2 set state='ONLINE'"
if [ $? -ne 0 ]; then
echo "set online failed!"
exit 1
fi
find $lexphome/ -name '*.dmp' -mtime +1 -exec rm -f {} ;
這樣空間使用就會始終保持在基線之上，達到一個相對合理的狀態。
明白了這一點，再來看看我們所說的報警，主庫的v$dataguard_status中有這樣一段內容，Error 12514 creating remote archivelog file '(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=xxxx)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=sadb2_XPT)(INSTANCE_NAME=adb2)(SERVER=dedicated)))'
大體意思就是從主庫傳送歸檔到備庫失敗，無法建立，無法建立的原因應該就是空間問題，但是備庫的空間馬上又釋放了，所以從日誌中還沒有體現出來。
所以在空間有限的情況下我們進行流程的優化，達到的效果還是一致的。