[MDEV-9123] Local variable TEXT has mangled data in stored procedure Created: 2015-11-12  Updated: 2016-06-14  Resolved: 2016-06-14

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Procedure
Affects Version/s: 10.0.22, 10.0, 10.1
Fix Version/s: 10.0.26

Type: Bug Priority: Major
Reporter: K WALKER Assignee: Vicențiu Ciorbaru
Resolution: Fixed Votes: 1
Labels: None
Environment:

CentOS release 6.4
Server version: 5.5.5-10.1.8-MariaDB MariaDB Server

Attachments: File my.cnf     File test.sql    
Issue Links:
Relates
relates to MDEV-9367 ExtractValue function doesn't work in... Closed
Sprint: 10.0.24

 Description   

I created a small test case to reproduce the problem, which seems to be this: When I have a table with a TEXT column, and when I have a stored procedure that SELECTs that TEXT column into a local TEXT variable, the content of the field is mangled. In the example below, the LOCAL_TEXT variable should contain "quick brown fox". When I select the field into a VARCHAR(45), it retains the value exactly. This problem did not exist prior to this version of MariaDB.

-Thank you

Here is the result of invoking RunTest():

mysql> call RunTest();
 
+-----------------+-----------------+-----------------+
 
| LOCAL TEXT      | LOCAL VARCHAR   | A1_TEXT         |
 
+-----------------+-----------------+-----------------+
 
|      brown fox | quick brown fox | quick brown fox |
 
+-----------------+-----------------+-----------------+
 
1 row in set (0.04 sec)
 
 
 
Query OK, 0 rows affected (0.04 sec)}}

The test.sql code is below. Into the table, I inserted the value "quick brown fox" to column A1_TEXT.

cat test.sql
 
-- -----------------------------------------------------
 
-- Table `table1`
 
-- -----------------------------------------------------
 
CREATE TABLE IF NOT EXISTS `table1` (
 
  `id` INT NOT NULL AUTO_INCREMENT,
 
  `A1_TEXT` TEXT NULL,
 
  PRIMARY KEY (`id`))
 
ENGINE = InnoDB;
 
 
 
DELIMITER $$
 
DROP PROCEDURE IF EXISTS `RunTest`;
 
CREATE PROCEDURE `RunTest`()
 
BEGIN
 
    DECLARE L_A1_TEXT TEXT DEFAULT NULL;
 
    DECLARE L_A1_VARC VARCHAR(45) DEFAULT NULL;
 
 
 
    SELECT table1.A1_TEXT INTO L_A1_TEXT FROM table1 where id=1;
 
    SELECT table1.A1_TEXT INTO L_A1_VARC FROM table1 where id=1;
 
 
 
    SELECT
 
        L_A1_TEXT as 'LOCAL TEXT',
 
        L_A1_VARC as 'LOCAL VARCHAR',
 
        table1.A1_TEXT
 
    FROM table1;
 
END
 
$$
 
DELIMITER ;



 Comments   
Comment by Elena Stepanova [ 2015-11-14 ]

Works okay for me.
Could you please attach all your cnf file(s)?

Also, if possible, do it all in one session, including your INSERT, and paste the output.

Comment by K WALKER [ 2015-11-30 ]

I've uploaded the cnf (it's the default) and test.sql, with an insert statement immediately following table creation. The problem persists.

Thank you,
Kim

Comment by K WALKER [ 2015-11-30 ]

My colleague suggested I change the storage engine from innodb to myisam. It works correctly with myisam.

Comment by Dennis Pasveer [ 2015-12-27 ]

I ran into this exact same bug.

Switching from InnoDB to MyISAM was not an option for me, so I downgraded from MariaDB 10.1.9 back to 10.0.23. Unfortunately, but the bug was still there. Only when I downgraded back to 10.0.21, the bug was gone. So, to me it seems this bug was introduced in version 10.0.22 or 10.0.23.

I hope this helps anyone!
Dennis

Comment by Elena Stepanova [ 2016-01-08 ]

Thanks for the report and the test case. Here is the MTR version:

--disable_warnings
 
DROP TABLE IF EXISTS `table1`;
 
CREATE TABLE `table1` (
 
  `id` INT NOT NULL AUTO_INCREMENT,
 
  `A1_TEXT` TEXT NULL,
 
  PRIMARY KEY (`id`));
 
 
 
INSERT INTO table1 (id, A1_TEXT) values(1,'quick brown fox');
 
 
 
--delimiter $$
 
DROP PROCEDURE IF EXISTS `RunTest`;
 
CREATE PROCEDURE `RunTest`()
 
BEGIN
 
    DECLARE L_A1_TEXT TEXT DEFAULT NULL;
 
    DECLARE L_A1_VARC VARCHAR(45) DEFAULT NULL;
 
 
 
    SELECT table1.A1_TEXT INTO L_A1_TEXT FROM table1 where id=1;
 
    SELECT table1.A1_TEXT INTO L_A1_VARC FROM table1 where id=1;
 
 
 
    SELECT
 
        L_A1_TEXT as 'LOCAL TEXT',
 
        L_A1_VARC as 'LOCAL VARCHAR',
 
        table1.A1_TEXT
 
    FROM table1;
 
END
 
$$
 
--delimiter ;
 
 
 
call RunTest();
 
 
 
DROP TABLE table1;
 
DROP PROCEDURE RunTest;

Appearance of the mangled vs correct data is a matter of luck, that's why it wasn't easily reproducible. For example, it returns bad data on my 10.0 build (with MyISAM too), but 10.1 is okay.

However, when the test is run with valgrind, it produces errors both on 10.0 and 10.1 tree:

Stack trace from 10.0 commit 8fcc0bfefadcb4e9f7acb13d11661daeea5097f9

 
==1813== Thread 4:
 
==1813== Invalid read of size 1
 
==1813==    at 0xFBDF70: escape_string_for_mysql (charset.c:939)
 
==1813==    by 0x965300: append_query_string(charset_info_st const*, String*, char const*, unsigned long, bool) (log_event.cc:727)
 
==1813==    by 0x9BCD03: sp_get_item_value(THD*, Item*, String*) (sp_head.cc:165)
 
==1813==    by 0x9BEA7D: subst_spvars(THD*, sp_instr*, st_mysql_lex_string*) (sp_head.cc:1049)
 
==1813==    by 0x9C3577: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3109)
 
==1813==    by 0x9BF41E: sp_head::execute(THD*, bool) (sp_head.cc:1371)
 
==1813==    by 0x9C10CA: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2159)
 
==1813==    by 0x6849D2: mysql_execute_command(THD*) (sql_parse.cc:4731)
 
==1813==    by 0x6891CF: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:6565)
 
==1813==    by 0x67BA8C: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1308)
 
==1813==    by 0x67AD52: do_command(THD*) (sql_parse.cc:998)
 
==1813==    by 0x7A0A4F: do_handle_one_connection(THD*) (sql_connect.cc:1377)
 
==1813==    by 0x7A07AE: handle_one_connection (sql_connect.cc:1292)
 
==1813==    by 0xD19CA0: pfs_spawn_thread (pfs.cc:1860)
 
==1813==    by 0x4E37B4F: start_thread (pthread_create.c:304)
 
==1813==    by 0x6B2C95C: clone (clone.S:112)
 
==1813==  Address 0xd57c4a8 is 40 bytes inside a block of size 136 free'd
 
==1813==    at 0x4C2964C: realloc (vg_replace_malloc.c:693)
 
==1813==    by 0xFE8937: my_realloc (my_malloc.c:164)
 
==1813==    by 0xE2ECBF: mi_alloc_rec_buff (mi_open.c:748)
 
==1813==    by 0xE25909: mi_reset (mi_extra.c:460)
 
==1813==    by 0xE032CB: ha_myisam::reset() (ha_myisam.cc:1934)
 
==1813==    by 0x88878D: handler::ha_reset() (handler.cc:5987)
 
==1813==    by 0x6194C8: close_thread_table(THD*, TABLE**) (sql_base.cc:1052)
 
==1813==    by 0x618C81: close_open_tables(THD*) (sql_base.cc:785)
 
==1813==    by 0x619289: close_thread_tables(THD*) (sql_base.cc:1009)
 
==1813==    by 0x686053: mysql_execute_command(THD*) (sql_parse.cc:5178)
 
==1813==    by 0x9C3923: sp_instr_stmt::exec_core(THD*, unsigned int*) (sp_head.cc:3204)
 
==1813==    by 0x9C3074: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) (sp_head.cc:2971)
 
==1813==    by 0x9C362D: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3120)
 
==1813==    by 0x9BF41E: sp_head::execute(THD*, bool) (sp_head.cc:1371)
 
==1813==    by 0x9C10CA: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2159)
 
==1813==    by 0x6849D2: mysql_execute_command(THD*) (sql_parse.cc:4731)
 
==1813== Invalid read of size 1
 
==1813==    at 0xFBE019: escape_string_for_mysql (charset.c:979)
 
==1813==    by 0x965300: append_query_string(charset_info_st const*, String*, char const*, unsigned long, bool) (log_event.cc:727)
 
==1813==    by 0x9BCD03: sp_get_item_value(THD*, Item*, String*) (sp_head.cc:165)
 
==1813==    by 0x9BEA7D: subst_spvars(THD*, sp_instr*, st_mysql_lex_string*) (sp_head.cc:1049)
 
==1813==    by 0x9C3577: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3109)
 
==1813==    by 0x9BF41E: sp_head::execute(THD*, bool) (sp_head.cc:1371)
 
==1813==    by 0x9C10CA: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2159)
 
==1813==    by 0x6849D2: mysql_execute_command(THD*) (sql_parse.cc:4731)
 
==1813==    by 0x6891CF: mysql_parse(THD*, char*, unsigned int, Parser_state*) (sql_parse.cc:6565)
 
==1813==    by 0x67BA8C: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1308)
 
==1813==    by 0x67AD52: do_command(THD*) (sql_parse.cc:998)
 
==1813==    by 0x7A0A4F: do_handle_one_connection(THD*) (sql_connect.cc:1377)
 
==1813==    by 0x7A07AE: handle_one_connection (sql_connect.cc:1292)
 
==1813==    by 0xD19CA0: pfs_spawn_thread (pfs.cc:1860)
 
==1813==    by 0x4E37B4F: start_thread (pthread_create.c:304)
 
==1813==    by 0x6B2C95C: clone (clone.S:112)
 
==1813==  Address 0xd57c4a8 is 40 bytes inside a block of size 136 free'd
 
==1813==    at 0x4C2964C: realloc (vg_replace_malloc.c:693)
 
==1813==    by 0xFE8937: my_realloc (my_malloc.c:164)
 
==1813==    by 0xE2ECBF: mi_alloc_rec_buff (mi_open.c:748)
 
==1813==    by 0xE25909: mi_reset (mi_extra.c:460)
 
==1813==    by 0xE032CB: ha_myisam::reset() (ha_myisam.cc:1934)
 
==1813==    by 0x88878D: handler::ha_reset() (handler.cc:5987)
 
==1813==    by 0x6194C8: close_thread_table(THD*, TABLE**) (sql_base.cc:1052)
 
==1813==    by 0x618C81: close_open_tables(THD*) (sql_base.cc:785)
 
==1813==    by 0x619289: close_thread_tables(THD*) (sql_base.cc:1009)
 
==1813==    by 0x686053: mysql_execute_command(THD*) (sql_parse.cc:5178)
 
==1813==    by 0x9C3923: sp_instr_stmt::exec_core(THD*, unsigned int*) (sp_head.cc:3204)
 
==1813==    by 0x9C3074: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) (sp_head.cc:2971)
 
==1813==    by 0x9C362D: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3120)
 
==1813==    by 0x9BF41E: sp_head::execute(THD*, bool) (sp_head.cc:1371)
 
==1813==    by 0x9C10CA: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2159)
 
==1813==    by 0x6849D2: mysql_execute_command(THD*) (sql_parse.cc:4731)
 
==1813== Invalid read of size 1
 
==1813==    at 0x4C2BCA8: __GI_memcpy (vg_replace_strmem.c:917)
 
==1813==    by 0x5D103E: Protocol::net_store_data(unsigned char const*, unsigned long) (protocol.cc:60)
 
==1813==    by 0x5D3161: Protocol::store_string_aux(char const*, unsigned long, charset_info_st const*, charset_info_st const*) (protocol.cc:1016)
 
==1813==    by 0x5D3BCA: Protocol_text::store(Field*) (protocol.cc:1175)
 
==1813==    by 0x89F034: Item_field::send(Protocol*, String*) (item.cc:6669)
 
==1813==    by 0x8A94A5: Item_sp_variable::send(Protocol*, String*) (item.h:1866)
 
==1813==    by 0x5D2DBD: Protocol::send_result_set_row(List<Item>*) (protocol.cc:903)
 
==1813==    by 0x643138: select_send::send_data(List<Item>&) (sql_class.cc:2556)
 
==1813==    by 0x6E28EE: end_send(JOIN*, st_join_table*, bool) (sql_select.cc:18946)
 
==1813==    by 0x6DF5AC: do_select(JOIN*, List<Item>*, TABLE*, Procedure*) (sql_select.cc:17447)
 
==1813==    by 0x6BC279: JOIN::exec_inner() (sql_select.cc:3084)
 
==1813==    by 0x6B966D: JOIN::exec() (sql_select.cc:2373)
 
==1813==    by 0x6BCAF8: mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (sql_select.cc:3308)
 
==1813==    by 0x6B2DDA: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:373)
 
==1813==    by 0x686606: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:5304)
 
==1813==    by 0x67E879: mysql_execute_command(THD*) (sql_parse.cc:2562)
 
==1813==  Address 0xd57c4a8 is 40 bytes inside a block of size 136 free'd
 
==1813==    at 0x4C2964C: realloc (vg_replace_malloc.c:693)
 
==1813==    by 0xFE8937: my_realloc (my_malloc.c:164)
 
==1813==    by 0xE2ECBF: mi_alloc_rec_buff (mi_open.c:748)
 
==1813==    by 0xE25909: mi_reset (mi_extra.c:460)
 
==1813==    by 0xE032CB: ha_myisam::reset() (ha_myisam.cc:1934)
 
==1813==    by 0x88878D: handler::ha_reset() (handler.cc:5987)
 
==1813==    by 0x6194C8: close_thread_table(THD*, TABLE**) (sql_base.cc:1052)
 
==1813==    by 0x618C81: close_open_tables(THD*) (sql_base.cc:785)
 
==1813==    by 0x619289: close_thread_tables(THD*) (sql_base.cc:1009)
 
==1813==    by 0x686053: mysql_execute_command(THD*) (sql_parse.cc:5178)
 
==1813==    by 0x9C3923: sp_instr_stmt::exec_core(THD*, unsigned int*) (sp_head.cc:3204)
 
==1813==    by 0x9C3074: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) (sp_head.cc:2971)
 
==1813==    by 0x9C362D: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3120)
 
==1813==    by 0x9BF41E: sp_head::execute(THD*, bool) (sp_head.cc:1371)
 
==1813==    by 0x9C10CA: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2159)
 
==1813==    by 0x6849D2: mysql_execute_command(THD*) (sql_parse.cc:4731)
 
==1813== Invalid read of size 1
 
==1813==    at 0x4C2BCB6: __GI_memcpy (vg_replace_strmem.c:917)
 
==1813==    by 0x5D103E: Protocol::net_store_data(unsigned char const*, unsigned long) (protocol.cc:60)
 
==1813==    by 0x5D3161: Protocol::store_string_aux(char const*, unsigned long, charset_info_st const*, charset_info_st const*) (protocol.cc:1016)
 
==1813==    by 0x5D3BCA: Protocol_text::store(Field*) (protocol.cc:1175)
 
==1813==    by 0x89F034: Item_field::send(Protocol*, String*) (item.cc:6669)
 
==1813==    by 0x8A94A5: Item_sp_variable::send(Protocol*, String*) (item.h:1866)
 
==1813==    by 0x5D2DBD: Protocol::send_result_set_row(List<Item>*) (protocol.cc:903)
 
==1813==    by 0x643138: select_send::send_data(List<Item>&) (sql_class.cc:2556)
 
==1813==    by 0x6E28EE: end_send(JOIN*, st_join_table*, bool) (sql_select.cc:18946)
 
==1813==    by 0x6DF5AC: do_select(JOIN*, List<Item>*, TABLE*, Procedure*) (sql_select.cc:17447)
 
==1813==    by 0x6BC279: JOIN::exec_inner() (sql_select.cc:3084)
 
==1813==    by 0x6B966D: JOIN::exec() (sql_select.cc:2373)
 
==1813==    by 0x6BCAF8: mysql_select(THD*, Item***, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) (sql_select.cc:3308)
 
==1813==    by 0x6B2DDA: handle_select(THD*, LEX*, select_result*, unsigned long) (sql_select.cc:373)
 
==1813==    by 0x686606: execute_sqlcom_select(THD*, TABLE_LIST*) (sql_parse.cc:5304)
 
==1813==    by 0x67E879: mysql_execute_command(THD*) (sql_parse.cc:2562)
 
==1813==  Address 0xd57c4aa is 42 bytes inside a block of size 136 free'd
 
==1813==    at 0x4C2964C: realloc (vg_replace_malloc.c:693)
 
==1813==    by 0xFE8937: my_realloc (my_malloc.c:164)
 
==1813==    by 0xE2ECBF: mi_alloc_rec_buff (mi_open.c:748)
 
==1813==    by 0xE25909: mi_reset (mi_extra.c:460)
 
==1813==    by 0xE032CB: ha_myisam::reset() (ha_myisam.cc:1934)
 
==1813==    by 0x88878D: handler::ha_reset() (handler.cc:5987)
 
==1813==    by 0x6194C8: close_thread_table(THD*, TABLE**) (sql_base.cc:1052)
 
==1813==    by 0x618C81: close_open_tables(THD*) (sql_base.cc:785)
 
==1813==    by 0x619289: close_thread_tables(THD*) (sql_base.cc:1009)
 
==1813==    by 0x686053: mysql_execute_command(THD*) (sql_parse.cc:5178)
 
==1813==    by 0x9C3923: sp_instr_stmt::exec_core(THD*, unsigned int*) (sp_head.cc:3204)
 
==1813==    by 0x9C3074: sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) (sp_head.cc:2971)
 
==1813==    by 0x9C362D: sp_instr_stmt::execute(THD*, unsigned int*) (sp_head.cc:3120)
 
==1813==    by 0x9BF41E: sp_head::execute(THD*, bool) (sp_head.cc:1371)
 
==1813==    by 0x9C10CA: sp_head::execute_procedure(THD*, List<Item>*) (sp_head.cc:2159)
 
==1813==    by 0x6849D2: mysql_execute_command(THD*) (sql_parse.cc:4731)

I could track the appearance of the problem down to this merge on 10.0 tree:

commit cfeedbfd3e292f61c7da8f0a7f86307cbeeddb64
 
Merge: bff1af9 16c4b3c
 
Author: Sergei Golubchik <serg@mariadb.org>
 
Date:   Fri Oct 9 17:12:26 2015 +0200
 
 
 
    Merge branch '5.5' into 10.0

Since I do not observe the problem on 5.5 tree, I can't tell which exactly change from this merge causes the trouble.

cvicentiu, if you decide it would be better handled by somebody else, please feel free to re-assign.

Comment by Vicențiu Ciorbaru [ 2016-02-11 ]

The bug is caused by this commit:
888fabd6909237f55ed9b9cf7a0c852c2e5f0beb

-    /*
 
-      Copy value if copy_blobs is set, or source is not a string and
 
-      we have a pointer to its internal string conversion buffer.
 
-    */
 
-    if (to->table->copy_blobs ||
 
-        (!blob->value.is_alloced() &&
 
-         from->real_type() != MYSQL_TYPE_STRING &&
 
-         from->real_type() != MYSQL_TYPE_VARCHAR))
 
+
 
+    if (!blob->value.is_alloced() && from->is_updatable())

Adding back

if (to->table->copy_blobs || ...)

fixes the problem.

Still need to investigate why this happens.

Comment by Patryk Pomykalski [ 2016-02-11 ]

I stumbled upon this problem today (MDEV-9551). It looks like it's fixed in MySQL 5.5.48

Comment by Vicențiu Ciorbaru [ 2016-06-14 ]

The bug was fixed in upstream and merged.

Generated at Thu Feb 08 07:32:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.