Uploaded image for project: 'Percona Server'
  1. Percona Server
  2. PS-4758

A sequence of LOCK TABLES FOR BACKUP and STOP SLAVE SQL_THREAD can cause replication to be blocked and cannot be restarted normally

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Pending Release
    • Priority: High
    • Resolution: Fixed
    • Affects Version/s: 5.7.22-22
    • Fix Version/s: 8.0.13-3, 5.6.NEXT, 5.7.NEXT
    • Component/s: None
    • Labels:

      Description

      Using Percona Server 5.7.22 to reproduce:

      On, Master, create many tables:

       

      sysbench --mysql-host=192.168.0.5 --mysql-port=18923 --mysql-user=sbtest --mysql-password=sbtest --mysql-db=sbtest  --tables=500 --table-size=100000 --threads=16 --time=600 /usr/share/sysbench/oltp_common.lua prepare

       

      On Slave, run:

       

      LOCK TABLES FOR BACKUP; 
      SELECT SLEEP(30);
      STOP SLAVE SQL_THREAD;
      

      The processlist on slave would look like this:

       

      MySQL [(none)]> show full processlist;
      +----+-------------+--------------------+--------+---------+------+----------------------------------+------------------------------------+-----------+---------------+
      | Id | User        | Host               | db     | Command | Time | State                            | Info                               | Rows_sent | Rows_examined |
      +----+-------------+--------------------+--------+---------+------+----------------------------------+------------------------------------+-----------+---------------+
      |  1 | system user |                    | NULL   | Connect |  909 | Waiting for master to send event | NULL                               |         0 |             0 |
      |  4 | root        | localhost:45108    | NULL   | Query   |  740 | Killing slave                    | STOP SLAVE SQL_THREAD              |         0 |             0 |
      |  5 | system user |                    | sbtest | Connect | 4368 | Waiting for backup lock          | CREATE INDEX k_367 ON sbtest367(k) |         0 |             0 |
      |  6 | sbtest      | 192.168.0.13:61127 | NULL   | Sleep   |  721 |                                  | NULL                               |         0 |             0 |
      |  7 | sbtest      | 192.168.0.13:61128 | NULL   | Sleep   |  639 |                                  | NULL                               |         0 |             0 |
      |  8 | sbtest      | 192.168.0.13:61252 | NULL   | Query   |    0 | starting                         | show full processlist              |         0 |             0 |
      +----+-------------+--------------------+--------+---------+------+----------------------------------+------------------------------------+-----------+---------------+
      6 rows in set (0.00 sec)

      SHOW SLAVE STATUS shows that replication is blocked

       

      MySQL [(none)]> SHOW SLAVE STATUS\G
      *************************** 1. row ***************************
                     Slave_IO_State: Waiting for master to send event
                        Master_Host: 127.0.0.1
                        Master_User: rsandbox
                        Master_Port: 18923
                      Connect_Retry: 60
                    Master_Log_File: mysql-bin.000012
                Read_Master_Log_Pos: 853298990
                     Relay_Log_File: mysql-relay.000026
                      Relay_Log_Pos: 604631379
              Relay_Master_Log_File: mysql-bin.000009
                   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: 604631166
                    Relay_Log_Space: 4075801822
                    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: 4553
      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: 100
                        Master_UUID: 00018923-1111-1111-1111-111111111111
                   Master_Info_File: /ssd/sandboxes/rsandbox_5_7_22/node1/data/master.info
                          SQL_Delay: 0
                SQL_Remaining_Delay: NULL
            Slave_SQL_Running_State: Waiting for backup 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
               Replicate_Rewrite_DB: 
                       Channel_Name: 
                 Master_TLS_Version: 
      1 row in set (0.00 sec)
      

      At this point, a kill -9, is the only way to get replication back running because shutting down normally is blocked too.

       

      2018-08-22T06:30:32.816013Z 1 [Note] Slave I/O thread killed while reading event for channel ''
      2018-08-22T06:30:32.816026Z 1 [Note] Slave I/O thread exiting for channel '', read up to log 'mysql-bin.000012', position 880140441
      2018-08-22T06:30:32.816847Z 0 [Note] Giving 4 client threads a chance to die gracefully
      2018-08-22T06:30:32.816860Z 0 [Note] Shutting down slave threads
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                sergei.glushchenko Sergei Glushchenko
                Reporter:
                jaime.sicam@percona.com Jaime Sicam
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 6 hours
                  6h