Description:
Currently performance_schema tracks IO to both the slave relay logs, and binary logs, and their related index files, as the same events - wait/io/file/sql/binlog and wait/io/file/sql/binlog_index. This is obvious when looking at summaries on the file level, however when trying to diagnose IO for background slave threads and looking at summaries from a thread perspective, it would be useful to have these broken out by relay log or binary log.
This is especially true of mid level servers in a replication tree, where the server may be a master and a slave where the slave SQL threads reads from the relay logs, and causes writes to the binary logs.
mysql> SELECT SUBSTRING_INDEX(file_name, '/', -1) AS file, fsbi.event_name,
-> count_read, sum_number_of_bytes_read,
-> count_write, sum_number_of_bytes_write
-> FROM file_summary_by_instance fsbi
-> JOIN file_instances USING (file_name)
-> WHERE fsbi.event_name = 'wait/io/file/sql/binlog'
-> AND open_count > 0\G
*************************** 1. row ***************************
file: mysql-bin.000001
event_name: wait/io/file/sql/binlog
count_read: 0
sum_number_of_bytes_read: 0
count_write: 6
sum_number_of_bytes_write: 931
*************************** 2. row ***************************
file: mysql_sandbox11045-relay-bin.000002
event_name: wait/io/file/sql/binlog
count_read: 37
sum_number_of_bytes_read: 5039
count_write: 76
sum_number_of_bytes_write: 5039
2 rows in set (0.00 sec)
Likewise the wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond event has different meanings depending on the context the server is in.
For a master server, it is the time a connected slave server thread has waited for an update to the binary log - i.e within MYSQL_BIN_LOG::wait_for_update_bin_log(), which corresponds to the "Master has sent all binlog to slave; waiting for binlog to be updated" state.
For a slave server, it is the time the SQL thread has waited for the IO thread to write more events to the relay log - i.e within MYSQL_BIN_LOG::wait_for_update_relay_log(), which corresponds to the "Slave has read all relay log; waiting for the slave I/O thread to update it" state.
In the same mid-level-tree replication server scenario, this makes it hard to differentiate based on different summaries.
How to repeat:
o Set up a simple master/slave replication, enable log_slave_updates
SELECT SUBSTRING_INDEX(file_name, '/', -1) AS file, fsbi.event_name,
count_read, sum_number_of_bytes_read,
count_write, sum_number_of_bytes_write
FROM file_summary_by_instance fsbi
JOIN file_instances USING (file_name)
WHERE fsbi.event_name = 'wait/io/file/sql/binlog'
AND open_count > 0\G
Suggested fix:
Add new wait/io/file/sql/relaylog and wait/io/file/sql/relaylog_index events to track relay log IO specifically.
Split wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond in to wait/synch/cond/sql/MYSQL_BIN_LOG::update_binlog_cond and wait/synch/cond/sql/MYSQL_BIN_LOG::update_relaylog_cond.
Description: Currently performance_schema tracks IO to both the slave relay logs, and binary logs, and their related index files, as the same events - wait/io/file/sql/binlog and wait/io/file/sql/binlog_index. This is obvious when looking at summaries on the file level, however when trying to diagnose IO for background slave threads and looking at summaries from a thread perspective, it would be useful to have these broken out by relay log or binary log. This is especially true of mid level servers in a replication tree, where the server may be a master and a slave where the slave SQL threads reads from the relay logs, and causes writes to the binary logs. mysql> SELECT SUBSTRING_INDEX(file_name, '/', -1) AS file, fsbi.event_name, -> count_read, sum_number_of_bytes_read, -> count_write, sum_number_of_bytes_write -> FROM file_summary_by_instance fsbi -> JOIN file_instances USING (file_name) -> WHERE fsbi.event_name = 'wait/io/file/sql/binlog' -> AND open_count > 0\G *************************** 1. row *************************** file: mysql-bin.000001 event_name: wait/io/file/sql/binlog count_read: 0 sum_number_of_bytes_read: 0 count_write: 6 sum_number_of_bytes_write: 931 *************************** 2. row *************************** file: mysql_sandbox11045-relay-bin.000002 event_name: wait/io/file/sql/binlog count_read: 37 sum_number_of_bytes_read: 5039 count_write: 76 sum_number_of_bytes_write: 5039 2 rows in set (0.00 sec) Likewise the wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond event has different meanings depending on the context the server is in. For a master server, it is the time a connected slave server thread has waited for an update to the binary log - i.e within MYSQL_BIN_LOG::wait_for_update_bin_log(), which corresponds to the "Master has sent all binlog to slave; waiting for binlog to be updated" state. For a slave server, it is the time the SQL thread has waited for the IO thread to write more events to the relay log - i.e within MYSQL_BIN_LOG::wait_for_update_relay_log(), which corresponds to the "Slave has read all relay log; waiting for the slave I/O thread to update it" state. In the same mid-level-tree replication server scenario, this makes it hard to differentiate based on different summaries. How to repeat: o Set up a simple master/slave replication, enable log_slave_updates SELECT SUBSTRING_INDEX(file_name, '/', -1) AS file, fsbi.event_name, count_read, sum_number_of_bytes_read, count_write, sum_number_of_bytes_write FROM file_summary_by_instance fsbi JOIN file_instances USING (file_name) WHERE fsbi.event_name = 'wait/io/file/sql/binlog' AND open_count > 0\G Suggested fix: Add new wait/io/file/sql/relaylog and wait/io/file/sql/relaylog_index events to track relay log IO specifically. Split wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond in to wait/synch/cond/sql/MYSQL_BIN_LOG::update_binlog_cond and wait/synch/cond/sql/MYSQL_BIN_LOG::update_relaylog_cond.