1. 程式人生 > >基於innodb_print_all_deadlocks從errorlog中解析MySQL死鎖日誌

基於innodb_print_all_deadlocks從errorlog中解析MySQL死鎖日誌

search 屬於 賦值 lock png rim img 顯示 dea

本文是說明如何獲取死鎖日誌記錄的,不是說明如何解決死鎖問題的。


MySQL的死鎖可以通過show engine innodb status;來查看,
但是show engine innodb status;只能顯示最新的一條死鎖,該方式無法完全捕獲到系統發生的死鎖信息。
如果想要記錄所有的死鎖日誌,打開innodb_print_all_deadlocks參數可以將所有的死鎖日誌記錄到errorlog中,
因此問題就變成了如何從errorlog解析死鎖日誌。

參考如下截圖,是errorlog中的一個典型的死鎖日誌信息,除了死鎖日誌,可以制造了一些其他的幹擾日誌(故意不輸入密碼登陸數據庫讓它記錄一些其他錯誤日誌信息)

如果要解析這個死鎖日誌(排除其他無關日誌),也即解析產生死鎖內容,拆分死鎖日誌內容中的兩個(或者)多個事務
1,死鎖開始和結束的標記====>截取單個死鎖日誌內容
2,解析第1步中的死鎖日誌===>截取各個事務日誌

技術分享圖片

以下解析基於一下規則,基本上都是根據本關鍵字和正則做匹配
1,死鎖日誌開始的標記: Transactions deadlock detected, dumping detailed information.
2,死鎖日中中事務開始的標記:*** (N) TRANSACTION:
3,死鎖結束的標記:WE ROLL BACK TRANSACTION (N)

import
os import time import datetime import re from IO.mysql_operation import mysql_operation class mysql_deadlock_analysis: def __init__(self): pass def is_valid_date(self,strdate): try: if ":" in strdate: time.strptime(strdate, "%Y-%m-%d %H:%M:%S
") else: time.strptime(strdate, "%Y-%m-%d") return True except: return False def insert_deadlock_content(self,str_id, str_content): connstr = {host: ‘***,***,***,***, port: 3306, user: ‘username, password: pwd, db: db01, charset: utf8mb4} mysqlconn = mysql_operation(host=connstr[host], port=connstr[port], user=connstr[user], password=connstr[password], db=connstr[db], charset=connstr[charset]) ‘‘‘ 死鎖日誌表結構,一個完整的死鎖日誌按照死鎖中第一個事務開始時間為主,deadlock_id一樣的話,說明是歸屬於一個死鎖 create table deadlock_log ( id int auto_increment primary key, deadlock_id varchar(50), deadlock_transaction_content text, create_date datetime ) ‘‘‘ str_sql = "insert into deadlock_log(deadlock_id,deadlock_transaction_content,create_date) " "values (‘%s‘,‘%s‘,now())" % (str_id, str_content) try: mysqlconn.execute_noquery(str_sql, None) except Exception as err: raise (Exception, "database operation error") #解析死鎖日誌內容 def read_mysqlerrorlog(self,file_name): try: deadlock_flag = 0 deadlock_set = set() deadlock_content = "" with open(file_name,"r") as f: for line in f: if(deadlock_flag == 0): str_datetime = line[0:19].replace("T"," ") if(self.is_valid_date(str_datetime)): if(line.find("deadlock")>0):#包含deadlock字符串,表示死鎖日誌開始 #輸出死鎖日誌,標記死鎖日誌開始 deadlock_content = deadlock_content+line deadlock_flag = 1 elif(deadlock_flag == 1): #輸出死鎖日誌 deadlock_content = deadlock_content + line #死鎖日誌結束 if (line.find("ROLL BACK")>0):#包含roll back 字符串,表示死鎖日誌結束 deadlock_flag = 0 #一個完整死鎖日誌的解析結束 deadlock_set.add(deadlock_content) deadlock_content = "" except IOError as err: raise (IOError, "read file error") return deadlock_set #解析死鎖日誌中的各個事務信息 def analysis_mysqlerrorlog(self,deadlock_set): #單個事務開始標記 transaction_begin_flag = 0 #死鎖中的單個事務信息 transaction_content = "" # 死鎖發生時間 str_datetime = "" #匹配事務開始標記正則 pattern = re.compile(r[*]* [(0-9)]* TRANSACTION:) for str_content in deadlock_set: arr_content = str_content.split("\n") for line in arr_content: if (self.is_valid_date(line[0:19].replace("T", " "))): #死鎖發生時間,在解析死鎖日誌內容的時候,每組死鎖日誌只賦值一次,一個死鎖中的所有事物都用第一次的時間 str_datetime = line[0:19].replace("T", " ") #死鎖日誌中的事務開始標記 if( pattern.search(line)): transaction_begin_flag = 1 #事務開始,將上一個事務內容寫入數據庫 if(transaction_content): self.insert_deadlock_content(str_datetime,transaction_content) #死鎖日誌中新開始一個事務,重置transaction_content以及事務開始標記 transaction_content = "" transaction_begin_flag = 0 else: #某一個事務產生死鎖的具體日誌 if(transaction_begin_flag==1): transaction_content = transaction_content +"\n"+ line #死鎖日誌中的最後一個事務信息 if (transaction_content): self.insert_deadlock_content(str_datetime, transaction_content) transaction_content = "" transaction_begin_flag = 0 if __name__ == __main__: file_path = "\path\mysql.err" analysis = mysql_deadlock_analysis() str_content = analysis.read_mysqlerrorlog(file_path) analysis.analysis_mysqlerrorlog(str_content)

以下是寫入到數據庫之後的效果id為1,2的對應一組死鎖的事務信息,id為3,4的對應一組死鎖事務

技術分享圖片

技術分享圖片

純屬快速嘗試自己的一些個想法,還有很多不足
1,解析後的日誌格式很粗
2,解析的都是常規的死鎖,不確定能hold所有的死鎖日誌格式,根據關鍵字解析的,不知道是不是總是有效
3,如何避免重復解析,也即定時解析MySQL的error的時候,沒判斷前一次解析過的內容的判斷
4,沒有做效率測試

基於innodb_print_all_deadlocks從errorlog中解析MySQL死鎖日誌