MySQL Bugs: #54646: SHOW PROFILES doesn't work for UPDATEs with triggers

Bug #54646	SHOW PROFILES doesn't work for UPDATEs with triggers
Submitted:	20 Jun 2010 21:41	Modified:	21 Jun 2010 4:23
Reporter:	Vojtech Kurka	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Logging	Severity:	S3 (Non-critical)
Version:	5.1.47, 5.1.48	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	profiling, show profiles, trigger, UPDATE
Triage:	Triaged: D2 (Serious)

Description:
SHOW PROFILES doesn't list UPDATE statemets, which were run against a table with an ON UPDATE trigger.

This used to work, I think it's a regression.

How to repeat:
mysql> 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> CREATE TABLE t1(id INT UNSIGNED NOT NULL) ENGINE=INNODB;
Query OK, 0 rows affected (0.00 sec)

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

mysql> INSERT INTO t1 SET id = 1;
Query OK, 1 row affected (0.00 sec)

mysql> UPDATE t1 SET id = 2;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> SHOW PROFILES;
+----------+------------+---------------------------+
| Query_ID | Duration   | Query                     |
+----------+------------+---------------------------+
|        1 | 0.00032000 | INSERT INTO t1 SET id = 1 |
|        2 | 0.00026700 | UPDATE t1 SET id = 2      |
+----------+------------+---------------------------+
2 rows in set (0.00 sec)

mysql> DELIMITER $$
mysql> CREATE TRIGGER `test`.`t1_tru` AFTER UPDATE ON `test`.`t1` FOR EACH ROW BEGIN SET @a = 1; END$$
Query OK, 0 rows affected (0.00 sec)

mysql> DELIMITER ;
mysql> UPDATE t1 SET id = 3;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> SHOW PROFILES;
+----------+------------+-----------------------------------------------------------------------------------------------+
| Query_ID | Duration   | Query                                                                                         |
+----------+------------+-----------------------------------------------------------------------------------------------+
|        1 | 0.00032000 | INSERT INTO t1 SET id = 1                                                                     |
|        2 | 0.00026700 | UPDATE t1 SET id = 2                                                                          |
|        3 | 0.00087600 | CREATE TRIGGER `test`.`t1_tru` AFTER UPDATE ON `test`.`t1` FOR EACH ROW BEGIN SET @a = 1; END |
|        4 | 0.00002100 | SET @a = 1                                                                                    |
+----------+------------+-----------------------------------------------------------------------------------------------+
4 rows in set (0.00 sec)

mysql> DROP TRIGGER `test`.`t1_tru`;
Query OK, 0 rows affected (0.00 sec)

mysql> UPDATE t1 SET id = 4;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> SHOW PROFILES;
+----------+------------+-----------------------------------------------------------------------------------------------+
| Query_ID | Duration   | Query                                                                                         |
+----------+------------+-----------------------------------------------------------------------------------------------+
|        1 | 0.00032000 | INSERT INTO t1 SET id = 1                                                                     |
|        2 | 0.00026700 | UPDATE t1 SET id = 2                                                                          |
|        3 | 0.00087600 | CREATE TRIGGER `test`.`t1_tru` AFTER UPDATE ON `test`.`t1` FOR EACH ROW BEGIN SET @a = 1; END |
|        4 | 0.00002100 | SET @a = 1                                                                                    |
|        5 | 0.00045900 | DROP TRIGGER `test`.`t1_tru`                                                                  |
|        6 | 0.00032500 | UPDATE t1 SET id = 4                                                                          |
+----------+------------+-----------------------------------------------------------------------------------------------+
6 rows in set (0.00 sec)

Suggested fix:
don't know

Verified with 5.1.48 on Windows also:

C:\Program Files\MySQL\MySQL Server 5.1\bin>mysql -uroot -proot -P3310 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 7
Server version: 5.1.48-community MySQL Community Server (GPL)

Copyright (c) 2000, 2010, Oracle and/or its affiliates. All rights reserved.
This software comes with ABSOLUTELY NO WARRANTY. This is free software,
and you are welcome to modify and redistribute it under the GPL v2 license

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql> CREATE TABLE t1(id INT UNSIGNED NOT NULL) ENGINE=INNODB;
Query OK, 0 rows affected (0.30 sec)

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

mysql> INSERT INTO t1 SET id = 1;
Query OK, 1 row affected (0.42 sec)

mysql>  UPDATE t1 SET id = 2;
Query OK, 1 row affected (0.25 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> show profiles;
+----------+------------+---------------------------+
| Query_ID | Duration   | Query                     |
+----------+------------+---------------------------+
|        1 | 0.41649850 | INSERT INTO t1 SET id = 1 |
|        2 | 0.24477125 | UPDATE t1 SET id = 2      |
+----------+------------+---------------------------+
2 rows in set (0.02 sec)

mysql> DELIMITER $$
mysql> CREATE TRIGGER `test`.`t1_tru` AFTER UPDATE ON `test`.`t1` FOR EACH ROW B
EGIN SET
    -> @a = 1; END$$
Query OK, 0 rows affected (0.45 sec)

mysql> DELIMITER ;
mysql> UPDATE t1 SET id = 3;
Query OK, 1 row affected (0.28 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> show profiles;
+----------+------------+-------------------------------------------------------
----------------------------------------+
| Query_ID | Duration   | Query
                                        |
+----------+------------+-------------------------------------------------------
----------------------------------------+
|        1 | 0.41649850 | INSERT INTO t1 SET id = 1
                                        |
|        2 | 0.24477125 | UPDATE t1 SET id = 2
                                        |
|        3 | 0.44519750 | CREATE TRIGGER `test`.`t1_tru` AFTER UPDATE ON `test`.
`t1` FOR EACH ROW BEGIN SET
@a = 1; END |
|        4 | 0.00008225 | SET @a = 1
                                        |
+----------+------------+-------------------------------------------------------
----------------------------------------+
4 rows in set (0.00 sec)