MariaDB / スロークエリログの設定方法と読み方

MariaDB

MariaDBのスロークエリログは、実行時間の基準を超えたSQLや、別途有効にした条件に合うSQLを記録する機能です。ファイルで読むにはslow_query_logを有効にし、log_outputにFILEを含め、実行する接続の時間基準とフィルターも確認します。稼働中の値はSQLで変更できますが、再起動後も維持するにはオプションファイルへの保存が必要です。

何が記録され、何を準備する必要がありますか？

このログはサーバー側のSQL実行時間や調査行数を分析する資料です。有効化するだけでSQLが速くなるわけではなく、実行計画やインデックスを検討するために使います。Webページの応答時間には通信やアプリの処理も含まれるため、SQLの時間とは一致しません。

通常の時間基準は秒単位のlong_query_timeです。1は1秒を意味します。インデックス未使用条件を有効にすると速いSQLも含まれる一方、行数の下限、フィルター、サンプリングによって基準超過のSQLが省かれる場合もあります。条件はMariaDBのスロークエリログ概要で確認できます。

対象は自分で管理するLinuxサーバーです。管理用SQLアカウントと設定ファイルを編集できるOS権限が必要で、グローバル変数の変更にはそのバージョンの対応権限も必要です。権限エラー時はアプリのユーザーに広い権限を与えず、管理アカウントを使います。マネージドDBでは提供元のパラメーター設定やログ画面が必要な場合があります。

MariaDB 10.11で一部の変数名が変わりましたが、以下の旧名も別名として利用できます。例では広く使われる旧名を用い、実サーバーで対応を確認します。サーバー変数の公式資料に範囲とバージョン条件が記載されています。

例で使用する名前	10.11以降の名前	役割
`slow_query_log`	`log_slow_query`	記録の有効化
`slow_query_log_file`	`log_slow_query_file`	ファイル名と保存先
`long_query_time`	`log_slow_query_time`	実行時間の基準
`min_examined_row_limit`	`log_slow_min_examined_row_limit`	最低調査行数

再起動せずに有効化して試験SQLで確認する

現在値と元に戻す設定を記録する

Ubuntuの一般的なローカルソケット認証ならsudo mariadbで接続できます。別構成ではmariadb -u 管理アカウント -pなど実際の認証方式を使います。まずバージョン、データディレクトリとグローバル値を保存します。別名を指定しても新しい変数名で表示される場合があります。

SELECT VERSION(), @@GLOBAL.datadir;
SHOW GLOBAL VARIABLES WHERE Variable_name IN (
  'slow_query_log', 'log_slow_query',
  'slow_query_log_file', 'log_slow_query_file',
  'long_query_time', 'log_slow_query_time',
  'log_output', 'general_log', 'log_slow_rate_limit',
  'min_examined_row_limit', 'log_queries_not_using_indexes',
  'log_slow_filter', 'log_slow_disabled_statements'
);

一時的な試験のあとで戻せるよう、同じ管理接続で以下の値も保存します。@saved_...はこの接続だけのユーザー変数です。切断すると失われるので、問い合わせ結果を別の作業記録にも残し、後述の復元SQLは同じ接続で実行します。

SET @saved_slow = @@GLOBAL.slow_query_log,
    @saved_file = @@GLOBAL.slow_query_log_file,
    @saved_output = @@GLOBAL.log_output,
    @saved_time = @@GLOBAL.long_query_time;

ファイル出力とセッションへの適用を区別する

以下はファイル出力の例です。相対名のmariadb-slow.logは@@GLOBAL.datadirの中に作られます。既に運用中のログがある場合は、名前を変更せず既存の保存先を使うこともできます。

SET GLOBAL slow_query_log_file = 'mariadb-slow.log';
SET GLOBAL log_output = 'FILE';
SET GLOBAL long_query_time = 1;
SET GLOBAL slow_query_log = ON;

log_outputは一般クエリログの出力先にも影響します。現在TABLEを使っている場合は、この例を適用する前にその要件を確認します。両方必要ならFILE,TABLEを選べます。NONEでは機能が有効でも出力されません。

グローバル値は新しい接続の既定値であり、既存セッションの時間基準などを自動で書き換えるものではありません。次のように両方の範囲を比較します。アプリの接続プールも古い接続を再利用するため、再接続するか該当セッションを変更するか計画します。SHOW VARIABLESのGLOBAL・SESSIONを参照できます。

SELECT @@GLOBAL.long_query_time AS global_seconds,
       @@SESSION.long_query_time AS session_seconds,
       @@GLOBAL.slow_query_log AS global_log,
       @@SESSION.slow_query_log AS session_log;

現在の接続で試験し、セッションを復元する

次の例は元のセッション設定を保存し、試験中だけ時間を1秒、調査行数の下限を0、サンプリングを1にし、フィルターを空にします。SLEEPはテーブルの行を調べないため、行数下限があると除外されることがあります。サーバー側の除外文種別でSELECTが対象外になっていないことも確認します。

SET @session_log = @@SESSION.slow_query_log,
    @session_time = @@SESSION.long_query_time,
    @session_rows = @@SESSION.min_examined_row_limit,
    @session_rate = @@SESSION.log_slow_rate_limit,
    @session_filter = @@SESSION.log_slow_filter;
SET SESSION slow_query_log = ON;
SET SESSION long_query_time = 1;
SET SESSION min_examined_row_limit = 0;
SET SESSION log_slow_rate_limit = 1;
SET SESSION log_slow_filter = '';
SELECT SLEEP(1.2) AS slow_log_probe_13708;

正常終了時の戻り値は0です。完了後にログ内でslow_log_probe_13708を確認します。実際の時間は負荷で変わります。このSQLは記録経路の試験であり、性能測定やインデックスの検証には使いません。

ファイルを確認したら同じSQL接続で試験前のセッション値に戻します。元の値へ戻るので、その後の実収集は意図したグローバル既定値を引き継ぐ新規接続などで別途確認します。

SET SESSION slow_query_log = @session_log;
SET SESSION long_query_time = @session_time;
SET SESSION min_examined_row_limit = @session_rows;
SET SESSION log_slow_rate_limit = @session_rate;
SET SESSION log_slow_filter = @session_filter;

Ubuntu・Rocky Linuxで設定を永続化する

SET GLOBALはオプションファイルの代わりにはなりません。実際のサービスが読むファイルと起動引数を確認し、機密設定があれば出力をそのまま共有しないようにします。

sudo systemctl cat mariadb
sudo mariadbd --help --verbose
sudo mariadbd --print-defaults

設定を確認してバックアップします。一般的なUbuntuパッケージは/etc/mysql/mariadb.conf.d/、Rocky Linuxでは/etc/my.cnf.d/を使います。後者はRocky LinuxのMariaDBガイドでも確認できます。実際の読み込み先を確認してからUbuntuで60-slow-log.cnf、Rockyでslow-query.cnfなどの専用ファイルを作れます。同名の既存ファイルを確認せず上書きしないでください。
サーバー用グループに以下を設定します。後のファイルや引数による上書きを調べ、競合する重複を解消します。1秒は開始点であり、すべてのサービスに適した固定値ではありません。

[mariadb]
slow_query_log=ON
slow_query_log_file=mariadb-slow.log
log_output=FILE
long_query_time=1
log_slow_rate_limit=1
min_examined_row_limit=0

保守時間に再起動し、値を確認します。mariadbd --print-defaultsで読み込みを調べてから再起動します。最後の接続命令とサービス名は実環境に合わせます。

sudo systemctl restart mariadb
sudo systemctl status mariadb --no-pager
sudo mariadb -e "SHOW GLOBAL VARIABLES LIKE 'slow_query_log%'; SHOW GLOBAL VARIABLES LIKE 'long_query_time'; SHOW GLOBAL VARIABLES LIKE 'log_output';"

新しいクライアントで保存先、時間、出力方式、セッション値を再確認し、試験SQLを再実行します。別の絶対パスを使う場合はサービスアカウントの書き込み権限と、UbuntuのAppArmor・RockyのSELinuxを検討します。例は既存データディレクトリ内の相対名から始め、新規フォルダーのポリシー変更を避けています。検索順はMariaDBオプションファイルの資料を参照してください。

ログファイルとテーブルを読む

ファイルを確認して時間・頻度別に集計する

SQLで確認した実際のパスを使います。例の/var/lib/mysql/は必要に応じて変更します。tail -Fはファイル名を追跡して新しい記録を表示し、Ctrl+Cで表示を終了できます。

sudo tail -n 80 /var/lib/mysql/mariadb-slow.log
sudo tail -F /var/lib/mysql/mariadb-slow.log

試験SQLなどの原文を見つけ、Query_time、Lock_time、Rows_sent、Rows_examinedを合わせて読みます。大量のログはmariadb-dumpslowで類似SQLをまとめられます。未導入なら配布元の提供パッケージを確認します。旧名のmysqldumpslowで存在する場合もあります。

sudo mariadb-dumpslow -s t -t 10 /var/lib/mysql/mariadb-slow.log
sudo mariadb-dumpslow -s at -t 10 /var/lib/mysql/mariadb-slow.log
sudo mariadb-dumpslow -s c -t 10 /var/lib/mysql/mariadb-slow.log

-s tは累積クエリ時間、-s atは平均時間、-s cは回数で並べ、-t 10は上位10グループを指定します。数値と文字列は既定で抽象化されます。集計で優先順位をつけ、その後に原文SQLと実行計画を調べます。

TABLE出力を使っている場合

log_outputにTABLEまたはFILE,TABLEが含まれる場合は、権限のあるアカウントでmysql.slow_logを読めます。上のFILEのみの例では、テーブルに新規記録がなくてもファイル記録の失敗ではありません。

SELECT start_time, query_time, lock_time,
       rows_sent, rows_examined, sql_text
FROM mysql.slow_log
ORDER BY start_time DESC
LIMIT 20;

テーブルとファイルでは機能や負荷が異なり、例えば拡張EXPLAIN出力はファイルのみです。共通の出力設定を不用意に変更せず、テーブルへのログ出力で制限を確認します。

改善するSQLの優先順位を決める

1回だけ遅い文に注目せず、頻度と累積時間も比較します。1回5秒のSQLと、0.2秒を1,000回実行するSQLでは平均と累積の優先順位が異なります。ただし時間基準1秒では後者は通常の時間条件で収集されません。条件付きログをDB負荷全体の記録と解釈しないようにします。

項目	読み方	追加の確認
`Query_time`	記録された文の実行時間	平均・累積・実行回数を比較
`Lock_time`	記録されたロック関連時間	全行ロック待ちを表すとは限らないため同時実行状況も調べる
`Rows_examined`と`Rows_sent`	調査行数と返却行数	条件、結合、インデックス、実行計画を確認
同形SQLの回数	反復コストと呼び出し頻度	アプリの不要な繰り返し取得を確認

ログだけでインデックス追加を決めません。小さなテーブルでは全走査が合理的な場合もあり、インデックスは書き込みと容量のコストを増やします。現実的な同じ条件で変更前後を比較します。ANALYZEなど実際に文を実行する診断は負荷と変更可能性を検討してから使います。

記録されない・多すぎる場合の確認

有効なのに空：NONE、ファイル・テーブルの選択、接続先インスタンス、セッションの有効化と時間を確認します。実行中のSQLは完了後まで記録されない場合があります。
試験SQLもない：行数下限、log_slow_filter、除外文種別、log_slow_rate_limitを調べます。1000は適格SQLを全部記録する意味ではなく、試験セッションでは1を使います。
速いSQLもある：log_queries_not_using_indexesやフィルターのnot_using_indexを確認します。時間基準を上げてもその条件の記録は残り得ます。
ファイル権限エラー：サービスアカウント、親フォルダー、AppArmor・SELinuxの拒否と空き容量を確認します。クライアント利用者の権限とサーバープロセスの権限は別です。

次のLinux確認例もパスを実環境に合わせます。起動に失敗したら拒否パスや不明なオプションを調べ、セキュリティ機構全体を無効にする方法で解決しないようにします。

sudo journalctl -u mariadb -b -n 100 --no-pager
sudo journalctl -k -b --no-pager
sudo ls -ld /var/lib/mysql
sudo ls -l /var/lib/mysql/mariadb-slow.log
df -h /var/lib/mysql

収集を止め、元の設定とログを管理する

次の文で記録を無効にします。ファイル削除ではないため既存ログは残ります。オプションファイルで有効なら次回再起動で再び有効になるので、永続設定も意図に合わせます。

SET GLOBAL slow_query_log = OFF;
SET SESSION slow_query_log = OFF;

元の値を保存した同じ管理接続が続いていれば、以下でグローバル設定を復元できます。切断済みなら未定義のユーザー変数で実行せず、別に記録した実際の元の値を使用します。既存アプリのセッションとオプションファイルは個別に確認します。

SET GLOBAL slow_query_log = OFF;
SET GLOBAL slow_query_log_file = @saved_file;
SET GLOBAL log_output = @saved_output;
SET GLOBAL long_query_time = @saved_time;
SET GLOBAL slow_query_log = @saved_slow;

長期収集では保存期間、ファイルサイズ、空き容量を管理します。名前だけ変更してもサーバーが古いファイルハンドルへ書き続けることがあるため、既存のlogrotate設定と再オープン処理を確認します。FLUSH SLOW LOGSは閉じて開き直す命令であり、保存・圧縮・自動削除の方針を作るものではありません。対応するRELOAD権限が必要です。

FLUSH SLOW LOGS;

MariaDBのLinuxログローテーションとFLUSHの資料に沿って運用方針と合わせます。データディレクトリ内のファイルも既存のローテーション対象か確認します。SQLには個人情報や秘密値が含まれ得るのでログとバックアップのアクセスを制限し、外部共有前には機密値を除去します。

MariaDB