你的位置:首页 > 数据库

[数据库]mysql中日志的配置与分析


默认情况下,如果日志没有配置,则只记录错误日志,记录到syslog,配置文件 /etc/mysql/conf.d/mysqld_safe_syslog.cnf (ubuntu下)

[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/bashmysqld_sa 25638 root mem  REG        8,2 99158576 4198587 /usr/lib/locale/locale-archivemysqld_sa 25638 root mem  REG        8,2   26060 4197707 /usr/lib64/gconv/gconv-modules.cachemysqld_sa 25638 root  0r  CHR        1,3    0t0  3857 /dev/nullmysqld_sa 25638 root  1w  CHR        1,3    0t0  3857 /dev/nullmysqld_sa 25638 root  2w  CHR        1,3    0t0  3857 /dev/nullmysqld_sa 25638 root 255r  REG        8,2   24632 4210700 /usr/bin/mysqld_safemysqld  26379 mysql cwd  DIR        8,2   4096 3932444 /var/lib/mysqlmysqld  26379 mysql rtd  DIR        8,2   4096    2 /mysqld  26379 mysql txt  REG        8,2 10438848 4207116 /usr/libexec/mysqldmysqld  26379 mysql  0r  CHR        1,3    0t0  3857 /dev/nullmysqld  26379 mysql  1w  REG        8,2   10234 937095 /data/logs/mysql/mysql_error.logmysqld  26379 mysql  2w  REG        8,2   10234 937095 /data/logs/mysql/mysql_error.logmysqld  26379 mysql  3u  REG        8,2    132 937139 /data/logs/mysql/binarylog/mysql_bin.indexmysqld  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.logmysqld  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.logmysqld  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 NAMEmysqld 26379 mysql cwd  DIR        8,2   4096 3932444 /var/lib/mysqlmysqld 26379 mysql rtd  DIR        8,2   4096    2 /mysqld 26379 mysql txt  REG        8,2 10438848 4207116 /usr/libexec/mysqldmysqld 26379 mysql  0r  CHR        1,3    0t0  3857 /dev/nullmysqld 26379 mysql  1w  REG        8,2   10234 937095 /data/logs/mysql/mysql_error.logmysqld 26379 mysql  2w  REG        8,2   10234 937095 /data/logs/mysql/mysql_error.logmysqld 26379 mysql  3u  REG        8,2    132 937139 /data/logs/mysql/binarylog/mysql_bin.indexmysqld 26379 mysql  4uW REG        8,2 446693376 3933686 /var/lib/mysql/ibdata1mysqld 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_logfile0mysqld 26379 mysql  10uW REG        8,2 67108864 3933688 /var/lib/mysql/ib_logfile1mysqld 26379 mysql  11w  REG        8,2   2618 937140 /data/logs/mysql/slow_query.logmysqld 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.logmysqld 26379 mysql  14u IPv4       373448    0t0   TCP *:mysql (LISTEN)mysqld 26379 mysql  15w  REG        8,2    425 937145 /data/logs/mysql/binarylog/mysql_bin.000003mysqld 26379 mysql  17u  REG        8,2   2048 3933369 /var/lib/mysql/mysql/host.MYImysqld 26379 mysql  18u  REG        8,2     0 3933385 /var/lib/mysql/mysql/host.MYDmysqld 26379 mysql  19u  REG        8,2   2048 3933388 /var/lib/mysql/mysql/user.MYImysqld 26379 mysql  20u  REG        8,2    828 3933421 /var/lib/mysql/mysql/user.MYDmysqld 26379 mysql  21u  REG        8,2   5120 3932436 /var/lib/mysql/mysql/db.MYImysqld 26379 mysql  22u  REG        8,2   2640 3932437 /var/lib/mysql/mysql/db.MYDmysqld 26379 mysql  23u  REG        8,2   5120 3933682 /var/lib/mysql/mysql/proxies_priv.MYImysqld 26379 mysql  24u  REG        8,2   1386 3933683 /var/lib/mysql/mysql/proxies_priv.MYDmysqld 26379 mysql  25u  REG        8,2   4096 3933612 /var/lib/mysql/mysql/tables_priv.MYImysqld 26379 mysql  26u  REG        8,2     0 3933613 /var/lib/mysql/mysql/tables_priv.MYDmysqld 26379 mysql  27u  REG        8,2   4096 3933615 /var/lib/mysql/mysql/columns_priv.MYImysqld 26379 mysql  28u  REG        8,2     0 3933616 /var/lib/mysql/mysql/columns_priv.MYDmysqld 26379 mysql  29u  REG        8,2   4096 3933648 /var/lib/mysql/mysql/procs_priv.MYImysqld 26379 mysql  30u  REG        8,2     0 3933649 /var/lib/mysql/mysql/procs_priv.MYDmysqld 26379 mysql  31u  REG        8,2   1024 3933609 /var/lib/mysql/mysql/servers.MYImysqld 26379 mysql  32u  REG        8,2     0 3933610 /var/lib/mysql/mysql/servers.MYDmysqld 26379 mysql  33u  REG        8,2   4096 3933657 /var/lib/mysql/mysql/event.MYImysqld 26379 mysql  34u  REG        8,2    168 3933658 /var/lib/mysql/mysql/event.MYDmysqld 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.MYImysqld 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 Dynamiclog-output=FILEgeneral_log=ONgeneral_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_logCreate 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_logCreate 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 = onslow-query-log-file = /data/logs/mysql/slow_query.loglog-queries-not-using-indexeslog-output=FILE

动态修改

mysql> SET GLOBAL slow_query_log = 'ON';mysql> SET GLOBAL slow_query_log = 'OFF';

远程调试 (log-output=TABLE) 同上

关闭慢查询日志

log-output=NONElog_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 

详细介绍 http://dev.mysql.com/doc/refman/5.1/en/log-destinations.html

四、二进制日志

默认没有开启

二进制日志记录 MySQL 数据库中所有与更新相关的操作,即二进制日志记录了所有的 DDL(数据定义语言)语句和 DML(数据操纵语言)语句,但是不包括数据查询语句。

最重要的两个用途 :恢复数据库和主从复制

配置

http://dev.mysql.com/doc/refman/5.6/en/replication-options-binary-log.html

binlog_format=mixedmax_binlog_size=1024Mlog_bin=/data/logs/mysql/binarylog/mysql_binexpire_logs_days=0binlog_cache_size = 2Mmax_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:05BINLOG '//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

· 当当前的中继日志文件变得太大时。“太大”含义的确定方法:

o max_relay_log_size,如果max_relay_log_size > 0

o 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文件中的行号
2Master_Log_File
3Read_Master_Log_Pos
4Master_Host
5Master_User
6密码(不由SHOW SLAVE STATUS显示)
7Master_Port
8Connect_Retry
9Master_SSL_Allowed
10Master_SSL_CA_File
11Master_SSL_CA_Path
12Master_SSL_Cert
13Master_SSL_Cipher
14Master_SSL_Key

2、由SQL线程更新relay-log.info文件。文件中的行和SHOW SLAVE STATUS显示的列的对应关系为:

描述
1Relay_Log_File
2Relay_Log_Pos
3Relay_Master_Log_File
4Exec_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) 

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}



参考来源

http://tech.uc.cn/?p=716

http://howtolamp.com/lamp/mysql/5.6/log-files/

http://dev.mysql.com/doc/refman/5.1/en/error-log.html

http://dev.mysql.com/doc/refman/5.1/en/binary-log.html

http://dev.mysql.com/doc/refman/5.1/en/slow-query-log.html

http://www.pontikis.net/blog/how-and-when-to-enable-mysql-logs

https://mariadb.com/kb/en/mariadb/relay-log/

http://segmentfault.com/a/1190000003072237