RMAN備份時遇到ORA-48132 &ORA-48170且備份變慢案例
2025-02-13 10:17 瀟湘隱者 閱讀(347) 評論(0) 收藏 舉報現象描述:
環境:
操作系統:Red Hat Enterprise Linux release 8.10
數據庫版本: Oracle 19.24.0.0.0 企業版
備份作業在執行RMAN備份時,告警日志中會出現ORA-48132 & ORA-48170錯誤,如下所示(數據庫實例用xxx做了混淆)
2025-02-12T11:10:11.070519+08:00
Errors in file /xxxdb/diag/rdbms/xxx/xxx/trace/xxx_ora_3430285.trc:
ORA-48132: requested file lock is busy, [HM_RUN] [/xxxdb/diag/rdbms/xxx/xxx/lck/AM_1618_3044626670.lck]
ORA-48170: unable to lock file - already in use
Linux-x86_64 Error: 11: Resource temporarily unavailable
Additional information: 8
Additional information: 2421413
2025-02-12T11:11:50.186760+08:00
Errors in file /xxxdb/diag/rdbms/xxx/xxx/trace/xxx_ora_3430287.trc:
ORA-48132: requested file lock is busy, [HM_RUN] [/xxxdb/diag/rdbms/xxx/xxx/lck/AM_1618_3044626670.lck]
ORA-48170: unable to lock file - already in use
Linux-x86_64 Error: 11: Resource temporarily unavailable
Additional information: 8
Additional information: 2421413
原因分析:
備份作業之前是完全正常的,而且沒有做過配置與參數的變更,突然間出現了這樣的報錯。研究了報錯的trc文件后確定是RMAN備份時拋出的錯誤,另外,在分析研究過程中,我們發現如果備份的時候能夠重現這個錯誤的話,就可以觀察到有ADR file lock。如果錯過了備份時間段,也可以通過AWR或ASH發現,如下截圖所示:

另外,我還發現一個很奇怪的問題,如下截圖所示,最開始遇到這個問題的時間是是2025-02-02,在出現這個問題后,發現備份時間從15分鐘多變成了50多分鐘,而且每秒寫出IO(OUTPUT_BYTES_PER_SEC_DISPLAY)也變小了,也就是說RMAN備份變慢了,如下所示:
CON_ID START_TIME END_TIME BACKUP_TYP IN_GB IO_IN_RATE OUT_GB IO_OUT_RAT ELAPSED_MIN OUTPUT_D
------ ------------------- ------------------- ---------- ------- ---------- ------- ---------- ----------- --------
1 2025-01-29 18:30:07 2025-01-29 18:45:54 DB FULL 588.6 636.47M 144.4 156.18M 15.8 DISK
1 2025-01-30 18:30:07 2025-01-30 18:46:02 DB FULL 587.8 630.25M 143.8 154.17M 15.9 DISK
1 2025-01-31 18:30:07 2025-01-31 18:45:54 DB FULL 587.8 635.63M 143.7 155.43M 15.8 DISK
1 2025-02-01 18:30:07 2025-02-01 18:46:00 DB FULL 587.4 631.12M 142.9 153.52M 15.9 DISK
1 2025-02-02 18:30:06 2025-02-02 19:21:39 DB FULL 582.1 192.73M 137.4 45.49M 51.6 DISK
1 2025-02-03 18:30:07 2025-02-03 19:21:39 DB FULL 582.3 192.84M 137.4 45.51M 51.5 DISK
1 2025-02-04 18:30:07 2025-02-04 19:21:39 DB FULL 582.2 192.80M 137.4 45.50M 51.5 DISK
1 2025-02-05 18:30:07 2025-02-05 19:21:39 DB FULL 588.0 194.74M 140.7 46.59M 51.5 DISK
1 2025-02-06 18:30:06 2025-02-06 19:21:38 DB FULL 586.4 194.22M 140.5 46.54M 51.5 DISK
1 2025-02-07 18:30:07 2025-02-07 19:21:38 DB FULL 582.6 193.00M 136.7 45.30M 51.5 DISK
1 2025-02-08 18:30:07 2025-02-08 19:21:39 DB FULL 583.4 193.21M 136.9 45.34M 51.5 DISK
1 2025-02-09 18:30:07 2025-02-09 19:21:40 DB FULL 583.6 193.21M 137.3 45.45M 51.6 DISK
1 2025-02-10 18:30:06 2025-02-10 19:21:40 DB FULL 583.7 193.17M 137.1 45.39M 51.6 DISK
1 2025-02-11 18:30:07 2025-02-11 19:21:38 DB FULL 584.4 193.62M 137.2 45.46M 51.5 DISK
1 2025-02-12 10:36:50 2025-02-12 11:20:23 DB FULL 590.2 231.30M 142.9 56.00M 43.6 DISK
1 2025-02-12 11:21:35 2025-02-12 11:35:55 DB FULL 550.4 655.32M 103.1 122.71M 14.3 DISK
16 rows selected

解決這個問題是在2025-02-12日10點多,臨時解決后RMAN備份速度又恢復正常了。我搜索了Oracle官方文檔,關于這個錯誤,其實官方文檔Oracle Support上有詳細文檔ORA-48132 ORA-48170 When Running RMAN Backups (Doc ID 2904353.1)介紹,我們這邊遇到的案例跟鏈接內容極其相似(但是還有點不同),這里就不畫蛇添足了,貼上具體內容如下所示
APPLIES TO:
Oracle Database - Enterprise Edition - Version 11.2.0.4 and later
Information in this document applies to any platform.
SYMPTOMS
Alert log flooded with below errors while running the RMAN backup.
ADR or AMH operation error:; err_code=48132, "dbkh_create_pseudo_run_ctx-1"=dbkh_create_pseudo_run_ctx-1
at 0xffffffff7fff5870 placed krbb.c@25071
ORA-48132: requested file lock is busy, [HM_RUN] [/db01/app/oracle/diag/rdbms/<DB_NAME>/<SID>/lck/AM_1618_3044626670.lck]
ORA-48170: unable to lock file - already in use
SVR4 Error: 11: Resource temporarily unavailable
Additional information: 8
Additional information: 2701
'ADR file lock' wait event observed during the backup.
INST_ID SID CH SEQ# EVENT STATE SECS
---------- ------- --------------------------- ------ ---------------------------- ---------- ----------
1 262 6114 SQL*Net message from client WAITING 50
1 467 rman channel=ORA_SBT_TAPE_1 898 ADR file lock WAITING 2 >>>>>>>>>>>>>>>>>>>>>>>>>
CHANGES
CAUSE
This symptom is being investigated by developer in Bug 10125939.
Bug 10125939 - GSFBDRA: RMAN VALIDATE HANG WAITING FOR 'ADR FILE LOCK' Closed as could not reproduce
SOLUTION
Choose the following workaround:
Solution 1:
Disable HM Monitor as below:
alter system set "_diag_hm_rc_enabled"=false scope=both;
Solution 2:
Enable krb trace , this might lead to more RMAN KRB traces to generate.
If RAC, Krb tracing needs to enabled on all nodes.
alter system set event='logon trace name krb_options level 20' scope=spfile; <==== To set it.
alter system set event='logon trace name krb_options off' scope=spfile; <==== To set it off
Solution 3:
Rename/Move lck folder.
ex: /db01/app/<BASE>/diag/rdbms/<sid>/<SID>/lck/AM_1618_3044626670.lck
Shutdown database;
cd /db01/app/<BASE>/diag/rdbms/<sid>/<SID>
mv lck lck_bkp
start the database
purge adrci
adrci>purge
這里我們通過刪除lck文件了暫時解決了RMAN備份時告警日志報ORA-48132&ORA-48170錯誤。在Oracle Service Requests提交SR反饋給官方后,Oracle技術人員也確認是遇到了bug,不過他們反饋遇到的是Bug 35500265 - Slow backups with errors ORA-48132 ORA-48170 ( Doc ID 35500265.8 )導致。而不是上文中的Bug 10125939,官方結論如下:
-- Conclusion:
The following bug might be hit:
Bug 35500265 - Slow backups with errors ORA-48132 ORA-48170 ( Doc ID 35500265.8 )
-- Evidence:
1. The symptom that RMAN backup slow with ORA-48132 and ORA-48170 is similar.
2. 19.24 is in the scope of 35500265's effected version.
3. The patch of 35500265 is not applied in this system
關于Bug 35500265,這個Bug已將在19.25.0.0.241015中fix掉了。如果要徹底解決這個問題就必須安裝相關補丁。

參考資料:
ORA-48132: Requested File Lock Is Busy, [HM_RUN] (Doc ID 3066412.1)
ORA-48132 ORA-48170 When Running RMAN Backups (Doc ID 2904353.1)
浙公網安備 33010602011771號