WL#12393: Logging: Add new global variable, log_slow_extra, for richer slow logging

Affects: Server-8.0   —   Status: Complete   —   Priority: Medium

Add a new command-line option, --log-slow-extra, that will turn on
richer logging in the slow query log.

(see next section, Functional and Non-Functional Requirements, for exact 
specification of the old and new formats)

Adapted from contribution from Facebook (BUG#89637).
Func-Req 1

1.1 A new global variable, log_slow_extra, shall be added.
1.2 Its value is boolean.
1.3 Its default is OFF.
1.4 Its value can be set at start-up on the command-line, and/or changed at run-
time with the SET command.
1.5 If a value is set while log_output does not include a FILE target, a warning 
is thrown (and the requested value set).


Func-Req 2

If --log-slow-extra is used, the line of a slow log record
that traditionally reads as follows,

  # Query_time: <duration>  Lock_time: <duration> 
    Rows_sent: <number>  Rows_examined: <number>

where possible is replaced by a richer variant, as shown below, also as a single 
line:

	# 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

The counters are intended to reflect per-statement values
rather than cumulative per-session ones.


Func-Req 3

Independent of switches given (see above), the line

  SET [last_insert_id=1,][insert_id=1,]timestamp=<time>

now uses the time at the beginning of statement execution
rather than at the time of logging (i.e. rather than at
the end of execution).
I-1  Semantics

NO CHANGE

I-2  Instrumentation

NO CHANGE

I-3  Error and Warnings

NO CHANGE

I-4  Install/Upgrade

NO CHANGE

I-5  Commercial plugins

NO CHANGE.

I-6  Replication

NO CHANGE

I-7  XProtocols

NO CHANGE

I-8  Protocols

NO CHANGE

I-9  Security

NO CHANGE

I-10  Log Files

YES.
[LOG04] The slow query log can now be set to a new, richer mode which contains 
more information, and to that end extends to existing format.
If the new, extended format is not specifically requested, slow queries are 
logged as before, in the well-known, documented format.
Logging slow queries to a table remains unaffected.

I-11  MySQL clients

NO CHANGE

I-12  Auth plugins

NO CHANGE

I-13  Globalization

NO CHANGE

I-14  Configuration

YES
[CONF01] A new command-line option is added, --log-slow-extra.

I-15  File formats

NO CHANGE (see log files for that)

I-16  Plugins/APIs

NO CHANGE

I-17  Other programs

NO CHANGE

I-18  Storage engines

NO CHANGE

I-19  Data types

NO CHANGE
- opt_log_slow_extra applies globally; having some sessions in terse and others 
in extended mode is not supported.

- If opt_log_slow_extra is active, thd->status_var is saved before
  execution begins. File_query_log::write_slow() is extended
  to accepted this saved state, and will print the deltas between 
  the saved start-values  and values at the end of execution (i.e.
  those found in thd->status at the time of logging).
  Various internal APIs in log.cc/log.h along the call chain are likewise
  updated to forward that saved state downwards for ultimate consumption
  in log_slow_do().

- If opt_log_slow_extra is false, the behavior is as in previous
  versions of the MySQL server.

- The change affects only the file-log; logging to table remains unchanged.

- To clarify, this mechanism is functionally independent from the existing
  --log-short-format that can be used to disable the preamble,

  # Time: <end_time>
  # User@Host: <user>@<host>  Id: <thread_id>