首页 / 日志 / 5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析

5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析

内容导读

互联网集市收集整理的这篇技术教程文章主要介绍了5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析，小编现在分享给大家，供广大互联网技能从业者学习和参考。文章包含7898字，纯文字阅读大概需要12分钟。

内容图文

问题描述：

同事使用mysqlbinlog工具的--read-from-remote-server --raw选项，从远程实例实时拉取二进制日志时，发现得到的二进制日志文件大小与远程实例上的源文件大小不相同，并且使用mysqlbinlog解析时会报错。

测试环境版本信息如下：

MySQL版本：5.7.17 log MySQL Community Server (GPL) 通用tar包安装

Mysqlbinlog版本：5.7.17 自带版本，mysqlbinlog Ver 3.4 for linux-glibc2.5 at x86_64

操作系统版本：CentOS Linux release 7.6.1810 (Core)

分析过程：

1、对比拉取到的二进制日志文件、源文件的大小，发现拉取到的二进制日志文件比源文件小，并且该文件大小：7315456/4096，刚好可以整除，源库上进行多次更新后，多次观察，发现该数值都可以被4096整除。

因为Linux块大小是4096 Bytes，所以，我先做个假设：mysqlbinlog工具以4096字节为单位进行写入

[root@192_168_129_128 tmp]# ll /usr/local/mysql-5.7.17-linux-glibc2.5-x86_64/data/mybinlog.000006 ; ll mybinlog.000006
-rw-r----- 1 mysql mysql 7318723 May 1216:55 /usr/local/mysql-5.7.17-linux-glibc2.5-x86_64/data/mybinlog.000006
-rw-r----- 1 root root 7315456 May 1216:55 mybinlog.000006

2、我在8.0.19版本中测试，问题却不能复现。

3、写一个简单的shell脚本，将mysqlbinlog拉取进程放到后台执行，获取到上一步的pid之后，使用pstack命令和strace命令，分别查看该进程的函数调用和系统调用

#!/bin/bash 

nohup mysqlbinlog --read-from-remote-server --host=192.168.129.128 --user=dba --password=123456 --raw --to-last-log binlog.000002 --stop-never &

pid=`ps -ef | grep mysqlbinlog | grep -v ‘grep‘ | awk‘{print $2}‘`

pstack $pid > pstack.log

strace -f -t -p $pid -o strace.log

pstack命令的输出结果如下，虽然没有直接的线索，但是后续可以利用这些函数栈名，去源码中找线索：

#00x00007faf58f60a2din recv () from /lib64/libpthread.so.0
#10x000000000045e9f9in inline_mysql_socket_recv (flags=0, n=5826, buf=0x1d959d1, mysql_socket=..., src_line=123, src_file=0x550918"/export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/vio/viosocket.c") at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/include/mysql/psi/mysql_socket.h:823
#2  vio_read (vio=0x1d90e60, buf=0x1d959d1"27399199-10542799900-96491182343-85303866742-80196460272-89060617578-51177070778-10421134155;80308169113-21291571753-18876715410-91134905277-85771492482\360j\003", size=5826) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/vio/viosocket.c:123
#30x0000000000434873in net_read_raw_loop (count=5826, net=0x1d8e550) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/net_serv.cc:672
#4  net_read_packet (net=0x1d8e550, complen=0x7fff6d023f88) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/net_serv.cc:859
#50x0000000000434a7cin my_net_read (net=0x1d8e550) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql/net_serv.cc:899
#60x000000000043985bin cli_safe_read_with_ok (mysql=0x1d8e550, parse_ok=0‘\000‘, is_data_packet=0x0) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/sql-common/client.c:1040
#70x0000000000426b36in dump_remote_log_entries (logname=0x7fff6d0277e9"binlog.000002", print_event_info=0x7fff6d0250f0) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/client/mysqlbinlog.cc:2664
#8  dump_single_log (logname=0x7fff6d0277e9"binlog.000002", print_event_info=0x7fff6d0250f0) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/client/mysqlbinlog.cc:2334
#9  dump_multiple_logs (argc=1, argv=<optimized out>) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/client/mysqlbinlog.cc:2374
#100x0000000000427821in main (argc=1, argv=0x1d58468) at /export/home/pb2/build/sb_0-21378219-1480347226.17/mysql-5.7.17/client/mysqlbinlog.cc:3436

strace命令的输出结果如下：

            ....................省略若干行....................

            20528
            11:24:25 recvfrom(3, "6813690-49945547265-44609719076-"..., 6605, 0, NULL, NULL) = 66052052811:24:25 lseek(4, 0, SEEK_CUR)    = 34242562052811:24:25write(4, "553290165-79173089006-0778194955"..., 4096) = 40962052811:24:25write(4, "2\360E\t\0\0p\3\0\0w71247594556-464035229"..., 4096) = 40962052811:24:25 recvfrom(3, " \0\0\211\0K\200\266^\20/\201\0\0\37\0\0\0\320d4\0\0\0\21\1\0\0\0\0\0\0"..., 16384, 0, NULL, NULL) = 15232052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 lseek(4, 0, SEEK_CUR)    = 34324482052811:24:25 recvfrom(3,

strace到这里就没有后续的输出了。

其中，recvfrom系统调用，是经socket接收数据；lseek是一个用于改变读写一个文件时读写指针位置的一个系统调用；write把buf中nbyte写入文件描述符handle所指的文档，成功时返回写的字节数，错误时返回-1.

分析strace日志中的多条write记录，发现每次write的写入字节数都是4096，看起来与前面的假设吻合。

但是，每达到4096字节才写入磁盘，那么拉取到的binlog几乎不可能与源库一致。而mysqlbinlog的help显示，--read-from-remote-server参数，实质上是调用MySQL Server的BINLOG-DUMP-NON-GTIDS接口，远程实例应该是实时发送binlog events才对。

-R, --read-from-remote-server 
                      Read binary logs from a MySQL server. This is an alias
                      for read-from-remote-master=BINLOG-DUMP-NON-GTIDS.

好吧，从pstack日志中得到的函数名，我们去源码中逐个查看，最终与本问题相关的是client/mysqlbinlog.cc中的dump_remote_log_entries()函数，如下：

            /*
            *
  Requests binlog dump from a remote server and prints the events it
  receives.

  @param[in,out] print_event_info Parameters and context state
  determining how to print.
  @param[in] logname Name of input binlog.

  @retval ERROR_STOP An error occurred - the program should terminate.
  @retval OK_CONTINUE No error, the program should continue.
  @retval OK_STOP No error, but the end of the specified range of
  events to process has been reached and the program should terminate.

            */
            static Exit_status dump_remote_log_entries(PRINT_EVENT_INFO *print_event_info,
                                           constchar* logname)
{
  ....................省略若干行....................
  for (;;)
  {
    constchar *error_msg= NULL;
    Log_event *ev= NULL;
    Log_event_type type= binary_log::UNKNOWN_EVENT;

    len= cli_safe_read(mysql, NULL);
    if (len == packet_error)
    {
      error("Got error reading packet from server: %s", mysql_error(mysql));
      DBUG_RETURN(ERROR_STOP);
    }
    if (len < 8 && net->read_pos[0] == 254)
      break; // end of data
    DBUG_PRINT("info",( "len: %lu  net->read_pos[5]: %d\n",
            len, net->read_pos[5]));
    /*
      In raw mode We only need the full event details if it is a 
      ROTATE_EVENT or FORMAT_DESCRIPTION_EVENT
    */

 
    ....................省略若干行....................
    if (raw_mode || (type != binary_log::LOAD_EVENT))
    {

 
....................省略若干行....................
      if (raw_mode)
      {
        DBUG_EXECUTE_IF("simulate_result_file_write_error",
                        DBUG_SET("+d,simulate_fwrite_error"););
        if (my_fwrite(result_file, net->read_pos + 1 , len - 1, MYF(MY_NABP)))
            /*可以看到，cli_safe_read()方法读取到的binlog event，都用调用my_fwrite函数进行写入，my_fwrite是对fwrite()系统调用的封装
            这里并没有以4096字节为单位写入，而是读多少就写入多少
            这就无法解释了，代码逻辑显示每次拿到数据之后，都会写入磁盘，为什么实际上却不是呢？*/
        {
          error("Could not write into log file ‘%s‘", log_file_name);
          retval= ERROR_STOP;
        }
        if (ev)
          reset_temp_buf_and_delete(ev);
      }
....................省略若干行....................

      if (retval != OK_CONTINUE)
        DBUG_RETURN(retval);
    }
    else
    {
....................省略若干行....................
    old_off+= len-1;
  }

  DBUG_RETURN(OK_CONTINUE);
}

请看我用中文注释在上述源码中的分析。

代码逻辑没有问题，那就有可能是BUG了。。。

结论：

通过上述分析，怀疑遇到了BUG，于是去官方的Release Notes中查找，最终在https://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-19.html 中找到如下说明：

Replication:

mysqlbinlog, if invoked with the --raw option, does not flush the output file until the process terminates. But if also invoked with the --stop-never option,

the process never terminates, thus nothing is ever written to the output file. Now the output is flushed after each event. (Bug #24609402)

但是这个BUG在BUG system中找不到，应该是需要有权限的MOS账号才能查看。

技术分享图片

原文：https://www.cnblogs.com/dba-john/p/12877608.html

内容总结

以上是互联网集市为您收集整理的5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析全部内容，希望文章能够帮你解决5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析所遇到的程序开发问题。如果觉得互联网集市技术教程内容还不错，欢迎将互联网集市网站推荐给程序员好友。

内容备注

版权声明：本文内容由互联网用户自发贡献，该文观点与技术仅代表作者本人。本站仅提供信息存储空间服务，不拥有所有权，不承担相关法律责任。如发现本站有涉嫌侵权/违法违规的内容，请发送邮件至 gblab@vip.qq.com 举报，一经查实，本站将立刻删除。

内容手机端

扫描二维码推送至手机访问。

本文链接：https://qyyshop.com/info/1160287.html

来源：【匿名】

【上一篇】asp.net 添加错误日志【下一篇】php错误日志怎么看

更多 ►

【5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析】教程文章相关的互联网学习教程文章

mysqlbinlog 查看binlog日志时报错unknown variable 'default-character-set=utf8'【代码】

mysqlbinlog 查看binlog日志时报错unknown variable ‘default-character-set=utf8‘ 在通过全备文件和增量binlog文件来导出sql文件，用以恢复完整的数据库时。由于裸的binlog文件是无法直视的，所以使用mysqlbinlog这个工具是用来查看binlog文件内容的（使用方式man mysqlbinlog查看），但是使用mysqlbinlog将binlog文件转换成人类可读的内容时却报错：[root@server data]$ mysqlbinlog mysql-bin.000009 mysqlbinlog: ...

MySQL的两个日志redo log和 binlog

MySQL的修改创建，涉及到写的东西，他们都会涉及两个重要的日志模块，redo log（重做日志）和 binlog（归档日志）。redo log在 MySQL 里也有这个问题，如果每一次的写操作都需要写进磁盘，然后磁盘也要找到对应的那条记录，然后再更新，整个过程 IO 成本、查找成本都很高。为了解决这个问题，MySQL 的设计者使用了redo log日志 redo log是InnoDB 引擎所特有的，当有些动作时，会先把记录写到 redo log文件里面，这个时候更新就算完...

怎么查看mysql 的binlog日志存放的位置【图】

image.png这个你可以看配置文件启用了才有这样的记录默认是没有的 linux系统中的/etc/my.cnfmy.cnf内容：log-bin = mysqlbin # 默认配置一般放在/var/lib/mysql 比如上面的设置重启数据库会生成mysqlbin.000001文件自定义文件存放位置修改配置文件，vi /etc/my.cnf，找到log-bin的部分配置自动清理在my.cnf文件中，这个文件路径不知道的话执行mysql --help | grep ‘Default options‘ -A 1，就会列出文件的路径来image.png然后重...

主从同步工作过程？(binlog日志)

在从数据库服务器的/var/lib/mysql/master.info 记录连接主数据库服务器信息文件mail-relay-bin.XXXXXX 中继日志文件（记录SQL）mail-relay-bin.index 索引文件（记录已有的中继日志文件）relay-log.info 记录日志信息文件start slave;Slave_IO_Running: Yes负责把master数据库服务器上binlog日志里SQL命令同步到本机的中继日志文件。出错：连接不是主数据库服务器(ping iptables selinux grant binlog日志信...

MySQL 5.6 新参数对binlog日志量的优化

数据库版本：5.6.*1.row日志image类型参数binlog_row_image 控制着这种image类型，默认为FULL（log all columns），即记录before&after images。该参数还有两种，minimal和noblob，minimal表示只记录after更改后的值，并且如果有主键或者非空唯一索引，则只以该字段作为where条件判断；noblob同full，只是不记录blob、text列。2.binlog日志对于insert则没有什么好说的，我们主要重点关注一下update和delete操作。binlog_row_image=...

无全量备份、未开启binlog日志，利用percona工具恢复delete的数据【图】

当我们忘记做全量备份时，并且没有开启binlog，并执行了deletefromsbtest;数据全部丢失，要想恢复是很有难度的。今天，利用PerconaDataRecoveryToolforInnoDB工当我们忘记做全量备份时，并且没有开启binlog，并执行了delete from sbtest;数据全部丢失，要想恢复是很有难度的。今天，利用Percona Data Recovery Tool for InnoDB工具（仅支持InnoDB，MyISAM不支持），可以找回被删除的数据。原理：在InnoDB引擎，delete删除操作，，不...

MySQL抑制binlog日志中的binlog部分

MySQL通过binlog来记录整个数据的变更过程，因此我们只要有MySQL的binlog日志即可完整的还原数据库。MySQL binlog日志记录有3种不 MySQL通过binlog来记录整个数据的变更过程，因此我们只要有MySQL的binlog日志即可完整的还原数据库。MySQL binlog日志记录有3种不同的方式，即：STATEMENT，MIXED，，ROW。对于不同的日志模式，生成的binlog有不同的记录方式。对于MIXED(部分SQL语句)和ROW模式是以base-64方式记录，会以BINLOG开头，...

mysql之binlog日志以及利用binlog日志恢复数据的示例代码分享

下面小编就为大家带来一篇解说mysql之binlog日志以及利用binlog日志恢复数据的方法。小编觉得挺不错的，现在就分享给大家，也给大家做个参考。一起跟随小编过来看看吧众所周知，binlog日志对于mysql数据库来说是十分重要的。在数据丢失的紧急情况下，我们往往会想到用binlog日志功能进行数据恢复（定时全备份+binlog日志恢复增量数据部分），化险为夷！废话不多说，下面是梳理的binlog日志操作解说：一、初步了解binlogMySQL的二进...

详解Mysql数据库之Binlog日志使用代码总结

下面小编就为大家带来一篇Mysql数据库之Binlog日志使用总结(必看篇)。小编觉得挺不错的，现在就分享给大家，也给大家做个参考。一起跟随小编过来看看吧binlog二进制日志对于mysql数据库的重要性有多大，在此就不多说了。下面根据本人的日常操作经历，并结合网上参考资料，对binlog日志使用做一梳理：一、binlog日志介绍1）什么是binlogbinlog日志用于记录所有更新了数据或者已经潜在更新了数据（例如，没有匹配任何行的一个DELETE）...

Mysql中错误日志、binlog日志、查询日志、慢查询日志简介【图】

前言数据库的日志是帮助数据库管理员，追踪分析数据库曾经发生的各种事件的有力依据，mysql中提供了错误日志、binlog日志(二进制日志)、查处日志、慢查询日志。在此，我力求解决以下问题：各个日志的作用是什么？怎样去控制这些日志呢？怎样去使用这些日志提供的信息呢？错误日志1.错误日志作用错误日志记录了mysql启动和停止时，以及服务器运行过程中发生任何严重性错误的相关信息。当数据库出现任何故障导致无法启动时候，比如my...

MySQL自动清理binlog日志的方法

说明：开启MySQL binlog日志的服务器，如果不设置自动清理日志，默认binlog日志一直保留着，时间一长，服务器磁盘空间被binlog日志占满，导致MySQL数据库出错。使用下面方法可以安全清理binlog日志一、没有主从同步的情况下清理日志mysql -uroot -p123456 -e PURGE MASTER LOGS BEFORE DATE_SUB( NOW( ),INTERVAL 5 DAY);#mysql 定时清理5天前的binlogmysql -u root -p #进入mysql 控制台reset master; #重置binlog二、MySQL主...

mysql5.6.12切换binlog二进制日志路径_MySQL

前言：有一个mysql学生说他们因为binlog产生太大了，需要把日志路径放到另外的磁盘上面去，问我有啥时机的操作方案，share弄了一个mysql的binlog的日志路径切换的例子给他。正好今天有空，就拿mysql5.6.12来做个实例，给大家演示一下。 1，查看binlog地址 [root@mysql5612 ~]# more /usr/local/mysql/my.cnf |grep log-bin log-bin =/home/data/mysql/binlog/mysql-bin.log [root@mysql5612 ~]# 2，验证binlog的正常使用 [root@...

mysql正确清理binlog日志的两种方法

mysq 正确清理binlog日志前言： MySQL中的binlog日志记录了数据库中数据的变动，便于对数据的基于时间点和基于位置的恢复，但是binlog也会日渐增大，占用很大的磁盘空间，因此，要对binlog使用正确安全的方法清理掉一部分没用的日志。【方法一】手动清理binlog清理前的准备：① 查看主库和从库正在使用的binlog是哪个文件show master status\G show slave status\G ② 在删除binlog日志之前，首先对binlog日志备份，以防万一开...

解说mysql之binlog日志以及利用binlog日志恢复数据的方法

众所周知，binlog日志对于mysql数据库来说是十分重要的。在数据丢失的紧急情况下，我们往往会想到用binlog日志功能进行数据恢复（定时全备份+binlog日志恢复增量数据部分），化险为夷！废话不多说，下面是梳理的binlog日志操作解说：一、初步了解binlogMySQL的二进制日志binlog可以说是MySQL最重要的日志，它记录了所有的DDL和DML语句（除了数据查询语句select），以事件形式记录，还包含语句所执行的消耗的时间，MySQL的二进制日...

Mysql数据库之Binlog日志使用总结(必看篇)

binlog二进制日志对于mysql数据库的重要性有多大，在此就不多说了。下面根据本人的日常操作经历，并结合网上参考资料，对binlog日志使用做一梳理：一、binlog日志介绍1）什么是binlog binlog日志用于记录所有更新了数据或者已经潜在更新了数据（例如，没有匹配任何行的一个DELETE）的所有语句。语句以“事件”的形式保存，它描述数据更改。 2）binlog作用因为有了数据更新的binlog，所以可以用于实时备份，与master/slave主从复制...

首页 / 日志 / 5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析

5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析

内容导读

内容图文

问题描述：

分析过程：

结论：

内容总结

内容备注

内容手机端

【5.7.17版本mysqlbinlog实时拉取的二进制日志不完整的原因分析】教程文章相关的互联网学习教程文章

二进制 - 相关标签

日志 - 相关标签

日志 - 最新教程

日志 - 最热教程