關(guān)于Raplication之大惑

weichongli

有Master-Slave結(jié)構(gòu)Mysql，以前一直同步正常。

最近經(jīng)常出現(xiàn)很怪異的問題：

mysql> show slave status\G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 192.168.1.1
                Master_User: dbuser
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000193
        Read_Master_Log_Pos: 257898263
             Relay_Log_File: Db-relay-bin.000601
              Relay_Log_Pos: 257898400
      Relay_Master_Log_File: mysql-bin.000193
           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: 257898263
            Relay_Log_Space: 257898400
            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: 0
1 row in set (0.00 sec)

1秒種之后，再執(zhí)行show slave status\G，結(jié)果如下

mysql> show slave status\G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 192.168.1.1
                Master_User:dbuser
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000193
        Read_Master_Log_Pos: 257903732
             Relay_Log_File: Db-relay-bin.000601
              Relay_Log_Pos: 257901335
      Relay_Master_Log_File: mysql-bin.000193
           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: 257901198
            Relay_Log_Space: 257903869
            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: 167
1 row in set (0.00 sec)

這也變的太快了吧？上一秒還是正常的，下一秒就落后Master服務(wù)器167秒了？？

為什么會(huì)這樣？Seconds_Behind_Master的值是怎么計(jì)算出來的？

helbreathszw

你有my.cnf文件嗎？
我瞧瞧

helbreathszw

應(yīng)該是說master執(zhí)行的延遲,可能是你們的數(shù)據(jù)量太多了。

weichongli

原帖由 helbreathszw 于 2007-5-11 16:51 發(fā)表
你有my.cnf文件嗎？
我瞧瞧

master的還是slave的？

helbreathszw

你發(fā)我信箱好了szw2001@gmail.com
是master和slave的my.cnf,可能是你們做了什么delay延遲的

weichongli

原帖由 helbreathszw 于 2007-5-11 16:54 發(fā)表
應(yīng)該是說master執(zhí)行的延遲,可能是你們的數(shù)據(jù)量太多了。

數(shù)據(jù)量確實(shí)很大。

但讓人摸不到頭緒的是：上一秒執(zhí)行show slave status\G，顯示
      Seconds_Behind_Master: 0，也就是說，SLAVE與MASTER是即時(shí)同步的
僅僅過了一秒就
      Seconds_Behind_Master: 167，SLAVE上僅過了一秒，在MASTER上居然已經(jīng)過了167秒，顯得有點(diǎn)荒唐。

過幾秒又顯示為0……如此反復(fù)，折騰死我了（有個(gè)定期的監(jiān)控腳本去檢查這個(gè)數(shù)值，高于15秒就會(huì)郵件短信一起來騷擾我）

      “Seconds_Behind_Master”這個(gè)值是怎么算出來的？太荒唐了。

補(bǔ)充下：兩臺(tái)機(jī)器曾經(jīng)在系統(tǒng)時(shí)間上相差了幾分鐘，但是后來用ntpdate校準(zhǔn)成一樣的了，這有可能是干擾因素嗎？

helbreathszw

`Slave_IO_State' and `Seconds_Behind_Master' columns to the
     output of `SHOW SLAVE STATUS'.  `Slave_IO_State' indicates the
     state of the slave I/O thread, and `Seconds_Behind_Master'
     indicates the number of seconds by which the slave is late
     compared to the master.

weichongli

原帖由 helbreathszw 于 2007-5-11 17:01 發(fā)表
你發(fā)我信箱好了
是master和slave的my.cnf,可能是你們做了什么delay延遲的

已發(fā)，3Q

weichongli

原帖由 helbreathszw 于 2007-5-11 17:08 發(fā)表
`Slave_IO_State' and `Seconds_Behind_Master' columns to the
     output of `SHOW SLAVE STATUS'.  `Slave_IO_State' indicates the
     state of the slave I/O thread, and `Seconds_Behind_Master'
   ...

那Seconds_Behind_master這個(gè)值是怎么算的？
是當(dāng)前Master的時(shí)間與SLAVE正在處理的日志所處的時(shí)間的差嗎？
還是其它方法？

helbreathszw

Apparently on some systems tmp can be <0. Here are possible reasons
        related to MySQL:
        - the master is itself a slave of another master whose time is ahead.
        - somebody used an explicit SET TIMESTAMP on the master.
        Possible reason related to granularity-to-second of time functions
        (nothing to do with MySQL), which can explain a value of -1:
        assume the master's and slave's time are perfectly synchronized, and
        that at slave's connection time, when the master's timestamp is read,
        it is at the very end of second 1, and (a very short time later) when
        the slave's timestamp is read it is at the very beginning of second
        2. Then the recorded value for master is 1 and the recorded value for
        slave is 2. At SHOW SLAVE STATUS time, assume that the difference
        between timestamp of slave and rli->last_master_timestamp is 0
        (i.e. they are in the same second), then we get 0-(2-1)=-1 as a result.
        This confuses users, so we don't go below 0: hence the max().

        last_master_timestamp == 0 (an "impossible" timestamp 1970) is a
        special marker to say "consider we have caught up".