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

標籤：查看   begin   .exe   密碼   pwd   mat   utf8   att   span   

 

本文是說明如何擷取死結日誌記錄的，不是說明如何解決死結問題的。

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 osimport timeimport datetimeimport refrom IO.mysql_operation import mysql_operationclass 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 = 0if __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死結日誌