內核不中斷前提下,Gaussdb(DWS)內存報錯排查方法

語言: CN / TW / HK
摘要:本文主要講解如何在內核保證操作不能中斷採取的特殊處理,理論上用户執行的sql使用的內存(dynamic_used_memory) 是不會大範圍的超過max_dynamic_memory的內存的

本文分享自華為雲社區《Gaussdb(DWS)內存報錯排查方法》,作者: fighttingman。

Gaussdb內存佈局

內存上下文memoryContext內存結構

一、內存問題定位方法

分析場景1:數據庫日誌出現ERROR:memory is temporarily unavailable

從報錯信息可以找到是哪個節點的內存不足,例如 dn_6003_6004: memory is temporarily unavailable , 這個就是dn_6003的內存不足了

1.從日誌分析

觀察對應dn的日誌,是否為“reaching the database memory limitation”,表示為數據庫的邏輯內存管理機制保護引起,需要進一步分析數據庫的視圖;若為“reaching the OS memory limitation”,表示為操作系統內存分配失敗引起,需要查看操作系統參數配置及內存硬件情況等。

1)reaching the database memory limitation情況實例

----debug_query_id=76279718689098154, memory allocation failed due to reaching the database memory limitation. Current thread is consuming about 10 MB, allocating 240064 bytes.
----debug_query_id=76279718689098154, Memory information of whole process in MB:max_dynamic_memory: 18770, dynamic_used_memory: 18770, dynamic_peak_memory: 18770, dynamic_used_shrctx: 1804, dynamic_peak_shrctx: 1826, max_sctpcomm_memory: 4000, sctpcomm_used_memory: 1786, sctpcomm_peak_memory: 1786, comm_global_memctx: 0, gpu_max_dynamic_memory: 0, gpu_dynamic_used_memory: 0, gpu_dynamic_peak_memory: 0, large_storage_memory: 0, process_used_memory: 22105, cstore_used_memory: 1022, shared_used_memory: 2605, other_used_memory: 0, os_totalmem: 257906, os_freemem: 16762.

此時,作業76279718689098154準備申請240064 bytes內存,dynamic_used_memory內存值為18770MB,二者之和大於max_dynamic_memory(18770MB),超出數據庫限制,內存申請失敗。

在811之後的版本還會打印top3的memoryContext內存佔用,示例如下

----debug_query_id=72339069014641088, sessId: 1670914731.140604465997568.coordinator1, sessType: postgres, contextName: ExprContext, level: 5, parent: FunctionScan_140604465997568, totalSize: 950010640, freeSize: 0, usedSize: 950010640
----debug_query_id=72339069014641053, pid=140604465997568, application_name=gsql, query=select * from pv_total_memory_detail, state=retrying, query_start=2022-12-13 14:59:22.059805+08, enqueue=no waiting queue, connection_info={"driver_name":"gsql","driver_version":"(GaussDB 8.2.0 build bc4cec20) compiled at 2022-12-13 14:45:14 commit 3629 last mr 5138 debug","driver_path":"/data3/x00574567/self/gaussdb/mppdb_temp_install/bin/gsql","os_user":"x00574567"}
----debug_query_id=72339069014641088, sessId: 1670914731.140604738627328.coordinator1, sessType: postgres, contextName: ExprContext, level: 5, parent: FunctionScan_140604738627328, totalSize: 900010080, freeSize: 0, usedSize: 900010080
----debug_query_id=72339069014641057, pid=140604738627328, application_name=gsql, query=select * from pv_total_memory_detail, state=retrying, query_start=2022-12-13 14:59:22.098775+08, enqueue=no waiting queue, connection_info={"driver_name":"gsql","driver_version":"(GaussDB 8.2.0 build bc4cec20) compiled at 2022-12-13 14:45:14 commit 3629 last mr 5138 debug","driver_path":"/data3/x00574567/self/gaussdb/mppdb_temp_install/bin/gsql","os_user":"x00574567"}
----debug_query_id=72339069014641088, sessId: 1670914731.140603779163904.coordinator1, sessType: postgres, contextName: ExprContext, level: 5, parent: FunctionScan_140603779163904, totalSize: 890009968, freeSize: 0, usedSize: 890009968
----debug_query_id=72339069014641058, pid=140603779163904, application_name=gsql, query=select * from pv_total_memory_detail, state=retrying, query_start=2022-12-13 14:59:22.117463+08, enqueue=no waiting queue, connection_info={"driver_name":"gsql","driver_version":"(GaussDB 8.2.0 build bc4cec20) compiled at 2022-12-13 14:45:14 commit 3629 last mr 5138 debug","driver_path":"/data3/x00574567/self/gaussdb/mppdb_temp_install/bin/gsql","os_user":"x00574567"}
----allBackendSize=34, idleSize=7, runningSize=7, retryingSize=20

重要字段解釋:

sessId:線程啟動時間+線程標識(字符串信息為timestamp.threadid)

sessType:線程名稱

contextName:memoryContext名字

totalSize:內存佔用大小,單位Byte

freeSize:當前memoryContext釋放內存總數,單位Byte

usedSize:當前memoryContext已使用的內存總數,單位Byte

application_name:連接到該後端的應用名

query:查詢語句

enqueue:排隊情況

allBackendSize:總線程個數,idleSize:idle線程個數,runningSize:活躍的線程個數,retryingSize:重試的線程個數

數據庫還會在複雜作業中進行檢查,查看複雜作業預估內存是否超過實際使用內存,如果存在,則打印下列信息,供分析。

----debug_query_id=76279718689098154, Total estimated Memory is 15196 MB, total current cost Memory is 16454 MB, the difference is 1258 MB.The count of complicated queries is 17 and the count of uncontrolled queries is 1.

上述信息表示全部複雜作業預計使用內存15196 MB,實際使用16454 MB,超出1258 MB。

複雜作業共17個,其中有1個作業實際使用內存超過預計內存。

----debug_query_id=76279718689098154, The abnormal query thread id 140664667547392.It current used memory is 13618 MB and estimated memory is 1102 MB.It also is the query which costs the maximum memory.

上述信息表示,異常線程id為140664667547392,該線程預估消耗內存1102MB,實際消耗13618MB。

----debug_query_id=76279718689098154, It is not the current session and beentry info : datid<16389>, app_name<cn_5001>, query_id<76279718688746485>, tid<140664667547392>, lwtid<173496>, parent_tid<0>, thread_level<0>, query_string<explainperformance with ws as (select d_year AS ws_sold_year, ws_item_sk, ws_bill_customer_sk ws_customer_sk, sum(ws_quantity) ws_qty, sum(ws_wholesale_cost) ws_wc, sum(ws_sales_price) ws_sp from web_sales left join web_returns on wr_order_number=ws_order_number and ws_item_sk=wr_item_sk join date_dim on ws_sold_date_sk = d_date_sk where wr_order_number is null group by d_year, ws_item_sk, ws_bill_customer_sk ), cs as (select d_year AS cs_sold_year, cs_item_sk, cs_bill_customer_sk cs_customer_sk, sum(cs_quantity) cs_qty, sum(cs_wholesale_cost) cs_wc, sum(cs_sales_price) cs_sp from catalog_sales left join catalog_returns on cr_order_number=cs_order_number and cs_item_sk=cr_item_sk join date_dim on cs_sold_date_sk =d_date_sk where cr_order_number is null group by d_year, cs_item_sk, cs_bill_customer_sk ), ss as (select d_year AS ss_sold_year, ss_item_sk, ss_customer_sk, sum(ss_quantity) ss_qty, sum(ss_wholesale_cost) ss_wc, sum(ss_sales_price) ss_spfrom store_sales left join store_returns on sr_ticket_numbe>.

上述信息進一步顯示內存使用超過預估內存的作業信息的sql信息,其中datid表示數據庫的OID,app_name表示application name,query_string表示查詢sql。

----debug_query_id=76279718689098154, WARNING: the common memory context 'HashContext' is using 1059 MB size larger than 989 MB.----debug_query_id=76279718689098154, WARNING: the common memory context 'VecHashJoin_76279718688746485_6' is using 12359 MB size larger than 10 MB.

上述信息表示超限的memcontext,76279718689098154號查詢中,memory context預設值的最大值為989MB,實際使用了1059 MB。

2)reaching the OS memory limitation

當GaussDB內存使用符合GUC中相關參數限制,但操作系統可用內存不足時,會出現與1.1中類似的日誌信息,格式如下

----debug_query_id=%lu, FATAL: memory allocation failed due to reaching the OS memory limitation. Current thread is consuming about %d MB, allocating %ld bytes.
----debug_query_id=%lu, Please check the sysctl configuration and GUC variable max_process_memory.
----debug_query_id=%lu, Memory information of whole process in MB:"
                            "max_dynamic_memory: %d, dynamic_used_memory: %d,
dynamic_peak_memory: %d, dynamic_used_shrctx: %d,
dynamic_peak_shrctx: %d, max_sctpcomm_memory: %d,
sctpcomm_used_memory: %d, sctpcomm_peak_memory: %d,
comm_global_memctx: %d, gpu_max_dynamic_memory: %d,
gpu_dynamic_used_memory: %d,
gpu_dynamic_peak_memory: %d, large_storage_memory: %d,
process_used_memory: %d, cstore_used_memory: %d,
shared_used_memory: %d, other_used_memory: %d,
os_totalmem: %d, os_freemem: %d

其中,os_totalmem是當前OS中的總內存,即“free”命令中的total信息。os_freemem是當前OS中的可用內存,即“free”命令中的free信息。

第一條日誌中“allocating %ld bytes”中的待申請的內存大於第三條日誌中“os_freemem”項,且數據庫可運行,無其他異常,則符合預期,説明OS內存不足。

2. 實例每個實例的內存使用情況,查詢pgxc_total_memory_detail

內存報錯後,語句使用的內存就會釋放,當時佔用內存高的語句可能會因為報錯,導致現場沒有了,查詢內存視圖查詢不到的情況

with a as (select *from pgxc_total_memory_detail where memorytype='dynamic_used_memory'), b as(select * from pgxc_total_memory_detail wherememorytype='dynamic_peak_memory'), c as (select * from pgxc_total_memory_detailwhere memorytype='max_dynamic_memory'), d as (select * frompgxc_total_memory_detail where memorytype='process_used_memory'), e as (select* from pgxc_total_memory_detail where memorytype='other_used_memory'), f as(select * from pgxc_total_memory_detail where memorytype='max_process_memory')select a.nodename,a.memorymbytes as dynamic_used_memory,b.memorymbytes asdynamic_peak_memory,c.memorymbytes as max_dynamic_memory,d.memorymbytes asprocess_used_memory,e.memorymbytes as other_used_memory,f.memorymbytes asmax_process_memory from a,b,c,d,e,f where a.nodename=b.nodename andb.nodename=c.nodename and c.nodename=d.nodename and d.nodename=e.nodename ande.nodename=f.nodename order by a.nodename;

在查詢這個視圖也有可能會因為內存不足報memory is temporarily unavailable,導致視圖查不出來,此時需要將disable_memory_protect設置為off。

set disable_memory_protect=off; 之後在查詢視圖就不會報錯。

通過上邊這視圖可以找到集羣中哪個節點的內存使用有異常,之後連接那個節點通過pv_session_memory_detail視圖找到有問題的memorycontext。

SELECT * FROM pv_session_memory_detail ORDER BY totalsize desc LIMIT 100;

結合pg_stat_activity視圖可以找到哪個語句使用的memcontext最多。

select sessid, contextname, level,parent, pg_size_pretty(totalsize) as total ,pg_size_pretty(freesize) as freesize, pg_size_pretty(usedsize) as usedsize, datname,query_id, query from pv_session_memory_detail a , pg_stat_activity b where split_part(a.sessid,'.',2) = b.pid order by totalsize desc limit 100;

緊急恢復

EXECUTE DIRECT ON(cn_5001) 'SELECT pg_terminate_backend(139780156290816)';

二、內存佔用高的場景分析

1.空閒連接過多導致內存佔用

先確認是哪個實例的內存佔用高,確認方法如上查詢pgxc_total_memory_detail,之後連上那個cn或者dn查詢如下sql

select b.state, sum(totalsize) as totalsize, sum(freesize) as freesize, sum(usedsize) as usedsize from pv_session_memory_detail a , pg_stat_activity b where split_part(a.sessid,'.',2) = b.pid group by b.state order by totalsize desc limit 100;

如果是上圖的idle狀態的totalsize佔用很多內存,可以嘗試清理idle狀態的空閒連接釋放內存

解決措施:清理idle狀態的空閒連接

CLEAN CONNECTION TO ALL FORCE FOR DATABASE xxxx;

clean connection 只能清理pg_pooler_status中 in_used是f狀態的空閒連接,不能清理in_used狀態為t的連接,in_used為t 一般是執行了pbe語句導致cn和dn的空閒連接不能釋放導致

如果上邊方法清理不掉,只能嘗試清理cn和客户端的連接,之後在執行clean connection清理cn和dn之間的連接,可以嘗試在cn上找到是idle狀態的空閒連接,此操作會斷掉cn和客户端的連接,需要和客户確認是否可以執行

select 'execute direct on ('||coorname||') ''select pg_terminate_backend('||pid||')'';' from pgxc_stat_activity where usename not in ('Ruby', 'omm') and state='idle';

將select的結果依次執行。

2.語句佔用內存過多,如果第一個步驟中的第一個語句查詢的是active狀態的語句內存佔用多,説明是正在執行語句佔用的內存多導致的

查詢下邊的語句找到內存佔用多的語句

select b.state as state, a.sessid as sessid, b.query_id as query_id, substr(b.query,1,100) as query, sum(totalsize) as totalsize, sum(freesize) as freesize, sum(usedsize) as usedsize from pv_session_memory_detail a , pg_stat_activity b where split_part(a.sessid,'.',2) = b.pid and usename not in ('Ruby', 'omm') group by state,sessid,query_id,query order by totalsize desc limit 100;

找到語句後,根據query_id去對應的cn上進行查殺這個異常sql

3.dynamic_used_shrctx內存使用較多

dynamic_used_shrctx是共享內存上下文使用的內存,也是通過MemoryContext分的,在線程之間共享。通過pg_shared_memory_detail視圖查看

select * from pg_shared_memory_detail order by totalsize desc limit 10;

一般共享內存上下文分配和語句有關的, contextname都會帶有線程號或者query_id,根據query_id或者線程號進行查殺異常sql,除此之外共享內存上下文一般是內核中各個模塊使用的內存,比如topsql,需要排查內存使用是否合理,以及釋放機制。

4. 內存視圖pv_total_memory_detail 中,dynamic_used_memory > max_dynamic_memory的情況

1)GUC參數disable_memory_protect為on的時候

2)分配內存的時候,debug_query_id為0

3)內核在執行關鍵代碼段的時候

4)內核Postmaster線程內的內存分配

5)在事務回滾階段

以上情況都是內核保證操作不能中斷採取的特殊處理,理論上用户執行的sql使用的內存(dynamic_used_memory) 是不會大範圍的超過max_dynamic_memory的內存的

 

點擊關注,第一時間瞭解華為雲新鮮技術~