0

I have a master MariaDB server and several replicas. All replicas report zero Seconds_Behind_Master. All but one replicas report Master_Log_File and Relay_Master_Log_File equal to that of the master.

However, here's the problem: one replica reports Master_Log_File and Relay_Master_Log_File several thousand files previous to the master, however, it shows Seconds_Behind_Master: 0.

on master:

mysql> select version();
+-----------------+
| version()       |
+-----------------+
| 10.1.37-MariaDB |
+-----------------+
1 row in set (0.03 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.078899 | 24541842 |              |                  |
+------------------+----------+--------------+------------------+

On the faulty replica:

MariaDB [(none)]> select version();
+-----------------+
| version()       |
+-----------------+
| 10.1.37-MariaDB |
+-----------------+

MariaDB [(none)]> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: <redacted>
                  Master_User: <redacted>
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysql-bin.077174
          Read_Master_Log_Pos: 54849284
               Relay_Log_File: mysql-relay-bin.000002
                Relay_Log_Pos: 709
        Relay_Master_Log_File: mysql-bin.076703
             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: 16886003
              Relay_Log_Space: 69470937760
              Until_Condition: None
               Until_Log_File:
                Until_Log_Pos: 0
           Master_SSL_Allowed: Yes
           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: 2
               Master_SSL_Crl:
           Master_SSL_Crlpath:
                   Using_Gtid: Slave_Pos
                  Gtid_IO_Pos: 1-1-7663401560,2-2-5634506789
      Replicate_Do_Domain_Ids:
  Replicate_Ignore_Domain_Ids:
                Parallel_Mode: conservative
1 row in set (0.00 sec)

To summarize, my master's current binlog file is mysql-bin.078899, but my replica's Master_Log_File is mysql-bin.077174 -- a difference of 1725 files. The replica's Relay_Master_Log_File is mysql-bin.076703 -- a difference from the master of 2196 files. However, this replica reports Seconds_Behind_Master: 0.

You should know that this replica is the replica that I have dedicated to be our "backup" replica. This is a cloud server, and our cloud provider lets us create a point-in-time snapshot of a disk. Every hour, a systemd timer shuts down MySQL, freezes its filesystem, and creates a snapshot of its /var/lib/mysql disk. After the snapshot is complete, the filesystem is unfrozen, MySQL is started, and replication continues.

I don't know when this problem began, but for several days now, after MySQL is restarted, it reports Seconds_Behind_Master: 0. I know this via monitoring which reports historical data.

Here's where it gets really strange: if use one of the recent disk snapshots created from this faulty replica and stand up a new MariaDB using this snapshot as the source of it's data disk, for 10 to 15 minutes after it comes up, it also reports Seconds_Behind_Master: 0. However, it soon reports a lag time of one day to several days. If I leave this sever replicating, eventually (several hours or days later), it catches up, and its Master_Log_File and Relay_Master_Log_File will eventually match that of the master's. However, the source server, the "backup" server, seems to never catch up its binlog file with that of its master.

Has anyone ever seen this kind of behavior before? Is this a known bug? I haven't done a ton of searching the MariaDB issues, but so far I haven't found anything that describes this scenario.

Can anyone assist me diagnosing this? Thank you in advance.

Edit: I disabled the systemd timer that shut down this replica every hour. In short time, replication lag shot up to around 3 days. I believe that there's a large set of changes in the binlog that could not be successfully applied before MySQL was shut down each hour. When the shutdown command was issued, MySQL rolled back everything it had been attempting to apply. This cycle continued for several days.

I'm still curious about why Seconds_Behind_Master is so wrong. I should probably just run pt-heartbeat, but I'm interested in hearing if this has happened for anyone else.

  • The Slave is a "Relay". Don't expect Relay_Master_Log_File to match the Master. – Rick James Apr 22 '19 at 5:03

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.