Grande atraso na replicação do mysql (Relay_Log_Pos e Exec_Master_Log_Pos não aumentam)

Question

Hoje meus dois escravos (um mysql 5.1 e um segundo MariaDB 5.5, mestre é o mysql 5.1) começaram a ficar atrasados. Situações similares são bastante freqüentes com atrasos que chegam a até 10000 segundos, porque os escravos têm uma configuração de hardware pior do que a master, mas agora estou bastante estressado. Os atrasos em ambos os servidores ainda estão aumentando e neste momento ele recua 25K segundos atrás do mestre. Então comecei a investigar o que está errado. Passar pelos logs do mysql no master e slave me deu nada. Servidores estão no Centos 5 e Mariadb está no Centos 6.

Esta é a saída do status do escravo MariaDB:

MariaDB [(none)]> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: masterserevr
                  Master_User: slaveuser
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: mysqld-bin.006778
          Read_Master_Log_Pos: 401041447
               Relay_Log_File: relay-bin.020343
                Relay_Log_Pos: 14867924
        Relay_Master_Log_File: mysqld-bin.006777
             Slave_IO_Running: Yes
            Slave_SQL_Running: Yes
              Replicate_Do_DB: 
          Replicate_Ignore_DB: ses,phar
           Replicate_Do_Table: 
       Replicate_Ignore_Table: portal.aaa_jm_tmp,portal.newsletter
      Replicate_Wild_Do_Table: 
  Replicate_Wild_Ignore_Table: 
                   Last_Errno: 0
                   Last_Error: 
                 Skip_Counter: 0
          Exec_Master_Log_Pos: 14867639
              Relay_Log_Space: 1474785535
              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: 26484
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: 1
1 row in set (0.00 sec)

De poucas saídas, notei que Relay_Log_Pos e Exec_Master_Log_Pos não aumentam. Eu tentei reiniciar os processos escravos, mas isso não mudou nada e os atrasos ainda aumentam. O próximo passo foi ver em qual consulta a replicação parou.

Usando mysqlbinlog

mysqlbinlog relay-bin.020343 > /root/RelayLogQueries1.txt

No RelayLogQueries1.txt eu fundei a posição 14867924:

# at 14867924
#130927 10:03:21 server id 1  end_log_pos 14867709      Query   thread_id=160780134     exec_time=3     error_code=0
SET TIMESTAMP=1380269001/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=9/*!*/;
BEGIN
/*!*/;
# at 14867994
# at 14868101
# at 14868669
# at 14869417
# at 14869873
# at 14870663
# at 14871697
# at 14872055
# at 14872845
# at 14873747
# at 14874591
# at 14875387
# at 14876265
# at 14877039
# at 14877985
# at 14878299
# at 14879091
# at 14879853
# at 14880255
# at 14881029
.
.
.
# at 117398235
# at 117399219
# at 117400203
# at 117401191
# at 117402179
# at 117403167
# at 117403969
# at 117404957
# at 117405945
# at 117406933
# at 117407921
# at 117408909
# at 117409897
# at 117410885
# at 117411873
# at 117412861
# at 117413849
# at 117414837
# at 117415785
# at 117416797
# at 117417839
# at 117418595
# at 117419585
#130927 10:03:21 server id 1  end_log_pos 14867816      Table_map: 'test'.'pac_list' mapped to number 216570427
#130927 10:03:21 server id 1  end_log_pos 14868384      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14869132      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14869588      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14870378      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14871412      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14871770      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14872560      Update_rows: table id 216570427
#130927 10:03:21 server id 1  end_log_pos 14873462      Update_rows: table id 216570427
.
.
.

Agora estou confuso porque primeiro não tenho ideia de como interpretar esse log (está tudo bem ou errado), e segundo não sei como consertar isso.

Às vezes, quando recebo alguns erros de replicação, esse truque é útil:

SET GLOBAL SQL_SLAVE_SKIP_COUNTER=1; START SLAVE;

Mas agora não tenho erros e ambos os processos escravos IO e SQL estão em execução.

Poderia definir SQL_SLAVE_SKIP_COUNTER = 1 para trazer de volta a replicação ??

O que posso fazer para diagnosticar mais esse problema e corrigi-lo sem definir a réplica do zero (esse último cenário que desejo evitar)

EDITAR: O lag startet quando um dos desenvolvedores copiou acidentalmente uma das tabelas pac_list (200MB com 600000 registros) e ele copiou nomeou test.pac_list (tem ponto no nome da tabela) ele quer criar cópia no banco de dados teste mas ele fez algo errado e createt tabela test.pac_list no mesmo banco de dados da tabela original. Depois que ele descobriu seu erro, ele descartou a tabela test.pac_list e criou tabelas pac_list no novo banco de dados. Poderia isso ser motivo de tamanha defasagem?

    

Answer 1

faça uma lista de processos completa para ver qual consulta está suspendendo a replicação.

também, vejo que há um começo:

14867924
SET TIMESTAMP=1380269001/!/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=9/!/;
BEGIN

então pode ser que a replicação esteja bloqueada até END?

link