Bug #89637 Contribution by Facebook: Slow Query Log Changes
Submitted: 13 Feb 2018 1:38 Modified: 15 Oct 2018 16:06
Reporter: FBContrib Admin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:8.0.4 OS:Any
Assigned to: CPU Architecture:Any

[13 Feb 2018 1:38] FBContrib Admin 
Description:
Background innformation provided by Facebook:
Abstract:
MySQL 5.6's slow query log outputs the wrong timestamp time.
Instead of the start-of-query time, it outputs the end-of-query time.
This fixes that problem and tests for regressions.

Repo: https://github.com/mysql/mysql-server
Patch on top of 8.0.4: https://github.com/mysql/mysql-server/commit/577fbcf856cd693434d554545d499559bcdd3695

Also adds more attributes to slow query log....
Query_time, Lock_time, Rows_sent and Rows_examined have always been there.
All others are new and improve performance debugging.
The new output is:
	# Query_time: 0  Lock_time: 0  Rows_sent: 0  Rows_examined: 0 \
	Thread_id: 3 Errno: 0 Killed: 0 Bytes_received: 110 \
	Bytes_sent: 134 Read_first: 0 Read_last: 0 Read_key: 2 \
	Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 0 \
	Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 \
	Sort_scan_count: 0 Created_tmp_disk_tables: 0 \
	Created_tmp_tables: 0 Start:  9:22:58 End:  9:22:58

Also, improves performance by moving some code out of the block in which
the log mutex is locked.

The second patch modifies the additional slow query log output statistics to 
be per-query rather than cumulative.

How to repeat:
See description

Suggested fix:
See contribution code attached
[13 Feb 2018 1:38] FBContrib Admin 
Slow Query Log Changes 
(*) This code is contributed under the Facebook agreement

Contribution: fb_patch_27.txt (text/plain), 40.82 KiB.
[15 Oct 2018 16:06] Paul DuBois 
Posted by developer:
 
Fixed in 8.0.14.

A new system variable, log_slow_extra, if enabled, causes the server
to write additional fields to slow query log lines that provide
information about slow statements. In addition, SET lines written to
the log to indicate statement timestamps now use the time from the
beginning of statement execution, rather than the time at the end of
execution. Thanks to Facebook for the contribution on which this
feature is based.