pt-heartbeat（percona toolkit）

pt-heartbeat是用来监控主从延迟的一款percona工具，现在我们大部分的MySQL架构还是基于主从复制，例如MHA,MMM,keepalived等解决方案。而主从环境的话，我们很关心的就是主从延迟的问题，一般情况下我们在从库执行以下语句：

mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 172.16.16.35
Master_User: root
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000016
Read_Master_Log_Pos: 299786938
Relay_Log_File: mxqmongodb2-relay-bin.000032
Relay_Log_Pos: 299787151
Relay_Master_Log_File: mysql-bin.000016
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 299786938
Relay_Log_Space: 299787451
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 353306
Master_UUID: 806ede0c-357e-11e7-9719-00505693235d
Master_Info_File: mysql.slave_master_info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Slave has read all relay log; waiting for more updates
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set: 806ede0c-357e-11e7-9719-00505693235d:666-330347
Executed_Gtid_Set: 6a4ab82c-4029-11e7-86b0-00505693235d:1-3,
806ede0c-357e-11e7-9719-00505693235d:1-330347
Auto_Position: 1
Replicate_Rewrite_DB:
Channel_Name:
Master_TLS_Version:
1 row in set (0.00 sec)

 

就可以很明显看得到主从的状态，一般我们都会监控以下两个进程的状态确定主从延迟是否出现错误：

Slave_IO_Running: Yes

Slave_SQL_Running: Yes

对于主从延迟来说，我们可能监控最多的就是通过SMB（Seconds_Behind_Master）来监控，但是这个也并不是很靠谱的。或者我们通过监控Read_Master_Log_Pos-Exec_Master_Log_Pos的差值来看从库是否有延迟，是否和主库会有一定的延迟。但是这个也并不是很完美。首先看SMB，这个参数是怎么比较出来的呢，SMB是通过将服务器当前的时间戳与二进制日志中的事件时间戳相对比得到的，而且是会产生误报的情况。比如主库执行一个大事物，时间执行很久，从库接收以后对比时间戳发现已经延迟了，就会瞬间增大SMB的值。Read_Master_Log_Pos-Exec_Master_Log_Pos的值也并不是完全可靠。现在pt-heartbeat就能帮我们解决这个问题。

下面我们来看一下pt-heartbeat的原理：

pt-heartbeat会在master上创建一张表，按照一定的时间频率更新该表的字段，向该表写入当前的时间戳，然后对比从库的时间戳和pt-heartbeat所在机器的时间戳来判断主从延迟。

其实这里就有一个问题了，如果pt-heartbeat部署在从库的话，要保证主从机器的时间是同步的，这个一般都是系统会每天自动对时间，是可以实现的。如果pt-heartbeat部署在主库就不会有这个问题。其实个人感觉比较好的方法就是对比主从两个库的这张表的时间戳来得出延迟更为靠谱一点，当然这也要考虑到主从查询的问题。

下面看一下基本的用法：

先创建表：

[root@mxqmongodb2 bin]# ./pt-heartbeat --host=172.16.16.35 --port=3306 --user=root --password=123456 --database=test --update --create-table --daemonize

 

看一下表结构：

mysql> desc heartbeat;
+-----------------------+---------------------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+-----------------------+---------------------+------+-----+---------+-------+
| ts | varchar(26) | NO | | NULL | |
| server_id | int(10) unsigned | NO | PRI | NULL | |
| file | varchar(255) | YES | | NULL | |
| position | bigint(20) unsigned | YES | | NULL | |
| relay_master_log_file | varchar(255) | YES | | NULL | |
| exec_master_log_pos | bigint(20) unsigned | YES | | NULL | |
+-----------------------+---------------------+------+-----+---------+-------+
6 rows in set (0.01 sec)
mysql> select * from heartbeat\G
*************************** 1. row ***************************
ts: 2017-06-23T09:27:49.001580
server_id: 353306
file: mysql-bin.000016
position: 299837221
relay_master_log_file: NULL
exec_master_log_pos: NULL
1 row in set (0.00 sec)

 

具体看一下，我们看一下数据库的链接，发现有一个更新操作：

UPDATE `test`.`heartbeat` SET ts='2017-06-23T09:32:47.001330', file='mysql-bin.000016', position='29

 

其实下面的操作只是开启了一个进程，对heartbeat表不停的进行更新，以获取最新的数据。

[root@mxqmongodb2 bin]# ./pt-heartbeat --host=172.16.16.35 --port=3306 --user=root --password=123456 --database=test --update --daemonize

 

接下来我们开启监控进程，这个是不停的刷新的：

[root@mxqmongodb2 bin]# ./pt-heartbeat -D test --monitor -h 172.16.16.34 -uroot -P3306 -p123456
0.00s [ 0.00s, 0.00s, 0.00s ]
0.00s [ 0.00s, 0.00s, 0.00s ]
0.00s [ 0.00s, 0.00s, 0.00s ]
0.00s [ 0.00s, 0.00s, 0.00s ]
0.00s [ 0.00s, 0.00s, 0.00s ]

 

我们指定会发现是没有延迟的，我们现在开启压测，再观察一下：

[root@mxqmongodb2 tpcc-mysql]# ./tpcc_start -h127.0.0.1 -P3306 -d tpcc -u root -p123456 -w 10 -c 20 -r 10 -l 600

 

观察延迟的情况：

0.71s [ 0.68s, 0.16s, 0.05s ]
1.71s [ 0.71s, 0.17s, 0.06s ]
0.85s [ 0.72s, 0.17s, 0.06s ]
0.93s [ 0.74s, 0.18s, 0.06s ]
0.00s [ 0.74s, 0.18s, 0.06s ]
0.82s [ 0.73s, 0.18s, 0.06s ]
0.66s [ 0.75s, 0.18s, 0.06s ]
0.00s [ 0.75s, 0.18s, 0.06s ]
0.88s [ 0.74s, 0.18s, 0.06s ]
1.00s [ 0.74s, 0.19s, 0.06s ]

 

我们可以看到延迟情况，我们可以把这些输出结果重定向到一个文件，对主从延迟进行监控，这也是很有效果的。

我们现在手动再从库停掉sql_thread：

mysql> stop slave sql_thread;
Query OK, 0 rows affected (0.03 sec)

 

然后再看输出结果：

53.00s [ 23.85s, 6.77s, 4.20s ]
54.00s [ 24.75s, 6.94s, 4.26s ]
55.00s [ 25.67s, 7.12s, 4.32s ]
56.00s [ 26.60s, 7.30s, 4.39s ]
57.00s [ 27.55s, 7.48s, 4.45s ]
58.00s [ 28.52s, 7.67s, 4.51s ]
59.00s [ 29.50s, 7.86s, 4.58s ]
60.00s [ 30.50s, 8.05s, 4.65s ]
61.00s [ 31.50s, 8.23s, 4.71s ]
62.00s [ 32.50s, 8.42s, 4.78s ]
63.00s [ 33.50s, 8.61s, 4.85s ]
64.00s [ 34.50s, 8.80s, 4.92s ]
65.00s [ 35.50s, 8.98s, 5.00s ]

 

发现是不停的递增的，一次间隔时间为一秒钟。我们再启动这个sql_thread，从库很快就跟上了主库。

或者我们可以通过下面进行监控：

[root@mxqmongodb2 bin]# ./pt-heartbeat -D test --check -h 172.16.16.34 -uroot -P3306 -p123456
1.00
[root@mxqmongodb2 bin]# ./pt-heartbeat -D test --check -h 172.16.16.34 -uroot -P3306 -p123456
0.00

 

他是会直接返回一个延迟的秒数，这个也是比较靠谱的。我们可以直接拿这个值进行监控。