Mysql Slave coincé dans "System lock"

8

Mon esclave MySQL y passe beaucoup de temps Slave_SQL_Running_State: System lock. Je peux voir que le système est actuellement lié en écriture aux E / S et qu'il traite le journal, bien que lentement. Show processlistn'affiche rien d'autre que "Attendre que le maître envoie l'événement" et "Verrouillage système" lorsqu'il est dans cet état.

Toutes mes tables (autres que les tables système) sont InnoDB et le verrouillage externe est désactivé. Que fait l'esclave dans cet état?

Voici quelques informations qui ont été demandées:

Tout d'abord, il s'agit de la communauté MySQL 5.6 sur une instance Amazon EC2, avec tout le stockage sur 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
la source
1
Quelque chose se passe avec votre stockage? S'il s'agit d'un disque local, recevez-vous des avertissements SMART ou se trouve-t-il dans une matrice RAID dégradée?
nedm
Veuillez fournir quelques entrées pertinentes à partir du mysqld.logmoment où la réplication s'est interrompue pour la première fois ET publier la sortie des éléments suivants: mysql> SHOW SLAVE STATUS \ G; mysql> SHOW FULL PROCESSLIST;
alexus
C'est un volume EC2 EBS. Il n'y a aucune erreur dans dmesg.
Greg
1
notez que cela pourrait simplement être un bogue de 5.6, envisagez de vérifier avec une autre version (par exemple 5.5): forums.mysql.com/read.php?22,598354,598354
the-wabbit
1
Voici la définition de l'état de verrouillage du système. Il semble que cela pourrait être lié au fait que votre système est lié en écriture aux E / S. Verrouillage système - Le thread va demander ou attend un verrouillage système interne ou externe pour la table. Pour SHOW PROFILE, cet état signifie que le thread demande le verrouillage (sans l'attendre). de: dev.mysql.com/doc/refman/5.6/en/general-thread-states.html
jbrahy

Réponses:

2

Bases de données fonctionnant sur facepalm de stockage distribué . Je comparerais le système de fichiers fonctionnant au-dessus du système de stockage EC2 EBS. La méthode la plus simple est probablement d'utiliser quelque chose comme s=$(date +%s); dd if=/dev/zero of=<database-dir> bs=1M count=512; e=$(date +%s); echo "scale=4; 512 / ( $e - $s )" | bc. Cela suppose que vous disposez de 512 Mo de rechange. Maintenant, le problème avec cette analyse comparative est que (1) elle ne prend pas en compte les effets de mise en cache et (2) la résolution n'est pas très fine. Mais si ce test est lent, le problème est définitivement avec EC2 EBS. Si le test est rapide ou nominal, nous devons creuser davantage et utiliser des techniques plus sophistiquées.

Le programme bonnie ++ est quelque peu adéquat, mais il (AFAIK) ne vide pas les tampons du système d'exploitation entre l'écriture et la lecture. Pourtant, vous devriez avoir une idée avec quelque chose comme bonnie++ -u mysql -r 8 -s 16:512 -n 1 -b -d <mysql-data-directory>. Lorsque je fais cela sur une machine virtuelle exécutée sur le stockage local, j'obtiens:

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

Voici ce que j'obtiens lors de l'exécution sur une machine virtuelle sur 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
la source
0

Votre instance EC2 esclave a-t-elle une taille similaire à celle du maître dans ce cas?

Si vous utilisez une instance plus petite pour économiser de l'argent, vous risquez de vous heurter à un goulot d'étranglement. Le retard est de plusieurs jours. La réplication a-t-elle été hors ligne pendant longtemps ou s'est-elle développée au fil du temps lors d'une sorte de pic de saisie de données?

zaznet
la source
L'esclave est définitivement plus lent. Je me demande s'il y a un moyen de savoir sur quelle requête l'esclave travaille, tout comme la façon dont «show processlist» sur le maître montre quelles requêtes sont en cours d'exécution.
Greg
1
C'est une relecture du journal. Vous pouvez voir où se trouvent l'esclave et le maître dans la sortie fournie précédemment. Read_Master_Log_Pos: 505452667 Relay_Log_Pos: 345413863
zaznet