Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-7395

change master to Relay_Log_File/log_pos breaks Relay_Master_Log_File:Exec_Master_Log_Pos

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Major
    • Resolution: Won't Fix
    • Affects Version/s: None
    • Fix Version/s: N/A
    • Component/s: OTHER
    • Labels:
      None

      Description

      After thinking I was well on the way to recovering a slave:

                        Master_Port: 3306
                      Connect_Retry: 60  
                    Master_Log_File: mysql-bin.006189
                Read_Master_Log_Pos: 50082470  
                     Relay_Log_File: mysqld-relay-bin.001144
                      Relay_Log_Pos: 104857605  
              Relay_Master_Log_File: mysql-bin.006105
                   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: 9258445
                    Relay_Log_Space: 8480309601  
                    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: 963719  
      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: 12022
                     Master_SSL_Crl:   
                 Master_SSL_Crlpath: 
                         Using_Gtid: No  
                        Gtid_IO_Pos: 
      1 row in set (0.00 sec)
      (interval < 30 sec)
       
      stop slave;
      set global sync_binlog=0, global innodb_flush_log_at_trx_commit=0
      start slave;
       
                       Master_Host: 192.168.179.103
                        Master_User: replication
                        Master_Port: 3306
                      Connect_Retry: 60  
                    Master_Log_File: mysql-bin.006189
                Read_Master_Log_Pos: 54032040
                     Relay_Log_File: mysqld-relay-bin.001144
                      Relay_Log_Pos: 104857605
              Relay_Master_Log_File: mysql-bin.006105
                   Slave_IO_Running: No
                  Slave_SQL_Running: No
                    Replicate_Do_DB: 
                Replicate_Ignore_DB: 
                 Replicate_Do_Table: 
             Replicate_Ignore_Table: 
            Replicate_Wild_Do_Table: 
        Replicate_Wild_Ignore_Table: 
                         Last_Errno: 1594  
                         Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
                       Skip_Counter: 0 
                Exec_Master_Log_Pos: 61589175
                    Relay_Log_Space: 8484259756
                    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: NULL
      Master_SSL_Verify_Server_Cert: No
                      Last_IO_Errno: 0
                      Last_IO_Error:   
                     Last_SQL_Errno: 1594
                     Last_SQL_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
        Replicate_Ignore_Server_Ids: 
                   Master_Server_Id: 12022
                     Master_SSL_Crl: 
                 Master_SSL_Crlpath: 
                         Using_Gtid: No
       
      Looking at the relay file:
      ls -al mysqld-relay-bin.001144
      -rw-rw---- 1 mysql mysql 104857705 Dec 19 03:23 mysqld-relay-bin.001144
       
       mysqlbinlog --start-position 104857605 mysqld-relay-bin.001144 | more
      ERROR: /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
      /*!40019 SET @@session.max_insert_delayed_threads=0*/;
      Error in Log_event::read_log_event(): 'Event too big', data_len: 1163019592, event_type: 48
      /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
      ERROR: DELIMITER /*!*/;
      Could not read entry at offset 104857605: Error in log format or read error.# at 4
       
      #141215  0:30:57 server id 12025  end_log_pos 248       Start: binlog v 4, server v 10.0.15-MariaDB-1~wheezy-log created 141215  0:30:57
      BINLOG '
      wSuOVA/5LgAA9AAAAPgAAAAAAAQAMTAuMC4xNS1NYXJpYURCLTF+d2...
      AAAAAAAAAAAEEwQAj+72WQ==
      '/*!*/;
      # at 291
      #141218 23:29:46 server id 12022  end_log_pos 248       Start: binlog v 4, server v 10.0.15-MariaDB-1~wheezy-log created 141218 23:29:46
      BINLOG '
      amOTVA/2LgAA9AAAAPgAAAAAAAQAM.....
      AAAAAAAAAAAEEwQA8pOnBg==
      '/*!*/;
      DELIMITER ;
      # End of log file
      ROLLBACK /* added by mysqlbinlog */;
      /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
      /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
      
      

      I concluded its 100 bytes from the end of the file, going to reposition to the the next file.

      MariaDB [(none)]> change master to relay_log_file='mysqld-relay-bin.001145',RELAY_LOG_POS=0;

      start slave

      I soon (<2 mins) there after found a duplicate key error on an insert which I suspected was related and quickly clear it. set sql_log_bin=0; REPLACE INTO seller_counters (seller_id, category_id, counter) VALUES (36239, 321, 1); set global sql_slave_skip_counter=1; start slave

      The show slave status soon (<2 mins) after found another error:

      Relay_Log_File: mysqld-relay-bin.001147
                      Relay_Log_Pos: 7901913
              Relay_Master_Log_File: mysql-bin.006189
                   Slave_IO_Running: Yes
                  Slave_SQL_Running: No
      

      (sorry I didn't record the full output at the time)

      So from position:

                     Relay_Log_File: mysqld-relay-bin.001144
                      Relay_Log_Pos: 104857605
              Relay_Master_Log_File: mysql-bin.006105
                Exec_Master_Log_Pos: 9258445
      

      until a very short time later after a change master to changed the relay_log_file/pos to the next file and with a 100 bytes changed the new position is:

      Relay_Log_File: mysqld-relay-bin.001147
                      Relay_Log_Pos: 7901913
              Relay_Master_Log_File: mysql-bin.006189
      

      The relay log files are 100M though though probably a logrotate not using shared scripts the following pattern occurs about 3 hourly

      -rw-rw----  1 mysql  mysql  104857912 Dec 21 00:33 mysqld-relay-bin.001187
      -rw-rw----  1 mysql  mysql        569 Dec 21 00:33 mysqld-relay-bin.001188
      -rw-rw----  1 mysql  mysql        341 Dec 21 00:33 mysqld-relay-bin.001189
      

      The master log files are more strict on 100M an only differ on on what appears to be a daily logrotate.

      The relay log file has gone from 001144 to 001147 in the same time Relay_Master_Log_File has gone from 006105 (19th December) to mysql-bin.006189 (30 December, which is the current binlog on the master).

      binlog_format                           | STATEMENT
      

      A few hours later I decided to capture this right without gaps.

      Take a stopped slave position and ignoring this error (i'll put a new bug for it).

      *************************** 1. row ***************************
                     Slave_IO_State: 
                        Master_Host: 192.168.179.103
                        Master_User: replication
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: mysql-bin.006189
                Read_Master_Log_Pos: 96248700
                     Relay_Log_File: mysqld-relay-bin.001150
                      Relay_Log_Pos: 94786159
              Relay_Master_Log_File: mysql-bin.006189
                   Slave_IO_Running: No
                  Slave_SQL_Running: No
                    Replicate_Do_DB: 
                Replicate_Ignore_DB: 
                 Replicate_Do_Table: 
             Replicate_Ignore_Table: 
            Replicate_Wild_Do_Table: 
        Replicate_Wild_Ignore_Table: 
                         Last_Errno: 1594
                         Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbin
      log' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you
       want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
                       Skip_Counter: 0
                Exec_Master_Log_Pos: 94785872
                    Relay_Log_Space: 8316760144
      

      change master to Relay_Log_File='mysqld-relay-bin.001150',relay_log_pos=94785831; show slave status;

                     Slave_IO_State: 
                        Master_Host: 192.168.179.103
                        Master_User: replication
                        Master_Port: 3306
                      Connect_Retry: 60
                    Master_Log_File: mysql-bin.006189
                Read_Master_Log_Pos: 96248700
                     Relay_Log_File: mysqld-relay-bin.001150
                      Relay_Log_Pos: 94785831
              Relay_Master_Log_File: mysql-bin.006189
                   Slave_IO_Running: No
                  Slave_SQL_Running: No
                    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: 96248700
                    Relay_Log_Space: 8316760144
                    Until_Condition: None
      

      so changing Relay_Log_Pos: 94785831
      to Relay_Log_Pos: 94786159

      changed

                Exec_Master_Log_Pos: 94785872
                Exec_Master_Log_Pos: 96248700
      

      so changing the relay_log_pos back 300 bytes made the exec_master_log_pos jump forward 1.5M.

      Looks like this is grabbing a current master position when then relay_log_pos/file is changed.

        Attachments

          Activity

            People

            Assignee:
            Unassigned Unassigned
            Reporter:
            danblack Daniel Black
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved:

                Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.