Bug #98220 with log_slow_extra=on Errno: info not getting updated correctly for error

Submitted: 14 Jan 2020 9:29 Modified: 22 Jan 2021 19:11
Reporter: lalit Choudhary Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:8.0.19 OS:Any
Assigned to: CPU Architecture:Any
Tags: log_slow_extra, slow_query_log

[14 Jan 2020 9:29] lalit Choudhary
Description:
https://dev.mysql.com/doc/refman/8.0/en/server-system-variables.html#sysvar_log_slow_extra
Enabling the log_slow_extra system variable (available as of MySQL 8.0.14) causes the server to write the following extra fields to FILE output

as per the documentation,

Errno: error_number
The statement error number, or 0 if no error occurred.

In a test, I found that even if SQL query fails with error in the slow query log Errno: has '0' value.

How to repeat:
ps 8.0.17

log_slow_extra=on

mysql [localhost] {msandbox} (test) > create table a(d decimal(4,2));
Query OK, 0 rows affected (0.06 sec)

mysql [localhost] {msandbox} (test) > create table b(as invalid);
ERROR 1064 (42000): You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'as invalid)' at line 1

# Time: 2020-01-14T09:08:50.703939Z
# User@Host: msandbox[msandbox] @ localhost []  Id:     8
# Query_time: 0.063812  Lock_time: 0.000490 Rows_sent: 0  Rows_examined: 0 Thread_id: 8 Errno: 0 Killed: 0 Bytes_received: 0 Bytes_sent: 11 Read_first: 0 Read_last: 0 Read_key: 18 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: 2020-01-14T09:08:50.640127Z End: 2020-01-14T09:08:50.703939Z Schema: test Rows_affected: 0
SET timestamp=1578992930;
create table a(d decimal(4,2));

# Time: 2020-01-14T09:09:32.811641Z
# User@Host: msandbox[msandbox] @ localhost []  Id:     8
# Query_time: 0.000096  Lock_time: 0.000000 Rows_sent: 0  Rows_examined: 0 Thread_id: 8 Errno: 0 Killed: 0 Bytes_received: 0 Bytes_sent: 170 Read_first: 0 Read_last: 0 Read_key: 0 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: 2020-01-14T09:09:32.811545Z End: 2020-01-14T09:09:32.811641Z Schema: test Rows_affected: 0
SET timestamp=1578992972;
create table b(as invalid);

Suggested fix:
Expected behavior: Errno field should have an error number for a failed query with an error.
[14 Jan 2020 9:38] lalit Choudhary
with log_slow_extra=on Errno: info not getting updated correctly for error
[16 Jan 2020 9:58] MySQL Verification Team
Hello Lalit,

Thank you for the report and test case.

regards,
Umesh
[22 Jan 2021 19:11] Paul DuBois
Posted by developer:
 
Fixed in 8.0.24.

With the log_slow_extra system variable enabled to add the Errno
field to slow query log output, the error number was 0 even for
failed statements.

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.052 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.