第155回　エラーログのフィルタリング

MySQL 8.0には2021年現在、log_filter_internalとlog_filter_dragnetという2つのフィルタコンポーネントがあり、エラーログをフィルタリングする仕組みが用意されています。今回はこの2つのコンポーネントについて、優先度ベースのエラーログのフィルタリングと、ルールベースのエラーログのフィルタリングについて紹介します。

なお、今回利用するMySQLはバージョン8.0.26、OSはCentOS7を利用しています。

log_filter_internal

log_filter_internalは優先度ベースのエラーログフィルタリングになります。こちらのコンポーネントはデフォルトで有効になっており、エラーイベントの優先度とエラーコードに基づいてフィルタリングを行います。関係するシステム変数は、log_error_verbosityとlog_error_suppression_listの2つになります。

log_error_verbosity

log_error_verbosityは、エラーログに出力されるイベントをログレベルで制御します。log_error_verbosityは1～3の値を入れることで、それぞれのログレベルのイベントを出力することができます。

log_error_verbosityの値	出力されるログイベント
1	ERROR
2（デフォルト）	ERROR, WARNING
3	ERROR, WARNING, INFORMATION

たとえば、log_error_verbosityに1を設定した場合はERRORに関するログのみが出力されるようになり、WARNING、INFORMATIONレベルのログは出力されません。

また、Systemのイベントはエラー以外の状況に関するシステムメッセージが出力されます。これはlog_error_verbosityの値に関係なく出力されます。

log_error_suppression_list

log_error_suppression_listは、特定のログを抑制したい場合に有効なシステム変数になります。ただし、有効なログはWARNINGかINFORMATIONのログであり、ERRORやSYSTEMのログを抑制することはできません。この変数を設定する場合は、抑制したいエラーのエラーコードかシンボルをカンマ区切りで設定することで抑制することができます。

対応するエラーコード、シンボルについては、公式ドキュメントのMySQL 8.0 Error Message Referenceに一覧があるのでこちらを参照ください。

設定

log_error_verbosityとlog_error_suppression_listはそれぞれ動的なシステム変数であるため、my.cnfに記述、または、起動中であればSET GLOBAL | PERSISTで設定することが可能です。現在の設定を確認する場合は、SHOW VARIABLESで設定を確認することができます。

また、システム変数に存在しない値を設定しようとするとエラーになります。

mysql> SHOW VARIABLES like 'log_error_%';
+----------------------------+---------------------------------------------------+
| Variable_name              | Value                                             |
+----------------------------+---------------------------------------------------+
| log_error_services         | log_filter_internal; log_sink_internal            |
| log_error_suppression_list | MY-013360,MY-010914,MY-010956,MY-010957,MY-011825 |
| log_error_verbosity        | 3                                                 |
+----------------------------+---------------------------------------------------+
3 rows in set (0.00 sec)

mysql> SET GLOBAL log_error_suppression_list = 'abcdef';
ERROR 1231 (42000): Variable 'log_error_suppression_list' can't be set to the value of 'abcdef'

もし、設定しているエラーコード情報の詳細などを確認したい場合は、perrorコマンドなどを駆使して確認すると良いかもしれません。

perrorコマンドについては、第12回　MySQLのヘルスチェックをする［死活監視の基礎編］のperrorの説明をご確認ください。

$ perror MY-013360
MySQL error code MY-013360 (ER_SERVER_WARN_DEPRECATED): '%s' is deprecated and will be removed in a future release. Please use %s instead

log_filter_dragnet

log_filter_dragnetは、ルールを定義して使用するログフィルタリングになります。こちらを利用する場合にはコンポーネントを追加する必要があります。コンポーネントの一覧は、mysqlのcomponentテーブルで確認することができます。

mysql> INSTALL COMPONENT 'file://component_log_filter_dragnet';
Query OK, 0 rows affected (0.00 sec)

mysql> SET GLOBAL log_error_services = 'log_filter_dragnet; log_sink_internal';
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM mysql.component;
+--------------+--------------------+---------------------------------------+
| component_id | component_group_id | component_urn                         |
+--------------+--------------------+---------------------------------------+
|            7 |                  7 | file://component_log_sink_syseventlog |
|           11 |                 11 | file://component_log_filter_dragnet   |
+--------------+--------------------+---------------------------------------+
2 rows in set (0.00 sec)

log_filter_dragnetの定義

log_filter_dragnetは、log_filter_dragnet Rule Languageという独自の文法を使って記述します。log_filter_dragnet Rule LanguageはIF condition THEN action.という形式で記述していきます。conditionには適用するエラーコード（シンボル）やイベント優先度（prio）を記述します。

例）

IF err_code == 13360 THEN ...
IF err_code == ER_SERVER_WARN_DEPRECATED THEN ..
IF prio == INFORMATION THEN ...

actionには次のいずれかを指定します。

drop: ログに記録しません。
throttle: 60秒あたりに表示する回数を指定します。たとえばthrottle 5とした場合、60秒間に5回だけ表示のように抑制します。; throttle 回数/秒数と指定した場合は設定時間中に設定回数だけに制限できます。たとえばthrottle 5/3600とした場合は1時間（3600秒）に5回に抑制できます。
set: フィールドに値を割り当てます。
unset: フィールドを破棄します。

log_filter_dragnetでフィルタリングルールを設定するにはSET GLOBAL| PERSISTでdragnet.log_error_filter_rulesに設定します。

例として、throttleでER_ACCESS_DENIED_ERROR_WITH_PASSWORDを3回に抑制するように設定します。

mysql> SET PERSIST dragnet.log_error_filter_rules = 'IF err_code==10926 THEN throttle 3.';
Query OK, 0 rows affected (0.00 sec)

設定したあとに間違ったパスワードなどで連続でログインを試みると、エラーログの出力が3回でとまりました。

今度はsetを利用して出力を書き換えてみます。

mysql> SET PERSIST dragnet.log_error_filter_rules = 'IF err_code==10926 THEN set label="HELO".
    '> IF err_code==10926 THEN set msg="アクセスが拒否されました".';
Query OK, 0 rows affected (0.00 sec)

error_logの出力

2021-09-15T19:58:20.401740+09:00 88 [HELO] [MY-010926] [Server] アクセスが拒否されました
2021-09-15T19:58:25.182735+09:00 89 [HELO] [MY-010926] [Server] アクセスが拒否されました

ログのラベルとメッセージが書き換わっているのが確認できます。現在の設定は、statusのdragnet.Statusを見ることで確認できます。

mysql> SHOW STATUS like 'dragnet.Status';
+----------------+-----------------------------------------------------------------------------------------------------------------------------+
| Variable_name  | Value                                                                                                                       |
+----------------+-----------------------------------------------------------------------------------------------------------------------------+
| dragnet.Status | IF err_code==MY-010926 THEN set label="HELO". IF err_code==MY-010926 THEN set msg="アクセスが拒否されました".             |
+----------------+-----------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.01 sec)

各種フィールドの情報やより詳しい設定方法については、公式ドキュメントのエラーイベントフィールドとルールベースのエラーログのフィルタリング（log_filter_dragnet）をご確認ください。

まとめ

今回は、エラーログのフィルタリングとしてlog_filter_internalとlog_filter_dragnetのコンポーネントを紹介しました。特定のログが大量に発生してしまい、容量を圧迫したり、ログの整理を行いたいときに利用すると良いかもしれません。ときどきはエラーログと向き合って、設定を考えてみてください。