Escravo do Mysql preso em "Bloqueio do sistema"

8

Meu escravo do MySQL está gastando muito tempo Slave_SQL_Running_State: System lock. Percebo que o sistema está atualmente ligado à gravação de E / S e processando o log, embora lentamente. Show processlistnão mostra nada além de "Aguardando que o mestre envie evento" e "Bloqueio do sistema" quando está nesse estado.

Todas as minhas tabelas (além das tabelas de sistema) são InnoDB e o bloqueio externo está desativado. O que o escravo está fazendo neste estado?

Aqui estão algumas informações que foram solicitadas:

Primeiro, esta é a comunidade MySQL 5.6 em uma instância do Amazon EC2, com todo o armazenamento no EBS.

mysql> show processlist;
+----+-------------+-----------+---------------+---------+--------+----------------------------------+------------------+
| Id | User        | Host      | db            | Command | Time   | State                            | Info             |
+----+-------------+-----------+---------------+---------+--------+----------------------------------+------------------+
|  1 | system user |           | NULL          | Connect |  26115 | Waiting for master to send event | NULL             |
|  2 | system user |           | NULL          | Connect | 402264 | System lock                      | NULL             |
| 14 | readonly    | localhost | theshadestore | Query   |      0 | init                             | show processlist |
+----+-------------+-----------+---------------+---------+--------+----------------------------------+------------------+
3 rows in set (0.00 sec)

mysql> show slave status\G
*************************** 1. row ***************************
               Slave_IO_State: Waiting for master to send event
                  Master_Host: 184.106.16.14
                  Master_User: replicant
                  Master_Port: 3306
                Connect_Retry: 60
              Master_Log_File: bin-log.000764
          Read_Master_Log_Pos: 505452667
               Relay_Log_File: relay-log.000197
                Relay_Log_Pos: 345413863
        Relay_Master_Log_File: bin-log.000746
             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: 345413702
              Relay_Log_Space: 19834085375
              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: 402263
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: 307009
                  Master_UUID: b1bf9a19-dac0-11e2-8ffa-b8ca3a5bce90
             Master_Info_File: mysql.slave_master_info
                    SQL_Delay: 0
          SQL_Remaining_Delay: NULL
      Slave_SQL_Running_State: System lock
           Master_Retry_Count: 86400
                  Master_Bind: 
      Last_IO_Error_Timestamp: 
     Last_SQL_Error_Timestamp: 
               Master_SSL_Crl: 
           Master_SSL_Crlpath: 
           Retrieved_Gtid_Set: 
            Executed_Gtid_Set: 
                Auto_Position: 0
1 row in set (0.00 sec)
Greg
fonte
1
Alguma coisa acontecendo com seu armazenamento? Se for um disco local, você está recebendo avisos SMART ou está possivelmente em uma matriz RAID degradada?
Nedm
Por favor, forneça algumas entradas relevantes a partir do mysqld.logmomento em que a replicação interrompeu na primeira vez E publique a seguinte saída: mysql> SHOW SLAVE STATUS \ G; mysql> MOSTRA PROCESSLIST COMPLETO;
Alexus4
É um volume EC2 EBS. Não há erros no dmesg.
Greg
1
nota que isso simplesmente pode ser um bug de 5,6, considerar verificar contra a outra versão (por exemplo, 5,5): forums.mysql.com/read.php?22,598354,598354
o wabbit
1
Aqui está a definição de System Lock State. Parece que isso pode estar relacionado ao seu sistema estar vinculado à gravação de E / S. Bloqueio do sistema - O encadeamento solicitará ou aguardará um bloqueio interno ou externo do sistema para a tabela. Para MOSTRAR PERFIL, esse estado significa que o encadeamento está solicitando o bloqueio (sem aguardá-lo). De: dev.mysql.com/doc/refman/5.6/en/general-thread-states.html
jbrahy

Respostas:

2

Bancos de dados em execução no armazenamento distribuído facepalm . Eu avaliaria o sistema de arquivos em execução no sistema de armazenamento EC2 EBS. Provavelmente, o método mais simples é usar algo parecido s=$(date +%s); dd if=/dev/zero of=<database-dir> bs=1M count=512; e=$(date +%s); echo "scale=4; 512 / ( $e - $s )" | bc. Isso pressupõe que você tenha 512 MB de sobra. Agora, o problema com esse benchmarking é que (1) ele não leva em consideração os efeitos de cache e (2) a resolução não é muito boa. Mas se esse teste for lento, então o problema está definitivamente no EC2 EBS. Se o teste for rápido ou nominal, precisamos cavar mais e usar técnicas mais sofisticadas.

O programa bonnie ++ é um pouco adequado, mas não (AFAIK) libera os buffers do SO entre a gravação e a leitura. Ainda assim, você deve ter uma idéia com algo assim bonnie++ -u mysql -r 8 -s 16:512 -n 1 -b -d <mysql-data-directory>. Quando faço isso em uma VM em execução no armazenamento local, recebo:

Version  1.96       ------Sequential Output------ --Sequential Input- --Random-
Concurrency   1     -Per Chr- --Block-- -Rewrite- -Per Chr- --Block-- --Seeks--
Machine   Size:chnk K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP  /sec %CP
test        16M:512  1173  99 +++++ +++ +++++ +++  3187  99 +++++ +++ +++++ +++
Latency              1553us      23us     330us     750us     173us    6372us
Version  1.96       ------Sequential Create------ --------Random Create--------
test                -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
              files  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
                  1  1850  20 +++++ +++ +++++ +++ +++++ +++ +++++ +++ +++++ +++
Latency             27428us      24us    1188us   30258us      36us    1107us

Aqui está o que eu recebo ao executar em uma VM sobre NFS:

Version  1.96       ------Sequential Output------ --Sequential Input- --Random-
Concurrency   1     -Per Chr- --Block-- -Rewrite- -Per Chr- --Block-- --Seeks--
Machine   Size:chnk K/sec %CP K/sec %CP K/sec %CP K/sec %CP K/sec %CP  /sec %CP
test        16M:512  1273  98 +++++ +++ +++++ +++  3053  99 +++++ +++ +++++ +++
Latency              1372us      28us     380us     832us      19us    9473us
Version  1.96       ------Sequential Create------ --------Random Create--------
test                -Create-- --Read--- -Delete-- -Create-- --Read--- -Delete--
              files  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP  /sec %CP
                  1   754  11 +++++ +++   728   8   751  12 +++++ +++   791   8
Latency             12695us      47us    5306us    3710us      30us    3278us
Otheus
fonte
0

Sua instância do EC2 escravo é de tamanho semelhante ao mestre nesse caso?

Se você estiver executando em uma instância menor para economizar dinheiro, poderá encontrar um gargalo lá. Os segundos atrasados ​​são vários dias. A replicação ficou offline por um longo tempo ou isso aumentou com o tempo durante algum tipo de pico de entrada de dados?

zaznet
fonte
O escravo é definitivamente mais lento. Gostaria de saber se existe uma maneira de saber em que consulta o escravo está trabalhando, assim como 'show processlist' no master mostra quais consultas estão em execução.
Greg
1
É uma repetição de log. Você pode ver onde o escravo e o mestre estão na saída fornecida anteriormente. Read_Master_Log_Pos: 505452667 Relay_Log_Pos: 345413863
zaznet