OceanBase:行鎖分析方法

說明

當(dāng)發(fā)生行鎖阻塞,我們可能要做兩件事情:

  • 應(yīng)急解開鎖阻塞
  • 如果鎖阻塞頻繁發(fā)生,導(dǎo)致業(yè)務(wù)響應(yīng)時間變長,需要幫助業(yè)務(wù)找到相關(guān)邏輯,優(yōu)化業(yè)務(wù),減少鎖阻塞的發(fā)生

本文檔主要介紹V3版本中找出阻塞源、分析業(yè)務(wù) SQL 的方法。

1. 制造鎖阻塞場景

--session1
--為方便觀察,把超時參數(shù)調(diào)大
set global ob_query_timeout = 3600000000;
set global ob_trx_timeout = 3600000000;
set global ob_trx_idle_timeout = 3600000000;
ob_trx_lock_timeout 默認(rèn)為-1,鎖等待沒有超時時間

--準(zhǔn)備數(shù)據(jù)
create table t1 (id number,name varchar2(12),primary key(id));
insert into t1 values(1,'A1');
insert into t1 values(2,'B1');
commit;
select * from t1;

--開啟事務(wù)加鎖
start transaction;
select * from t1 where id = 1 for update;

--session2
--開啟事務(wù)加鎖
start transaction;
select * from t1 where id = 2 for update;
select * from t1 where id = 1 for update;

--session1 制造死鎖場景(默認(rèn)不開啟死鎖檢測)
select * from t1 where id = 2 for update;

2. 通過視圖分析鎖阻塞

如果有現(xiàn)場,我們可以通過系統(tǒng)視圖分析鎖阻塞。

2.1 查找鎖的阻塞關(guān)系

先給出一個直接查出鎖阻塞關(guān)系的方法,然后再介紹 __all_virtual_lock_wait_stat、__all_virtual_trans_lock_stat 兩個視圖的限制。

SELECT 
wait.TENANT_ID,
wait.SVR_IP,
wait.table_name,
wait.table_id_extract waiting_table_id,
wait.need_wait,
wait.SESSION_ID waiting_session_id,                     -- 被阻塞事務(wù)的session_id(后端連接ID)
tx.trans_id waiting_trans_id,                           -- 被阻塞事務(wù)的ID
tx.ctx_create_time waiting_trx_started,                 -- 被阻塞事務(wù)的開啟時間
wait.waiting_rowkey,                                    -- 正在嘗試加鎖的行的主鍵值
usec_to_time(wait.RECV_TS) waiting_query_started,       -- 被阻塞的SQL開始執(zhí)行的時間
usec_to_time(wait.LOCK_TS) waiting_last_lock_started,   -- 被阻塞的SQL上一次嘗試加鎖的時間(10秒重試一次)
wait.TRY_LOCK_TIMES waiting_lock_retry_cnt,             -- 加鎖重試次數(shù)
wait.TIME_AFTER_RECV/1000 waiting_query_age_ms,         -- 被阻塞的SQL等待鎖的時長,單位毫秒
trans.trans_id blocking_trans_id,                       -- 持有鎖的事務(wù)ID
trans.session_id blocking_session_id,                   -- 持有鎖的session_id,即阻塞源
trans.rowkey blocking_rowkey,                           -- 持有鎖的行的主鍵值(防止異常join結(jié)果有誤,可人工比對)
trans.ctx_create_time blocking_trx_started              -- 持有鎖的事務(wù)開啟時間
FROM __all_virtual_trans_lock_stat trans
JOIN (
    SELECT 
        *,
        SUBSTRING_INDEX(SUBSTRING_INDEX(rowkey, 'table_id=', -1), ' ', 1) AS table_id_extract,
        CONCAT(
            'rowkey_object=[{"%',
            '":"',
            SUBSTRING_INDEX(SUBSTRING_INDEX(rowkey, '":"', -1), '"}]', 1),
            '"}]'
        ) AS waiting_rowkey
FROM gv$lock_wait_stat
) wait
ON trans.table_id = wait.table_id_extract 
AND trans.rowkey LIKE CONCAT('%', wait.waiting_rowkey, '%')
join __all_virtual_trans_stat tx 
on wait.SESSION_ID=tx.session_id\G

輸出結(jié)果:
2.2 __all_virtual_lock_wait_stat 查看鎖等待情況

只有當(dāng)發(fā)生行鎖阻塞 __all_virtual_lock_wait_stat 才會有信息:

  • 每行信息表示被阻塞的連接當(dāng)前正在嘗試對哪一行加鎖,以及它的后端連接 ID
  • 無法直觀看出是被哪個連接阻塞

以如下示例來看:

  • session_id: 3222011615 正在獲取 table_id=1100611139453783,rowkey=1 的鎖,被阻塞了,阻塞源未知
  • session_id: 3221980123 正在獲取table_id=1100611139453783,rowkey=2 的鎖,被阻塞了,阻塞源未知
2.3 __all_virtual_trans_lock_stat 查看持有鎖的源頭

上一步通過 __all_virtual_lock_wait_stat 查看被阻塞的事務(wù)正在獲取 rowkey=1 這一行的鎖,因此接下來通過 __all_virtual_trans_lock_stat 查看持有 rowkey=1 這一行鎖的是哪個事務(wù)、哪個連接:

  • session_id: 3221980123 持有了 rowkey=1 這一行鎖,根據(jù)上一步得到的信息,可推測它阻塞了 session_id: 3222011615
  • session_id: 3222011615 持有 rowkey=2 這一行鎖,根據(jù)上一步得到的信息,可推測它阻塞了 session_id: 3221980123
2.4 kill 鎖源頭

此處其實(shí)是死鎖場景,如果要應(yīng)急解開鎖阻塞,需要 kill 阻塞源,也就是持有鎖的 session。這里我們選擇把 session2 執(zhí)行的 query 殺掉:

--連2883端口登錄業(yè)務(wù)租戶
kill query 3222011615;
2.5 分析業(yè)務(wù)鎖阻塞的原因

通過 gv$sql_audit 可以看到鎖阻塞的SQL執(zhí)行情況:

  • 被鎖阻塞的SQL執(zhí)行時 retry_cnt 很大
  • 被鎖阻塞的SQL執(zhí)行時,elapsed_time 很大,但是 execute_time 很小

要分析業(yè)務(wù)為什么會有鎖阻塞,需要根據(jù)事務(wù)ID查詢 gv$sql_audit 記錄的每個事務(wù)的所有SQL:

select usec_to_time(request_time), svr_ip, sid, transaction_hash,
user_name, query_sql, ret_code, plan_type, elapsed_time,execute_time, retry_cnt from 
gv$sql_audit where transaction_hash=14355367465281276788 order by 
request_time;

select usec_to_time(request_time), svr_ip, sid, transaction_hash,
user_name, query_sql, ret_code, plan_type, elapsed_time ,execute_time, retry_cnt from 
gv$sql_audit where transaction_hash=12615662878457240999 order by 
request_time;

結(jié)果如下:

  • 第一個事務(wù)被 kill 回滾了,因此我們只看到一個 SQL
  • 第二個事務(wù)與第一個事務(wù)都對 id=2 這一行數(shù)據(jù)加鎖,所以發(fā)生阻塞,把這個信息給到業(yè)務(wù)開發(fā),優(yōu)化業(yè)務(wù)邏輯

3. 通過日志分析鎖阻塞

當(dāng)沒有抓到鎖阻塞的現(xiàn)場,但是又想分析業(yè)務(wù)為什么發(fā)生鎖等待,可以從 observer.log 來找到鎖阻塞的信息。搜索關(guān)鍵字:on_wlock_retry

日志中可能會有很多相關(guān)日志,每一次重試加鎖都會打印一行日志??梢愿鶕?jù)日志中的事務(wù) ID 去gv$sql_audit 中查看事務(wù)內(nèi)容,和業(yè)務(wù)一起分析原因。

最后編輯于
?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
【社區(qū)內(nèi)容提示】社區(qū)部分內(nèi)容疑似由AI輔助生成,瀏覽時請結(jié)合常識與多方信息審慎甄別。
平臺聲明:文章內(nèi)容(如有圖片或視頻亦包括在內(nèi))由作者上傳并發(fā)布,文章內(nèi)容僅代表作者本人觀點(diǎn),簡書系信息發(fā)布平臺,僅提供信息存儲服務(wù)。

相關(guān)閱讀更多精彩內(nèi)容

友情鏈接更多精彩內(nèi)容