MySQL的各种日志

错误日志：

记录了mysql在执行过程中的错误信息，但是不仅仅记录错误信息，还有其他信息：

mysql执行过程总的错误信息

mysql执行过程中的警告信息

events scheduler运行时产生的信息

mysql启动和停止过程中输出的信息，未必是错误信息

主从复制中，从服务器IO复制线程的启动信息

mysql> show variables like '%log_error%';

+---------------------+-------------------------------------------------+

| Variable_name | Value |

+---------------------+-------------------------------------------------+

| binlog_error_action | ABORT_SERVER |

| log_error | /data1/mysql_root/data/20143/TENCENT64.site.err |

+---------------------+-------------------------------------------------+

之前说过log_warnings变量的值也与错误日志有关，那么log_warnings代表什么意思呢？

log_warnings的值为0：表示不记录警告信息

log_warnings的值为1：警告记录一并记录到错误日志中

log_warnings的值大于1：表示‘失败的连接’的信息和创建新连接时‘拒绝访问’类的错误会记录到错误日志中。

mysql> show variables like '%log_warnings%';

+---------------+-------+

| Variable_name | Value |

+---------------+-------+

| log_warnings | 1 |

+---------------+-------+

如果想要用就修改该参数，需要在配置文件中加入：

log_warnings=2

重启mysql

查询日志：

查询日志在mysql中被称作‘通用日志’，不要错误的以为仅仅记录select的记录，查询日志记录了mysql执行的所有命令，不管执行的语句是否正确，都会被记录！

由于mysql操作指令可能非常多而且操作频繁，因为开启了查询日志后可能需要不停的写入查询日志，这样会增大服务器的IO压力，增加系统开销，因此默认情况下，查询日志是没有开启的！

如果开启查询日志，我们可以通过三种方式存储查询日志：

1：存放在指定的文件中

2：存放于mysql.general_log表中

3：同时存放于上面的两个位置

看下查询日志的具体参数：

mysql> show variables where variable_name like '%general_log%' or variable_name="log_output";

+------------------+--------------------------------------------+

| Variable_name | Value |

+------------------+--------------------------------------------+

| general_log | OFF |

| general_log_file | /data1/mysql_root/data/20143/TENCENT64.log |

| log_output | FILE |

+------------------+--------------------------------------------+

general_log ：表示查询日志是否开启

我们尝试修改下改参数看看效果：

mysql> set global general_log=ON;

Query OK, 0 rows affected (0.00 sec)

mysql> show variables where variable_name like '%general_log%' or variable_name="log_output";

+------------------+-----------------------------+

| Variable_name | Value |

+------------------+-----------------------------+

| general_log | ON |

| general_log_file | /var/lib/mysql/VM-75-68.log |

| log_output | FILE |

+------------------+-----------------------------+

mysql> set global log_output='FILE,TABLE';

Query OK, 0 rows affected (0.00 sec)

mysql> show variables where variable_name like '%general_log%' or variable_name="log_output";

+------------------+-----------------------------+

| Variable_name | Value |

+------------------+-----------------------------+

| general_log | ON |

| general_log_file | /var/lib/mysql/VM-75-68.log |

| log_output | FILE,TABLE |

+------------------+-----------------------------+

OK，参数修改好了。

mysql> use relay;

Reading table information for completion of table and column names

You can turn off this feature to get a quicker startup with -A

Database changed

mysql> show tables;

+-----------------+

| Tables_in_relay |

+-----------------+

| account00 |

+-----------------+

1 row in set (0.00 sec)

mysql> select * from account00;

+-------------+--------------+-----------+--------------+

+-------------+--------------+-----------+--------------+

| 21323211 | 787492757373 | 314342427 | 989997979799 |

| 21323212 | 787492757374 | 314342426 | 989997979798 |

| 21323213 | 787492757375 | 314342425 | 989997979797 |

+-------------+--------------+-----------+--------------+

3 rows in set (0.00 sec)

mysql> ni hao ya;

ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'ni hao ya' at line 1

我们执行了一些操作，下面看下日志的记录情况。

mysql> select * from mysql.general_log;

+---------------------+---------------------------+-----------+-----------+--------------+---------------------------------------------------------------------------------------+

+---------------------+---------------------------+-----------+-----------+--------------+---------------------------------------------------------------------------------------+

| 2019-10-10 10:17:57 | root[root] @ localhost [] | 9 | 2 | Query | show variables where variable_name like '%general_log%' or variable_name="log_output" |

| 2019-10-10 10:18:54 | root[root] @ localhost [] | 9 | 2 | Query | show databases |

| 2019-10-10 10:19:00 | root[root] @ localhost [] | 9 | 2 | Query | SELECT DATABASE() |

| 2019-10-10 10:19:00 | root[root] @ localhost [] | 9 | 2 | Init DB | relay |

| 2019-10-10 10:19:00 | root[root] @ localhost [] | 9 | 2 | Query | show databases |

| 2019-10-10 10:19:00 | root[root] @ localhost [] | 9 | 2 | Query | show tables |

| 2019-10-10 10:19:00 | root[root] @ localhost [] | 9 | 2 | Field List | account00 |

| 2019-10-10 10:19:02 | root[root] @ localhost [] | 9 | 2 | Query | show tables |

| 2019-10-10 10:19:10 | root[root] @ localhost [] | 9 | 2 | Query | select * from account00 |

| 2019-10-10 10:19:22 | root[root] @ localhost [] | 9 | 2 | Query | show variables where variable_name like '%general_log%' or variable_name="log_output" |

| 2019-10-10 10:20:10 | root[root] @ localhost [] | 9 | 2 | Query | select * from mysql.general_log |

+---------------------+---------------------------+-----------+-----------+--------------+---------------------------------------------------------------------------------------+

上面是表的记录情况，下面看看日志文件的记录情况：

[root@VM-75-68 mysql]# cat VM-75-68.log

/usr/local/mysql/bin/mysqld, Version: 5.6.41-log (MySQL Community Server (GPL)). started with:

Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock

Time Id Command Argument

191010 10:17:32 9 Query show variables where variable_name like '%general_log%' or variable_name="log_output"

191010 10:17:55 9 Query set global log_output='FILE,TABLE'

191010 10:17:57 9 Query show variables where variable_name like '%general_log%' or variable_name="log_output"

191010 10:18:54 9 Query show databases

191010 10:19:00 9 Query SELECT DATABASE()

9 Init DB relay

9 Query show databases

9 Query show tables

9 Field List account00

191010 10:19:02 9 Query show tables

191010 10:19:10 9 Query select * from account00

191010 10:19:22 9 Query show variables where variable_name like '%general_log%' or variable_name="log_output"

191010 10:20:10 9 Query select * from mysql.general_log

191010 10:20:45 9 Query select * from mysql.general_log

191010 10:21:17 9 Query delete from account00

191010 10:21:19 9 Query select * from mysql.general_log

191010 10:22:17 9 Quit

[root@VM-75-68 mysql]# pwd

/var/lib/mysql

OK，也有了！

这里查询日志的功能搞清楚了，但是要记住，一般线上咱们是不开启这个参数的！

慢查询日志：

某些sql的执行完毕时间花费得比较长，我们将这种响应比较慢的语句记录在慢查询日志中，不要被名字误导，除了查询语句，其他所有的更新语句只要超过定义的慢查询时间，都算作慢查询！

默认情况下，慢查询日志也是不开启的，开启之后，还需要定义超时时间，至于定义为多少，就需要看具体业务了！

mysql> show variables like '%slow%log%';

+---------------------+---------------------------------------------+

| Variable_name | Value |

+---------------------+---------------------------------------------+

| slow_query_log | ON |

| slow_query_log_file | /data1/mysql_root/data/20125/slow_query.log |

+---------------------+---------------------------------------------+

2 rows in set (0.00 sec)

mysql> show variables like '%long_query%';

+-----------------+-----------+

| Variable_name | Value |

+-----------------+-----------+

| long_query_time | 10.000000 |

+-----------------+-----------+

我们修改相关参数：

mysql> set global long_query_time=3;

Query OK, 0 rows affected (0.00 sec)

mysql> set global slow_query_log=ON;

Query OK, 0 rows affected (0.00 sec)

mysql> select sleep(5); #手动执行超时语句！

+----------+

| sleep(5) |

+----------+

| 0 |

+----------+

1 row in set (4.99 sec)

看下记录情况：

mysql> select * from mysql.slow_log;

+---------------------+---------------------------+------------+-----------+-----------+---------------+----+----------------+-----------+-----------+-----------------+-----------+

+---------------------+---------------------------+------------+-----------+-----------+---------------+----+----------------+-----------+-----------+-----------------+-----------+

| 2019-10-10 10:35:29 | root[root] @ localhost [] | 00:00:05 | 00:00:00 | 1 | 0 | | 0 | 0 | 2 | select sleep(5) | 12 |

| 2019-10-10 10:35:49 | root[root] @ localhost [] | 00:00:05 | 00:00:00 | 1 | 0 | | 0 | 0 | 2 | select sleep(5) | 12 |

| 2019-10-10 10:35:55 | root[root] @ localhost [] | 00:00:04 | 00:00:00 | 1 | 0 | | 0 | 0 | 2 | select sleep(4) | 12 |

+---------------------+---------------------------+------------+-----------+-----------+---------------+----+----------------+-----------+-----------+-----------------+-----------+

我们还能够使用下面的语句查看从mysql进程启动到当前的时间一共记录了多少条慢查询日志：

mysql> show global status like '%slow_queries%';

+---------------+-------+

| Variable_name | Value |

+---------------+-------+

| Slow_queries | 3 |

+---------------+-------+

1 row in set (0.00 sec)

注意：当mysql重启后，这里的数据会被清零，但是慢查询日志和slow_log表中的日志不会被清除。

下面看下慢查询日志的文件内容：

[root@VM-75-68 mysql]# cat VM-75-68-slow.log

/usr/local/mysql/bin/mysqld, Version: 5.6.41-log (MySQL Community Server (GPL)). started with:

Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock

Time Id Command Argument

# Time: 191010 10:35:29

# User@Host: root[root] @ localhost [] Id: 12

# Query_time: 5.000320 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0

SET timestamp=1570674929;

select sleep(5);

# Time: 191010 10:35:49

# User@Host: root[root] @ localhost [] Id: 12

# Query_time: 5.000206 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0

SET timestamp=1570674949;

select sleep(5);

# Time: 191010 10:35:55

# User@Host: root[root] @ localhost [] Id: 12

# Query_time: 4.000201 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0

SET timestamp=1570674955;

select sleep(4);

[root@VM-75-68 mysql]# pwd

/var/lib/mysql

同时，mysql还自带了慢查询日志的统计分析工具：mysqldumpslow

[root@VM-75-68 mysql]# /usr/local/mysql/bin/mysqldumpslow -s l VM-75-68-slow.log

Reading mysql slow query log from VM-75-68-slow.log

Count: 3 Time=4.67s (14s) Lock=0.00s (0s) Rows=1.0 (3), root[root]@localhost

select sleep(N)

其中，‘-s’表示排序，根据什么排序呢？看‘-s’后面的参数：

c：执行计数，执行次数多的语句排在前面。

l：锁定时间

r：返回记录

t：执行时间

al：平均锁定时间

ar：平均返回记录数

at：平均执行时间

我们还能使用-t选项指定读取前几条信息：

[root@VM-75-68 mysql]# /usr/local/mysql/bin/mysqldumpslow -s t -t 2 VM-75-68-slow.log

Reading mysql slow query log from VM-75-68-slow.log

Count: 3 Time=4.67s (14s) Lock=0.00s (0s) Rows=1.0 (3), root[root]@localhost

select sleep(N)

Died at /usr/local/mysql/bin/mysqldumpslow line 161, <> chunk 3.

只读取前两条信息，但是这里只有一条，仅仅展示语句的用法！

二进制日志：

二进制日志有三种记录方式：

这里我看了下，腾讯的线上云DB采用的是MIXED方式：

mysql> show variables like '%binlog_format%';

+---------------+-------+

| Variable_name | Value |

+---------------+-------+

| binlog_format | MIXED |

+---------------+-------+

相关参数：

mysql> show variables like '%log_bin%';

+---------------------------------+--------------------------------------------+

| Variable_name | Value |

+---------------------------------+--------------------------------------------+

| log_bin | ON |

| log_bin_basename | /data/mysql_root/log/20125/mysql-bin |

| log_bin_index | /data/mysql_root/log/20125/mysql-bin.index |

| log_bin_trust_function_creators | ON |

| log_bin_use_v1_row_events | OFF |

| sql_log_bin | ON |

+---------------------------------+--------------------------------------------+

mysql> show variables like '%binlog%';

+-----------------------------------------+----------------------+

| Variable_name | Value |

+-----------------------------------------+----------------------+

| max_binlog_cache_size | 18446744073709547520 |

| max_binlog_size | 1073741824 |

| sync_binlog | 0 |

+-----------------------------------------+----------------------+

其中：

log_bin：用于控制是否开启二进制日志，默认情况下可能这个值为OFF，如果想要开启只需要把这个值设置为二进制日志的文件名即可，但需要注意的是，这里不能在交互式界面直接set，需要在my.cnf中定义：log_bin=mybinlog，重启mysql就能在mysql的数据目录下生成mybinlog为前缀的二进制日志文件，如果想要禁用，在配置文件里删除这条参数即可；

sql_log_bin：用于标识当前会话的操作是否会被记录在二进制日志中，若该值为ON，标识当前会话的操作会被记录在二进制日志中，所以即使开启了二进制日志功能，如果这个值为OFF，当前会话的操作也不会被记录在日志中，同样，主从结构中的从db也就不会收到重演指令；该变量是会话级别变量，只能使用set，而不能使用set global，同时也不能存在于my.cnf中，否则mysql没法启动！

binlog_format：上面解释过

max_binlog_size：单个二进制文件的最大大小，单位是字节，这里显示的是1G，超过这个值，就会自动滚动。

sync_binlog：之前总结的‘双一’模式中的其中一个值，由于二进制日志一开始存在于内存中；

该值为1：每次事务提交之后都会立即将内存中的二进制日志同步到磁盘中的二进制日志文件中，安全性最高，性能最差；

该值为0：表示当事务提交后，不会立即将内存中的同步到磁盘中的bbinlog，而是由文件系统决定什么时候刷写，取决于文件系统的缓存机制，此时一旦宕机，将丢失未从内存中同步到磁盘中的binlog，因此安全性最差，但是性能最高；

该值为N：在有N次事务提交之后，将binlog从内存中刷写到磁盘中，该值越大，可能丢失的日志就越多，同时性能也就越好！

如果设置0或N,推荐为操作系统准备带有备用电源的缓存！

从上面参数看到这里mysql已经开启了二进制日志：

[root@VM-75-68 mysql]# pwd

/var/lib/mysql

[root@VM-75-68 mysql]# ll

total 628432

-rw-rw----. 1 mysql mysql 56 May 17 20:46 auto.cnf

-rw-rw----. 1 mysql mysql 79691776 Oct 10 10:21 ibdata1

-rw-rw----. 1 mysql mysql 268435456 Oct 10 10:21 ib_logfile0

-rw-rw----. 1 mysql mysql 268435456 May 17 20:46 ib_logfile1

-rw-rw----. 1 mysql mysql 132 Oct 10 13:29 master.info

drwx------. 2 mysql mysql 4096 May 17 20:46 mysql

-rw-rw----. 1 mysql mysql 2160 May 21 03:53 mysql-bin.000001

-rw-rw----. 1 mysql mysql 43064 Jul 24 01:42 mysql-bin.000002

-rw-rw----. 1 mysql mysql 3909 Jul 25 00:19 mysql-bin.000003

-rw-rw----. 1 mysql mysql 190 Sep 11 20:35 mysql-bin.index

除了一些二进制文件，还有一个index文件，这里后面再看。

查看二进制文件列表：

mysql> show binary logs;

+------------------+-----------+

| Log_name | File_size |

+------------------+-----------+

| mysql-bin.000001 | 2160 |

| mysql-bin.000002 | 43064 |

| mysql-bin.000003 | 3909 |

+------------------+-----------+

或者：

mysql> show master logs;

+------------------+-----------+

| Log_name | File_size |

+------------------+-----------+

| mysql-bin.000001 | 2160 |

| mysql-bin.000002 | 43064 |

| mysql-bin.000003 | 3909 |

+------------------+-----------+

查看具体binlog内容：

mysql> show binlog events in 'mysql-bin.000010';

+------------------+-----+-------------+-----------+-------------+---------------------------------------+

+------------------+-----+-------------+-----------+-------------+---------------------------------------+

| mysql-bin.000010 | 4 | Format_desc | 2 | 120 | Server ver: 5.6.41-log, Binlog ver: 4 |

| mysql-bin.000010 | 120 | Query | 2 | 201 | BEGIN |

| mysql-bin.000010 | 201 | Query | 2 | 298 | use `relay`; delete from account00 |

| mysql-bin.000010 | 298 | Xid | 2 | 329 | COMMIT /* xid=58 */ |

+------------------+-----+-------------+-----------+-------------+---------------------------------------+

Pos：表示时间开始的position

End_log_pos：表示时间结束的position

此外，我们还能够从指定的位置查看二进制日志：

这里的from 317，就是制定的位置！

我们还能够控制显示日志的数量：

我们还能够使用下面的指令查看当前系统正在使用那个二进制，以及二进制日志记录到哪个位置了：

在二进制日志到达指定大小之后会刷新，同时，我们也能手动刷新二进制日志：

mysql> flush logs;

Query OK, 0 rows affected (0.00 sec)

mysql> show master logs;

+------------------+-----------+

| Log_name | File_size |

+------------------+-----------+

| mysql-bin.000001 | 2160 |

| mysql-bin.000002 | 43064 |

| mysql-bin.000003 | 3909 |

| mysql-bin.000004 | 143 |

| mysql-bin.000005 | 143 |

| mysql-bin.000006 | 2694 |

| mysql-bin.000007 | 989 |

| mysql-bin.000008 | 9134 |

| mysql-bin.000009 | 787 |

| mysql-bin.000010 | 376 |

| mysql-bin.000011 | 120 |

+------------------+-----------+

可以看到多了一个‘mysql-bin.000011’，同时我们看下‘mysql-bin.index’这个文件，可以直接cat：

[root@VM-75-68 mysql]# cat mysql-bin.index

./mysql-bin.000001

./mysql-bin.000002

./mysql-bin.000003

./mysql-bin.000004

./mysql-bin.000005

./mysql-bin.000006

./mysql-bin.000007

./mysql-bin.000008

./mysql-bin.000009

./mysql-bin.000010

./mysql-bin.000011

这个文件仅仅是记录了有哪些二进制日志文件而已。

设置当前会话不会别记录到binlog：

mysql> set sql_log_bin=OFF; ##关闭当前会话的binlog记录功能

Query OK, 0 rows affected (0.00 sec)

执行一些操作：

mysql> use RW

Reading table information for completion of table and column names

You can turn off this feature to get a quicker startup with -A

mysql> select * from T;

此时再次查看binlog的情况：

mysql> show master logs;

+------------------+-----------+

| Log_name | File_size |

+------------------+-----------+

| mysql-bin.000001 | 2160 |

| mysql-bin.000002 | 43064 |

| mysql-bin.000003 | 3909 |

| mysql-bin.000004 | 143 |

| mysql-bin.000005 | 143 |

| mysql-bin.000006 | 2694 |

| mysql-bin.000007 | 989 |

| mysql-bin.000008 | 9134 |

| mysql-bin.000009 | 787 |

| mysql-bin.000010 | 376 |

| mysql-bin.000011 | 120 |

+------------------+-----------+

我们看到mysql-bin.000011的大小没有变化，也就是说，上面这些步骤的sql都没有被记录在binlog中！

除了能够在mysql交互界面使用‘show binlog events’指令查看binlog外，还能用通过mysqlbinlog指令读取二进制日志文件：

[root@VM-75-68 mysql]# /usr/local/mysql/bin/mysqlbinlog --no-defaults mysql-bin.000010

/*!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

#190911 20:35:31 server id 2 end_log_pos 120 CRC32 0x5cd581ef Start: binlog v 4, server v 5.6.41-log created 190911 20:35:31

BINLOG '

E+p4XQ8CAAAAdAAAAHgAAAAAAAQANS42LjQxLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA

AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAe+B

1Vw=

'/*!*/;

# at 120

#191010 10:21:17 server id 2 end_log_pos 201 CRC32 0xecd3cb40 Query thread_id=9 exec_time=0 error_code=0

SET TIMESTAMP=1570674077/*!*/;

SET @@session.pseudo_thread_id=9/*!*/;

SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;

SET @@session.sql_mode=1075838976/*!*/;

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 201

#191010 10:21:17 server id 2 end_log_pos 298 CRC32 0x57e2097b Query thread_id=9 exec_time=0 error_code=0

use `relay`/*!*/;

SET TIMESTAMP=1570674077/*!*/;

delete from account00

/*!*/;

# at 298

#191010 10:21:17 server id 2 end_log_pos 329 CRC32 0x22972e8a Xid = 58

COMMIT/*!*/;

# at 329

#191010 14:05:01 server id 2 end_log_pos 376 CRC32 0xb582eebc Rotate to mysql-bin.000011 pos: 4

DELIMITER ;

# End of log file

ROLLBACK /* added by mysqlbinlog */;

/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

我们把上面的部分拆开来看：

第一部分：

/*!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

#190911 20:35:31 server id 2 end_log_pos 120 CRC32 0x5cd581ef Start: binlog v 4, server v 5.6.41-log created 190911 20:35:31

BINLOG '

E+p4XQ8CAAAAdAAAAHgAAAAAAAQANS42LjQxLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA

AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAe+B

1Vw=

'/*!*/;

以上部分，是二进制日志的版本信息和属性信息，我们不用在意他们。

以上就是MySQL的一些相关日志，共勉！

posted @ 2020-08-05 21:21 一个运维阅读(590) 评论(0) 编辑收藏举报

会员力量，点亮园子希望

刷新页面返回顶部

一个运维

每天都要有收获~

MySQL的各种日志

公告