真实的国产乱ⅩXXX66竹夫人,五月香六月婷婷激情综合,亚洲日本VA一区二区三区,亚洲精品一区二区三区麻豆

成都創(chuàng)新互聯(lián)網(wǎng)站制作重慶分公司

手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析

這篇文章給大家分享的是有關(guān)手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析的內(nèi)容。小編覺(jué)得挺實(shí)用的,因此分享給大家做個(gè)參考,一起跟隨小編過(guò)來(lái)看看吧。

創(chuàng)新互聯(lián)公司專(zhuān)注于互助企業(yè)網(wǎng)站建設(shè),響應(yīng)式網(wǎng)站建設(shè),商城網(wǎng)站開(kāi)發(fā)。互助網(wǎng)站建設(shè)公司,為互助等地區(qū)提供建站服務(wù)。全流程按需定制網(wǎng)站,專(zhuān)業(yè)設(shè)計(jì),全程項(xiàng)目跟蹤,創(chuàng)新互聯(lián)公司專(zhuān)業(yè)和態(tài)度為您提供的服務(wù)

一、問(wèn)題來(lái)源

有一個(gè)朋友@水米田 問(wèn)我,基于POSITION的主從。他做了如下的操作

  • 將備份的一些binlog文件加入到了目錄中

  • 修改index文件,加入了這些binlog文件

  • flush binary logs

然后整個(gè)主從環(huán)境大量延遲。

二、朋友的測(cè)試

下面是另外一個(gè)朋友@徐晨亮的測(cè)試:

master上:
(root:db1@xucl:10:30:22)[(none)]> show binary logs;
+---------------------+-----------+| Log_name            | File_size |
+---------------------+-----------+
| MySQL-binlog.000031 |      1019 || mysql-binlog.000032 |       424 |
| mysql-binlog.000033 |       244 || mysql-binlog.000034 |      2332 |
| mysql-binlog.000035 |      2134 || mysql-binlog.000036 |    845915 |
| mysql-binlog.000037 |     11735 || mysql-binlog.000038 |       284 |
| mysql-binlog.000039 |       284 || mysql-binlog.000040 |       284 |
| mysql-binlog.000041 |       284 || mysql-binlog.000042 |       234 |
+---------------------+-----------+
12 rows in set (0.00 sec)
(root:db1@xucl:10:30:34)[(none)]> purge binary logs to 'mysql-binlog.000039';
Query OK, 0 rows affected (0.00 sec)
(root:db1@xucl:10:30:49)[(none)]> show binary logs;
+---------------------+-----------+
| Log_name            | File_size |+---------------------+-----------+| mysql-binlog.000039 |       284 |
| mysql-binlog.000040 |       284 || mysql-binlog.000041 |       284 |
| mysql-binlog.000042 |       234 |+---------------------+-----------+4 rows in set (0.00 sec)
執(zhí)行插入數(shù)據(jù)
(root:db1@xucl:10:31:23)[xucl]> insert into t values(9,9);
將備份的binlog拷貝回原先的目錄并修改index文件進(jìn)行注冊(cè)
[root@izbp12nspj47ypto9t6vyez logs]# ll總用量 884-rw-r----- 1 mysql mysql   1019 5月  20 22:03 mysql-binlog.000031-rw-r----- 1 mysql mysql    424 5月  20 22:03 mysql-binlog.000032-rw-r----- 1 mysql mysql    244 5月  20 22:03 mysql-binlog.000033-rw-r----- 1 mysql mysql   2332 5月  20 22:03 mysql-binlog.000034-rw-r----- 1 mysql mysql   2134 5月  20 22:03 mysql-binlog.000035-rw-r----- 1 mysql mysql 845915 5月  20 22:03 mysql-binlog.000036-rw-r----- 1 mysql mysql  11735 5月  20 22:05 mysql-binlog.000037-rw-r----- 1 mysql mysql    284 5月  20 22:06 mysql-binlog.000038
-rw-r----- 1 mysql mysql    284 5月  21 10:28 mysql-binlog.000039
-rw-r----- 1 mysql mysql    284 5月  21 10:28 mysql-binlog.000040-rw-r----- 1 mysql mysql    284 5月  21 10:28 mysql-binlog.000041-rw-r----- 1 mysql mysql    491 5月  21 10:31 mysql-binlog.000042-rw-r----- 1 mysql mysql    204 5月  21 10:30 mysql-binlog.index
主庫(kù)flush binary logs
(root:db1@xucl:10:32:51)[(none)]> flush binary logs;
Query OK, 0 rows affected (0.01 sec)
(root:db1@xucl:10:32:57)[(none)]> show binary logs;
+---------------------+-----------+| Log_name            | File_size |
+---------------------+-----------+
| mysql-binlog.000031 |      1019 || mysql-binlog.000032 |       424 |
| mysql-binlog.000033 |       244 || mysql-binlog.000034 |      2332 |
| mysql-binlog.000035 |      2134 || mysql-binlog.000036 |    845915 |
| mysql-binlog.000037 |     11735 || mysql-binlog.000038 |       284 |
| mysql-binlog.000039 |       284 || mysql-binlog.000040 |       284 |
| mysql-binlog.000041 |       284 || mysql-binlog.000042 |       541 |
| mysql-binlog.000043 |       234 |+---------------------+-----------+13 rows in set (0.00 sec)
此時(shí),slave報(bào)錯(cuò)如下:
(root:db1@xucl:10:31:05)[(none)]> show slave status\G
*************************** 1. row ***************************               Slave_IO_State:
                  Master_Host: 127.0.0.1
                  Master_User: repl                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-binlog.000035
          Read_Master_Log_Pos: 194
               Relay_Log_File: izbp12nspj47ypto9t6vyez-relay-bin.000011
                Relay_Log_Pos: 373
        Relay_Master_Log_File: mysql-binlog.000035
             Slave_IO_Running: No            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: 194
              Relay_Log_Space: 648
              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: NULLMaster_SSL_Verify_Server_Cert: No                Last_IO_Errno: 1236
                Last_IO_Error: Got fatal error 1236 from master when reading data from binary log: 'Cannot replicate GTID-transaction when @@GLOBAL.GTID_MODE = OFF, at file /storage/single/mysql3306/logs/mysql-binlog.000035, position 194.; the first event 'mysql-binlog.000039' at 234, the last event read from '/storage/single/mysql3306/logs/mysql-binlog.000035' at 259, the last byte read from '/storage/single/mysql33'
               Last_SQL_Errno: 0
               Last_SQL_Error:
  Replicate_Ignore_Server_Ids:
             Master_Server_Id: 3306
                  Master_UUID: e8bdf01a-c79b-11e8-82b3-00163e088352
             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: 190521 10:32:57
     Last_SQL_Error_Timestamp:
               Master_SSL_Crl:
           Master_SSL_Crlpath:
           Retrieved_Gtid_Set:
            Executed_Gtid_Set: 4c423515-6661-11e9-b767-00163e088352:1-7,
e8bdf01a-c79b-11e8-82b3-00163e088352:1-57192
                Auto_Position: 0
         Replicate_Rewrite_DB:
                 Channel_Name:
           Master_TLS_Version:
1 row in set (0.00 sec)
從slave上的報(bào)錯(cuò)來(lái)看,在主庫(kù)flush binary logs后,從庫(kù)又讀取注冊(cè)的binlog并且又apply了

三、現(xiàn)象說(shuō)明

從整個(gè)測(cè)試來(lái)看,MySQL視乎將手動(dòng)注冊(cè)的文件進(jìn)行了傳輸和應(yīng)用。報(bào)錯(cuò)是因?yàn)檫@個(gè)庫(kù)以前是GITD_MODE=ON的,但是測(cè)試的時(shí)候已經(jīng)關(guān)閉了GTID_MODE,改為了POSITION的模式,這個(gè)報(bào)錯(cuò)是因?yàn)镈UMP線(xiàn)程會(huì)進(jìn)行檢測(cè):

手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析

image.png

這個(gè)圖來(lái)自我新寫(xiě)的一個(gè)系列(暫時(shí)還沒(méi)發(fā)布,大概年底才能寫(xiě)好)。不管怎么說(shuō),DUMP線(xiàn)程已經(jīng)在開(kāi)始傳輸老的binlog文件了。那么原因是什么呢?下面我們將進(jìn)行解釋。

四、flush binary logs對(duì)binlog的操作

flush binary logs 將包含如下操作:

  • 獲取新的binlog文件名字

  • 關(guān)閉舊的binlog

  • 關(guān)閉index file

  • 打開(kāi)index file

  • 打開(kāi)新的binlog

  • 將新的binlog加入到indexfile

具體可以參考函數(shù)MYSQL_BIN_LOG::new_file_impl。其中要說(shuō)明一下獲取新的binlog文件名字是通過(guò)函數(shù)find_uniq_filename實(shí)現(xiàn)的,其中包含如下代碼:

  file_info= dir_info->dir_entry;  for (i= dir_info->number_off_files ; i-- ; file_info++)
  {    if (strncmp(file_info->name, start, length) == 0 &&
    is_number(file_info->name+length, &number,0))
    {
      set_if_bigger(max_found, number);
    }
  }
...
 *next= (need_next || max_found == 0) ? max_found + 1 : max_found;

大概意思就是掃描index file文件里面的binlog文件,獲取其序號(hào)最高的一個(gè),然后加1。棧幀如下:

#0  find_uniq_filename (name=0x7fffec5ec6d0 "/mysqldata/mysql3340/log/binlog", next=0x7fffec5ec678, need_next=true)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:3679#1  0x000000000187d208 in generate_new_log_name (new_name=0x7fffec5ec6d0 "/mysqldata/mysql3340/log/binlog", new_ext=0x0, 
    log_name=0x7ffedc011520 "/mysqldata/mysql3340/log/binlog", is_binlog=true) at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:3767#2  0x0000000001884fdb in MYSQL_BIN_LOG::new_file_impl (this=0x2e83640, need_lock_log=false, extra_description_event=0x0)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7175#3  0x0000000001884cbb in MYSQL_BIN_LOG::new_file_without_locking (this=0x2e83640, extra_description_event=0x0)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7099#4  0x0000000001886b6b in MYSQL_BIN_LOG::rotate (this=0x2e83640, force_rotate=true, check_purge=0x7fffec5ecbfb)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7775#5  0x0000000001886d53 in MYSQL_BIN_LOG::rotate_and_purge (this=0x2e83640, thd=0x7ffedc000b90, force_rotate=true)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:7846

因此即便我們手動(dòng)修改了index file,flush binary logs卻不會(huì)有問(wèn)題,因?yàn)樗鼘?shí)際掃描了index file文件。
同時(shí)我們也看到flush binary logs重新加載了index file,這個(gè)時(shí)候手動(dòng)修改的index file就生效了,使用show binary logs就能查看到你加入的文件了。

五、主從問(wèn)題的產(chǎn)生

binlog切換后,DUMP線(xiàn)程也需要讀取下一個(gè)binlog文件。我們來(lái)看看它是怎么確認(rèn)讀取哪一個(gè)文件的。

在函數(shù)sender.run()中可以找到循環(huán)每個(gè)binlog文件的代碼。下面一句是尋找下一個(gè)binlog文件:

int error= mysql_bin_log.find_next_log(&m_linfo, 0);

mysql_bin_log.find_next_log 包含的代碼:

  my_b_seek(&index_file, linfo->index_file_offset);//進(jìn)行偏移量偏移
  linfo->index_file_start_offset= linfo->index_file_offset;
  length=my_b_gets(&index_file, fname, FN_REFLEN));//讀取文件名字...    if(normalize_binlog_name(full_fname, fname, is_relay_log))
...
  linfo->index_file_offset= my_b_tell(&index_file);//偏移量從新記錄以備下一次使用

我們能夠看到DUMP線(xiàn)程并沒(méi)有實(shí)際掃描整個(gè)index文件,而是通過(guò)一個(gè)index文件的偏移量進(jìn)行讀取。如果手動(dòng)修改index文件那么偏移量就出現(xiàn)了錯(cuò)亂。因此DUMP發(fā)送的下一個(gè)文件將是不確定的。因此出現(xiàn)了發(fā)送手動(dòng)注冊(cè)的binlog文件給從庫(kù)的現(xiàn)象,這種情況下可能出現(xiàn)下面情況:

  • 如果是GTID_MODE 關(guān)閉,使用POSITION那么這種情況一定報(bào)錯(cuò),比如重復(fù)的行。

  • 如果是GTID_MODE 和AUTO_POSITION=1,那么DUMP線(xiàn)程會(huì)進(jìn)行GTID的過(guò)濾不發(fā)送,因?yàn)镋vent不發(fā)送所以延遲會(huì)持續(xù)一段時(shí)間為0。

  • 如果是GTID_MODE 和AUTO_POSITION=0,那么SQL線(xiàn)程應(yīng)用GITD_EVENT的時(shí)候會(huì)進(jìn)行過(guò)濾,延遲可能出現(xiàn)很大的情況。

盡管GTID可能可以屏蔽這種問(wèn)題,但是DUMP線(xiàn)程已經(jīng)在考慮發(fā)送老的binlog文件了,這是不合適的。

六、purge binary logs能夠維護(hù)這個(gè)偏移量

為什么purge binary logs不會(huì)出現(xiàn)問(wèn)題呢,因?yàn)樵趐urge binary logs的語(yǔ)句下,會(huì)維護(hù)這個(gè)偏移量如下:

  virtual void operator()(THD *thd)
  {
    LOG_INFO* linfo;
    mysql_mutex_lock(&thd->LOCK_thd_data);    if ((linfo= thd->current_linfo))//b binlog.cc:2829
    {      /*
        Index file offset can be less that purge offset only if
        we just started reading the index file. In that case
        we have nothing to adjust.
      */
      if (linfo->index_file_offset < m_purge_offset)
        linfo->fatal = (linfo->index_file_offset != 0);      else
        linfo->index_file_offset -= m_purge_offset;
    }
    mysql_mutex_unlock(&thd->LOCK_thd_data);

我們可以看到linfo->index_file_offset -= m_purge_offset;這樣一個(gè)語(yǔ)句。下面是棧幀:

#0  Adjust_offset::operator() (this=0x7fffec5ec720, thd=0x7ffedc000be0) at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:2831#1  0x0000000000eef320 in Do_THD::operator() (this=0x7fffec5ec6a0, thd=0x7ffedc000be0) at /mysqldata/percona-server-locks-detail-5.7.22/sql/mysqld_thd_manager.cc:46#2  0x0000000000eefa0f in std::for_each (__first=0x3003358, __last=0x3003368, __f=...)
    at /usr/lib/gcc/x86_64-redhat-linux/4.4.7/../../../../include/c++/4.4.7/bits/stl_algo.h:4200#3  0x0000000000eeefc0 in Global_THD_manager::do_for_all_thd (this=0x3003340, func=0x7fffec5ec720)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/mysqld_thd_manager.cc:273#4  0x000000000187ae0a in adjust_linfo_offsets (purge_offset=0) at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:2873#5  0x0000000001883239 in MYSQL_BIN_LOG::remove_logs_from_index (this=0x2e83640, log_info=0x7fffec5ec7d0, need_update_threads=true)
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:6352#6  0x0000000001883676 in MYSQL_BIN_LOG::purge_logs (this=0x2e83640, to_log=0x7fffec5eca80 "/mysqldata/mysql3340/log/binlog.000001", included=false, 
    need_lock_index=true, need_update_threads=true, decrease_log_space=0x0, auto_purge=false) at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:6469#7  0x000000000187b4b5 in purge_master_logs (thd=0x7ffee0000c00, to_log=0x7ffee0006600 "binlog.000001")
    at /mysqldata/percona-server-locks-detail-5.7.22/sql/binlog.cc:3127

七、測(cè)試POSITION模式下的報(bào)錯(cuò)

1、 環(huán)境
mysql> show binary logs;
+---------------+-----------+
| Log_name      | File_size |
+---------------+-----------+
| binlog.000001 |       198 |
| binlog.000002 |       154 |
+---------------+-----------+2 rows in set (0.00 sec)
mysql> show create table testcp \G;
*************************** 1. row ***************************
       Table: testcp
Create Table: CREATE TABLE `testcp` (
  `id` int(11) NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf81 row in set (0.00 sec)
ERROR: 
No query specified
2、執(zhí)行一個(gè)語(yǔ)句

主庫(kù):

mysql> insert into testcp values(20);
Query OK, 1 row affected (0.43 sec)
mysql> select * from testcp;
+----+| id |+----+| 10 || 20 |+----+2 rows in set (0.01 sec)

從庫(kù):

mysql> show slave status \G;
*************************** 1. row ***************************               Slave_IO_State: Waiting for master to send event                  Master_Host: 192.168.99.41
                  Master_User: repl                  Master_Port: 3340
                Connect_Retry: 60
              Master_Log_File: binlog.000002
          Read_Master_Log_Pos: 417
               Relay_Log_File: relay.000004
                Relay_Log_Pos: 624
        Relay_Master_Log_File: binlog.000002
             Slave_IO_Running: Yes            Slave_SQL_Running: Yes
...
mysql> select * from testcp;
+----+| id |+----+| 10 || 20 |+----+

這個(gè)時(shí)候DUMP線(xiàn)程index file偏移指針如下:

手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析

image.png

3、主庫(kù)執(zhí)行purge binary logs

做之前拷貝原有binlog.000001為binlog.000001bak因?yàn)榈葧?huì)要拷貝回去

mysql> purge binary logs to  'binlog.000002';
Query OK, 0 rows affected (3.14 sec)
mysql> show binary logs;
+---------------+-----------+| Log_name      | File_size |
+---------------+-----------+
| binlog.000002 |       417 |+---------------+-----------+1 row in set (0.00 sec)

因?yàn)閜urge binary logs命令會(huì)維護(hù)偏移指針,這個(gè)時(shí)候DUMP線(xiàn)程的index file偏移指針如下:

手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析

image.png

4、手動(dòng)更改

將binlog.000001bak拷貝為binlog.000001,然后修改index file將binlog.000001加入回去,然后flush binary logs如下:

mysql> flush binary logs;
Query OK, 0 rows affected (0.15 sec)
mysql> show binary logs;
+---------------+-----------+| Log_name      | File_size |
+---------------+-----------+
| binlog.000001 |         198 || binlog.000002 |       461 |
+---------------+-----------+
2 rows in set (0.00 sec)

手動(dòng)完成這個(gè)工作并不會(huì)維護(hù)DUMP線(xiàn)程的index file偏移指針,因此如下:

手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析

image.png

就這樣DUMP線(xiàn)程重新發(fā)送了一次binlog.000002的內(nèi)容,POSITION的從庫(kù)只能報(bào)錯(cuò)了如下:

mysql> select * from replication_applier_status_by_worker  \G
*************************** 1. row ***************************
         CHANNEL_NAME: 
            WORKER_ID: 1
            THREAD_ID: NULL
        SERVICE_STATE: OFF
LAST_SEEN_TRANSACTION: ANONYMOUS
    LAST_ERROR_NUMBER: 1062
   LAST_ERROR_MESSAGE: Worker 1 failed executing transaction 'ANONYMOUS' at master log binlog.000002, end_log_pos 386; Could not execute Write_rows event on table testmts.testcp; Duplicate entry '20' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log binlog.000002, end_log_pos 386
 LAST_ERROR_TIMESTAMP: 2019-05-21 14:46:26

感謝各位的閱讀!關(guān)于“手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析”這篇文章就分享到這里了,希望以上內(nèi)容可以對(duì)大家有一定的幫助,讓大家可以學(xué)到更多知識(shí),如果覺(jué)得文章不錯(cuò),可以把它分享出去讓更多的人看到吧!


標(biāo)題名稱(chēng):手動(dòng)注冊(cè)binlog文件造成主從異常的示例分析
當(dāng)前地址:http://weahome.cn/article/pdpecd.html

其他資訊

在線(xiàn)咨詢(xún)

微信咨詢(xún)

電話(huà)咨詢(xún)

028-86922220(工作日)

18980820575(7×24)

提交需求

返回頂部