Bug #77778 tuning the log_lock contention for IO_THREAD and SQL_THREAD in rpl_slave.cc

• Submitted: 19 Jul 2015 5:57
• Modified: 31 Mar 2017 17:24
• Reporter: Fangxin Flou (OCA)
• Status: Closed
• Category: MySQL Server: Replication
• Severity: S3 (Non-critical)
• Version: 5.6.25
• OS: Any
• CPU Architecture: Any
• Tags: binlog, slave

[19 Jul 2015 5:57] Fangxin Flou

Description:
When slave processing the current relay log file, the binary relay performance becomes extremely slow.

The IO_THREAD and SQL_THREAD have hot lock contention on log_lock when save or read event from file.

How to repeat:
Make lot's of transactions on master, then watch the sql relay speed.

Suggested fix:
The best way is to optimized the log_lock usage. Use the fast_next_event to replace the old next_event.

I have test it on slave, after several binary log switch, and check the table data of master and slave.

Check the attachement for the patch file.

[19 Jul 2015 5:58] Fangxin Flou

Patch file for log_lock optimization.

Attachment: mysql-5.6.25-slave-lockless.txt (text/plain), 20.51 KiB.

[19 Jul 2015 7:17] Fangxin Flou

fix a bug of the patch

Attachment: mysql-5.6.25-slave-lockless.txt (text/plain), 20.54 KiB.

[20 Jul 2015 11:31] Fangxin Flou

keep on tuning the log_lock

Attachment: mysql-5.6.25-slave-lockless.txt (text/plain), 22.56 KiB.

[20 Jul 2015 11:33] Fangxin Flou

I tested today, got the same performance for current relay log as non-hot log performance, this is critical for slave.

And with the new patch, the IO_THREAD can update the relay log with append mode only, avoid the setting of the file pos for each binlog event.

Thanks.

[26 Dec 2016 3:09] Fangxin Flou

The following code need to be changed

+ 	    mysql_mutex_lock(log_lock);
+ 	    rli->flushed_relay_log_id = get_binary_log_index(rli->relay_log.get_log_fname());
+ 	    rli->flushed_relay_log_pos = rli->relay_log.get_log_file()->end_of_file;
+ 	    mysql_mutex_unlock(log_lock);

the new code

+ 	    mysql_mutex_lock(log_lock);
+ 	    rli->flushed_relay_log_id = get_binary_log_index(rli->relay_log.get_log_fname());
+          if (0 == flush_io_cache(rli->relay_log.get_log_file()))
+ 	        rli->flushed_relay_log_pos = rli->relay_log.get_log_file()->end_of_file;
+ 	    mysql_mutex_unlock(log_lock);

to flush the remain bytes of the hot log IO_CACHE buffer.

[26 Dec 2016 3:09] Fangxin Flou

The following code need to be changed

+ 	    mysql_mutex_lock(log_lock);
+ 	    rli->flushed_relay_log_id = get_binary_log_index(rli->relay_log.get_log_fname());
+ 	    rli->flushed_relay_log_pos = rli->relay_log.get_log_file()->end_of_file;
+ 	    mysql_mutex_unlock(log_lock);

the new code

+ 	    mysql_mutex_lock(log_lock);
+ 	    rli->flushed_relay_log_id = get_binary_log_index(rli->relay_log.get_log_fname());
+          if (0 == flush_io_cache(rli->relay_log.get_log_file()))
+ 	        rli->flushed_relay_log_pos = rli->relay_log.get_log_file()->end_of_file;
+ 	    mysql_mutex_unlock(log_lock);

to flush the remain bytes of the hot log IO_CACHE buffer.

[31 Mar 2017 17:24] Daniel Price

Posted by developer:
 
Fixed as of the upcoming 8.0.1 release, and here's the changelog entry:

Lock contention impeded binary relay performance during processing of the
relay log file on the slave.