1、 故障現象
某數據庫在2025-04-02發現備庫同步中斷,簡單查看數據庫LOG日誌中有如下的報錯信息:
2025-04-02 09:42:00.899 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:01.763 CST [2895266] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:03.773 CST [2895297] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:05.780 CST [2895370] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:05.903 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:07.786 CST [2895372] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:09.795 CST [2895438] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:10.906 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:11.803 CST [2895497] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:13.809 CST [2895567] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:15.818 CST [2895638] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:15.910 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:17.825 CST [2895689] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:19.831 CST [2895708] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:20.915 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:22.188 CST [2895730] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:24.194 CST [2895731] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:25.919 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2、 故障分析
2.1、 查詢failover工具日誌
查詢備庫的pg_auto_failover日誌信息,詳細信息如下:
2025-04-01 14:13:36.242576+08 | 0/2 | secondary | catchingup | Node node 2 "htzz_2" (192.168.111.12:1821) is marked as unhealthy by the monitor
2025-04-01 14:31:42.846598+08 | 0/2 | catchingup | catchingup | New state is reported by node 2 "htzz_2" (192.168.111.12:1821): "catchingup"
2025-04-01 14:31:44.043195+08 | 0/2 | catchingup | catchingup | Node node 2 "htzz_2" (192.168.111.12:1821) is marked as healthy by the monitor
2025-04-01 14:31:44.071861+08 | 0/2 | catchingup | secondary | Setting goal state of node 2 "htzz_2" (192.168.111.12:1821) to secondary after it caught up.
2025-04-01 15:06:55.821311+08 | 0/2 | catchingup | catchingup | Setting goal state of node 2 "htzz_2" (192.168.111.12:1821) to catchingup after it became unhealthy.
2025-04-01 15:07:50.768441+08 | 0/2 | catchingup | catchingup | Node node 2 "htzz_2" (192.168.111.12:1821) is marked as unhealthy by the monitor
在14:08:51分中備庫的狀態從secondary轉到catchingup的狀態,表示備庫此時出現同步延遲的情況,在結合後面的不監控狀態,説明此時備庫數據庫異常。在後續狀態中反反覆覆的發生狀態變化,最後狀態變成了catchingup,表示備庫一直在狀態主庫,此時也可以説明備庫數據庫環境出現了一段時間的不穩定現象。
查看主庫的pg_auto_failover日誌的信息,詳細信息如下:
主庫在相同的時間提示主庫的狀態從primary轉到wait_primary,跟備庫的日誌時間可以對應上。
通過上面日誌可以説明監控節點到兩台PG服務器之間網絡肯定沒有問題,其中備庫服務器也並未異常。
2.2、 備庫日誌分析
2.2.1、 亂碼日誌分析
分析在上面提到的故障時間點備庫日誌消息信息,詳細日誌如下:
2025-04-01 13:02:16.451 CST [1587210] ????: ?????? "192.168.111.12", ?? "postgres", ??? "postgres", no encryption ? pg_hba.conf ??
2025-04-01 14:13:28.203 CST [1455865] ??: ????? (fast) ????
2025-04-01 14:13:28.209 CST [1455865] ??: ????????
2025-04-01 14:13:28.927 CST [1455868] ??: ????
2025-04-01 14:13:28.961 CST [1455865] ??: ????????
日誌文件有大量上面重複的內容,通過保存下來的英語文字,大概可以推斷應該是連接備庫有問題了。
繼續往下分析日誌,有如下的日誌:
2025-04-01 15:07:45.304 CST [1686586] ??: ??????????????????
2025-04-01 15:07:45.304 CST [1686586] ??: ????? (immediate) ????
2025-04-01 15:07:45.304 CST [1686586] ??: ?????? "postmaster.pid": ENOENT
2025-04-01 15:07:45.319 CST [1686586] ??: ????????
2025-04-01 15:07:45.329 CST [1727667] ??: ???? PostgreSQL 14.9 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 7.3.0, 64-bit
2025-04-01 15:07:45.329 CST [1727667] ??: ????IPv4??"0.0.0.0",?? 1821
2025-04-01 15:07:45.329 CST [1727667] ??: ????IPv6??"::",?? 1821
2025-04-01 15:07:45.329 CST [1727667] ??: ?????? "postmaster.pid": ENOENT
2025-04-01 15:07:45.330 CST [1727667] ??: ?Unix??? "/var/run/postgresql/.s.PGSQL.1821"???
2025-04-01 15:07:45.330 CST [1727667] ??: ?????? "postmaster.pid": ENOENT
2025-04-01 15:07:45.330 CST [1727667] ??: ?Unix??? "/tmp/.s.PGSQL.1821"???
2025-04-01 15:07:45.333 CST [1727667] ??: ?????? "postmaster.pid": ENOENT
2025-04-01 15:07:45.334 CST [1727670] ??: ?????2025-04-01 14:31:41 CST?????,????????
2025-04-01 15:07:45.334 CST [1727670] ??: ??????????,????????????,????????????????
這裏看到備庫數據庫有重啓的操作,重啓以後還是無法連接。
2.2.2、 正常日誌分析
簡單調整環境後得到下面的日誌內容:
2025-04-02 09:42:05.780 CST [2895370] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:05.903 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:07.786 CST [2895372] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:09.795 CST [2895438] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:10.906 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:11.803 CST [2895497] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:13.809 CST [2895567] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:15.818 CST [2895638] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:15.910 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:17.825 CST [2895689] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:19.831 CST [2895708] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:20.915 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
2025-04-02 09:42:22.188 CST [2895730] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:24.194 CST [2895731] 致命錯誤: 數據庫系統啓動中
2025-04-02 09:42:25.919 CST [1952298] 日誌: 在456/7ECCB34D8處的資源管理器ID54不合法
這裏提示資源管理54不合法。
2.3、 資源管理器54分析
在PG中資源管理分為自定義和系統內置的,其中內置的資源管理器ID為0~21,自定義的資源管理ID為128-255。在備庫應用日誌時,會判斷資源ID是否合法,如果合法繼續往後面執行,如果非法,直接拋出異常。此時的ID 54並不在內置和自定的資源管理器中,所以被定義為異常ID,直接報錯。可以參看如下的源代碼:
#undef PG_RMGR
#define RM_MAX_ID UINT8_MAX
#define RM_MAX_BUILTIN_ID (RM_NEXT_ID - 1)
#define RM_MIN_CUSTOM_ID 128
#define RM_MAX_CUSTOM_ID UINT8_MAX
#define RM_N_IDS (UINT8_MAX + 1)
#define RM_N_CUSTOM_IDS (RM_MAX_CUSTOM_ID - RM_MIN_CUSTOM_ID + 1)
static inline bool
內置資源ID的判斷
RmgrIdIsBuiltin(int rmid)
{
return rmid <= RM_MAX_BUILTIN_ID;
}
static inline bool
自定義資源ID的判斷
RmgrIdIsCustom(int rmid)
{
return rmid >= RM_MIN_CUSTOM_ID && rmid <= RM_MAX_CUSTOM_ID;
}
判斷資源ID是否合規
#define RmgrIdIsValid(rmid) (RmgrIdIsBuiltin((rmid)) || RmgrIdIsCustom((rmid)))
/*
* RmgrId to use for extensions that require an RmgrId, but are still in
下面在看看日誌應用的代碼:
if (!RmgrIdIsValid(record->xl_rmid))
{
report_invalid_record(state,
"invalid resource manager ID %u at %X/%08X",
record->xl_rmid, LSN_FORMAT_ARGS(RecPtr));
return false;
}
如果資源ID異常,拋出上面的錯誤,並返回false。
3、 原因分析
備庫的WAL日誌文件來由主庫通過網絡傳遞給備庫,並且在異常前,有數據庫鏈接不上等異常的信息,所以導致WAL日誌損壞的原因有很多種。在當前環境中主庫暫時未開啓歸檔日誌,所以暫時無法獲得歷史的WAL日誌用於驗證WAL損壞發生在那個環境。下面我們簡單羅列幾個WAL損壞的原因:
- 網絡丟包,導致包傳輸不完整。
- 操作系統IO寫丟失。
- 內存損壞
-
4、 解決方案
由於主庫WAL日誌丟失,所以暫時選擇重新搭建整個容災環境。
------------------作者介紹-----------------------
姓名:黃廷忠
現就職:Oracle中國高級服務團隊
曾就職:OceanBase、雲和恩墨、東方龍馬等