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