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

時間 2019-12-07

標籤基於 innodb print deadlocks errorlog 解析 mysql 死鎖日誌欄目 MySQL 简体版

原文原文鏈接

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

MySQL的死鎖能夠經過show engine innodb status;來查看，
可是show engine innodb status;只能顯示最新的一條死鎖，該方式沒法徹底捕獲到系統發生的死鎖信息。
若是想要記錄全部的死鎖日誌，打開innodb_print_all_deadlocks參數能夠將全部的死鎖日誌記錄到errorlog中，
所以問題就變成了如何從errorlog解析死鎖日誌。sql

參考以下截圖，是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_content = str_content.replace("'","''")

　　　　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)