Bug #71892 Missing information in slow query log for slow HANDLER statements

• Submitted: 28 Feb 2014 22:00
• Modified: 24 Mar 2015 21:40
• Reporter: Davi Arnaut (OCA)
• Status: Closed
• Category: MySQL Server: Logging
• Severity: S2 (Serious)
• Version: 5.5,5.6,5.7
• OS: Any
• CPU Architecture: Any
• Tags: Rows_examined, Rows_sent, slow query log

[28 Feb 2014 22:00] Davi Arnaut

Description:
The Rows_sent and Rows_examined fields of the slow query log are always zero for HANDLER statements.
This rather reduces the usefulness of the slow query log for the analysis of slow HANDLER statements.

How to repeat:
mysql> SET GLOBAL log_output='TABLE';
Query OK, 0 rows affected (0.00 sec)

mysql> SET SESSION long_query_time=1;
Query OK, 0 rows affected (0.00 sec)

mysql> HANDLER t1 OPEN;
Query OK, 0 rows affected (0.00 sec)

mysql> HANDLER t1 READ FIRST WHERE a > SLEEP(2);
+---+------+
| a | b    |
+---+------+
| 1 |    1 |
+---+------+
1 row in set (2.00 sec)

mysql> SELECT sql_text, rows_sent, rows_examined FROM mysql.slow_log;
+------------------------------------------+-----------+---------------+
| sql_text                                 | rows_sent | rows_examined |
+------------------------------------------+-----------+---------------+
| HANDLER t1 READ FIRST WHERE a > SLEEP(2) |         0 |             0 |
+------------------------------------------+-----------+---------------+
1 row in set (0.00 sec)

[3 Mar 2014 8:05] MySQL Verification Team

Hello Davi,

Thank you for the bug report.
Verified as described.

Thanks,
Umesh

[24 Mar 2015 21:40] Paul DuBois

Noted in 5.7.7, 5.8.0 changelogs.

Information written to the slow query log for HANDLER ... READ
statements always had rows_sent and rows_examined values of 0.