Bug #74614 events_statements_history has errors=0 when there are errors
Submitted: 29 Oct 2014 9:15 Modified: 14 Jul 2015 14:07
Reporter: Daniël van Eeden (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Performance Schema Severity:S3 (Non-critical)
Version:5.6.16, 5.6.22, 5.7.7 OS:Any
Assigned to: CPU Architecture:Any

[29 Oct 2014 9:15] Daniël van Eeden
Description:
The errors column has errors=0 while MYSQL_ERRNO, RETURNED_SQLSTATE and MESAGE_TEXT indicate there are errors.

mysql> select left(sql_text,40),MYSQL_ERRNO,RETURNED_SQLSTATE,MESSAGE_TEXT,errors,warnings from events_statements_history where thread_id=(select thread_id from threads where processlist_id=4388062) order by timer_start;
+------------------------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
| left(sql_text,40)                        | MYSQL_ERRNO | RETURNED_SQLSTATE | MESSAGE_TEXT                                           | errors | warnings |
+------------------------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
xxxxxx
| INSERT INTO xxxxxxxxxxxxxxxxxxxxxxxxxxxx |        1205 | HY000             | Lock wait timeout exceeded; try restarting transaction |      0 |        0 |
+------------------------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
10 rows in set (0.00 sec)

From http://dev.mysql.com/doc/refman/5.6/en/events-statements-current-table.html
"ERRORS
Whether an error occurred for the statement. The value is 0 if the SQLSTATE value 
begins with 00 (completion) or 01 (warning). The value is 1 is the SQLSTATE value is anything else."

How to repeat:
See description

Suggested fix:
make sure errors>0 when there are errors.
[31 Oct 2014 10:06] Umesh Shastry
Hello Daniël,

Thank you for the report.

Thanks,
Umesh
[31 Oct 2014 10:07] Umesh Shastry
// PS Enabled all instruments/consumers - just as not to miss anything

mysql> update setup_instruments set enabled='yes';
mysql> update setup_consumers set enabled='yes';

// Session 1

SELECT * FROM tiny_table FOR UPDATE;

// Session 2

INSERT INTO tiny_table values(1); <--ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

// Session 3
mysql> select left(sql_text,40),MYSQL_ERRNO,RETURNED_SQLSTATE,MESSAGE_TEXT,errors,warnings from performance_schema.events_statements_history where thread_id=(select thread_id from performance_schema.threads where processlist_id=5) order by timer_start;
+---------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
| left(sql_text,40)         | MYSQL_ERRNO | RETURNED_SQLSTATE | MESSAGE_TEXT                                           | errors | warnings |
+---------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
| insert into t1 values(10) |        1205 | HY000             | Lock wait timeout exceeded; try restarting transaction |      0 |        0 |
+---------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
1 row in set (0.00 sec)
[12 Jun 2015 7:14] Daniël van Eeden
With 5.7.7
I used '\R mysql [conn-\C] > ' to set the prompt for each session.

mysql [conn-2] > use performance_schema
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql [conn-2] > update setup_instruments set enabled='yes';
Query OK, 662 rows affected (0.02 sec)
Rows matched: 981  Changed: 662  Warnings: 0

mysql [conn-2] > update setup_consumers set enabled='yes';
Query OK, 8 rows affected (0.00 sec)
Rows matched: 15  Changed: 8  Warnings: 0

mysql [conn-2] > use test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql [conn-2] > create table tiny_table (id int primary key);
Query OK, 0 rows affected (0.03 sec)

mysql [conn-2] > START TRANSACTION;
Query OK, 0 rows affected (0.00 sec)

mysql [conn-2] > SELECT * FROM tiny_table FOR UPDATE;
Empty set (0.00 sec)

mysql [conn-3] > use test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql [conn-3] > INSERT INTO tiny_table values(1);
Query OK, 1 row affected (0.01 sec)

mysql [conn-3] > INSERT INTO tiny_table values(1);
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

mysql [conn-4] > use performance_schema
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed

mysql [conn-4] > select left(sql_text,40),MYSQL_ERRNO,RETURNED_SQLSTATE,MESSAGE_TEXT,errors,warnings from performance_schema.events_statements_history where thread_id=(select thread_id from performance_schema.threads where processlist_id=3) order by timer_start;
+----------------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
| left(sql_text,40)                | MYSQL_ERRNO | RETURNED_SQLSTATE | MESSAGE_TEXT                                           | errors | warnings |
+----------------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
| select USER()                    |           0 | NULL              | NULL                                                   |      0 |        0 |
| SELECT DATABASE()                |           0 | NULL              | NULL                                                   |      0 |        0 |
| NULL                             |           0 | 00000             | NULL                                                   |      0 |        0 |
| show databases                   |           0 | NULL              | NULL                                                   |      0 |        0 |
| show tables                      |           0 | NULL              | NULL                                                   |      0 |        0 |
| NULL                             |           0 | NULL              | NULL                                                   |      0 |        0 |
| NULL                             |           0 | NULL              | NULL                                                   |      0 |        0 |
| NULL                             |           0 | NULL              | NULL                                                   |      0 |        0 |
| INSERT INTO tiny_table values(1) |           0 | 00000             | NULL                                                   |      0 |        0 |
| INSERT INTO tiny_table values(1) |        1205 | HY000             | Lock wait timeout exceeded; try restarting transaction |      0 |        0 |
+----------------------------------+-------------+-------------------+--------------------------------------------------------+--------+----------+
10 rows in set (0.01 sec)

As errors=0 even when MYSQL_ERRNO<>0 I consider this bug to also apply to 5.7.7.
[14 Jul 2015 14:07] Paul Dubois
Noted in 5.6.27, 5.7.9, 5.8.0 changelogs.

The Performance Schema events_statements_history table could have an
ERRORS column value of 0 when other columns indicated there were
errors.