mysql中的日志(一)_MySQL
[mysqld_safe]
syslog
移除 /etc/mysql/conf.d/mysqld_safe_syslog.cnf ,然后在 /etc/mysql/my.cnf 添加相关配置
MySQL有多种类型的日志:Error Log、General Query Log、Binary Log 、Slow Query Log、Relay log(slave server)还有undo log/redo log 来实现事务
查看服务器中有哪些日志
[root@dev ~]# lsof -nc mysqld | grep -vE '(.so(..*)?$|.frm|.MY?|.ibd|ib_logfile|ibdata|TCP)' mysqld_sa 25638 root cwd DIR 8,2 4096 2 / mysqld_sa 25638 root rtd DIR 8,2 4096 2 / mysqld_sa 25638 root txt REG 8,2 941720 3145826 /bin/bash mysqld_sa 25638 root mem REG 8,2 99158576 4198587 /usr/lib/locale/locale-archive mysqld_sa 25638 root mem REG 8,2 26060 4197707 /usr/lib64/gconv/gconv-modules.cache mysqld_sa 25638 root 0r CHR 1,3 0t0 3857 /dev/null mysqld_sa 25638 root 1w CHR 1,3 0t0 3857 /dev/null mysqld_sa 25638 root 2w CHR 1,3 0t0 3857 /dev/null mysqld_sa 25638 root 255r REG 8,2 24632 4210700 /usr/bin/mysqld_safe mysqld 26379 mysql cwd DIR 8,2 4096 3932444 /var/lib/mysql mysqld 26379 mysql rtd DIR 8,2 4096 2 / mysqld 26379 mysql txt REG 8,2 10438848 4207116 /usr/libexec/mysqld mysqld 26379 mysql 0r CHR 1,3 0t0 3857 /dev/null mysqld 26379 mysql 1w REG 8,2 10234 937095 /data/logs/mysql/mysql_error.log mysqld 26379 mysql 2w REG 8,2 10234 937095 /data/logs/mysql/mysql_error.log mysqld 26379 mysql 3u REG 8,2 132 937139 /data/logs/mysql/binarylog/mysql_bin.index mysqld 26379 mysql 6u REG 8,2 0 1048581 /tmp/ibzlBDfl (deleted) mysqld 26379 mysql 7u REG 8,2 0 1048582 /tmp/ib48cnZp (deleted) mysqld 26379 mysql 8u REG 8,2 0 1048583 /tmp/ibidAZvz (deleted) mysqld 26379 mysql 11w REG 8,2 2618 937140 /data/logs/mysql/slow_query.log mysqld 26379 mysql 12u REG 8,2 0 1048584 /tmp/ibpL9bkE (deleted) mysqld 26379 mysql 13w REG 8,2 8059 937141 /data/logs/mysql/general_log.log mysqld 26379 mysql 15w REG 8,2 425 937145 /data/logs/mysql/binarylog/mysql_bin.000003 通过PID来查看 [root@dev ~]# sudo lsof -p 26379 | grep -vE '(.so(..*)?$)' COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME mysqld 26379 mysql cwd DIR 8,2 4096 3932444 /var/lib/mysql mysqld 26379 mysql rtd DIR 8,2 4096 2 / mysqld 26379 mysql txt REG 8,2 10438848 4207116 /usr/libexec/mysqld mysqld 26379 mysql 0r CHR 1,3 0t0 3857 /dev/null mysqld 26379 mysql 1w REG 8,2 10234 937095 /data/logs/mysql/mysql_error.log mysqld 26379 mysql 2w REG 8,2 10234 937095 /data/logs/mysql/mysql_error.log mysqld 26379 mysql 3u REG 8,2 132 937139 /data/logs/mysql/binarylog/mysql_bin.index mysqld 26379 mysql 4uW REG 8,2 446693376 3933686 /var/lib/mysql/ibdata1 mysqld 26379 mysql 5u REG 8,2 0 1048580 /tmp/ibM08Tvg (deleted) mysqld 26379 mysql 6u REG 8,2 0 1048581 /tmp/ibzlBDfl (deleted) mysqld 26379 mysql 7u REG 8,2 0 1048582 /tmp/ib48cnZp (deleted) mysqld 26379 mysql 8u REG 8,2 0 1048583 /tmp/ibidAZvz (deleted) mysqld 26379 mysql 9uW REG 8,2 67108864 3933687 /var/lib/mysql/ib_logfile0 mysqld 26379 mysql 10uW REG 8,2 67108864 3933688 /var/lib/mysql/ib_logfile1 mysqld 26379 mysql 11w REG 8,2 2618 937140 /data/logs/mysql/slow_query.log mysqld 26379 mysql 12u REG 8,2 0 1048584 /tmp/ibpL9bkE (deleted) mysqld 26379 mysql 13w REG 8,2 8059 937141 /data/logs/mysql/general_log.log mysqld 26379 mysql 14u IPv4 373448 0t0 TCP *:mysql (LISTEN) mysqld 26379 mysql 15w REG 8,2 425 937145 /data/logs/mysql/binarylog/mysql_bin.000003 mysqld 26379 mysql 17u REG 8,2 2048 3933369 /var/lib/mysql/mysql/host.MYI mysqld 26379 mysql 18u REG 8,2 0 3933385 /var/lib/mysql/mysql/host.MYD mysqld 26379 mysql 19u REG 8,2 2048 3933388 /var/lib/mysql/mysql/user.MYI mysqld 26379 mysql 20u REG 8,2 828 3933421 /var/lib/mysql/mysql/user.MYD mysqld 26379 mysql 21u REG 8,2 5120 3932436 /var/lib/mysql/mysql/db.MYI mysqld 26379 mysql 22u REG 8,2 2640 3932437 /var/lib/mysql/mysql/db.MYD mysqld 26379 mysql 23u REG 8,2 5120 3933682 /var/lib/mysql/mysql/proxies_priv.MYI mysqld 26379 mysql 24u REG 8,2 1386 3933683 /var/lib/mysql/mysql/proxies_priv.MYD mysqld 26379 mysql 25u REG 8,2 4096 3933612 /var/lib/mysql/mysql/tables_priv.MYI mysqld 26379 mysql 26u REG 8,2 0 3933613 /var/lib/mysql/mysql/tables_priv.MYD mysqld 26379 mysql 27u REG 8,2 4096 3933615 /var/lib/mysql/mysql/columns_priv.MYI mysqld 26379 mysql 28u REG 8,2 0 3933616 /var/lib/mysql/mysql/columns_priv.MYD mysqld 26379 mysql 29u REG 8,2 4096 3933648 /var/lib/mysql/mysql/procs_priv.MYI mysqld 26379 mysql 30u REG 8,2 0 3933649 /var/lib/mysql/mysql/procs_priv.MYD mysqld 26379 mysql 31u REG 8,2 1024 3933609 /var/lib/mysql/mysql/servers.MYI mysqld 26379 mysql 32u REG 8,2 0 3933610 /var/lib/mysql/mysql/servers.MYD mysqld 26379 mysql 33u REG 8,2 4096 3933657 /var/lib/mysql/mysql/event.MYI mysqld 26379 mysql 34u REG 8,2 168 3933658 /var/lib/mysql/mysql/event.MYD mysqld 26379 mysql 35u IPv4 374008 0t0 TCP localhost:mysql->localhost:51908 (ESTABLISHED) mysqld 26379 mysql 44u IPv4 374010 0t0 TCP localhost:mysql->localhost:51913 (ESTABLISHED) mysqld 26379 mysql 45u IPv4 374011 0t0 TCP localhost:mysql->localhost:51918 (ESTABLISHED) mysqld 26379 mysql 46u IPv4 374014 0t0 TCP localhost:mysql->localhost:51920 (ESTABLISHED) mysqld 26379 mysql 47u IPv4 374062 0t0 TCP localhost:mysql->localhost:54839 (ESTABLISHED) mysqld 26379 mysql 50u REG 8,2 4096 3933645 /var/lib/mysql/mysql/proc.MYI mysqld 26379 mysql 51u REG 8,2 212 3933646 /var/lib/mysql/mysql/proc.MYD
一、错误日志
默认情况下查询日志是开启的
它记录的事件有:
1、服务器启动和关闭过程中的信息
2、服务器运行过程中的错误信息
3、事件调度器运行一个事件时产生的信息
4、(如果被配置为从服务器)启动从服务器进程时产生的信息
配置
//log-error[=FILENAME/PATH_TO_FILENAME] Static
//log-warnings[=NUMERIC_VALUE] Dynamic
[mysqld_safe] log_error=/data/logs/mysql/mysql_error.log
[mysqld] log_error=/data/logs/mysql/mysql_error.log
配置选项
log-warnings | skip-log-warnings
syslog | skip-syslog
作用范围为全局或会话级别,可用于配置文件,属非动态变量
二、查询日志
默认情况下查询日志是关闭的。
调试的时候可以开启,一般情况下不要开启,查询日志会增加很多磁盘 I/O
配置
//general-log[={0,1}] Dynamic //general_log_file[=FILENAME] Dynamic //log-output=PATH_TO_FILE/TABLE/NONE Dynamic log-output=FILE general_log=ON general_log_file=/data/logs/mysql/general_log.log
动态修改
mysql> SET GLOBAL general_log = 'ON';
mysql> SET GLOBAL general_log = 'OFF';
远程调试 (log-output=TABLE)
mysql> SHOW CREATE TABLE mysql.general_log \G *************************** 1. row *************************** Table: general_log Create Table: CREATE TABLE `general_log` ( `event_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, `user_host` mediumtext NOT NULL, `thread_id` bigint(21) unsigned NOT NULL, `server_id` int(10) unsigned NOT NULL, `command_type` varchar(64) NOT NULL, `argument` mediumtext NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='General log' 1 row in set (0.01 sec) mysql> SHOW CREATE TABLE mysql.slow_log \G *************************** 1. row *************************** Table: slow_log Create Table: CREATE TABLE `slow_log` ( `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, `user_host` mediumtext NOT NULL, `query_time` time NOT NULL, `lock_time` time NOT NULL, `rows_sent` int(11) NOT NULL, `rows_examined` int(11) NOT NULL, `db` varchar(512) NOT NULL, `last_insert_id` int(11) NOT NULL, `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, `thread_id` bigint(21) unsigned NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' 1 row in set (0.01 sec)
针对 general_log and slow_query_log
三、慢查询日志
默认情况下查询日志是关闭的
慢查询是指执行时长(包括等待CPU/IO的时间)超过 long_query_time 这个变量定义的时长的查询
开销比较小,可以用于定位性能问题,建议开启
配置
//slow-query-log[={0,1}] Dynamic //slow_query_log_file[=FILENAME] Dynamic //log-output=PATH_TO_FILE/TABLE/NONE Dynamic //log-slow-admin-statements[={OFF,ON}] //log-queries-not-using-indexes[={OFF,ON}] Dynamic //log-slow-slave-statements[={OFF,ON}] slave //log-short-format[={FALSE,TRUE}] //long_query_time[=NUMERIC] Dynamic //min-examined-row-limit[=NUMERIC] Dynamic long_query_time = 2 slow-query-log = on slow-query-log-file = /data/logs/mysql/slow_query.log log-queries-not-using-indexes log-output=FILE
动态修改
mysql> SET GLOBAL slow_query_log = 'ON';
mysql> SET GLOBAL slow_query_log = 'OFF';
远程调试 (log-output=TABLE) 同上
关闭慢查询日志
1
2
log-output=NONE
log_slow_queries=0
日志分析
mysqldumpslow / mysqlsla / myprofi / mysql-explain-slow-log / mysqllogfilter
这里我使用 pt-query-digest (percona toolkit)
# 390ms USER TIME, 10ms system TIME, 15.67M rss, 105.84M vsz # CURRENT DATE: Thu DEC 29 13:22:42 2014 # Hostname: test # Files: slow.log # Overall: 776 total, 11 UNIQUE, 0.00 QPS, 0.00x concurrency _____________ # TIME range: 2014-09-10 04:03:19 TO 2014-12-29 05:02:51 # Attribute total MIN MAX avg 95% stddev median # ============ ======= ======= ======= ======= ======= ======= ======= # EXEC TIME 5657s 2s 33s 7s 23s 6s 5s # LOCK TIME 33s 0 19s 43ms 98us 715ms 38us # ROWS sent 323.38k 0 107.36k 426.73 0.99 6.35k 0 # ROWS examine 323.39k 0 107.36k 426.74 0 6.35k 0 # Query SIZE 217.95k 38 562 287.61 420.77 81.78 284.79
四、二进制日志
默认没有开启
二进制日志记录 MySQL 数据库中所有与更新相关的操作,即二进制日志记录了所有的 DDL(数据定义语言)语句和 DML(数据操纵语言)语句,但是不包括数据查询语句。
最重要的两个用途 :恢复数据库和主从复制
配置
http://dev.mysql.com/doc/refman/5.6/en/replication-options-binary-log.html
binlog_format=mixed
max_binlog_size=1024M
log_bin=/data/logs/mysql/binarylog/mysql_bin
expire_logs_days=0
binlog_cache_size = 2M
max_binlog_cache_size = 4M
log-bin-index 指向 master-bin 这个文件,记录有哪些分块的Binlog文件名。
log-bin 记录Binlog文件名前缀,后缀会用数字递增
Binlog有3种格式,STATMENT,ROW,MIXED,混合格式(mixed)会在适当时候切换row和statment格式
https://dev.mysql.com/doc/refman/5.1/en/binary-log-mixed.html mysql> SHOW VARIABLES LIKE 'log_bin%'; +---------------------------------+--------------------------------------------+ | Variable_name | Value | +---------------------------------+--------------------------------------------+ | log_bin | ON | | log_bin_basename | /data/logs/mysql/binarylog/mysql_bin | | log_bin_index | /data/logs/mysql/binarylog/mysql_bin.index | | log_bin_trust_function_creators | OFF | | log_bin_use_v1_row_events | OFF | +---------------------------------+--------------------------------------------+ mysql> show variables like '%binlog%'; +-----------------------------------------+----------------------+ | Variable_name | Value | +-----------------------------------------+----------------------+ | binlog_cache_size | 32768 | | binlog_checksum | CRC32 | | binlog_direct_non_transactional_updates | OFF | | binlog_error_action | IGNORE_ERROR | | binlog_format | MIXED | | binlog_gtid_simple_recovery | OFF | | binlog_max_flush_queue_time | 0 | | binlog_order_commits | ON | | binlog_row_image | FULL | | binlog_rows_query_log_events | OFF | | binlog_stmt_cache_size | 32768 | | binlogging_impossible_mode | IGNORE_ERROR | | innodb_api_enable_binlog | OFF | | innodb_locks_unsafe_for_binlog | OFF | | max_binlog_cache_size | 18446744073709547520 | | max_binlog_size | 209715200 | | max_binlog_stmt_cache_size | 18446744073709547520 | | simplified_binlog_gtid_recovery | OFF | | sync_binlog | 0 | +-----------------------------------------+----------------------+
查看命令
mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql_bin.000001 | 167 | | mysql_bin.000002 | 167 | | mysql_bin.000003 | 167 | | mysql_bin.000004 | 167 | | mysql_bin.000005 | 2606 | | mysql_bin.000006 | 143 | | mysql_bin.000007 | 143 | | mysql_bin.000008 | 143 | | mysql_bin.000009 | 143 | | mysql_bin.000010 | 143 | | mysql_bin.000011 | 143 | | mysql_bin.000012 | 143 | | mysql_bin.000013 | 120 | | mysql_bin.000014 | 120 | +------------------+-----------+ 14 rows in set (0.14 sec) mysql> show master status; +------------------+----------+--------------+------------------+-------------------+ | File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set | +------------------+----------+--------------+------------------+-------------------+ | mysql_bin.000014 | 120 | | | | +------------------+----------+--------------+------------------+-------------------+ 1 row in set (0.00 sec) mysql> show binlog events; +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | mysql_bin.000001 | 4 | Format_desc | 1 | 120 | Server ver: 5.6.25-log, Binlog ver: 4 | | mysql_bin.000001 | 120 | Rotate | 1 | 167 | mysql_bin.000002;pos=4 | +------------------+-----+-------------+-----------+-------------+---------------------------------------+
分析日志
[root@localhost binarylog]# mysqlbinlog --no-defaults mysql_bin.000005 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #151019 21:26:05 server id 1 end_log_pos 120 CRC32 0x001e6758 Start: binlog v 4, server v 5.6.25-log created 151019 21:26:05 BINLOG ' //at 4 偏移值 //事件的日期事件,MySQL会使用他们来产生SET TIMESTAMP //服务器的服务器id //end_log_pos 下一个事件的偏移字节 //事件类型,这里是Xid,常见的还有其他,例如:Intvar,Query,Stop,Format_desc //原服务器上执行语句的线程id,用于审计和CONNECTION_ID() //exec_time对于master端的Binlog来说是执行这个event所花费的时间 //原服务器产生的错误代码
二进制日志实现稍微有点复杂,可以从更深层次来分析
日志导出
[root@localhost binarylog]# mysqlbinlog --start-position="120" --stop-position="332" mysql_bin.000005 | gzip >extra_01.sql.gz [root@localhost binarylog]# mysqlbinlog --start-position="120" --stop-position="332" /mysql_bin.000005 | mysql -uroot -p [root@localhost binarylog]# mysqlbinlog --start-datetime="2014-12-15 20:15:23" /mysql_bin.000005 --result-file=extra02.sql [root@localhost binarylog]# mysqlbinlog --start-position="120" --stop-position="332" mysql_bin.000005 mysql_bin.000006 | more [root@localhost binarylog]# mysqlbinlog --database=test --set-charset=utf8 mysql_bin.000005 mysql_bin.000006 >test.sql [root@localhost binarylog]# mysqlbinlog -urobin -p -h192.168.1.116 -P3306 --stop-datetime="2014-12-15 20:30:23" --read-from-remote-server mysql_bin.000005 |more [root@localhost binarylog]# mysqlbinlog -urobin -p -h192.168.1.177 -P3606 --read-from-remote-server -vv mysql_bin.000005 >row.sql
日志清除
//清除所有日志(不存在主从复制关系)
mysql> RESET MASTER;
//清除指定日志之前的所有日志
mysql> PURGE MASTER LOGS TO 'mysql-bin.000003';
//清除某一时间点前的所有日志
mysql> PURGE MASTER LOGS BEFORE '2015-01-01 00:00:00';
//清除 n 天前的所有日志
mysql> PURGE MASTER LOGS BEFORE CURRENT_DATE - INTERVAL 10 DAY;
五、中继日志
中继日志是一组复制在从服务器复制过程中创建的日志文件。
格式和二进制日志相同,其中包含影响数据或结构事件的记录,mysqlbinlog可用于显示其内容。它由一组的中继日志文件和包含所有中继日志文件的列表的索引文件,从主服务器的二进制日志读取然后写入到从服务器。一旦不再需要的旧中继日志文件将自动删除,没有直接的删除中继日志的机制,因为SQL线程可以负责完 成。
在下面的条件下创建新的中继日志
每次I/O线程启动时创建一个新的中继日志。
当日志被刷新时;例如,用FLUSH LOGS或 mysqladmin flush-logs。
当当前的中继日志文件变得太大时。“太大”含义的确定方法:
max_relay_log_size,如果max_relay_log_size > 0
max_binlog_size,如果max_relay_log_size = 0
master.info && relay-log.info
从服务器在数据目录中另外创建两个小文件。这些状态文件默认名为主master.info和relay-log.info
1、由I/O线程更新master.info文件。文件中的行和SHOW SLAVE STATUS显示的列的对应关系为
行 描述
1 文件中的行号
2 Master_Log_File
3 Read_Master_Log_Pos
4 Master_Host
5 Master_User
6 密码(不由SHOW SLAVE STATUS显示)
7 Master_Port
8 Connect_Retry
9 Master_SSL_Allowed
10 Master_SSL_CA_File
11 Master_SSL_CA_Path
12 Master_SSL_Cert
13 Master_SSL_Cipher
14 Master_SSL_Key
2、由SQL线程更新relay-log.info文件。文件中的行和SHOW SLAVE STATUS显示的列的对应关系为:
行 描述
1 Relay_Log_File
2 Relay_Log_Pos
3 Relay_Master_Log_File
4 Exec_Master_Log_Pos
当备份从服务器的数据时,你还应备份这两个小文件以及中继日志文件。它们用来在恢复从服务器的数据后继续进行复制。如果丢失了中继日志但仍然有relay-log.info文 件,你可以通过检查该文件来确定SQL线程已经执行的主服务器中二进制日志的程度。然后可以用Master_Log_File和Master_LOG_POS选 项执行CHANGE MASTER TO来告诉从服务器重新从该点读取二进制日志。当然,要求二进制日志仍然在主服务器上。
如果从服务器正复制LOAD DATA INFILE语句,你应也备份该目录内从服务器用于该目的的任何SQL_LOAD-*文件。从 服务器需要这些文件继续复制任何中断的LOAD DATA INFILE操作。用--slave-load-tmpdir选项来指定目录的位置。如果未指 定, 默认值为tmpdir变量的值
查看日志
SHOW RELAYLOG ['connection_name'] EVENTS
[IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count]
六、日志切割
不要忘记了切割日志.否则日志文件将会很大
In Debian (and Debian derivatives as Ubuntu etc)
1
vim /etc/logrotate.d/mysql-server
其他版本,可能需要一些改变
# - I put everything in one block and added sharedscripts, so that mysql gets # flush-logs'd only once. # Else the binary logs would automatically increase by n times every day. # - The error log is obsolete, messages go to syslog now. /var/log/mysql.log /var/log/mysql/mysql.log /var/log/mysql/mysql-slow.log { daily rotate 7 missingok create 640 mysql adm compress sharedscripts postrotate test -x /usr/bin/mysqladmin || exit 0 # If this fails, check debian.conf! MYADMIN="/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf" if [ -z "`$MYADMIN ping 2>/dev/null`" ]; then # Really no mysqld or rather a missing debian-sys-maint user? # If this occurs and is not a error please report a bug. #if ps cax | grep -q mysqld; then if killall -q -s0 -umysql mysqld; then exit 1 fi else $MYADMIN flush-logs fi endscript }