3.2 日志文件
日志文件记录了影响MySQL数据库的各种类型活动。MySQL数据库中常见的日志文件有：
?错误日志（error log）
?二进制日志（binlog）
?慢查询日志（slow query log）
?查询日志（log）
这些日志文件可以帮助DBA对MySQL数据库的运行状态进行诊断，从而更好地进行数据库层面的优化。
3.2.1 错误日志
错误日志文件对MySQL的启动、运行、关闭过程进行了记录。MySQL DBA在遇到问题时应该首先查看该文件以便定位问题。该文件不仅记录了所有的错误信息，也记录一些警告信息或正确的信息。用户可以通过命令SHOW VARIABLES LIKE 'log_error'来定位该文件，如：
mysql> SHOW VARIABLES LIKE 'log_error'\G;
*************************** 1. row ***************************
Variable_name: log_error
Value: /mysql_data_2/stargazer.log
1 row in set (0.00 sec)
mysql> system hostname
stargazer
可以看到错误文件的路径和文件名，在默认情况下错误文件的文件名为服务器的主机名。如上面看到的，该主机名为stargazer，所以错误文件名为startgazer.err。当出现MySQL数据库不能正常启动时，第一个必须查找的文件应该就是错误日志文件，该文件记录了错误信息，能很好地指导用户发现问题。当数据库不能重启时，通过查错误日志文件可以得到如下内容：
[root@nineyou0-43 data]# tail -n 50 nineyou0-43.err
090924 11:31:18 mysqld started
090924 11:31:18 InnoDB: Started; log sequence number 8 2801063331
090924 11:31:19 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.host' doesn't exist
090924 11:31:19 mysqld ended
这里，错误日志文件提示了找不到权限库mysql，所以启动失败。有时用户可以直接在错误日志文件中得到优化的帮助，因为有些警告（warning）很好地说明了问题所在。而这时可以不需要通过查看数据库状态来得知，例如，下面的错误文件中的信息可能告诉用户需要增大InnoDB存储引擎的redo log：
090924 11:39:44 InnoDB: ERROR: the age of the last checkpoint is 9433712,
InnoDB: which exceeds the log group capacity 9433498.
InnoDB: If you are using big BLOB or TEXT rows, you must set the
InnoDB: combined size of log files at least 10 times bigger than the
InnoDB: largest such row.
090924 11:40:00 InnoDB: ERROR: the age of the last checkpoint is 9433823,
InnoDB: which exceeds the log group capacity 9433498.
InnoDB: If you are using big BLOB or TEXT rows, you must set the
InnoDB: combined size of log files at least 10 times bigger than the
InnoDB: largest such row.
090924 11:40:16 InnoDB: ERROR: the age of the last checkpoint is 9433645,
InnoDB: which exceeds the log group capacity 9433498.
InnoDB: If you are using big BLOB or TEXT rows, you must set the
InnoDB: combined size of log files at least 10 times bigger than the
InnoDB: largest such row.
3.2.2 慢查询日志
3.2.1小节提到可以通过错误日志得到一些关于数据库优化的信息，而慢查询日志（slow log）可帮助DBA定位可能存在问题的SQL语句，从而进行SQL语句层面的优化。例如，可以在MySQL启动时设一个阈值，将运行时间超过该值的所有SQL语句都记录到慢查询日志文件中。DBA每天或每过一段时间对其进行检查，确认是否有SQL语句需要进行优化。该阈值可以通过参数long_query_time来设置，默认值为10，代表10秒。
在默认情况下，MySQL数据库并不启动慢查询日志，用户需要手工将这个参数设为ON：
mysql> SHOW VARIABLES LIKE 'long_query_time'\G;
*************************** 1. row ***************************
Variable_name: long_query_time
Value: 10.000000
1 row in set (0.00 sec)
mysql> SHOW VARIABLES LIKE 'log_slow_queries'\G;
*************************** 1. row ***************************
Variable_name: log_slow_queries
Value: ON
1 row in set (0.00 sec)
这里有两点需要注意。首先，设置long_query_time这个阈值后，MySQL数据库会记录运行时间超过该值的所有SQL语句，但运行时间正好等于long_query_time的情况并不会被记录下。也就是说，在源代码中判断的是大于long_query_time，而非大于等于。其次，从MySQL 5.1开始，long_query_time开始以微秒记录SQL语句运行的时间，之前仅用秒为单位记录。而这样可以更精确地记录SQL的运行时间，供DBA分析。对DBA来说，一条SQL语句运行0.5秒和0.05秒是非常不同的，前者可能已经进行了表扫，后面可能是进行了索引。
另一个和慢查询日志有关的参数是log_queries_not_using_indexes，如果运行的SQL语句没有使用索引，则MySQL数据库同样会将这条SQL语句记录到慢查询日志文件。首先确认打开了log_queries_not_using_indexes：
mysql> SHOW VARIABLES LIKE 'log_queries_not_using_indexes'\G;
*************************** 1. row ***************************
Variable_name: log_queries_not_using_indexes
Value: ON
1 row in set (0.00 sec)
MySQL 5.6.5版本开始新增了一个参数log_throttle_queries_not_using_indexes，用来表示每分钟允许记录到slow log的且未使用索引的SQL语句次数。该值默认为0，表示没有限制。在生产环境下，若没有使用索引，此类SQL语句会频繁地被记录到slow log，从而导致slow log文件的大小不断增加，故DBA可通过此参数进行配置。
DBA可以通过慢查询日志来找出有问题的SQL语句，对其进行优化。然而随着MySQL数据库服务器运行时间的增加，可能会有越来越多的SQL查询被记录到了慢查询日志文件中，此时要分析该文件就显得不是那么简单和直观的了。而这时MySQL数据库提供的mysqldumpslow命令，可以很好地帮助DBA解决该问题：
[root@nh122-190 data]# mysqldumpslow nh122-190-slow.log
Reading mysql slow query log from nh122-190-slow.log
Count: 11 Time=10.00s (110s) Lock=0.00s (0s) Rows=0.0 (0), dbother[dbother]@localhost
insert into test.DbStatus select now(),(N-com_select)/(N-uptime),(N-com_insert)/(N-uptime),(N-com_update)/(N-uptime),(N-com_delete)/(N-uptime),N-(N/N),N-(N/N),N.N/N,N-N/(N*N),GetCPULoadInfo(N) from test.CheckDbStatus order by check_id desc limit N
Count: 653 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 9YOUgs_SC[9YOUgs_SC]@[192.168.43.7]
select custom_name_one from 'low_game_schema'.'role_details' where role_id='S'
rse and summarize the MySQL slow query log. Options are
--verbose verbose
--debug debug
--help write this text to standard output
-v verbose
-d debug
-s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default
al: average lock time
ar: average rows sent
at: average query time
c: count
l: lock time
r: rows sent
t: query time
-r reverse the sort order (largest last instead of first)
-t NUM just show the top n queries
-a don't abstract all numbers to N and strings to 'S'
-n NUM abstract numbers with at least n digits within names
-g PATTERN grep: only consider stmts that include this string
-h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
default is '*', i.e. match all
-i NAME name of server instance (if using mysql.server startup script)
-l don't subtract lock time from total time
如果用户希望得到执行时间最长的10条SQL语句，可以运行如下命令：
[root@nh119-141 data]# mysqldumpslow -s al -n 10 david.log
Reading mysql slow query log from david.log
Count: 5 Time=0.00s (0s) Lock=0.20s (1s) Rows=4.4 (22), Audition[Audition]@[192.168.30.108]
SELECT OtherSN, State FROM wait_friend_info WHERE UserSN = N
Count: 1 Time=0.00s (0s) Lock=0.00s (0s) Rows=1.0 (1), audition-kr[audition-kr]@[192.168.30.105]
SELECT COUNT(N) FROM famverifycode WHERE UserSN=N AND verifycode='S'
……
MySQL 5.1开始可以将慢查询的日志记录放入一张表中，这使得用户的查询更加方便和直观。慢查询表在mysql架构下，名为slow_log，其表结构定义如下：
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(11) NOT NULL,
'sql_text' mediumtext NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log'
1 row in set (0.00 sec)
参数log_output指定了慢查询输出的格式，默认为FILE，可以将它设为TABLE，然后就可以查询mysql架构下的slow_log表了，如：
mysql>SHOW VARIABLES LIKE 'log_output'\G;
+---------------+---------+
| Variable_name | Value |
+---------------+---------+
| log_output | FILE |
+---------------+---------+
1 row in set (0.00 sec)
mysql>SET GLOBAL log_output='TABLE';
Query OK, 0 rows affected (0.00 sec)
mysql>SHOW VARIABLES LIKE 'log_output'\G;
+---------------+---------+
| Variable_name | Value |
+---------------+---------+
| log_output | TABLE |
+---------------+---------+
1 row in set (0.00 sec)
mysql> select sleep(10)\G;
+-----------+
| sleep(10)|
+-----------+
| 0 |
+-----------+
1 row in set (10.01 sec)
mysql> SELECT * FROM mysql.slow_log\G;
*************************** 1. row ***************************
start_time: 2009-09-25 13:44:29
user_host: david[david] @ localhost []
query_time: 00:00:09
lock_time: 00:00:00
rows_sent: 1
rows_examined: 0
db: mysql
last_insert_id: 0
insert_id: 0
server_id: 0
sql_text: select sleep(10)
1 row in set (0.00 sec)
参数log_output是动态的，并且是全局的，因此用户可以在线进行修改。在上表中人为设置了睡眠（sleep）10秒，那么这句SQL语句就会被记录到slow_log表了。
查看slow_log表的定义会发现该表使用的是CSV引擎，对大数据量下的查询效率可能不高。用户可以把slow_log表的引擎转换到MyISAM，并在start_time列上添加索引以进一步提高查询的效率。但是，如果已经启动了慢查询，将会提示错误：
mysql>ALTER TABLE mysql.slow_log ENGINE=MyISM;
ERROR 1580 (HY000): You cannot 'ALTER' a log table if logging is enabled
mysql>SET GLOBAL slow_query_log=off;
Query OK, 0 rows affected (0.00 sec)
mysql>ALTER TABLE mysql.slow_log ENGINE=MyISAM;
Query OK, 1 row affected (0.00 sec)
Records: 1 Duplicates: 0 Warnings: 0
不能忽视的是，将slow_log表的存储引擎更改为MyISAM后，还是会对数据库造成额外的开销。不过好在很多关于慢查询的参数都是动态的，用户可以方便地在线进行设置或修改。
MySQL的slow log通过运行时间来对SQL语句进行捕获，这是一个非常有用的优化技巧。但是当数据库的容量较小时，可能因为数据库刚建立，此时非常大的可能是数据全部被缓存在缓冲池中，SQL语句运行的时间可能都是非常短的，一般都是0.5秒。
InnoSQL版本加强了对于SQL语句的捕获方式。在原版MySQL的基础上在slow log中增加了对于逻辑读取（logical reads）和物理读取（physical reads）的统计。这里的物理读取是指从磁盘进行IO读取的次数，逻辑读取包含所有的读取，不管是磁盘还是缓冲池。例如：
# Time: 111227 23:49:16
# User@Host: root[root] @ localhost [127.0.0.1]
# Query_time: 6.081214 Lock_time: 0.046800 Rows_sent: 42 Rows_examined: 727558 Logical_reads: 91584 Physical_reads: 19
use tpcc;
SET timestamp=1325000956;
SELECT orderid,customerid,employeeid,orderdate
FROM orders
WHERE orderdate IN
( SELECT MAX(orderdate)
FROM orders
GROUP BY (DATE_FORMAT(orderdate,'%Y%M'))
);
从上面的例子可以看到该子查询的逻辑读取次数是91?584次，物理读取为19次。从逻辑读与物理读的比例上看，该SQL语句可进行优化。
用户可以通过额外的参数long_query_io将超过指定逻辑IO次数的SQL语句记录到slow log中。该值默认为100，即表示对于逻辑读取次数大于100的SQL语句，记录到slow log中。而为了兼容原MySQL数据库的运行方式，还添加了参数slow_query_type，用来表示启用slow log的方式，可选值为：
?0表示不将SQL语句记录到slow log
?1表示根据运行时间将SQL语句记录到slow log
?2表示根据逻辑IO次数将SQL语句记录到slow log
?3表示根据运行时间及逻辑IO次数将SQL语句记录到slow log
3.2.3 查询日志
查询日志记录了所有对MySQL数据库请求的信息，无论这些请求是否得到了正确的执行。默认文件名为：主机名.log。如查看一个查询日志：
[root@nineyou0-43 data]# tail nineyou0-43.log
090925 11:00:24 44 Connect zlm@192.168.0.100 on
44 Query SET AUTOCOMMIT=0
44 Query set autocommit=0
44 Quit
090925 11:02:37 45 Connect Access denied for user 'root'@'localhost' (using password: NO)
090925 11:03:51 46 Connect Access denied for user 'root'@'localhost' (using password: NO)
090925 11:04:38 23 Query rollback
通过上述查询日志会发现，查询日志甚至记录了对Access denied的请求，即对于未能正确执行的SQL语句，查询日志也会进行记录。同样地，从MySQL 5.1开始，可以将查询日志的记录放入mysql架构下的general_log表中，该表的使用方法和前面小节提到的slow_log基本一样，这里不再赘述。
3.2.4 二进制日志
二进制日志（binary log）记录了对MySQL数据库执行更改的所有操作，但是不包括SELECT和SHOW这类操作，因为这类操作对数据本身并没有修改。然而，若操作本身并没有导致数据库发生变化，那么该操作可能也会写入二进制日志。例如：
mysql> UPDATE t SET a = 1 WHERE a = 2;
Query OK, 0 rows affected (0.00 sec)
Rows matched: 0 Changed: 0 Warnings: 0
mysql> SHOW MASTER STATUS\G;
*************************** 1. row ***************************
File: mysqld.000008
Position: 383
Binlog_Do_DB:
Binlog_Ignore_DB:
Executed_Gtid_Set:
1 row in set (0.00 sec)
mysql> SHOW BINLOG EVENTS IN 'mysqld.000008'\G;
*************************** 1. row ***************************
Log_name: mysqld.000008
Pos: 4
Event_type: Format_desc
Server_id: 1
End_log_pos: 120
Info: Server ver: 5.6.6-m9-log, Binlog ver: 4
*************************** 2. row ***************************
Log_name: mysqld.000008
Pos: 120
Event_type: Query
Server_id: 1
End_log_pos: 199
Info: BEGIN
*************************** 3. row ***************************
Log_name: mysqld.000008
Pos: 199
Event_type: Query
Server_id: 1
End_log_pos: 303
Info: use 'test'; UPDATE t SET a = 1 WHERE a = 2
*************************** 4. row ***************************
Log_name: mysqld.000008
Pos: 303
Event_type: Query
Server_id: 1
End_log_pos: 383
Info: COMMIT
4 rows in set (0.00 sec)
从上述例子中可以看到，MySQL数据库首先进行UPDATE操作，从返回的结果看到Changed为0，这意味着该操作并没有导致数据库的变化。但是通过命令SHOW BINLOG EVENT可以看出在二进制日志中的确进行了记录。
如果用户想记录SELECT和SHOW操作，那只能使用查询日志，而不是二进制日志。此外，二进制日志还包括了执行数据库更改操作的时间等其他额外信息。总的来说，二进制日志主要有以下几种作用。
?恢复（recovery）：某些数据的恢复需要二进制日志，例如，在一个数据库全备文件恢复后，用户可以通过二进制日志进行point-in-time的恢复。
?复制（replication）：其原理与恢复类似，通过复制和执行二进制日志使一台远程的MySQL数据库（一般称为slave或standby）与一台MySQL数据库（一般称为master或primary）进行实时同步。
?审计（audit）：用户可以通过二进制日志中的信息来进行审计，判断是否有对数据库进行注入的攻击。
通过配置参数log-bin［=name］可以启动二进制日志。如果不指定name，则默认二进制日志文件名为主机名，后缀名为二进制日志的序列号，所在路径为数据库所在目录（datadir），如：
mysql> show variables like 'datadir';
+---------------+----------------------------+
| Variable_name | Value |
+---------------+----------------------------+
| datadir | /usr/local/mysql/data/ |
+---------------+----------------------------+
1 row in set (0.00 sec)
mysql> system ls -lh /usr/local/mysql/data/;
total 2.1G
-rw-rw---- 1 mysql mysql 6.5M Sep 25 15:13 bin_log.000001
-rw-rw---- 1 mysql mysql 17 Sep 25 00:32 bin_log.index
-rw-rw---- 1 mysql mysql 300M Sep 25 15:13 ibdata1
-rw-rw---- 1 mysql mysql 256M Sep 25 15:13 ib_logfile0
-rw-rw---- 1 mysql mysql 256M Sep 25 15:13 ib_logfile1
drwxr-xr-x 2 mysql mysql 4.0K May 7 10:08 mysql
drwx------ 2 mysql mysql 4.0K May 7 10:09 test
这里的bin_log.00001即为二进制日志文件，我们在配置文件中指定了名字，所以没有用默认的文件名。bin_log.index为二进制的索引文件，用来存储过往产生的二进制日志序号，在通常情况下，不建议手工修改这个文件。
二进制日志文件在默认情况下并没有启动，需要手动指定参数来启动。可能有人会质疑，开启这个选项是否会对数据库整体性能有所影响。不错，开启这个选项的确会影响性能，但是性能的损失十分有限。根据MySQL官方手册中的测试表明，开启二进制日志会使性能下降1%。但考虑到可以使用复制（replication）和point-in-time的恢复，这些性能损失绝对是可以且应该被接受的。
以下配置文件的参数影响着二进制日志记录的信息和行为：
?max_binlog_size
?binlog_cache_size
?sync_binlog
?binlog-do-db
?binlog-ignore-db
?log-slave-update
?binlog_format
参数max_binlog_size指定了单个二进制日志文件的最大值，如果超过该值，则产生新的二进制日志文件，后缀名+1，并记录到.index文件。从MySQL 5.0开始的默认值为1?073?741?824，代表1?G（在之前版本中max_binlog_size默认大小为1.1G）。
当使用事务的表存储引擎（如InnoDB存储引擎）时，所有未提交（uncommitted）的二进制日志会被记录到一个缓存中去，等该事务提交（committed）时直接将缓冲中的二进制日志写入二进制日志文件，而该缓冲的大小由binlog_cache_size决定，默认大小为32K。此外，binlog_cache_size是基于会话（session）的，也就是说，当一个线程开始一个事务时，MySQL会自动分配一个大小为binlog_cache_size的缓存，因此该值的设置需要相当小心，不能设置过大。当一个事务的记录大于设定的binlog_cache_size时，MySQL会把缓冲中的日志写入一个临时文件中，因此该值又不能设得太小。通过SHOW GLOBAL STATUS命令查看binlog_cache_use、binlog_cache_disk_use的状态，可以判断当前binlog_cache_size的设置是否合适。Binlog_cache_use记录了使用缓冲写二进制日志的次数，binlog_cache_disk_use记录了使用临时文件写二进制日志的次数。现在来看一个数据库的状态：
mysql> show variables like 'binlog_cache_size';
+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| binlog_cache_size | 32768 |
+-------------------+-------+
1 row in set (0.00 sec)
mysql> show global status like 'binlog_cache%';
+-----------------------+--------------+
| Variable_name | Value |
+-----------------------+---------------+
| binlog_cache_disk_use | 0 |
| binlog_cache_use | 33553 |
+-----------------------+---------------+
2 rows in set (0.00 sec)
使用缓冲次数为33?553，临时文件使用次数为0。看来32KB的缓冲大小对于当前这个MySQL数据库完全够用，暂时没有必要增加binlog_cache_size的值。
在默认情况下，二进制日志并不是在每次写的时候同步到磁盘（用户可以理解为缓冲写）。因此，当数据库所在操作系统发生宕机时，可能会有最后一部分数据没有写入二进制日志文件中，这会给恢复和复制带来问题。参数sync_binlog=［N］表示每写缓冲多少次就同步到磁盘。如果将N设为1，即sync_binlog=1表示采用同步写磁盘的方式来写二进制日志，这时写操作不使用操作系统的缓冲来写二进制日志。sync_binlog的默认值为0，如果使用InnoDB存储引擎进行复制，并且想得到最大的高可用性，建议将该值设为ON。不过该值为ON时，确实会对数据库的IO系统带来一定的影响。
但是，即使将sync_binlog设为1，还是会有一种情况导致问题的发生。当使用InnoDB存储引擎时，在一个事务发出COMMIT动作之前，由于sync_binlog为1，因此会将二进制日志立即写入磁盘。如果这时已经写入了二进制日志，但是提交还没有发生，并且此时发生了宕机，那么在MySQL数据库下次启动时，由于COMMIT操作并没有发生，这个事务会被回滚掉。但是二进制日志已经记录了该事务信息，不能被回滚。这个问题可以通过将参数innodb_support_xa设为1来解决，虽然innodb_support_xa与XA事务有关，但它同时也确保了二进制日志和InnoDB存储引擎数据文件的同步。
参数binlog-do-db和binlog-ignore-db表示需要写入或忽略写入哪些库的日志。默认为空，表示需要同步所有库的日志到二进制日志。
如果当前数据库是复制中的slave角色，则它不会将从master取得并执行的二进制日志写入自己的二进制日志文件中去。如果需要写入，要设置log-slave-update。如果需要搭建master=>slave=>slave架构的复制，则必须设置该参数。
binlog_format参数十分重要，它影响了记录二进制日志的格式。在MySQL 5.1版本之前，没有这个参数。所有二进制文件的格式都是基于SQL语句（statement）级别的，因此基于这个格式的二进制日志文件的复制（Replication）和Oracle 的逻辑Standby有点相似。同时，对于复制是有一定要求的。如在主服务器运行rand、uuid等函数，又或者使用触发器等操作，这些都可能会导致主从服务器上表中数据的不一致（not sync）。另一个影响是，会发现InnoDB存储引擎的默认事务隔离级别是REPEATABLE READ。这其实也是因为二进制日志文件格式的关系，如果使用READ COMMITTED的事务隔离级别（大多数数据库，如Oracle，Microsoft SQL Server数据库的默认隔离级别），会出现类似丢失更新的现象，从而出现主从数据库上的数据不一致。
MySQL 5.1开始引入了binlog_format参数，该参数可设的值有STATEMENT、ROW和MIXED。
（1）STATEMENT格式和之前的MySQL版本一样，二进制日志文件记录的是日志的逻辑SQL语句。
（2）在ROW格式下，二进制日志记录的不再是简单的SQL语句了，而是记录表的行更改情况。基于ROW格式的复制类似于Oracle的物理Standby（当然，还是有些区别）。同时，对上述提及的Statement格式下复制的问题予以解决。从MySQL 5.1版本开始，如果设置了binlog_format为ROW，可以将InnoDB的事务隔离基本设为READ COMMITTED，以获得更好的并发性。
（3）在MIXED格式下，MySQL默认采用STATEMENT格式进行二进制日志文件的记录，但是在一些情况下会使用ROW格式，可能的情况有：
1）表的存储引擎为NDB，这时对表的DML操作都会以ROW格式记录。
2）使用了UUID()、USER()、CURRENT_USER()、FOUND_ROWS()、ROW_COUNT()等不确定函数。
3）使用了INSERT DELAY语句。
4）使用了用户定义函数（UDF）。
5）使用了临时表（temporary table）。
此外，binlog_format参数还有对于存储引擎的限制，如表3-1所示。
binlog_format是动态参数，因此可以在数据库运行环境下进行更改，例如，我们可以将当前会话的binlog_format设为ROW，如：
mysql>SET @@session.binlog_format='ROW';
Query OK, 0 rows affected (0.00 sec)
mysql>SELECT@@session.binlog_format;
+-------------------------------+
| @@session.binlog_format |
+-------------------------------+
| ROW |
+-------------------------------+
1 row in set (0.00 sec)
当然，也可以将全局的binlog_format设置为想要的格式，不过通常这个操作会带来问题，运行时要确保更改后不会对复制带来影响。如：
mysql>SET GLOBAL binlog_format='ROW';
Query OK, 0 rows affected (0.00 sec)
mysql>SELECT @@global.binlog_format;
+------------------------------+
| @@global.binlog_format |
+------------------------------+
| ROW |
+------------------------------+
1 row in set (0.00 sec)
在通常情况下，我们将参数binlog_format设置为ROW，这可以为数据库的恢复和复制带来更好的可靠性。但是不能忽略的一点是，这会带来二进制文件大小的增加，有些语句下的ROW格式可能需要更大的容量。比如我们有两张一样的表，大小都为100W，分别执行UPDATE操作，观察二进制日志大小的变化：
mysql>SELECT @@session.binlog_format\G;
*************************** 1. row ***************************
@@session.binlog_format: STATEMENT
1 row in set (0.00 sec)
mysql>SHOW MASTER STATUS\G;
*************************** 1. row ***************************
File: test.000003
Position: 106
Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)
mysql>UPDATE t1 SET username=UPPER(username);
Query OK, 89279 rows affected (1.83 sec)
Rows matched: 100000 Changed: 89279 Warnings: 0
mysql>SHOW MASTER STATUS\G;
*************************** 1. row ***************************
File: test.000003
Position: 306
Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)
可以看到，在binlog_format格式为STATEMENT的情况下，执行UPDATE语句后二进制日志大小只增加了200字节（306-106）。如果使用ROW格式，同样对t2表进行操作，可以看到：
mysql>SET SESSION binlog_format='ROW';
Query OK, 0 rows affected (0.00 sec)
mysql>SHOW MASTER STATUS\G;
*************************** 1. row ***************************
File: test.000003
Position: 306
Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)
mysql>UPDATE t2 SET username=UPPER(username);
Query OK, 89279 rows affected (2.42 sec)
Rows matched: 100000 Changed: 89279 Warnings: 0
mysql>SHOW MASTER STATUS\G;
*************************** 1. row ***************************
File: test.000003
Position: 13782400
Binlog_Do_DB:
Binlog_Ignore_DB:
1 row in set (0.00 sec)
这时会惊讶地发现，同样的操作在ROW格式下竟然需要13?782?094字节，二进制日志文件的大小差不多增加了13MB，要知道t2表的大小也不超过17MB。而且执行时间也有所增加（这里我设置了sync_binlog=1）。这是因为这时MySQL数据库不再将逻辑的SQL操作记录到二进制日志中，而是记录对于每行的更改。
上面的这个例子告诉我们，将参数binlog_format设置为ROW，会对磁盘空间要求有一定的增加。而由于复制是采用传输二进制日志方式实现的，因此复制的网络开销也有所增加。
二进制日志文件的文件格式为二进制（好像有点废话），不能像错误日志文件、慢查询日志文件那样用cat、head、tail等命令来查看。要查看二进制日志文件的内容，必须通过MySQL提供的工具mysqlbinlog。对于STATEMENT格式的二进制日志文件，在使用mysqlbinlog后，看到的就是执行的逻辑SQL语句，如：
[root@nineyou0-43 data]# mysqlbinlog --start-position=203 test.000004
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
….
#090927 15:43:11 server id 1 end_log_pos 376 Query thread_id=188 exec_time=1 error_code=0
SET TIMESTAMP=1254037391/*!*/;
update t2 set username=upper(username) where id=1
/*!*/;
# at 376
#090927 15:43:11 server id 1 end_log_pos 403 Xid = 1009
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
通过SQL语句UPDATE t2 SET username=UPPER（username）WHERE id=1可以看到，二进制日志的记录采用SQL语句的方式（为了排版的方便，省去了一些开始的信息）。在这种情况下，mysqlbinlog和Oracle LogMiner类似。但是如果这时使用ROW格式的记录方式，会发现mysqlbinlog的结果变得“不可读”（unreadable），如：
[root@nineyou0-43 data]# mysqlbinlog --start-position=1065 test.000004
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
……
# at 1135
# at 1198
#090927 15:53:52 server id 1 end_log_pos 1198 Table_map: 'member'.'t2' mapped to number 58
#090927 15:53:52 server id 1 end_log_pos 1378 Update_rows: table id 58 flags: STMT_END_F
BINLOG '
EBq/ShMBAAAAPwAAAK4EAAAAADoAAAAAAAAABm1lbWJlcgACdDIACgMPDw/+CgsPAQwKJAAoAEAA
/gJAAAAA
EBq/ShgBAAAAtAAAAGIFAAAQADoAAAAAAAEACv////8A/AEAAAALYWxleDk5ODh5b3UEOXlvdSA3
Y2JiMzI1MmJhNmI3ZTljNDIyZmFjNTMzNGQyMjA1NAFNLacPAAAAAABjEnpxPBIAAAD8AQAAAAtB
TEVYOTk4OFlPVQQ5eW91IDdjYmIzMjUyYmE2YjdlOWM0MjJmYWM1MzM0ZDIyMDU0AU0tpw8AAAAA
AGMSenE8EgAA
'/*!*/;
# at 1378
#090927 15:53:52 server id 1 end_log_pos 1405 Xid = 1110
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
这里看不到执行的SQL语句，反而是一大串用户不可读的字符。其实只要加上参数-v或-vv就能清楚地看到执行的具体信息了。-vv会比-v多显示出更新的类型。加上-vv选项，可以得到：
[root@nineyou0-43 data]# mysqlbinlog -vv --start-position=1065 test.000004
……
BINLOG '
EBq/ShMBAAAAPwAAAK4EAAAAADoAAAAAAAAABm1lbWJlcgACdDIACgMPDw/+CgsPAQwKJAAoAEAA
/gJAAAAA
EBq/ShgBAAAAtAAAAGIFAAAQADoAAAAAAAEACv////8A/AEAAAALYWxleDk5ODh5b3UEOXlvdSA3
Y2JiMzI1MmJhNmI3ZTljNDIyZmFjNTMzNGQyMjA1NAFNLacPAAAAAABjEnpxPBIAAAD8AQAAAAtB
TEVYOTk4OFlPVQQ5eW91IDdjYmIzMjUyYmE2YjdlOWM0MjJmYWM1MzM0ZDIyMDU0AU0tpw8AAAAA
AGMSenE8EgAA
'/*!*/;
### UPDATE member.t2
### WHERE
### @1=1 /* INT meta=0 nullable=0 is_null=0 */
### @2='david' /* VARSTRING(36) meta=36 nullable=0 is_null=0 */
### @3='family' /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
### @4='7cbb3252ba6b7e9c422fac5334d22054' /* VARSTRING(64) meta=64 nullable=0 is_null=0 */
### @5='M' /* STRING(2) meta=65026 nullable=0 is_null=0 */
### @6='2009:09:13' /* DATE meta=0 nullable=0 is_null=0 */
### @7='00:00:00' /* TIME meta=0 nullable=0 is_null=0 */
### @8='' /* VARSTRING(64) meta=64 nullable=0 is_null=0 */
### @9=0 /* TINYINT meta=0 nullable=0 is_null=0 */
### @10=2009-08-11 16:32:35 /* DATETIME meta=0 nullable=0 is_null=0 */
### SET
### @1=1 /* INT meta=0 nullable=0 is_null=0 */
### @2='DAVID' /* VARSTRING(36) meta=36 nullable=0 is_null=0 */
### @3=family /* VARSTRING(40) meta=40 nullable=0 is_null=0 */
### @4='7cbb3252ba6b7e9c422fac5334d22054' /* VARSTRING(64) meta=64 nullable=0 is_null=0 */
### @5='M' /* STRING(2) meta=65026 nullable=0 is_null=0 */
### @6='2009:09:13' /* DATE meta=0 nullable=0 is_null=0 */
### @7='00:00:00' /* TIME meta=0 nullable=0 is_null=0 */
### @8='' /* VARSTRING(64) meta=64 nullable=0 is_null=0 */
### @9=0 /* TINYINT meta=0 nullable=0 is_null=0 */
### @10=2009-08-11 16:32:35 /* DATETIME meta=0 nullable=0 is_null=0 */
# at 1378
#090927 15:53:52 server id 1 end_log_pos 1405 Xid = 1110
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
现在mysqlbinlog向我们解释了它具体做的事情。可以看到，一句简单的update t2 set username=upper(username)where id=1语句记录了对于整个行更改的信息，这也解释了为什么前面更新了10W行的数据，在ROW格式下，二进制日志文件会增大13MB。
