一次binlog暴涨的分析

程序员文章站 2022-06-28 17:29:06

某库最近binlog暴涨，撑到备份磁盘告警。几分钟就生成了500m，但是data文件不怎么涨-rw-rw---- 1 mysql mysql 525780067 Jan 14 09:27 mysql-bin.002058-rw-rw---- 1 mysql mysql 525172203 Jan 14 09:32 mysql-bin.002059-rw-rw---- 1 mysql mysql 524929124 Jan 14 09:38 mysql-bin.002060-rw-rw---- 1...

某库最近binlog暴涨，撑到备份磁盘告警。几分钟就生成了500m，但是data文件不怎么涨

-rw-rw---- 1 mysql mysql 525780067 Jan 14 09:27 mysql-bin.002058
-rw-rw---- 1 mysql mysql 525172203 Jan 14 09:32 mysql-bin.002059
-rw-rw---- 1 mysql mysql 524929124 Jan 14 09:38 mysql-bin.002060
-rw-rw---- 1 mysql mysql 524452959 Jan 14 09:44 mysql-bin.002061
-rw-rw---- 1 mysql mysql 525471819 Jan 14 09:50 mysql-bin.002062

binlog默认是row模式，我们环境也是row模式
show binlog events in 'mysql-bin.000002'; --查看binlog中的事物
该命令还看不到sql语句，只能看到command和table

| mysql-bin.002063 | 460249060 | Gtid           | 1496221631 |   460249108 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568350'                      |
| mysql-bin.002063 | 460249108 | Query          | 1496221631 |   460249181 | BEGIN                                                                                         |
| mysql-bin.002063 | 460249181 | Table_map      | 1496221631 |   460249251 | table_id: 190 (lzl.tab1)                                                        |
| mysql-bin.002063 | 460249251 | Update_rows_v1 | 1496221631 |   460249413 | table_id: 190 flags: STMT_END_F                                                               |
| mysql-bin.002063 | 460249413 | Xid            | 1496221631 |   460249444 | COMMIT /* xid=882251666 */                                                                    |
| mysql-bin.002063 | 460249444 | Gtid           | 1496221631 |   460249492 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568351'                      |
| mysql-bin.002063 | 460249492 | Query          | 1496221631 |   460249565 | BEGIN                                                                                         |
| mysql-bin.002063 | 460249565 | Table_map      | 1496221631 |   460249636 | table_id: 179 (lzl.tab2)                                                    |
| mysql-bin.002063 | 460249636 | Update_rows_v1 | 1496221631 |   460249814 | table_id: 179 flags: STMT_END_F                                                               |
| mysql-bin.002063 | 460249814 | Xid            | 1496221631 |   460249845 | COMMIT /* xid=882251677 */                                                                    |
| mysql-bin.002063 | 460249845 | Gtid           | 1496221631 |   460249893 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568352'                      |
| mysql-bin.002063 | 460249893 | Query          | 1496221631 |   460249966 | BEGIN                                                                                         |
| mysql-bin.002063 | 460249966 | Table_map      | 1496221631 |   460250066 | table_id: 23377 (lzl.tab3)                                                          |
| mysql-bin.002063 | 460250066 | Update_rows_v1 | 1496221631 |   461751954 | table_id: 23377 flags: STMT_END_F                                                             |
| mysql-bin.002063 | 461751954 | Xid            | 1496221631 |   461751985 | COMMIT /* xid=882251696 */                                                                    |
| mysql-bin.002063 | 461751985 | Gtid           | 1496221631 |   461752033 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568353'                      |
| mysql-bin.002063 | 461752033 | Query          | 1496221631 |   461752106 | BEGIN                                                                                         |
| mysql-bin.002063 | 461752106 | Table_map      | 1496221631 |   461752176 | table_id: 190 (lzl.tab1)                                                        |
| mysql-bin.002063 | 461752176 | Update_rows_v1 | 1496221631 |   461752340 | table_id: 190 flags: STMT_END_F                                                               |
| mysql-bin.002063 | 461752340 | Xid            | 1496221631 |   461752371 | COMMIT /* xid=882251710 */                                                                    |
| mysql-bin.002063 | 461752371 | Gtid           | 1496221631 |   461752419 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568354'                      |
| mysql-bin.002063 | 461752419 | Query          | 1496221631 |   461752492 | BEGIN                                                                                         |
| mysql-bin.002063 | 461752492 | Table_map      | 1496221631 |   461752562 | table_id: 190 (lzl.tab1)                                                        |
| mysql-bin.002063 | 461752562 | Update_rows_v1 | 1496221631 |   461752692 | table_id: 190 flags: STMT_END_F                                                               |
| mysql-bin.002063 | 461752692 | Xid            | 1496221631 |   461752723 | COMMIT /* xid=882251781 */                                                                    |
| mysql-bin.002063 | 461752723 | Gtid           | 1496221631 |   461752771 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568355'                      |
| mysql-bin.002063 | 461752771 | Query          | 1496221631 |   461752844 | BEGIN                                                                                         |
| mysql-bin.002063 | 461752844 | Table_map      | 1496221631 |   461752915 | table_id: 179 (lzl.tab2)                                                    |
| mysql-bin.002063 | 461752915 | Update_rows_v1 | 1496221631 |   461753093 | table_id: 179 flags: STMT_END_F                                                               |
| mysql-bin.002063 | 461753093 | Xid            | 1496221631 |   461753124 | COMMIT /* xid=882251797 */                                                                    |
| mysql-bin.002063 | 461753124 | Gtid           | 1496221631 |   461753172 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568356'                      |
| mysql-bin.002063 | 461753172 | Query          | 1496221631 |   461753245 | BEGIN                                                                                         |
| mysql-bin.002063 | 461753245 | Table_map      | 1496221631 |   461753315 | table_id: 190 (lzl.tab1)                                                        |
| mysql-bin.002063 | 461753315 | Update_rows_v1 | 1496221631 |   461753479 | table_id: 190 flags: STMT_END_F                                                               |
| mysql-bin.002063 | 461753479 | Xid            | 1496221631 |   461753510 | COMMIT /* xid=882251819 */                                                                    |
| mysql-bin.002063 | 461753510 | Gtid           | 1496221631 |   461753558 | SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568357'                      |
| mysql-bin.002063 | 461753558 | Query          | 1496221631 |   461753631 | BEGIN                                                                                         |
| mysql-bin.002063 | 461753631 | Table_map      | 1496221631 |   461753870 | table_id: 18684 (lzl.t_instance)                                                            |
| mysql-bin.002063 | 461753870 | Update_rows_v1 | 1496221631 |   461923580 | table_id: 18684 flags: STMT_END_F                                                             |
| mysql-bin.002063 | 461923580 | Xid            | 1496221631 |   461923611 | COMMIT /* xid=882251832 */

mysqlbinlog mysql-bin.000002|more --直接查看binlog裸文件

DELIMITER /*!*/;
# at 4
#210114  9:57:14 server id 1496221631  end_log_pos 120 CRC32 0xc594bc32         Start: binlog v 4, server v 5.6.49-log created 210114  9:57:14
BINLOG '
+qT/Xw+/hy5ZdAAAAHgAAAAAAAQANS42LjQ5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAATK8
lMU=
'/*!*/;
# at 120
#210114  9:57:14 server id 1496221631  end_log_pos 231 CRC32 0x5e1813f1         Previous-GTIDs
# 7e5b6c89-982a-11ea-8870-a4fa76014150:1-29568458,
# e707932a-b150-11ea-ac70-6805ca858b80:1-45964
# at 231
#210114  9:57:14 server id 1496221631  end_log_pos 279 CRC32 0x1102ed96         GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29568459'/*!*/;
# at 279
#210114  9:57:14 server id 1496221631  end_log_pos 352 CRC32 0x1feec83c         Query   thread_id=14805497      exec_time=0     error_code=0
SET TIMESTAMP=1610589434/*!*/;
SET @@session.pseudo_thread_id=14805497/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=2097152/*!*/;
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 352
#210114  9:57:14 server id 1496221631  end_log_pos 452 CRC32 0x3e5289d5         Table_map: `lzl`.`tab3` mapped to number 23377
# at 452
#210114  9:57:14 server id 1496221631  end_log_pos 1502344 CRC32 0x3ab659bb     Update_rows: table id 23377 flags: STMT_END_F

binlog row模式的sql是用base64编码的，可以用--base64-output来查看sql
sql也只能看到sql语句主题，看不到where后的条件
如果要完整的sql需要第三方工具比如mysql2sql，不好上传，暂时先不用

#mysqlbinlog -vv --base64-output='decode-rows' mysql-bin.002063|more

/*!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
#210114  9:50:13 server id 1496221631  end_log_pos 120 CRC32 0x91fae40c         Start: binlog v 4, server v 5.6.49-log created 210114  9:50:13
# at 120
#210114  9:50:13 server id 1496221631  end_log_pos 231 CRC32 0x3e1cce9f         Previous-GTIDs
# 7e5b6c89-982a-11ea-8870-a4fa76014150:1-29567594,
# e707932a-b150-11ea-ac70-6805ca858b80:1-45964
# at 231
#210114  9:50:13 server id 1496221631  end_log_pos 279 CRC32 0xa76bf991         GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29567595'/*!*/;
# at 279
#210114  9:50:13 server id 1496221631  end_log_pos 352 CRC32 0x263e8009         Query   thread_id=14804858      exec_time=0     error_code=0
SET TIMESTAMP=1610589013/*!*/;
SET @@session.pseudo_thread_id=14804858/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=2097152/*!*/;
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 352
#210114  9:50:13 server id 1496221631  end_log_pos 422 CRC32 0xef62cc16         Table_map: `lzl`.`tab1` mapped to number 190
# at 422
#210114  9:50:13 server id 1496221631  end_log_pos 584 CRC32 0x15d016ee         Update_rows: table id 190 flags: STMT_END_F
### UPDATE `lzl`.`tab1`
### WHERE
###   @1='docker010026004049' /* VARSTRING(384) meta=384 nullable=0 is_null=0 */
###   @2='10.26.4.49' /* VARSTRING(3072) meta=3072 nullable=1 is_null=0 */
###   @3='slave_docker010026004049' /* VARSTRING(384) meta=384 nullable=0 is_null=0 */
###   @4='2021-01-14 09:50:08' /* DATETIME(0) meta=0 nullable=0 is_null=0 */
### SET
###   @1='docker010026004049' /* VARSTRING(384) meta=384 nullable=0 is_null=0 */
###   @2='10.26.4.49' /* VARSTRING(3072) meta=3072 nullable=1 is_null=0 */
###   @3='slave_docker010026004049' /* VARSTRING(384) meta=384 nullable=0 is_null=0 */
###   @4='2021-01-14 09:50:13' /* DATETIME(0) meta=0 nullable=0 is_null=0 */
# at 584
#210114  9:50:13 server id 1496221631  end_log_pos 615 CRC32 0x26c2ed4e         Xid = 882236022
COMMIT/*!*/;
# at 615
#210114  9:50:13 server id 1496221631  end_log_pos 663 CRC32 0xf73fa414         GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '7e5b6c89-982a-11ea-8870-a4fa76014150:29567596'/*!*/;
# at 663
#210114  9:50:13 server id 1496221631  end_log_pos 736 CRC32 0xf00fd6d2         Query   thread_id=14803571      exec_time=0     error_code=0
SET TIMESTAMP=1610589013/*!*/;

过滤计算哪些表update最多
[root@xxx /home/mysql/data3118/mysql]

#mysqlbinlog -vv --base64-output='decode-rows' mysql-bin.002063|grep UPDATE|sort -n|uniq -c
     84 ### UPDATE `lzl`.`tab2`
    337 ### UPDATE `lzl`.`tab1`
     59 ### UPDATE `lzl`.`t_instance`
    344 ### UPDATE `lzl`.`tab3`
     38 ### UPDATE `mysql`.`tab4

update虽然不多，但是有个表中有text字段，怀疑是这个字段导致binlog很大。因为在看binlog详细数据时，可以发现有个字段非常大

mysql> desc 

    -> ;
+------------------+---------------------+------+-----+---------+----------------+
| Field            | Type                | Null | Key | Default | Extra          |
+------------------+---------------------+------+-----+---------+----------------+
| id               | bigint(20) unsigned | NO   | PRI | NULL    | auto_increment |
...
| error_message    | text                | YES  |     | NULL    |                |
+------------------+---------------------+------+-----+---------+----------------+
23 rows in set (0.00 sec)

sql和问题原因查的差不多了，业务方怎么处理先不管

现在来清理binlog。清理之前要理一下备份的逻辑。
binlog日志存储在local本地，默认保存18h。这个最好不要删，因为备库可能需要这些binlog去reset slave。（如果删了需要从备份服务器拉）
备份服务器发现有新的binlog生成，便打包mysql-bin.xxxxx到备份服务器（备份盘就是这里满了）
因为备份没有压缩，打开压缩备份功能（云平台的）

主库手动切换一次binlog
mysql> flush logs;
Query OK, 0 rows affected (0.00 sec)

查看一下本地binlog和备份服务器binlog信息
local:

-rw-rw---- 1 mysql mysql 525780067 Jan 14 09:27 mysql-bin.002058
-rw-rw---- 1 mysql mysql 525172203 Jan 14 09:32 mysql-bin.002059
-rw-rw---- 1 mysql mysql 524929124 Jan 14 09:38 mysql-bin.002060
-rw-rw---- 1 mysql mysql 524452959 Jan 14 09:44 mysql-bin.002061
-rw-rw---- 1 mysql mysql 525471819 Jan 14 09:50 mysql-bin.002062
-rw-rw---- 1 mysql mysql 524382355 Jan 14 09:57 mysql-bin.002063
-rw-rw---- 1 mysql mysql 524534500 Jan 14 10:05 mysql-bin.002064
-rw-rw---- 1 mysql mysql    208483 Jan 14 14:36 mysql-bin.002066

ftp:

#ls -lrth
total 260G
-rw-r--r-- 1 ftpadmin ftpadmin 401M Jan 10 18:57 mysql-bin.001535.tar
-rw-r--r-- 1 ftpadmin ftpadmin 380M Jan 11 00:57 mysql-bin.001536.tar
-rw-r--r-- 1 ftpadmin ftpadmin 429M Jan 11 06:57 mysql-bin.001537.tar
-rw-r--r-- 1 ftpadmin ftpadmin 501M Jan 11 11:51 mysql-bin.001538.tar
-rw-r--r-- 1 ftpadmin ftpadmin 502M Jan 11 11:57 mysql-bin.001539.tar
-rw-r--r-- 1 ftpadmin ftpadmin 501M Jan 11 12:03 mysql-bin.001540.tar
-rw-r--r-- 1 ftpadmin ftpadmin 502M Jan 11 12:08 mysql-bin.001541.tar
-rw-r--r-- 1 ftpadmin ftpadmin 501M Jan 11 12:14 mysql-bin.001542.tar
-rw-r--r-- 1 ftpadmin ftpadmin 502M Jan 11 12:20 mysql-bin.001543.tar
-rw-r--r-- 1 ftpadmin ftpadmin 502M Jan 11 12:26 mysql-bin.001544.tar
-rw-r--r-- 1 ftpadmin ftpadmin 501M Jan 11 12:32 mysql-bin.001545.tar
-rw-r--r-- 1 ftpadmin ftpadmin 502M Jan 11 12:38 mysql-bin.001546.tar
-rw-r--r-- 1 ftpadmin ftpadmin 502M Jan 11 12:44 mysql-bin.001547.tar
...
-rw-r--r-- 1 ftpadmin ftpadmin  23K Jan 14 14:37 mysql-bin.002066.tar.gz

看到tar.gz表示压缩功能正常
压缩以后binlog备份应该就小很多了

本文地址：https://blog.csdn.net/qq_40687433/article/details/112621787

相关标签： MYSQL BASIC MYSQL TROUBLESHOOTING

上一篇： JAVA线程的概念和多线程的实现方式

下一篇： mysql卸载再安装作死级尝试（测试前记得备份数据库）

一次binlog暴涨的分析

linux系统中一次用户态进程死循环案例的分析过程以及解决办法

第一次作业：关于Linux 2.6.20进程模型和O(1)调度器算法的分析

记一次vue长列表的内存性能分析和优化

第一次作业：基于Linux 4.5的进程模型与调度器分析

第一次作业：基于Linux-0.12的进程分析

Android记录一次InstallerPackage apk报错的问题分析

binlog_format 为 ROW 的分析

EFS加密技术的概念分析及一次解密经过

基于MySQL binlog分析的开源项目收录

基于MySQL binlog分析的开源项目收录