星期六晚上沒有想看的球賽,來筆記幾個月前碰到的問題: Intra-Query Parallel Thread Deadlocks,內部平行查詢死結。
為了追蹤不明死結(Deadlock)的原因,我們使用擴充事件(Extended events)記錄了系統內的死結資訊,於是就在幾個月前,我們收到了死結檔案,解析花了一點時間,好在RiCO大的分享讓我們很快確認問題原因以及排解方法。
死結檔案內容
死結資訊的檔案是一份使用xml格式的xdl檔案,我們先不看Deadlock Graph,這次用肉眼來解析內容,並且將process id中的值很快取代成T1,T2,T3..的假想嫌疑犯代號。
檔案內容主要分成被害人區、關係人區、證物區:
- 第一區victim-list: 被害人,會顯示被犧牲的process id,此次被犧牲的是ProcessT1
- 第二區process-list: 關係人資訊,總共有T1,T2,T3
- 第三區resource-list:現場採證,彼此間的關係,單就鎖定資源來看,資源有一個Data Page,兩個exchangeEvent,type分別為e_waitPortOpen及e_waitPipeGetRow3個證物。
Process間的關係
凡事講求證據,我們先從resource-list區間觀察現場採集出來的3項證物:
1.解析第一個資源(證物): exchangeEvent + e_waitPortOpen
<exchangeEvent id="Port8032cc00" WaitType="e_waitPortOpen" nodeId="3">
<owner-list>
<owner id="processT2" />
</owner-list>
<waiter-list>
<waiter id="processT1" />
</waiter-list>
</exchangeEvent>
在平行處理時,Thread-Pool會有許多等待工作,其中Parallel query resource owner下的說明就是exchangeEvent,等待的狀態種類包含
e_waitNone、e_waitPipeNewRow、e_waitPipeGetRow、e_waitSynchronizeConsumerOpen、e_waitPortOpen、e_waitPortClose、e_waitRange
好,第一個資源在處理序間的關係是:
T2擁有了這一個平行查詢資源,然後T1也想使用,所以等待中。
T1 >> T2
2.解析第二個資源(證物): exchangeEvent + e_ waitPipeGetRow
<exchangeEvent id="Pipe1409dc1200" WaitType="e_waitPipeGetRow" nodeId="66">
<owner-list>
<owner id="processT3" />
</owner-list>
<waiter-list>
<waiter id="processT2" />
</waiter-list>
</exchangeEvent>
T3擁有了這一個平行查詢資源,然後T2也想使用,所以等待中。
T2 >> T3
3.最後是我們比較熟悉的 Data Page Lock
<pagelock fileid="1" pageid="7454418" dbid="9" …
<owner-list>
<owner id="processT1" mode="U" />
</owner-list>
<waiter-list>
<waiter id="processT3" mode="U" requestType="wait" />
</waiter-list>
</pagelock>
T1擁有了這個Page的更新鎖定(U),然後T3也想上更新鎖定,所以等待中。
T3 >> T1
最終 T1 >> T2 >> T3 >> T1 ,踢皮球任務達成!! SQL Server最終也選擇T1作為犧牲(被害人)。
Process辨識
下一步我們從< process-list>認識T1,T2,T3 這些關係人,為了方便呈現,我們簡化了以下的內容,只留下關鍵的訊息。
<process-list>
<process id="processT1" waittime="15629" status="suspended" spid="67" sbid="0"… >
<frame line="125" sqlhandle="0x030009004f4cee672cfa160122a700000100000000000000">
</process>
<process id="processT2" waittime="2079" status="suspended" spid="67" sbid="0" …>
<frame line="125" sqlhandle="0x030009004f4cee672cfa160122a700000100000000000000">
</process>
<process id="processT3" waittime="6974" spid="67" sbid="0".. >
<frame line="125" sqlhandle="0x030009004f4cee672cfa160122a700000100000000000000">
</process>
</process-list>
- 首先注意到了T1,T2,T3 三個process的Server process Id(spid)都是67,更奇妙的是Server batch Id(sbid)還都是0!
- 從執行的堆疊中發現行號都是125,sqlhandle也都相同,這表示還執行相同的預存程序或t-sql語法,還卡在同一行T-SQL程式。
- 同一個session、同一段語法、再加上Exchange Event的資源特徵,看來我們是碰上了平行死結了!
分裂了你們
*可以透過dmv sys.dm_exec_sql_text取得sqlhandle內的t-sql語法或是預存程序名稱。
SELECT * FROM sys.dm_exec_sql_text(0x0….
解決Intra-Query Parallel Thread Deadlocks
由於死結發生在同一個Session執行同一支預存程序在平行作業時碰到的死結,唯一資料表鎖定的層級也是Page,本來也寫上Handle 1205 Re-Try機制了,但因為發現發生死結當下,系統整體反應時間較長,為了避免系統在當下使用過多資源來處理,看來只能用限制核心數來避免Deadlock(maxdop 1)。
Deadlock Graph
補充
系統內偵測到的死結內執行堆疊(executionstack),也可以在死結檔案中找到。
程式行203行是預存程序中遇到Deadlock的retry段落,代表當時第一次發生deadlock後,又重複發生了2次,程式行125則是出現平行死結的那一段update。
小結:
- 已開CASE報案,但目前曾發生的兩個版本(SQL Server 2008 R2/2014)似乎沒有patch可以修理SQL Server。
- 感謝RiCO大的筆記。
明明排好好的..
2017.07.22 富錦街台菜香檳
參考:
Analyze Deadlocks with SQL Server Profiler
sys.dm_os_waiting_tasks (Transact-SQL)
sys.dm_exec_sql_text (Transact-SQL)