Bug #93034 replication logging - please move to performance_schema
Submitted: 31 Oct 2018 18:24 Modified: 9 Nov 2018 12:33
Reporter: Simon Mudd (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S4 (Feature request)
Version:8.0.13 OS:Any
Assigned to: CPU Architecture:Any
Tags: logging, performance_schema, replication
Triage: Needs Triage: D5 (Feature request)

[31 Oct 2018 18:24] Simon Mudd
Description:
I see these logs in my system every 2 minutes:

2018-10-31T17:52:42.509623Z 5 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 121; events assigned = 12525569; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 2730510184400 waited (count) when Workers occupied = 0 waited when Workers occupied = 0
2018-10-31T17:54:43.617469Z 5 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 121; events assigned = 12592129; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 2744546840600 waited (count) when Workers occupied = 0 waited when Workers occupied = 0
2018-10-31T17:56:43.001382Z 5 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 120; events assigned = 12658689; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 2759298694200 waited (count) when Workers occupied = 0 waited when Workers occupied = 0
2018-10-31T17:58:43.785779Z 5 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 120; events assigned = 12759041; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 2780638594600 waited (count) when Workers occupied = 0 waited when Workers occupied = 0
2018-10-31T18:00:44.268489Z 5 [Note] [MY-010559] [Repl] Multi-threaded slave statistics for channel '': seconds elapsed = 121; events assigned = 12834817; worker queues filled over overrun level = 0; waited due a Worker queue full = 0; waited due the total size = 0; waited at clock conflicts = 2797422939800 waited (count) when Workers occupied = 0 waited when Workers occupied = 0

This is noisy and not easy to read. Docs on the MySQL web site don't help much. I got pointed at https://www.percona.com/blog/2017/07/19/multi-threaded-slave-statistics/ which helps a lot more.  Thanks JF.

$ sudo grep -c MY-010559 /var/log/mysqld.log
200

not been running long but it’s noisy.

How to repeat:
setup replication, at least with write set and watch the noise.
Then wonder what it means.

Suggested fix:
1. At least i can turn off the noise with dragnet logging
2. However the information is useful. Please expose this via a performance_schema table.
3. If you don't stop the logging make the display interval configurable, including setting it to 0 meaning don't show anything.
4. Improve the documentation to mention this output or the P_S table if you create one so it can be better understood as https://dev.mysql.com/doc/refman/8.0/en/error-messages-server.html does not help.
[9 Nov 2018 12:33] Umesh Shastry
Hello Simon,

Thank you for the feature request!

regards,
Umesh
[28 Dec 2018 11:15] Amit Wadkar
I'm also facing this issue in 5.7.17 with MTS(Multi Thread slave)