MySQL Bugs: #78618: Please report the SQL thread position when it stops

Bug #78618	Please report the SQL thread position when it stops
Submitted:	29 Sep 2015 7:55	Modified:	15 Jun 2016 12:36
Reporter:	Simon Mudd (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S4 (Feature request)
Version:	5.6+, 5.7.10	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	logging, position, replication, sql_thread

Description:
When you execute stop slave you see:

2015-09-29T07:43:35.915013Z 2 [Note] Error reading relay log event for channel '': slave SQL thread was killed
2015-09-29T07:43:35.916100Z 1 [Note] Slave I/O thread killed while reading event for channel ''
2015-09-29T07:43:35.916139Z 1 [Note] Slave I/O thread exiting for channel '', read up to log 'binlog.002148', position 61629216

( This is from 5.7 but 5.6 logs roughly the same thing. )

This shows the position that the I/O thread stopped.
It does not show the position at which the SQL thread(s) stopped.
The latter is important as it gives you a state in the database corresponding to the last "event processed" rather than the last "event received".

How to repeat:
Run STOP SLAVE; and see what the logs say.

Suggested fix:
Please add to the logging the stopped position of the SQL thread.
If you're using MTS then log something that's useful and can be used for forensics if needed.
If using GTID log the GTID executed position, so we know this value too.

If a later change to a different master causes problems then the existing logging allows you to recover. Without it the required information is not available in the logs.

I'm sure I requested this some time ago (years?) but can't find the bug report, so if this is a duplicate then please mark it as such. Nevertheless hopefully this description is clear and may be clearer than any previous FR.

Hello Simon,

Thank you for the feature request!

Thanks,
Umesh

// 5.7.10 - extracts from log

2015-09-30T08:16:06.268864Z 0 [Note] bin/mysqld: ready for connections.
Version: '5.7.10-enterprise-commercial-advanced-log'  socket: '/export/umesh/server/binaries/mysql-advanced-5.7.10/run/slave.sock'  port: 15001  MySQL Enterprise Server - Advanced Edition (Commercial)
2015-09-30T08:19:27.856191Z 2 [Note] 'CHANGE MASTER TO FOR CHANNEL '' executed'. Previous state master_host='', master_port= 3306, master_log_file='', master_log_pos= 4, master_bind=''. New state master_host='localhost', master_port= 15000, master_log_file='master-bin.000001', master_log_pos= 1220, master_bind=''.
.
.
2015-09-30T08:41:36.219609Z 5 [Note] Error reading relay log event for channel '': slave SQL thread was killed
2015-09-30T08:41:36.219986Z 3 [Note] Slave I/O thread killed while reading event for channel ''
2015-09-30T08:41:36.220009Z 3 [Note] Slave I/O thread exiting for channel '', read up to log 'master-bin.000001', position 1220

Adding the master_host and master_user might be convenient too.

and GTID information is also surprisingly absent.