您的位置:首页 > 数据库 > MySQL

MySQL日志

2016-02-05 20:23 423 查看

错误日志error log

记录mysql运行状态
启动错误记录日志
在不同情况下,错误日志会记录在不同的位置,如果没有在配置文件中指定文件名,则默认为hostname.err
可以通过my.cnf文件进行配置(重启服务配置生效)

mysql的重大的错误看日志

#show variables like "%log_error%";

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

| Variable_name       | Value                                |

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

| log_error           | /data/mysql/mysql_3308/log/error.log |

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

1 rows in set (0.00 sec)

log_error定义错误日志的名字及路径

慢日志:slow log

会记录数据库的慢查询
帮助DBA找到缓慢SQL
默认不开启
分析手工开启
修改以下配置需要重启数据库服务使之生效

SLOW_QUERY_LOG=on|off
是否开启慢查询日志
SLOW_QUERY_LOG_FILE=FILENAME
指定慢查询日志的保存路径,不设置产生默认值 hostname-slow.log
LONG_QUERY_TIME=2
指定多少秒返回结果的查询语句属于慢查询
LONG_QUERUES_NOT_USING_INDEXES
记录没有使用到索引的语句
MIN_EXAMINED_ROW_LIMIT=1000
记录那些由于查找了多余1000次而引发的慢查询
LOG_SLOW_ADMIN-STATEMENTS
记录那些慢的OPTIMIZE TABLE ANALYZE
TABLE和ALTER TABLE
LOG-SLOW-SLAVE-STATEMENTS
记录由slave所产生的慢查询
不重启修改慢查询配置
库里面SET的方式
#show variables like '%slow%';
+---------------------------+-----------------------------------+
|Variable_name             | Value                             |
+---------------------------+-----------------------------------+
|log_slow_admin_statements | OFF                               |
|log_slow_slave_statements | OFF                               |
|slow_launch_time          | 2                                 |
|slow_query_log            | OFF                               |
|slow_query_log_file       |/var/lib/mysql/localhost-slow.log |
+---------------------------+-----------------------------------+
5 rows in set(0.00 sec) 
#showvariables like '%long%';
+--------------------------------------------------------+-----------+
|Variable_name                                          |Value     |
+--------------------------------------------------------+-----------+
|long_query_time                                        |10.000000 |
|performance_schema_events_stages_history_long_size     | 10000    |
|performance_schema_events_statements_history_long_size | 10000     |
|performance_schema_events_waits_history_long_size      | 10000     |
+--------------------------------------------------------+-----------+
4 rows in set(0.00 sec)
 
#showvariables like '%min%';
+---------------------------+-------+
|Variable_name             | Value |
+---------------------------+-------+
|ft_min_word_len           | 4     |
|innodb_ft_min_token_size  | 3     |
|log_slow_admin_statements | OFF   |
|min_examined_row_limit    | 0     |
|query_cache_min_res_unit  | 4096  |
+---------------------------+-------+
5 rows in set(0.00 sec) 
#set global long_query_time=2; 
#set long_query_time=2; 
定义当前会话慢查询
Query OK, 0rows affected (0.00 sec)
#showvariables like 'long%';
+-----------------+----------+
|Variable_name   | Value    |
+-----------------+----------+
|long_query_time | 2.000000 |
+-----------------+----------+
1 row in set(0.00 sec)
mysql> select sleep(3);
+----------+
| sleep(3) |
+----------+
|        0 |
+----------+
1 row in set(3.00 sec)
 
#
tail -f localhost-slow.log
/usr/sbin/mysqld,Version: 5.6.22-enterprise-commercial-advanced (MySQL Enterprise Server -Advanced Edition (Commercial)). started with:
Tcp port:3306  Unix socket:/var/lib/mysql/mysql.sock
Time                 Id Command    Argument
# Time: 15032016:56:08
# User@Host:root[root] @ localhost []  Id:     5
# Query_time:3.000283  Lock_time: 0.000000 Rows_sent:1  Rows_examined: 0
SETtimestamp=1426841768;
selectsleep(3)
 
常见慢查询的分析工具 
mysqldumpSlow
Mysqlsla 
需要下载
Percona-toolkit中的pt-query-digest
[root@localhostmysql]# mysqldumpslowlocalhost-slow.log

Reading mysqlslow query log from localhost-slow.log
Count:2  Time=3.50s (7s)  Lock=0.00s (0s)  Rows=1.0 (2)应该返回一行
这次返回2行, root[root]@localhost
root在本地下达的命令
 select sleep(N)
 
root@localhost mysql]# ./mysqlsla-2.03localhost-slow.log

Auto-detectedlogs as slow logs
Report forslow logs: localhost-slow.log
2queries total, 1 unique  --2个慢查询
是一样的
Sorted by't_sum'
GrandTotals: Time 7 s
影响7秒, Lock 0 s
锁是0, Rows sent 2返回2行,
Rows Examined 0 
______________________________________________________________________001 ___
Count         : 2 (100.00%)
Time          : 7.001218 s total, 3.500609 s avg,3.000283 s to 4.000935 s max  (100.00%)执行时间
LockTime (s) : 0 total, 0 avg, 0 to 0 max (0.00%)
产生的锁
Rowssent     : 1 avg, 1 to 1 max  (100.00%)返回的行数
Rows examined: 0 avg, 0 to 0 max  (0.00%)
Database      :

Users         :

root@localhost  : 100.00% (2)of query, 100.00% (2) of all users
 
Queryabstract:
查询的列子
SETtimestamp=N; SELECT sleep(N);
 
Query sample:
SETtimestamp=1426841768;
selectsleep(3);
# rpm -qlp percona-toolkit-2.2.7-1.noarch.rpm 
#
pt-query-digest  /var/lib/mysql/mysql1-slow.log 
# 200ms usertime, 20ms system time, 21.73M rss, 173.06M vsz
# Currentdate: Thu Apr 16 19:33:37 2015
# Hostname:mysql1
# Files:/var/lib/mysql/mysql1-slow.log
# Overall: 2total, 1 unique, 0.07 QPS, 0.23x concurrency ________________
# Time range:2015-04-16 17:05:17 to 17:05:47
#Attribute          total     min    max     avg     95% stddev  median
#============     ======= ======= ============== ======= ======= =======
# Exectime             7s      3s     4s      4s      4s  708ms      4s
# Locktime              0       0      0       0       0      0       0
# Rowssent              2       1      1       1       1      0       1
# Rowsexamine           0       0      0       0       0      0       0
# Querysize            30      15     15      15      15      0      15
 
# Profile
# Rank QueryID           Response time Calls R/CallV/M   Item
# ====================== ============= ===== ====== ===== ======
#    1 0xF9A57DD5A41825CA 7.0034 100.0%     2 3.5017 0.14 SELECT
 
# Query 1:0.07 QPS, 0.23x concurrency, ID 0xF9A57DD5A41825CA at byte 372
# This item isincluded in the report because it matches --limit.
# Scores: V/M=
16843
0.14
# Time range:2015-04-16 17:05:17 to 17:05:47
#Attribute    pct   total    min     max     avg    95%  stddev  median
# =============== ======= ======= ======= ======= ======= ======= =======
# Count        100       2
# Exectime    100      7s     3s      4s      4s     4s   708ms      4s
# Locktime      0       0      0       0       0      0       0       0
# Rowssent    100       2      1       1       1      1       0       1
# Rowsexamine   0       0      0       0       0      0       0       0
# Querysize   100      30     15      15      15     15       0      15
# String:
# Hosts        localhost
# Users        root
# Query_timedistribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s ################################################################
#  10s+
# EXPLAIN/*!50100 PARTITIONS*/
selectsleep(4)\G

二进制日志:binlog

记录对数据库发生或是潜在发生更改的sql语句

二进制格式保存

用途广泛,包括:
查看数据库变更历史
数据库增量备份
数据库灾难恢复
mysql复制
不重启请修改二进制日志配置
mysql> showvariables like '%bin%';
+-----------------------------------------+----------------------+
|Variable_name                           |Value                |
+-----------------------------------------+----------------------+
|bind_address                            |*                    |
|binlog_cache_size                       |32768                |
|binlog_checksum                         |CRC32                |
|binlog_direct_non_transactional_updates | OFF                  |
|binlog_error_action                     |IGNORE_ERROR         |
|binlog_format                           |STATEMENT            |
|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                  |
| log_bin                                 | OFF                  |
|log_bin_basename                       |                      |
|log_bin_index                          |                      |
|log_bin_trust_function_creators         |OFF                  |
|log_bin_use_v1_row_events               |OFF                  |
|max_binlog_cache_size                   |18446744073709547520 |
|max_binlog_size                         |1073741824           |
|max_binlog_stmt_cache_size              |18446744073709547520 |
|simplified_binlog_gtid_recovery         |OFF                  |
|sql_log_bin                             |ON                   |
|sync_binlog                             |0                    |
+-----------------------------------------+----------------------+
常用二进制日志相关参数
log-bin
开启并制定二进制日志文件路径以及文件名。不设置则使用默认值,默认存放在数据文件目录
Max-binlog-size=500m(达到最大开启新的文件)
设置单个二进制日志文件的最大值默认为1G(默认值也为1G)
Binlog-do-dbbinlog-ignore-db
指定二进制日志文件记录那些数据库操作
binlog-cache-size=100m
设置二进制日志缓存大小(数据库繁忙的时候qps(请求)达到10000)每秒io上千次
二进制日志先写到缓存合并写入磁盘中
sync-binlog=N
每隔N秒将缓存中的二进制日志写回硬盘默认是0,不过你经常会陷入groupcommit函数与I.O之间二选一的矛盾(向二进制写入操作记录可能是并发操作产生的记录写入二进制之后才会提交成功写入的本身是一个单进程的
group commit来解决这个事情),如果在relicaition环境中
由于考虑耐久性一致性则需要设置成1同时innodb_flush_log_at_trx_commit=1
以及innofb_support-xa=1(默认开启)
Groupcommit多个并发提交打包成组来提交 
做两条修改
mysql>update t18 set  name='leilei' where id=1;
Query OK, 1row affected (0.01 sec)
Rows matched:1  Changed: 1  Warnings: 0
 
mysql>update t18 set  name='laoyan' where id=8;
Query OK, 1row affected (0.01 sec)
Rows matched:1  Changed: 1  Warnings: 0
查看二进制文件
从一个at开始到一个end结束
一条一条的记录SQL语句
root@localhost mysql]#
mysqlbinlog localhost-bin.000001
# at 197
#15032020:08:39时间 server id 1  服务器end_log_pos
309结束process CRC32 0x6cc80436        Query        thread_id=2        exec_time=0        error_code=0
use `db1`/*!*/;
SETTIMESTAMP=1426853319/*!*/;
update t18 set  name='leilei' where id=1
/*!*/;
# at
309  --编辑了一段操作
#150320 20:08:39 serverid 1  end_log_pos
340 CRC32 0xdffeed2c        Xid = 20
COMMIT/*!*/;
# at
340
#150320 20:09:09 serverid 1  end_log_pos 417 CRC32 0xac517602        Query        thread_id=2        exec_time=0        error_code=0
SETTIMESTAMP=1426853349/*!*/;
BEGIN
/*!*/;
# at 417
#150320 20:09:09 serverid 1  end_log_pos 529 CRC32 0x9ba01b0c        Query        thread_id=2        exec_time=0        error_code=0
SETTIMESTAMP=1426853349/*!*/;
update t18 set  name='laoyan' where id=8
/*!*/;
# at 529
#150320 20:09:09 serverid 1  end_log_pos 560 CRC32 0x5a1ee166        Xid = 21
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added bymysqlbinlog */;
/*!50003 SETCOMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET@@SESSION.PSEUDO_SLAVE_MODE=0*/;
 
#show variableslike 'binlog%';
+-----------------------------------------+--------------+
| Variable_name                           | Value        |
+-----------------------------------------+--------------+
| binlog_cache_size                       | 32768        |
| binlog_checksum                         | CRC32        |
|binlog_direct_non_transactional_updates | OFF          |
|binlog_error_action                     |IGNORE_ERROR |
|binlog_format                           | STATEMENT    |ROW
事务二进制日志
最为完整 3.混合模式基于row可能使用statement(具体所下达的sql语句)
|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 |
+-----------------------------------------+--------------+
11 rows in set (0.00 sec)
 
#set @@global.binlog_format=ROW;
Query OK, 0rows affected (0.00 sec)
#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                           | STATEMENT    |
|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 |
+-----------------------------------------+--------------+
11 rows in set(0.00 sec)
 
#set binlog_format=ROW;(事务本身以二进制日志方式记录)
Query OK, 0rows affected (0.00 sec)
 
#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                           | ROW          |
|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 |
+-----------------------------------------+--------------+
11 rows in set(0.00 sec)
mysql>update t18 set name='haha' where id=3;
Query OK, 1row affected (0.01 sec)
Rows matched:1  Changed: 1  Warnings: 0
# mysqlbinloglocalhost-bin.000001(看不大懂加-V参数)
BINLOG '
hBEMVRMBAAAAMQAAAKgCAAAAAEoAAAAAAAEAA2RiMQADdDE4AAMDDwMCCgAHq0tP/Q==
hBEMVR8BAAAAQgAAAOoCAAAAAEoAAAAAAAEAAgAD///4AwAAAAZub3JtYW4AAAAA+AMAAAAEaGFo
YQAAAADPZ8NX
'/*!*/;
# at 746
#15032020:24:36 server id 1  end_log_pos 777CRC32 0x7a4b99a5         Xid = 30
COMMIT/*!*/;
DELIMITER ;
# End of logfile
ROLLBACK /*added by mysqlbinlog */;
/*!50003 SETCOMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET@@SESSION.PSEUDO_SLAVE_MODE=0*/;
# mysqlbinlog -v localhost-bin.000001

# at 680
#15032020:24:36 server id 1  end_log_pos 746CRC32 0x57c367cf         Update_rows:table id 74 flags: STMT_END_F
 
BINLOG '
hBEMVRMBAAAAMQAAAKgCAAAAAEoAAAAAAAEAA2RiMQADdDE4AAMDDwMCCgAHq0tP/Q==
hBEMVR8BAAAAQgAAAOoCAAAAAEoAAAAAAAEAAgAD///4AwAAAAZub3JtYW4AAAAA+AMAAAAEaGFo
YQAAAADPZ8NX
'/*!*/;
###UPDATE `db1`.`t18`
###WHERE
###   @1=3
###   @2='norman'
###   @3=0
###SET
###   @1=3
###   @2='haha'
###   @3=0
# at746
#15032020:24:36 server id 1  end_log_pos 777CRC32 0x7a4b99a5         Xid = 30
COMMIT/*!*/;
DELIMITER ;
# End of logfile

描述某段时间的二进制日志
Datetime
只能到秒
[root@localhost mysql]#mysqlbinlog -v --start-position=680 --stop-position=746 localhost-bin.000001

/*!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
#150320 20:02:27 serverid 1 
end_log_pos120 CRC32 0xba0133d8        Start: binlog v 4, server v5.6.22-enterprise-commercial-advanced-lo
# Warning: this binlog iseither in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
UwwMVQ8BAAAAdAAAAHgAAAABAAQANS42LjIyLWVudGVycHJpc2UtY29tbWVyY2lhbC1hZHZhbmNl
ZC1sb2cAAAAAAAAAAABTDAxVEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAdgz
Abo=
'/*!*/;
# at 680
#150320 20:24:36 serverid 1  end_log_pos 746 CRC32 0x57c367cf        Update_rows: table id 74 flags:STMT_END_F
 
BINLOG '
hBEMVR8BAAAAQgAAAOoCAAAAAEoAAAAAAAEAAgAD///4AwAAAAZub3JtYW4AAAAA+AMAAAAEaGFo
YQAAAADPZ8NX
'/*!*/;
### Row event for unknowntable #74DELIMITER ;
# End of log file
ROLLBACK /* added bymysqlbinlog */;
/*!50003 SETCOMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET@@SESSION.PSEUDO_SLAVE_MODE=0*/;
删除二进制日志
1.操作系统命令删除
[root@localhostmysql]# ls
auto.cnf     ib_logfile1           localhost.localdomain.err  mysqlsla-2.03                       RPM_UPGRADE_HISTORY
db1         
localhost-bin.000001 localhost.localdomain.pid mysql.sock                         RPM_UPGRADE_MARKER-LAST
ibdata1     
localhost-bin.000002  localhost-slow.log        percona-toolkit-2.2.7-1.noarch.rpm viewdb
ib_logfile0  localhost-bin.index   mysql                      performance_schema                  worlddb
#reset master;删除过去所有的二进制日志文件从新创建新的二进制日志文件
ERROR 2006(HY000): MySQL server has gone away
No connection.Trying to reconnect...
Connectionid:    1
Currentdatabase: db1
Query OK, 0rows affected (0.06 sec)
# ls
auto.cnf     ib_logfile1                localhost.localdomain.pid  mysql.sock                         RPM_UPGRADE_MARKER-LAST
db1       
  localhost-bin.000001(原来的都删除了创建了新的二进制日志文件)      localhost-slow.log        percona-toolkit-2.2.7-1.noarch.rpm viewdb
ibdata1      localhost-bin.index        mysql                      performance_schema                  worlddb
ib_logfile0  localhost.localdomain.err  mysqlsla-2.03              RPM_UPGRADE_HISTORY 
# ls
auto.cnf    
localhost-bin.000001  localhost-bin.index        mysqlsla-2.03                       RPM_UPGRADE_MARKER-LAST
db1         
localhost-bin.000002  localhost.localdomain.err  mysql.sock                          viewdb
ibdata1      localhost-bin.000003  localhost.localdomain.pid  percona-toolkit-2.2.7-1.noarch.rpm  worlddb
ib_logfile0  localhost-bin.000004  localhost-slow.log         performance_schema
ib_logfile1  localhost-bin.000005  mysql                      RPM_UPGRADE_HISTORY
#purge master logs to'localhost-bin.000003';(删除到0003之前的二进制日志)
# ls
auto.cnf     ib_logfile1           localhost-bin.index        mysql                               performance_schema       worlddb
db1          localhost-bin.000003  localhost.localdomain.err  mysqlsla-2.03                       RPM_UPGRADE_HISTORY
ibdata1      localhost-bin.000004  localhost.localdomain.pid  mysql.sock                          RPM_UPGRADE_MARKER-LAST
ib_logfile0  localhost-bin.000005  localhost-slow.log        percona-toolkit-2.2.7-1.noarch.rpm viewdb
 
日志即影响性能又占用大量磁盘空间,因此往往做采样分析时才会打开
即使做采样分析,也最好仅在一台测试机上开启
二进制日志由于用途广泛,大多数情况下回开启,需要制定合理的备份计划和管理策略

通用日志:general log
通用查询日志

MYSQL的通用查询日志默认是不开启的,可以手动开启,一般不在配置文件中修改,做分析查询时候用的
建议:采样的时候开不采样的时候就关了
#set global general_log=1;
Query OK,0 rows affected (0.02 sec)

#show global variables like"gen_%";
+------------------+-----------------------------------+
| Variable_name    | Value                            |
+------------------+-----------------------------------+
| general_log      | OFF                               |
| general_log_file | /data/mysql/mytest_3306/mysql.log |
#tail -f /data/mysql/mytest_3306/mysql.log
跟踪通用日志做抓包分析
关闭通用日志

#set globalgeneral_log=0;
Query OK, 0rows affected (0.01 sec)

# rm -rf /data/mysql/mytest_3306/mysql.log
不用了就删除掉
内容来自用户分享和网络整理,不保证内容的准确性,如有侵权内容,可联系管理员处理 点击这里给我发消息
标签: