Forum Stats

  • 3,853,815 Users
  • 2,264,280 Discussions
  • 7,905,457 Comments

Discussions

IO thread works slowly and most of time in 'system lock' status

2784987
2784987 Member Posts: 54
edited May 18, 2016 10:23AM in MySQL Community Space

OS: Oracle linux 6.2

MySQL:5.7.10

I was using sysbench to test the delay of the slave and found the bottleneck was in IO thread.

most of the time,it was in 'system lock' status and it took a lot of time to transfer the binlogs:

mysql> show slave status\G

*************************** 1. row ***************************

               Slave_IO_State: System lock

                  Master_Host: szxftd5db02.huawei.com

                  Master_User: repluser

                  Master_Port: 30001

                Connect_Retry: 60

              Master_Log_File: master-bin.000006

          Read_Master_Log_Pos: 709990687

               Relay_Log_File: relay-log.000017

                Relay_Log_Pos: 642200342

        Relay_Master_Log_File: master-bin.000006

             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: 642200127

              Relay_Log_Space: 6079023471

              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: 19245

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: 101

                  Master_UUID: 956c8d6a-1b32-11e6-b4d0-80000048fe80

             Master_Info_File: mysql.slave_master_info

                    SQL_Delay: 0

          SQL_Remaining_Delay: NULL

      Slave_SQL_Running_State: Reading event from the relay log

           Master_Retry_Count: 86400

                  Master_Bind:

      Last_IO_Error_Timestamp:

     Last_SQL_Error_Timestamp:

               Master_SSL_Crl:

           Master_SSL_Crlpath:

           Retrieved_Gtid_Set: 956c8d6a-1b32-11e6-b4d0-80000048fe80:1-2015411

            Executed_Gtid_Set: 02de1c14-1b48-11e6-971d-80000048fe80:1,

956c8d6a-1b32-11e6-b4d0-80000048fe80:1-1985309

                Auto_Position: 1

         Replicate_Rewrite_DB:

                 Channel_Name:

           Master_TLS_Version:

1 row in set (0.03 sec)

the processlist in slave is as below:

mysql> show full processlist;

+----+-------------+-----------+------+---------+--------+---------------------------------------+-----------------------+

| Id | User        | Host      | db   | Command | Time   | State                                 | Info                  |

+----+-------------+-----------+------+---------+--------+---------------------------------------+-----------------------+

|  4 | system user |           | NULL | Connect | 165845 | System lock                           | NULL                  |

|  5 | system user |           | NULL | Connect |      0 | Reading event from the relay log      | NULL                  |

|  6 | system user |           | NULL | Connect |  20066 | Waiting for an event from Coordinator | NULL                  |

|  7 | system user |           | NULL | Connect |  20066 | Waiting for an event from Coordinator | NULL                  |

| 10 | root        | localhost | NULL | Query   |      0 | starting                              | show full processlist |

+----+-------------+-----------+------+---------+--------+---------------------------------------+-----------------------+

5 rows in set (0.00 sec)

in the same time,the master status is as following:

mysql> show full processlist;

+-----+----------+-------------------+------+------------------+--------+-------------------+-----------------------+

| Id  | User     | Host              | db   | Command          | Time   | State             | Info                  |

+-----+----------+-------------------+------+------------------+--------+-------------------+-----------------------+

|  43 | repluser | 10.63.68.95:50424 | NULL | Binlog Dump GTID | 165029 | Sending to client | NULL                  |

| 207 | root     | localhost         | NULL | Query            |      0 | starting          | show full processlist |

+-----+----------+-------------------+------+------------------+--------+-------------------+-----------------------+

2 rows in set (0.00 sec)

and

mysql> show master status\G

*************************** 1. row ***************************

             File: master-bin.000008

         Position: 428697670

     Binlog_Do_DB:

Binlog_Ignore_DB:

Executed_Gtid_Set: 956c8d6a-1b32-11e6-b4d0-80000048fe80:1-2673501

1 row in set (0.00 sec)

How to find the root cause and fix it?

thanks

Answers