欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页  >  IT编程

基于innodb_print_all_deadlocks从errorlog中解析MySQL死锁日志

程序员文章站 2023-09-28 08:43:47
本文是说明如何获取死锁日志记录的,不是说明如何解决死锁问题的。 MySQL的死锁可以通过show engine innodb status;来查看,但是show engine innodb status;只能显示最新的一条死锁,该方式无法完全捕获到系统发生的死锁信息。如果想要记录所有的死锁日志,打开 ......

 

本文是说明如何获取死锁日志记录的,不是说明如何解决死锁问题的。


MySQL的死锁可以通过show engine innodb status;来查看,
但是show engine innodb status;只能显示最新的一条死锁,该方式无法完全捕获到系统发生的死锁信息。
如果想要记录所有的死锁日志,打开innodb_print_all_deadlocks参数可以将所有的死锁日志记录到errorlog中,
因此问题就变成了如何从errorlog解析死锁日志。

参考如下截图,是errorlog中的一个典型的死锁日志信息,除了死锁日志,可以制造了一些其他的干扰日志(故意不输入密码登陆数据库让它记录一些其他错误日志信息)
如果要解析这个死锁日志(排除其他无关日志),也即解析产生死锁内容,拆分死锁日志内容中的两个(或者)多个事务
1,死锁开始和结束的标记====>截取单个死锁日志内容
2,解析第1步中的死锁日志===>截取各个事务日志

基于innodb_print_all_deadlocks从errorlog中解析MySQL死锁日志

以下解析基于如下规则,基本上都是根据本关键字和正则做匹配
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的对应一组死锁事务

基于innodb_print_all_deadlocks从errorlog中解析MySQL死锁日志

 基于innodb_print_all_deadlocks从errorlog中解析MySQL死锁日志

 

纯属快速尝试自己的一些个想法,还有很多不足
1,解析后的日志格式很粗
2,解析的都是常规的死锁,不确定能hold所有的死锁日志格式,根据关键字解析的,不知道是不是总是有效
3,如何避免重复解析,也即定时解析MySQL的error的时候,没判断前一次解析过的内容的判断
4,没有做效率测试