[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 }