客戶報告在做 job 匯入的時候偶爾會碰到 ORA-00060 錯誤，客戶端日志如下：
| 2020-11-23 12:22:15 (GMT+0100) [ERROR] : java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource |
因為碰不到客戶的生產環境，所以要了一下他們的服務端日志，一般來講，ORA-00060 總是結對出現，然后我們根據這個錯誤拋出的程式呼叫堆疊，可以分別找到對應的兩個執行緒，根據背景關系及各自的 sql 陳述句不難得出資料庫死鎖的原因所在，
但本文案例有些特殊，屬于二般情況，拿到服務端日志以后直奔 ORA-00060 的拋錯呼叫堆疊而去，卻發現只有一種執行緒堆疊，對應的 sql 陳述句也只有一種：
update jobother set jobother.allocatestatus='C' where job_unid in (142000000000397637,140000000000397301,140000000000397302,140000000000397303,140000000000397304,140000000000397543,140000000000397548,140000000000397638,140000000000397639,140000000000397640,140000000000397641,140000000000397642,140000000000397643)
走到這里，先頭腦風暴一下，
- 上述 sql 在同一時間段內有五處日志列印，難道是重復執行？
- 對端死鎖 sql 是什么，服務端日志里沒有發現 00060 下的其他 sql，難道上述 sql 的 session 拋 00060 后對端執行緒就能得以成功執行？
- 抑或是上述 sql 由五個執行緒同時執行，它們同時執行了同樣的邏輯，但為何會有五個相同的業務邏輯在同時執行，是客戶端重復請求還是介面沒有做好冪等性設計？
帶著這些疑問去問客戶要了 trc 檔案，直奔 Deadlock graph：
可見這是一個 Transaction Deadlock 型死鎖，查找 session 425 的當前 sql：
update jobother set jobother.allocatestatus=:1 where job_unid in (142000000000405269,140000000000405066,140000000000405237,140000000000405264,140000000000405272,140000000000405275,140000000000405277,140000000000405279,140000000000405281,140000000000405283,140000000000405285,140000000000405287,140000000000405289,140000000000405291)
然后再找到 session 627 的當前執行 sql：
update jobother set jobother.allocatestatus=:1 where job_unid in (142000000000405269,140000000000405066,140000000000405237,140000000000405264,140000000000405272,140000000000405275,140000000000405277,140000000000405279,140000000000405281,140000000000405283,140000000000405285,140000000000405287,140000000000405289,140000000000405291)
對比之下，它們其實是一樣的，頭腦風暴 3 命中，這個線索很關鍵，這個分布式環境中 db 這一塊的情況已經清晰明了，目前要做的事情則是找到介面介入的源頭情況，帶著它回過頭去繼續去分析服務端日志，兩路并進，按圖索驥：
- 找到 00060 拋出的執行緒堆疊，找到該處代碼往前捋；
- 在服務端日志 00060 處拋出，結合相關代碼往前捋，
兩路互相結合參考分析，接著就發現確實有 5 個執行緒在執行同樣的邏輯，重復請求？抑或是多執行緒誤啟了 5 個執行緒執行同樣邏輯？帶著這些疑問繼續往前捋，最終發現是確實有 5 個檔案需要匯入，五個不同的任務執行緒分別同時執行匯入，在執行到上述 sql 時造成死鎖：
| cargoMateFinishedQueue/ID:Defonds-Prod-App.hhh-37181-1606128682104-1:1:2189:1:1 cargoMateFinishedQueue/ID:Defonds-Prod-App.hhh-37181-1606128682104-1:1:2197:1:1 cargoMateFinishedQueue/ID:Defonds-Prod-App.hhh-37181-1606128682104-1:1:2200:1:1 cargoMateFinishedQueue/ID:Defonds-Prod-App.hhh-37181-1606128682104-1:1:2207:1:1 cargoMateFinishedQueue/ID:Defonds-Prod-App.hhh-37181-1606128682104-1:1:2213:1:1 |
經分析，這 5 個檔案是同樣的內容，導致問題的根本完全是上游服務器誤生成了同樣不同名的五個匯入檔案，并非是下游 job 匯入服務器的介面冪等性問題，
轉載請註明出處，本文鏈接：https://www.uj5u.com/qita/257393.html
標籤：AI