masalibの日記

システム開発、運用と猫の写真ブログです

mysqスロークエリの解析について

設定について

スロークエリとは実行時間が長いSQLクエリを記録する機能であり、パフォーマンスの分析やチューニングに役立ちます。

  1. MySQLサーバーの設定ファイルを編集する:

    • MySQLの設定ファイル(my.cnfやmy.ini)の場所は、インストールされた環境によって異なります。Linuxでは通常/etc/my.cnfや/etc/mysql/my.cnfに、WindowsではC:\ProgramData\MySQL\MySQL Server x.x\内にあります。
    • 設定ファイルをテキストエディタで開き、以下の設定を追加または変更します(x.xはバージョン番号)。
  2. スロークエリログを有効にする設定:

    • スロークエリログを有効にするには、slow_query_logを1に設定します。

    [mysqld] slow_query_log = 1 slow_query_log_file = /path/to/your/log-file long_query_time = 2 log_queries_not_using_indexes = 1

    • slow_query_log_fileは、スロークエリログのファイルパスです。
    • long_query_timeは、この秒数以上かかるクエリをスロークエリとして記録します。上記の例では2秒に設定されています。
    • log_queries_not_using_indexesは、インデックスを使用していないクエリもログに記録するかどうかを設定します。必要に応じて1に設定してください。
  3. MySQLサーバーを再起動する:

    • 設定を適用するためには、MySQLサーバーを再起動する必要があります。Linuxでは通常、sudo systemctl restart mysqlやsudo service mysql restartで再起動できます。Windowsでは、サービス管理ツールを使用して「MySQL」サービスを再起動します。
  4. スロークエリログの確認:

    • スロークエリログが有効になっていると、指定したファイルに長いクエリが記録されます。ログファイルを定期的にチェックして、パフォーマンスに影響を与えている可能性のあるクエリを特定しましょう。

これらの設定を行うことで、MySQLのパフォーマンス分析と最適化に役立つ情報を得ることができます。 ただし、スロークエリログはディスクスペースを消費するため、 本番環境での使用には注意が必要です。適切なログローテーションの設定もする必要があります

解析について

mysqlslowdumpは、スロークエリログを解析してサマリーとして出力するコマンドラインツールというのがあるのですがこれは使いません。 古い人間が多いのでエクセルで管理したいです。

簡単な流れは
・スロークエリログを解析ツールでJSONにする
JSONをエクセルで読み込む

ツールの前提としてはpythonは3系です。Windows環境でも動かすためにutf8を指定しています。

スロークエリログを解析ツールの概要

  1. 指定されたディレクトリ内のすべてのファイルからスロークエリログを解析し、それらのクエリを集計して結果を出力します。

  2. まず、parse_slow_query_log関数は指定されたディレクトリ内のすべてのファイルを開き、各行を解析します。各行が特定の文字列で始まる場合、その行の情報は現在のクエリの辞書に追加されます。すべてのクエリが解析されると、この関数はスロークエリのリストを返します。

  3. 次に、save_queries_to_file関数は、解析されたスロークエリをJSON形式でファイルに保存します。

  4. summarize_queries関数は、解析されたスロークエリのリストを取り、各クエリタイプ(SELECT、INSERT、UPDATE、DELETE、またはその他)の統計情報を集計します。これには、クエリの数、合計および最大クエリ時間、合計および最大ロック時間、合計行の調査数が含まれます。集計が完了すると、この関数はクエリタイプごとの統計情報の辞書を返します。

  5. 最後に、このコードは指定されたディレクトリからスロークエリを解析し、結果をファイルに保存し、クエリの統計情報を出力します。

スロークエリログを解析ツールのソース

import os
import re
import json
from collections import defaultdict

def parse_slow_query_log(directory):
    """
    Parses the slow query log files in the specified directory and returns a list of dictionaries,
    where each dictionary represents a slow query entry with its corresponding information.

    Args:
        directory (str): The directory path where the slow query log files are located.

    Returns:
        list: A list of dictionaries, where each dictionary represents a slow query entry.
              Each dictionary contains the following keys:
              - 'Time': The timestamp of the slow query.
              - 'SET timestamp': The timestamp when the query was executed.
              - 'use': The database schema used for the query.
              - 'User@Host': The user and host information.
              - 'Schema': The database schema associated with the query.
              - 'Query_time': The execution time of the query.
              - 'Lock_time': The time spent waiting for locks.
              - 'Rows_sent': The number of rows sent.
              - 'Rows_examined': The number of rows examined.
              - 'Rows_affected': The number of rows affected.
              - 'Bytes_sent': The number of bytes sent.
              - 'Query': The SQL query itself.
    """
    slow_queries = []
    file_paths = [os.path.join(directory, file) for file in os.listdir(directory)]
    
    for file_path in file_paths:
        with open(file_path, 'r', encoding="utf-8") as file:
            lines = file.readlines()
        
        current_query = {}
        capture_query = False  
        for line in lines:
            if line.startswith('# Time:'):
                if current_query:
                    slow_queries.append(current_query)
                    current_query = {}
                capture_query = True
                current_query['Time'] = line.split('# Time:')[1].strip()
            elif line.startswith('SET timestamp='):
                current_query['SET timestamp'] = line.strip()
            elif line.startswith('use '):
                current_query['use'] = line.strip()
            elif line.startswith('# User@Host:'):
                current_query['User@Host'] = line.split('# User@Host:')[1].strip()
            elif line.startswith('# Schema:'):
                current_query['Schema'] = line.split('# Schema:')[1].split()[0].strip()
            elif line.startswith('# Query_time:'):
                current_query['Query_time'] = line.split('Query_time:')[1].split()[0].strip()
                current_query['Lock_time'] = line.split('Lock_time:')[1].split()[0].strip()
                current_query['Rows_sent'] = line.split('Rows_sent:')[1].split()[0].strip()
                current_query['Rows_examined'] = line.split('Rows_examined:')[1].split()[0].strip()
                current_query['Rows_affected'] = line.split('Rows_affected:')[1].split()[0].strip()
            elif line.startswith('# Bytes_sent:'):
                current_query['Bytes_sent'] = line.split('Bytes_sent:')[1].split()[0].strip()
            elif not line.startswith('#') and line.strip() and capture_query:
                if 'Query' not in current_query:
                    current_query['Query'] = line.strip()
                else:
                    current_query['Query'] += ' ' + line.strip()
        
        # last query
        if current_query:
            slow_queries.append(current_query)
    
    return slow_queries
    
def save_queries_to_file(slow_queries, output_file):
    with open(output_file, 'w',encoding="utf-8") as file:
        json.dump(slow_queries, file, indent=4)

def summarize_queries(slow_queries):
    print("summarize start")

    query_summary = defaultdict(lambda: {'count': 0, 'total_query_time': 0, 'max_query_time': 0,
                                         'total_lock_time': 0, 'max_lock_time': 0, 'total_rows_examined': 0})
    for query_info in slow_queries:
        # SET timestamp=sanitize
        #if 'SET timestamp=' in query_info['Query']:
        #    continue

        # querytype(SELECT, INSERT, UPDATE, DELETE)
        match = re.search(r'^(SELECT|INSERT|UPDATE|DELETE)', query_info['Query'], re.IGNORECASE)
        if match:
            query_type = match.group(1).upper()
        else:
            query_type = 'OTHER'
        
        summary = query_summary[query_type]
        summary['count'] += 1
        query_time = float(query_info['Query_time'])
        lock_time = float(query_info['Lock_time'])
        rows_examined = int(query_info['Rows_examined'])

        summary['total_query_time'] += query_time
        summary['max_query_time'] = max(summary['max_query_time'], query_time)

        summary['total_lock_time'] += lock_time
        summary['max_lock_time'] = max(summary['max_lock_time'], lock_time)

        summary['total_rows_examined'] += rows_examined
    
    # summary result
    for query_type, stats in query_summary.items():
        if stats['count'] > 0:
            stats['average_query_time'] = stats['total_query_time'] / stats['count']
            stats['average_lock_time'] = stats['total_lock_time'] / stats['count']
        else:
            stats['average_query_time'] = 0
            stats['average_lock_time'] = 0

    return dict(query_summary)

# sample
directory = './slowQuerylogs/'
output_file = './output_file.json'
slow_queries = parse_slow_query_log(directory)

# output sample
save_queries_to_file(slow_queries, output_file)

print("Done. Parsed slow queries are saved ")

# summary do
summary = summarize_queries(slow_queries)

# output summary
for query_type, stats in summary.items():
    print(f"{query_type}:")
    print(f"  Count: {stats['count']}")
    print(f"  Average Query Time: {stats['average_query_time']:.2f}s")
    print(f"  Max Query Time: {stats['max_query_time']:.2f}s")
    print(f"  Average Lock Time: {stats['average_lock_time']:.2f}s")
    print(f"  Max Lock Time: {stats['max_lock_time']:.2f}s")
    print(f"  Total Rows Examined: {stats['total_rows_examined']}")
    print()

出力されたJSONをエクセルで読み込む

手順は以下のページが参考になります

https://qiita.com/afukuma/items/65c6e96bd15b319e160f

結果のイメージは以下になります

これならエクセルおじさん(自分)でも解析ができます