Bug #60687 dramatic slowdown of execution of PROCEDURE w/ LOCATE and string var
Submitted: 29 Mar 2011 10:30 Modified: 27 Apr 2011 18:12
Reporter: Paul Lucassen Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Stored Routines Severity:S1 (Critical)
Version:5.5.10 OS:Linux
Assigned to: CPU Architecture:Any
Tags: LOCATE, memory leak, performance loss

[29 Mar 2011 10:30] Paul Lucassen
Description:
Repeatedly using a string variable in the LOCATE function, within a LOOP in a STORED PROCEDURE gives rise to (increasingly) large execution times of the procedure.
Each successive CALL of the SP lasts approximately twice as long.
When a fresh connection is made the execution time is normal at first but increases again with each CALL.
Also a large amount of memory is claimed (2M per call).
If a string literal is used in stead of string variable, the execution time is normal and not increasing.

We see this with 5.5.10-community and 5.5.8-commercial on SLES11 64bit.

We filed this as S1 (critical) as the problem prohibits migration to 5.5. We have a lot of Stored Procedures and there is no apparent workaround.

How to repeat:
/*
repeatedly executing the following procedure (on the same connection/session) gives dramatically increasing runtimes (0.6s,1.5s,2.5s,etc).
Per execution approx 2Mb of additional memory is claimed by mysqld.

If a literal string is used in stead of the variable string, there is no performance loss.

*/

DELIMITER //

DROP PROCEDURE IF EXISTS string_bug_test
//
CREATE PROCEDURE string_bug_test (
)
BEGIN
  DECLARE string  VARCHAR(200)  DEFAULT 'aaaaaaaaaabbbbbbbbbbbccccccccccccddddddddddddddeeeeeeeeeeeeeefffffffffffffffggggggggggghhhhhhhhhhhiiiiiiiiiiii';

  DECLARE i           INT           DEFAULT 0;
  DECLARE npos        INT           DEFAULT 0;

  SET i := 0;
  label1: REPEAT
    SET i := i + 1;
    SET npos := LOCATE('a',string);
/*    SET npos := LOCATE('a','aaaaaaaaaabbbbbbbbbbbccccccccccccddddddddddddddeeeeeeeeeeeeeefffffffffffffffggggggggggghhhhhhhhhhhiiiiiiiiiiii');*/

    UNTIL i>=10000
  END REPEAT label1;
END;
//

DELIMITER ;
[29 Mar 2011 12:39] MySQL Verification Team
Thank you for the bug report. Verified as described on Windows Vista X86_64:

mysql 5.5 >
mysql 5.5 >DELIMITER ;
mysql 5.5 >call string_bug_test();
Query OK, 0 rows affected (3.02 sec)

mysql 5.5 >call string_bug_test();
Query OK, 0 rows affected (13.07 sec)

mysql 5.5 >call string_bug_test();
Query OK, 0 rows affected (24.57 sec)

mysql 5.5 >call string_bug_test();
Query OK, 0 rows affected (35.86 sec)

mysql 5.5 >show variables like "%version%";
+-------------------------+---------------------+
| Variable_name           | Value               |
+-------------------------+---------------------+
| innodb_version          | 1.1.6               |
| protocol_version        | 10                  |
| slave_type_conversions  |                     |
| version                 | 5.5.11              |
| version_comment         | Source distribution |
| version_compile_machine | x86                 |
| version_compile_os      | Win64               |
+-------------------------+---------------------+
7 rows in set (0.03 sec)

mysql 5.5 >
[31 Mar 2011 21:04] MySQL Verification Team
related: bug #60025
[27 Apr 2011 18:12] MySQL Verification Team
Duplicate of bug: http://bugs.mysql.com/bug.php?id=60025.