目次
Aurora MySQL の場合
Aurora MySQL は以下のログファイルをモニタリングできます。
- IAM データベース認証エラーログ
- エラーログ(Error Log)
- スロークエリログ(Slow Query Log)
- 全般ログ(General Log)
- 監査ログ(Audit Log)
- インスタンスログ
IAM データベース認証エラーログ(IAM DB 認証エラーログ)
IAM DB 認証に失敗した理由を見るためのログです。IAM DB 認証とは、DB ユーザーのパスワードではなく、IAM 認証トークンを使って Aurora MySQL に接続する方式です。クエリログは出力されません。
エラーログ
Aurora MySQL のエラーログはデフォルトで生成されます。Aurora MySQL は mysql-error.log ファイルにエラーを書き込みます。基本的にログのタイムスタンプは UTC(Coordinated Universal Time)で出力されます。エラーログは DB エラーのログなので通常のクエリログは出力されません。DB起動・停止、クラッシュ、内部エラー、接続エラー、レプリケーション系エラーなどのログが出力されます。
スロークエリログ(Slow Query Log)
スロークエリログ(Slow Query Log)は、性能調査が目的となります。一定時間以上かかったSQLを記録するログです。
slow_query_log = 1
long_query_time = 1
log_output = FILE
slow_query_log を1 にするとスロークエリログが作成されます。
ログへの記録対象にするクエリの最短実行時間はlong_query_time で秒単位で指定できます。上記は 1秒を超えた SQL が記録対象になります。ただし、long_query_time の値を小さくしすぎるとログ量と負荷が増えます。ワークロードに応じて調整することが推奨されます。
log_queries_not_using_indexes
log_queries_not_using_indexes を有効にすると、実行時間に関係なくインデックスを使わないクエリも記録できます。これは、スロークエリログに記録される条件が増えるという意味です。
通常、スロークエリログは以下のような条件で記録されます。これは実行時間が1秒以上かかったSQLをスロークエリログに記録するという意味です。
slow_query_log = 1
long_query_time = 1
さらに以下を有効にします。
log_queries_not_using_indexes = 1
そうすると、実行時間が 1秒未満でも、インデックスを使っていない SQL もスロークエリログに記録されます。
log_queries_not_using_indexes を利用する具体例
例えば、テーブルがこうだとします。
CREATE TABLE users (
id bigint primary key,
email varchar(255),
name varchar(255),
created_at datetime
);
email にインデックスがない状態で、以下を実行します。
SELECT *FROM usersWHERE email = 'test@example.com';
このSQLは、email にインデックスがないため、MySQLがテーブル全体を上から順に探す可能性があります。
つまり、users テーブルを全件スキャンするという動きになります。このSQLが 0.05秒で終わった としても、log_queries_not_using_indexes = 1 ならスロークエリログに出る可能性があります。遅くはないけど、将来的に危ないSQLを見つけられます。
例えば今はデータが少ないので、0.05秒で終わる。でも、将来データが増えると、5秒かかったり、DB負荷が高くなるというSQLがあります。log_queries_not_using_indexes は、こういう 将来遅くなりそうなSQL を早めに見つけるための設定です。
全般ログ(General Log)
Aurora MySQL の全般ログ(General Log)は、DB に対して発生した接続・切断・実行 SQL など細かく記録するログです。MySQL が受け取った処理を記録するログです。ただし、本番環境で常時ONにするログというより、調査時に短時間だけ有効化するログと考えた方が安全です。
- 接続 … どのユーザーが接続したか
- 切断 … 接続が終了したこと
- 実行 SQL … SELECT / INSERT / UPDATE / DELETE など
- 管理系コマンド … SET, SHOW, COMMIT, ROLLBACK など
有効な調査
- アプリが本当にSQLを投げているか … SQL実行有無が分かる
- 想定外のSQLが流れていないか … SQL本文を確認できる
- 特定テーブルにアクセスしているか … SQL内のテーブル名から確認できる
- どのユーザーで接続しているか … DBユーザー情報を確認できる
- トランザクションが発生しているか … BEGIN, COMMIT, ROLLBACK などが見える
しかし、以下は全般ログをだけでは分かりません。
- このSQLで何件返ったか
- どんな個人情報が返却されたか
- どのWeb画面の操作で発生したか
本番で常時ONにしない方がよい理由
全般ログは便利ですが、本番では注意が必要です。理由は主に3つです。
- ログ量が非常に多くなる
- DB性能に影響する可能性がある
- SQL本文に個人情報が含まれる可能性がある
特に個人情報保護の観点では、以下のようなSQLがログに残る可能性があります。
SELECT *FROM usersWHERE email = 'test@example.com';
この場合、メールアドレスがログに残ります。
また、アプリの実装によっては以下のように、個人情報そのものがSQL本文に出る可能性もあります。
INSERT INTO customers (name, email, tel)VALUES ('山田太郎', 'yamada@example.com', '090-xxxx-xxxx');
そのため、全般ログを CloudWatch Logs に出す場合は、CloudWatch Logs自体が機微情報の保管場所になると考えた方がよいです。
監査ログ(Audit Log)
Aurora MySQL の 監査ログ(Audit Log) は、誰が、いつ、DBに接続して、どのような操作をしたかを記録するためのログです。Aurora MySQL では、この機能は Advanced Auditing と言います。DBクラスターのパラメータを設定して有効化します。
- 誰が … DBユーザー
- いつ … 実行時刻
- どこから … 接続元ホスト/IP
- 何を … 接続、切断、SQL実行、DDL、DML、DCLなど
- どのDBで … 対象データベース
- どのSQLを … 設定によってSQL本文
全般ログとの違い
監査ログと全般ログは似ていますが、目的が違います。
- 全般ログ … 実際に流れているSQLを広く確認する
- 監査ログ … 監査証跡として、接続や操作を記録する
全般ログは「とにかくSQLを見る」用途です。
一方、監査ログは、監査対象のイベントを選んで記録するという使い方ができます。そのため、個人情報保護や不正操作調査では、通常は全般ログより監査ログの方が向いています。
有効化する主なパラメータ
Aurora MySQL の監査ログは、主に DBクラスター・パラメータグループ で設定します。
代表的なパラメータは以下です。
- server_audit_logging … 監査ログを有効/無効化する
- server_audit_events … 記録するイベント種別を指定する
- server_audit_incl_users … 監査対象に含めるDBユーザーを指定する
- server_audit_excl_users … 監査対象から除外するDBユーザーを指定する
設定例
server_audit_logging = 1
server_audit_events = CONNECT,QUERY_DDL,QUERY_DML,QUERY_DCL
server_audit_excl_users = rdsadmin
- server_audit_logging = 1 … 監査ログをON
- CONNECT … 接続・切断を記録
- QUERY_DDL … CREATE / ALTER / DROP などを記録
- QUERY_DML … SELECT / INSERT / UPDATE / DELETE などを記録
- QUERY_DCL … GRANT / REVOKE などを記録
- server_audit_excl_users = rdsadmin … Aurora 内部管理ユーザー(rdsadmin)のログを除外
イベント種別
- CONNECT … 接続・切断(例)ログイン、ログアウト
- QUERY … クエリ全般(例)SELECT, INSERT, ALTER, GRANT など
- QUERY_DDL … スキーマ変更(例)CREATE, ALTER, DROP, TRUNCATE
- QUERY_DML … データ操作(例)SELECT, INSERT, UPDATE, DELETE
- QUERY_DCL … 権限操作(例)GRANT, REVOKE
- TABLE … テーブルアクセス(例)対象テーブル情報
TABLE とは
イベント種別のTABLE は、Aurora MySQL の監査ログでいうと、SQL本文ではなく、そのSQLがアクセスしたテーブル情報を記録するイベント種別です。つまり、QUERY_DML やQUERY が「実行されたSQL」を見るためのイベントだとすると、TABLE は、そのSQLによって、どのテーブルが READ / WRITE / CREATE / ALTER / DROP されたかを見るイベントというイメージです。
監査ログフォーマットでも、TABLE イベントでは複数行が追加される(下記にて解説しますが、JOIN で複数テーブルを読み込む場合などです)ことがあり、queryid を使って関連する QUERY イベントとテーブルイベントを紐づけられます。また、TABLE イベントの object にはテーブル名が入ります。
QUERY と TABLE の違い
例えば、次のSQLが実行されたとします。
SELECT *
FROM users
WHERE id = 100;
QUERY / QUERY_DML では、ログの object に SQL 本文が出ます。
operation: QUERY
database : app_db
object : SELECT * FROM users WHERE id = 100
一方、TABLE では、そのSQLがアクセスしたテーブルが出ます。
operation: READ
database : app_db
object : users
つまり、以下のようなイメージです。
- QUERY系 → どんなSQLを実行したか
- TABLE → どのテーブルにアクセスしたか
TABLE イベントの operation
- READ … テーブルを読んだ(SELECT)
- WRITE … テーブルを書き込んだ(INSERT, UPDATE, DELETE)
- CREATE … テーブルなどを作成(CREATE TABLE)
- ALTER … テーブルなどを変更(ALTER TABLE)
- RENAME … 名前変更(RENAME TABLE)
- DROP … 削除(DROP TABLE)
【例】
SELECT *
FROM users
WHERE email = 'test@example.com';
QUERY_DML を有効にしていると、SQL本文が出ます。
QUERY, app_db, SELECT * FROM users WHERE email = 'test@example.com'
TABLE を有効にしていると、対象テーブルが出ます。
READ, app_db, users
QUERY_DML では test@example.com のような個人情報がログに残る可能性があります。
一方で TABLE は、基本的には users テーブルが読まれたという情報です。
【例 JOIN で複数行が出る場合】
SELECT *
FROM orders o
JOIN customers c ON o.customer_id = c.id
WHERE c.email = 'test@example.com';
この場合、TABLE イベントでは複数行出る可能性があります。
READ, app_db, orders
READ, app_db, customers
コメント