C5 C6 D6 F8 F9 S6 U10

MySQLのログの種類とログの仕方を調べてみた（実施例）

2012年11月9日 2017年8月9日

ご利用のブラウザは、JavaScript が無効となっていませんか？
このサイトでは、コンテンツの一部が非表示、あるいは、コメント、お問い合わせの投稿ができない、検索ができないことがあります。

今回は、MySQLでロギングを行ってみます。

一口にロギングと言ってもMySQLでは、以下の４つの種類があります。

エラーログ
一般クエリログ
バイナリログ
スロークエリログ

今回は、上記４つのロギングをとり方について、簡単に解説してみます。

目次
1. MySQLでロギングを行う
履歴

2012年11月9日初版

MySQLでロギングを行う

各ログの種類ごとに以下に簡単に解説します。

各ロギングの設定例では、mysqlの設定ファイルを一律 /etc/my.cnf としています。
これは、RedHat系(CentoOS,Scientific Linuxなど)のデフォルトの設定ファイルになります。
Deabin系(Debian,Ubuntuなど)では、/etc/mysql/my.cnf というディレクトリ配下がデフォルトになっています。ファイルの場所の違いに注意してください。もちろん、設定する内容は同じです。

エラーログ

エラーログは、システムロギングとも言われ
mysqld (サーバー)の起動、実行、停止のロギング、また発生した問題のエラー情報などをロギングします。

ロギング例

以下は、mysqld (サーバー)起動時のロギングの出力例です。以下の中で[Note] は、注意です。エラーは、[Error] 、警告は、[Warning] と表記されます。

121109 15:21:56 InnoDB: The InnoDB memory heap is disabled
121109 15:21:56 InnoDB: Mutexes and rw_locks use InnoDB's own implementation
121109 15:21:56 InnoDB: Compressed tables use zlib 1.2.3
121109 15:21:56 InnoDB: Initializing buffer pool, size = 16.0M
121109 15:21:56 InnoDB: Completed initialization of buffer pool
121109 15:21:56 InnoDB: highest supported file format is Barracuda.
121109 15:21:56 InnoDB: Waiting for the background threads to start
121109 15:21:57 InnoDB: 1.1.8 started; log sequence number 2511587907
121109 15:21:57 [Note] Event Scheduler: Loaded 0 events
121109 15:21:57 [Note] /usr/libexec/mysqld: ready for connections.
Version: '5.5.28-log'  socket: ''  port: 3306  MySQL Community Server (GPL)
...

ロギング設定

このロギングを行うには、mysqlの設定ファイル(/etc/my.cnf)以下の設定を行います。
... [mysqld] ... # Error log log_error="/var/log/mysql/mysqld.log" log_warnings=1 ...
log_error
エラーログのファイル名を設定します。

log_warnings
警告も全て出力する場合は、1を設定します。0は出力しません。また0の場合、接続を中断した情報をエラーログに出力しないので注意が必要です。

システム変数（my.cnfで設定するパラメータ）は、ハイフォン(“-“)を使わなくなりました。おそらく、mysqld の起動オプションでハイフォン(“-“)を使って、システム変数では使わなくしてはっきり区別しているのだと思います。

そこで、ここのシステム変数も以前は、
log-err → log_error
log-warnings → log_warnings
と変化している点に注意してください。
基本的に両方の名前が利用できるようになっていますが、そのうち、ハイフォンは無くなると思います。ハイフォン使用の変数を使っていると起動時に Warning が出力されます。

一般クエリログ

一般クエリログは、クエリ(SQL)ロギングとも言われ
mysqld (サーバー)がクライアントとの接続と実行したクエリ(SQL)をロギングします。

ロギング例

以下は、Wordpressのサイトを起動した際のロギングの出力例です。

/usr/libexec/mysqld, Version: 5.5.28-log (MySQL Community Server (GPL)). started with:
TCP Port: 3306, Named Pipe: /var/lib/mysql/mysql.sock
Time                 Id Command    Argument
121109  2:25:17	    1 Connect	hoge@localhost on 
		    1 Query	SET NAMES utf8
		    1 Init DB	hoge
		    1 Query	SELECT option_name, option_value FROM wp_options WHERE autoload = 'yes'
		    1 Query	SELECT option_value FROM wp_options WHERE option_name = 'akismet_comment_nonce' LIMIT 1
		    1 Query	SHOW TABLES LIKE 'wp_comment_rating'
		    1 Query	UPDATE `wp_options` SET `option_value` = '0' WHERE `option_name` = 'del_revision_getPosts'
		    1 Query	SELECT option_value FROM wp_options WHERE option_name = 'smilies_themer' LIMIT 1
		    1 Query	SELECT option_value FROM wp_options WHERE option_name = '_transient_timeout_doing_cron' LIMIT 1
		    1 Query	SELECT autoload FROM wp_options WHERE option_name = '_transient_doing_cron'
		    1 Query	SELECT autoload FROM wp_options WHERE option_name = '_transient_timeout_doing_cron'
		    1 Query	SELECT option_value FROM wp_options WHERE option_name = '_transient_doing_cron' LIMIT 1
		    1 Query	INSERT INTO `wp_options` (`option_name`, `option_value`, `autoload`) VALUES ('_transient_doing_cron', '1352395517', 'yes') ON DUPLICATE KEY UPDATE `option_name` = VALUES(`option_name`), `option_value` = VALUES(`option_value`), `autoload` = VALUES(`autoload`)
...

1行目 : mysqldのバージョン表記と開始のログ
2行目 : tcpポート番号、パイプ名のログ
3行目 : 4行目からのタイトル出力
4行目 : 日付 (121109 → 2012/11/09 のこと) 時間 ID番号コマンド(Connect:接続の意味) パラメータ(hoge@localhost on → localhostのhogeさんが接続してきたの意味)

…
以降は、日時については、同じID番号の場合、省略されます。

コマンドにQueryとある行は、SQLが処理されているロギングになります。

ロギング設定

このロギングを行うには、mysqlの設定ファイル(/etc/my.cnf)以下の設定を行います。
... [mysqld] ... # Query log log="/var/log/mysql/sql.log" ...
log
一般クエリログを採取するか否か示します。一般的に、ここにログファイル名を指定することで、有効にします。キーのlogのみを指定して、ファイル名を指定しない場合は、ホスト名.log のファイル名で保存されます。
ロギングしたくない場合は、キーのlog自体を削除します。
先の設定例は、古くからある設定方法のようで、以下のような設定でも行うことができるようになっています。
... [mysqld] ... # Query log general_log=1 general_log_file="/var/log/mysql/sql.log" log_output=FILE ...
general_log
一般クエリログを採取するか否か示します。1:ロギングする、0:ロギングしない

general_log_file
一般クエリログのファイル名を設定します。指定しない場合は、ホスト名.log のファイル名で保存されます。

log_output
一般クエリログとスロークエリログの出力先ディレクトリを設定します。
TABLE:テーブルへのログ、FILE:ファイルへのログ、NONE:テーブルまたはファイルにログしないのいずれか。

バイナリログ

バイナリログは、バイナリ(バックアップ)ロギングとも言われ
mysqld (サーバー)のデータ変更のステートメントをバイナリ情報でロギングします。また、レプリケーションにも使用されます。

ロギング例

バイナリ情報なので、直接中身をみてもわかりません。
mysqlbinlogコマンドを使ってロギングされている内容を確認することができます。

$ mysqlbinlog /var/log/mysql/bin.000002 --start-datetime "2012-11-09 03:47:00" --stop-datetime "2012-11-09 03:48:00"
...
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#121109  2:24:33 server id 1  end_log_pos 107   Start: binlog v 4, server v 5.5.28-log created 121109  2:24:33 at startup
ROLLBACK/*!*/;
BINLOG '
0eqbUA8BAAAAZwAAAGsAAAAAAAQANS41LjI4LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAADR6ptQEzgNAAgAEgAEBAQEEgAAVAAEGggAAAAICAgCAA==
'/*!*/;
# at 44447
#121109  3:47:30 server id 1  end_log_pos 44516         Query   thread_id=11 exec_time=0     error_code=0
SET TIMESTAMP=1352400450/*!*/;
SET @@session.pseudo_thread_id=11/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 44516
#121109  3:47:30 server id 1  end_log_pos 44679         Query   thread_id=11 exec_time=0     error_code=0
use hoge/*!*/;
SET TIMESTAMP=1352400450/*!*/;
UPDATE `wp_options` SET `option_value` = '0' WHERE `option_name` = 'del_revision_getPosts'
/*!*/;
...

mysqlbinlogコマンドにバイナリログのファイル名を指定するとロールバック用のSQL文が出力されます。
バイナリログがバックアップログといわれるところは、バイナリログがあれば、好きな位置へロールバック（戻る）ことができる点にあります。

ロギング設定

このロギングを行うには、mysqlの設定ファイル(/etc/my.cnf)以下の設定を行います。
... [mysqld] ... # Binary log log_bin="/var/log/mysql/bin.log" log_bin_index="/var/log/mysql/bin.list" max_binlog_size=1M expire_logs_days=1 ...
log_bin
バイナリログを採取するか否か示します。ここにログファイル名を指定することで、有効にします。

log_bin_index
バイナリログインデックスファイル名を設定します。バイナリログファイル名を管理するためのファイルの名前になります。

max_binlog_size
バイナリログの最大ファイルサイズを指定します。ここで指定したファイルサイズを超えた場合は、ローテートします。設定可能な値は、4096 バイト以上 1 GB (デフォルト) 以下です。

expire_logs_days
バイナリログの保存期間を日数で指定します。この日数を超えたものは削除されます。デフォルト 0 は、削除しません。

上記以外にもバイナリログに関しては、色々と設定できるようになっています。例えば、

binlog_format : バイナリロギング形式。STATEMENT(デフォルト)、ROW、MIXED のどれかになる。

これ以外にも、まだあります。詳しく、http://dev.mysql.com/doc/refman/5.5/en/server-system-variables.html を参照してください。

また、システム変数（my.cnfで設定するパラメータ）は、ハイフォン(“-“)を使わなくなりました。おそらく、mysqld の起動オプションでハイフォン(“-“)を使って、システム変数では使わなくしてはっきり区別しているのだと思います。

そこで、ここのシステム変数も以前は、
log-bin → log_bin
log-bin-index → log_bin_index
max-binlog-size → max_binlog_size
~~expire-logs-days~~ → expire_logs_days
と変化している点に注意してください。
基本的に両方の名前が利用できるようになっていますが、expire-logs-days については、少なくとも 5.5では使えなくなっています。
仮に使えても、ハイフォン使用の変数を使っていると起動時に Warning が出力されます。

スロークエリログ

スロークエリログは、スロークエリ (デバッグ)ロギングとも言われ
mysqld (サーバー)で long_query_time で指定した秒数より時間を要したクエリ(SQL)、またはインデックスを使用しなかったクエリ(SQL)のロギングを行います。

ロギング例

以下は、Wordpressのサイトを起動した際のロギングの出力例です。

# Time: 121109  3:44:23
# User@Host: hoge[hoge] @ localhost [127.0.0.1]
# Query_time: 0.015625  Lock_time: 0.000000 Rows_sent: 6  Rows_examined: 1442
SET timestamp=1352400263;
SELECT DISTINCT wp_posts.*, ROUND((select AVG(rating0) from wp_post_judge where  ( wp_post_judge.post_id = wp_posts.ID AND wp_post_judge.rating0<>0 )),2) AS ratings_average  
 
	FROM wp_posts 
		INNER JOIN wp_term_relationships ON (wp_posts.ID = wp_term_relationships.object_id) 
		INNER JOIN wp_term_taxonomy ON (wp_term_relationships.term_taxonomy_id = wp_term_taxonomy.term_taxonomy_id) 
 
	WHERE 
		wp_posts.post_password = '' AND 
		wp_posts.post_date < '2012-11-09 03:44:23' AND 
		wp_posts.post_status = 'publish' AND 
		wp_term_taxonomy.taxonomy = 'category' AND 
		wp_term_taxonomy.term_id in (6) 
 
	ORDER BY ratings_average DESC;
...

1行目 : 日時(前ログと同じ場合は省略されることがあります)
2行目 : 接続ユーザ、ホスト名
3行目 : Query_time : クエリ実行時間、Lock_time : テーブル or データベースがロックされた時間、Rows_examined : 処理対象となった行数
4行目以降 : 実際のSQL文

…
Query_timeは、CPU処理時間でなく、実際のリアクションするまでの時間なので、レスポンスが遅い場合などは、このログを見ると遅延箇所がはっきりします。

ロギング設定

このロギングを行うには、mysqlの設定ファイル(/etc/my.cnf)以下の設定を行います。
... [mysqld] ... # Slow Query log slow_query_log=1 slow_query_log_file="/var/log/mysql/slow.log" log_queries_not_using_indexes log_slow_admin_statements
slow_query_log
スロークエリログを採取するか否か示します。1:ロギングする、0:ロギングしない

slow_query_log_file
スロークエリログのファイル名を設定します。指定しない場合は、general_log_file に従います。

long_query_time
クエリの処理時間（秒単位）を指定します。この秒数を超えるとスロークエリログに出力されます。

log_queries_not_using_indexes
インデックスしていないクエリを全て出力する場合に指定します。

log_slow_admin_statements
管理用のステートメント(OPTIMIZE TABLE、ANALYZE TABLE、ALTER TABLE など) についても同様に処理に時間がかかるものをロギングしたい場合に指定します。

システム変数（my.cnfで設定するパラメータ）は、ハイフォン(“-“)を使わなくなりました。おそらく、mysqld の起動オプションでハイフォン(“-“)を使って、システム変数では使わなくしてはっきり区別しているのだと思います。

そこで、ここのシステム変数も以前は、
log-slow-queries → slow_query_log , slow_query_log_file
long-query-time → long_query_time
log-queries-not-using-indexes → log_queries_not_using_indexes
log-slow-admin-statements → log_slow_admin_statements
と変化している点に注意してください。
基本的に両方の名前が利用できるようになっていますが、そのうち、ハイフォンは無くなると思います。ハイフォン使用の変数を使っていると起動時に Warning が出力されます。

ざっと、こんな感じです。

色々なログがありますが、用途によって必要なもの不必要なものがあるかと思います。臨機応変に使いこなせば、かなりメンテナンスの助けになることは間違いないでしょう。

まずは、お試しあれ。

(amazon )	インフラエンジニア教本2――システム管理・構築技術解説 (SoftwareDesign別冊)に寄稿しました。「ログを読む技術」の再掲載になります。 8月号を見逃された方は、是非、ご一読くださいませ。
(amazon )	Software Design 8月号に寄稿しました。「ログを読む技術」について寄稿しました。興味のある方は、是非、ご一読くださいませ。
また、執筆や当サイトにおける広告のご依頼などございましたら、お問い合わせページよりご一報ください。

MySQLのログの種類とログの仕方を調べてみた（実施例）

MySQLでロギングを行う

エラーログ

一般クエリログ

バイナリログ

スロークエリログ

最近投稿の記事

さくらのVPS 全プランリニューアルです。（石狩(北海道)も選択可）

カテゴリ

Serverman@VPS 完全1ヶ月無料キャンペーン実施中です。

リンク

KVM採用 ConoHa VPSは、時間単位で借りれる便利なVPSです。

KVM採用お名前.com VPS(KVM) 2G プラン初期設定費無料キャンペーン実施です。

MySQLのログの種類とログの仕方を調べてみた（実施例）

MySQLでロギングを行う

エラー ログ

一般クエリ ログ

バイナリ ログ

スロー クエリ ログ

最近投稿の記事

さくらのVPS 全プラン リニューアルです。（石狩(北海道)も選択可）

カテゴリ

Serverman@VPS 完全1ヶ月無料 キャンペーン実施中です。

リンク

KVM採用 ConoHa VPSは、時間単位で借りれる便利なVPSです。

KVM採用 お名前.com VPS(KVM) 2G プラン 初期設定費無料 キャンペーン 実施です。

エラーログ

一般クエリログ

バイナリログ

スロークエリログ

さくらのVPS 全プランリニューアルです。（石狩(北海道)も選択可）

Serverman@VPS 完全1ヶ月無料キャンペーン実施中です。

KVM採用お名前.com VPS(KVM) 2G プラン初期設定費無料キャンペーン実施です。