Bug #38674 Substring of longtext fails in stored procedure (using "from" syntax)
Submitted: 8 Aug 2008 16:11 Modified: 21 Sep 2008 12:35
Reporter: Antoine JAUSSOIN Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Stored Routines Severity:S2 (Serious)
Version:5.0.51b, 5.0.66a, 5.1.26-rc OS:Windows (XP)
Assigned to: Assigned Account CPU Architecture:Any
Tags: from, longtext, stored procedure, substring

[8 Aug 2008 16:11] Antoine JAUSSOIN
Description:
Calling substring(.. from ..) with a text variable whose length is greater than approx. 2000 characters will cause an error :

Incorrect string value: '\xCFa%\x00\x00\x00...' for column 'mystr' at row 1

It doesn't seem to happen using substring(str,start,length).
This only seems to happen using set x = substring(... from ...) (but not "select substring(... from ...)")

This seems to have regressed since 5.0.51a as it was working on that version.

How to repeat:
1) Create a stored procedure as follows:

DELIMITER $$

DROP PROCEDURE IF EXISTS `parseString` $$
CREATE PROCEDURE `parseString`(str   LONGTEXT  )
BEGIN

DECLARE mystr   LONGTEXT  DEFAULT str;

SET mystr = SUBSTRING(mystr from 2);

END $$

DELIMITER ;

2) Then run the SP with a (very) long string (example follows) :
call parseString(lpad("a",10000,"b"));
[8 Aug 2008 16:17] MySQL Verification Team
this sounds strikingly similar to bug #38469
[8 Aug 2008 17:49] Valeriy Kravchuk
Thank you for a problem report. Verified with 5.0.66a on XP:

C:\Program Files\MySQL\MySQL Server 5.0\bin>mysql -uroot -proot -P3308 test
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 6
Server version: 5.0.66a-enterprise-gpl-nt MySQL Enterprise Server (GPL)

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> delimiter $$
mysql> DROP PROCEDURE IF EXISTS `parseString` $$
Query OK, 0 rows affected, 1 warning (0.05 sec)

mysql> CREATE PROCEDURE `parseString`(str   LONGTEXT  )
    -> BEGIN
    ->
    -> DECLARE mystr   LONGTEXT  DEFAULT str;
    ->
    -> SET mystr = SUBSTRING(mystr from 2);
    ->
    -> END $$
Query OK, 0 rows affected (0.09 sec)

mysql> call parseString(lpad("a", 10000, "b"))$$
ERROR 1366 (HY000): Incorrect string value: '\xE2O\x04@:S...' for column 'mystr'
 at row 1
mysql> call parseString(lpad("a", 100, "b"))$$
Query OK, 0 rows affected (0.00 sec)
[8 Aug 2008 17:51] Valeriy Kravchuk
Same problem with 5.1.26:

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

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql> delimiter $$
mysql> DROP PROCEDURE IF EXISTS `parseString` $$
Query OK, 0 rows affected, 1 warning (0.08 sec)

mysql> CREATE PROCEDURE `parseString`(str   LONGTEXT  )
    -> BEGIN
    -> DECLARE mystr   LONGTEXT  DEFAULT str;
    -> SET mystr = SUBSTRING(mystr from 2);
    -> END $$
Query OK, 0 rows affected (0.00 sec)

mysql> call parseString(lpad("a", 10000, "b"))$$
ERROR 1366 (HY000): Incorrect string value: '\xBF\x00\xC0>7\x02...' for column '
mystr' at row 1
mysql> call parseString(lpad("a", 100, "b"))$$
Query OK, 0 rows affected (0.00 sec)
[11 Aug 2008 12:40] David Carr
correction - it fails on a fresh install of 5.0.51a as well.
[11 Aug 2008 12:57] MySQL Verification Team
Not repeatable with source servers:

c:\dbs>c:\dbs\5.0\bin\mysql -uroot --port=3500 --prompt="mysql 5.0 > "
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.0.68-nt-debug-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql 5.0 > use test
Database changed
mysql 5.0 > delimiter $$
mysql 5.0 >  DROP PROCEDURE IF EXISTS `parseString` $$
Query OK, 0 rows affected, 1 warning (0.06 sec)

mysql 5.0 >  CREATE PROCEDURE `parseString`(str   LONGTEXT  )
    ->  BEGIN
    ->  DECLARE mystr   LONGTEXT  DEFAULT str;
    ->  SET mystr = SUBSTRING(mystr from 2);
    ->  END $$
Query OK, 0 rows affected (0.05 sec)

mysql 5.0 >  call parseString(lpad("a", 10000, "b"))$$
Query OK, 0 rows affected (0.06 sec)

mysql 5.0 > call parseString(lpad("a", 100, "b"))$$
Query OK, 0 rows affected (0.00 sec)

mysql 5.0 >

c:\dbs>c:\dbs\5.1\bin\mysql -uroot --port=3510 --prompt="mysql 5.1 >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 4
Server version: 5.1.28-nt-debug-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql 5.1 >use test
Database changed
mysql 5.1 >delimiter $$
mysql 5.1 > DROP PROCEDURE IF EXISTS `parseString` $$
Query OK, 0 rows affected, 1 warning (0.08 sec)

mysql 5.1 > CREATE PROCEDURE `parseString`(str   LONGTEXT  )
    ->  BEGIN
    ->  DECLARE mystr   LONGTEXT  DEFAULT str;
    ->  SET mystr = SUBSTRING(mystr from 2);
    ->  END $$
Query OK, 0 rows affected (0.11 sec)

mysql 5.1 > call parseString(lpad("a", 10000, "b"))$$
Query OK, 0 rows affected (0.03 sec)

mysql 5.1 >call parseString(lpad("a", 100, "b"))$$
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >
[11 Aug 2008 13:43] MySQL Verification Team
you have to run the server with --default-character-set=utf8
[11 Aug 2008 14:19] MySQL Verification Team
Tried the release version too:

c:\dbs>c:\dbs\5.1\bin\mysql -uroot --port=3510 --prompt="mysql 5.1 >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.1.28-nt-log Source distribution

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

mysql 5.1 >use dt6
Database changed
mysql 5.1 >delimiter $$
mysql 5.1 > DROP PROCEDURE IF EXISTS `parseString` $$
Query OK, 0 rows affected, 1 warning (0.06 sec)

mysql 5.1 > CREATE PROCEDURE `parseString`(str   LONGTEXT  )
    ->  BEGIN
    ->  DECLARE mystr   LONGTEXT  DEFAULT str;
    ->  SET mystr = SUBSTRING(mystr from 2);
    ->  END $$
Query OK, 0 rows affected (0.03 sec)

mysql 5.1 > call parseString(lpad("a", 10000, "b"))$$
Query OK, 0 rows affected (0.00 sec)

mysql 5.1 >call parseString(lpad("a", 100, "b"))$$
Query OK, 0 rows affected (0.00 sec)
[11 Aug 2008 14:56] MySQL Verification Team
miguel can you try when running server under valgrind? the bug is not the presence of a warning or not.  it's an invalid read of memory, which may or may not have any visible effects to the user :)

my 5.1.28 gave valgrind error:
==29405== Invalid read of size 1
==29405==    at 0x40065F5: memmove (mc_replace_strmem.c:503)
==29405==    by 0x819EBDF: well_formed_copy_nchars(charset_info_st*, char*, unsigned, charset_info_st*, char const*, unsigned, unsigned, char const**, char const**, char const**) (sql_string.cc:991)
<cut>

and no warning:
mysql> call parseString(lpad("a",10000,"b"));
Query OK, 0 rows affected (0.42 sec)
[11 Aug 2008 16:05] David Carr
Tested on 5.0.67 Windows 64Bit. Brand new install.

Have pinned it down to:

sql-mode="STRICT_TRANS_TABLES,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"

in the my.ini file.

If the stored procedure is created when the database is started with the option above, it will fail with the reported error:

mysql> CREATE DEFINER=`root`@`localhost` PROCEDURE `parseString`(str   LONGTEXT
 )
    -> BEGIN
    ->
    -> DECLARE mystr   LONGTEXT  DEFAULT str;
    ->
    -> SET mystr = SUBSTRING(mystr from 2);
    ->
    -> END $$
Query OK, 0 rows affected (0.00 sec)

mysql>
mysql> DELIMITER ;
mysql> CALL parseString(lpad("",3000,"b"));
ERROR 1366 (HY000): Incorrect string value: '\xC8\x02\x0F\x01\x00\x00...' for co
lumn 'mystr' at row 1

Removing the option and restarting makes no difference(not sure how to do this on the command line but I commented out the line and restarted mysqld at this point):

mysql> CALL parseString(lpad("",3000,"b"));
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    2
Current database: test

ERROR 1366 (HY000): Incorrect string value: '\xC8\x02\x0F\x01\x00\x00...' for co
lumn 'mystr' at row 1

Now if I recreate the procedure without restarting or doing anything else:

mysql> DROP PROCEDURE IF EXISTS `test`.`parseString` $$
Query OK, 0 rows affected (0.00 sec)

mysql> CREATE DEFINER=`root`@`localhost` PROCEDURE `parseString`(str   LONGTEXT
 )
    -> BEGIN
    ->
    -> DECLARE mystr   LONGTEXT  DEFAULT str;
    ->
    -> SET mystr = SUBSTRING(mystr from 2);
    ->
    -> END $$
Query OK, 0 rows affected (0.00 sec)

mysql>
mysql> DELIMITER ;
mysql> CALL parseString(lpad("",3000,"b"));
Query OK, 0 rows affected, 1 warning (0.00 sec)

No problem.

Interestingly, often when I recreate the procedure after switching between sql-mode=... to having it commented it out and then calling the procedure the database stops!! I'm not sure whether this is a separate problem and I'm happy to submit it as another bug report. db.err trace for the crash is:

080811 16:43:00 - mysqld got exception 0xc0000005 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=8384512
read_buffer_size=131072
max_used_connections=2
max_connections=100
threads_connected=2
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 225787 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0000000001B127F0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
00000000006DE8CE    mysqld.exe!???
00000000006EDD88    mysqld.exe!???
00000000005E466E    mysqld.exe!???
000000000042CEF9    mysqld.exe!???
000000000046221E    mysqld.exe!???
0000000000535480    mysqld.exe!???
000000000053F385    mysqld.exe!???
0000000000536345    mysqld.exe!???
000000000053A472    mysqld.exe!???
000000000053A728    mysqld.exe!???
000000000053C2C9    mysqld.exe!???
000000000053D7C1    mysqld.exe!???
000000000059C544    mysqld.exe!???
000000000059F988    mysqld.exe!???
00000000005A1049    mysqld.exe!???
00000000005A23F7    mysqld.exe!???
00000000005A2758    mysqld.exe!???
000000000068AC89    mysqld.exe!???
00000000007D5247    mysqld.exe!???
00000000007D5315    mysqld.exe!???
0000000077D6B6DA    kernel32.dll!BaseThreadStart()
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0000000001B1E490=CALL parseString(lpad("",3000,"b"))
thd->thread_id=2
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.

David
[11 Aug 2008 16:26] MySQL Verification Team
I will re-verify. Thanks for the feedback.
[11 Aug 2008 16:41] MySQL Verification Team
Back to verified I was now able to repeat.
[21 Sep 2008 12:35] Kristofer Pettersson
Solved by fix in Bug#38469