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>
Copyright (c) 2000, 2019, Oracle Corporation and/or its affiliates. All rights reserved.