Bug #67315 Crashing server by stored function referencing user defined variable in query
Submitted: 21 Oct 2012 15:32 Modified: 12 Nov 2012 17:51
Reporter: Shlomi Noach (OCA) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Stored Routines Severity:S2 (Serious)
Version:5.6.7-rc/5.7 OS:Any
Assigned to: CPU Architecture:Any
Tags: crash, stored function, stored routines, user defined variable

[21 Oct 2012 15:32] Shlomi Noach
Description:
A stored function references a user-defined-variable. Upon SELECTing value of this function, and in a very specific SELECT scenariom server crashes:

mysql> select weird('', 'z') = '3' or weird('', 'z') is null;
ERROR 2013 (HY000): Lost connection to MySQL server during query

Complete log follows:
=====================

15:29:23 UTC - mysqld got signal 11 ;
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=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=3
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68187 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x26e2640
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...
stack_bottom = 7fc91d8bfe28 thread_stack 0x40000
/home/shlomi/sandboxes/5.6.7/bin/mysqld(my_print_stacktrace+0x35)[0x8b47d5]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(handle_fatal_signal+0x401)[0x64b181]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xfcb0)[0x7fc933dadcb0]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(alloc_root+0x11)[0x8ac1f1]
/home/shlomi/sandboxes/5.6.7/bin/mysqld[0x5e3078]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN22Item_func_get_user_var18fix_length_and_decEv+0x46)[0x5e73a6]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN9Item_func10fix_fieldsEP3THDPP4Item+0x22d)[0x5e455d]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN9Item_func10fix_fieldsEP3THDPP4Item+0x25f)[0x5e458f]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z20sp_prepare_func_itemP3THDPP4Item+0x4f)[0x64b4af]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z12sp_eval_exprP3THDP5FieldPP4Item+0x4a)[0x64b52a]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12sp_instr_set9exec_coreEP3THDPj+0x34)[0x7ef5e4]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12sp_lex_instr23reset_lex_and_exec_coreEP3THDPjb+0x46e)[0x7efc0e]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12sp_lex_instr29validate_lex_and_execute_coreEP3THDPjb+0x93)[0x7f0f13]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN7sp_head7executeEP3THDb+0x702)[0x6523a2]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN7sp_head16execute_functionEP3THDPP4ItemjP5Field+0x5a8)[0x652b18]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12Item_func_sp12execute_implEP3THD+0x13a)[0x5e243a]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12Item_func_sp7executeEv+0x26)[0x5e7936]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12Item_func_sp7val_strEP6String+0x50)[0x5f1460]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN14Arg_comparator14compare_stringEv+0x20)[0x5b5870]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12Item_func_eq7val_intEv+0x23)[0x5b9813]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN4Item8val_boolEv+0xac)[0x598b9c]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN12Item_cond_or7val_intEv+0x3a)[0x5b3c7a]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN4Item4sendEP8ProtocolP6String+0x1fd)[0x596d7d]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN8Protocol19send_result_set_rowEP4ListI4ItemE+0x9a)[0x64601a]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN11select_send9send_dataER4ListI4ItemE+0x72)[0x68bf72]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_ZN4JOIN4execEv+0x5ce)[0x6a266e]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_P10SQL_I_ListI8st_orderESB_S7_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x198)[0x6e9dd8]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z13handle_selectP3THDP13select_resultm+0x19f)[0x6e9fdf]
/home/shlomi/sandboxes/5.6.7/bin/mysqld[0x6c3e1d]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z21mysql_execute_commandP3THD+0x2230)[0x6c6f70]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x33d)[0x6c9b7d]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x966)[0x6ca9d6]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(_Z24do_handle_one_connectionP3THD+0x10f)[0x697d8f]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(handle_one_connection+0x45)[0x697e65]
/home/shlomi/sandboxes/5.6.7/bin/mysqld(pfs_spawn_thread+0x13b)[0x8fb8fb]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a)[0x7fc933da5e9a]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fc932a7bdbd]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7fc8fc006d20): select weird('', 'z') = '3' or weird('', 'z') is null
Connection ID (thread ID): 3
Status: NOT_KILLED

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.
121021 17:29:23 mysqld_safe Number of processes running now: 0
121021 17:29:23 mysqld_safe mysqld restarted
121021 17:29:23 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
121021 17:29:23 [Note] Plugin 'FEDERATED' is disabled.
121021 17:29:23 InnoDB: The InnoDB memory heap is disabled
121021 17:29:23 InnoDB: Mutexes and rw_locks use GCC atomic builtins
121021 17:29:23 InnoDB: Compressed tables use zlib 1.2.3
121021 17:29:23 InnoDB: Using Linux native AIO
121021 17:29:23 InnoDB: CPU does not support crc32 instructions
121021 17:29:23 InnoDB: Initializing buffer pool, size = 128.0M
121021 17:29:23 InnoDB: Completed initialization of buffer pool
121021 17:29:23 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
121021 17:29:23  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
InnoDB: Last MySQL binlog file position 0 1549748, file name mysql-bin.000035
121021 17:29:23 InnoDB: 128 rollback segment(s) are active.
121021 17:29:23 InnoDB: Waiting for the background threads to start
121021 17:29:23 InnoDB: 1.2.7 started; log sequence number 154240164
121021 17:29:23 [Note] Recovering after a crash using mysql-bin
121021 17:29:23 [Note] Starting crash recovery...
121021 17:29:23 [Note] Crash recovery finished.
121021 17:29:23 [Note] Server hostname (bind-address): '*'; port: 14701
121021 17:29:23 [Note] IPv6 is available.
121021 17:29:23 [Note]   - '::' resolves to '::';
121021 17:29:23 [Note] Server socket created on IP: '::'.
121021 17:29:23 [Warning] Neither --relay-log nor --relay-log-index were used; so replication may break when this MySQL server acts as a slave and has his hostname changed!! Please use '--relay-log=mysql_sandbox14701-relay-bin' to avoid this problem.
121021 17:29:24 [Warning] Storing MySQL user name or password information in the master.info repository is not secure and is therefore not recommended. Please see the MySQL Manual for more about this issue and possible alternatives.
121021 17:29:24 [Note] Slave I/O thread: connected to master 'rsandbox@127.0.0.1:14702',replication started in log 'mysql-bin.000007' at position 2625575
121021 17:29:24 [Note] Event Scheduler: Loaded 0 events
121021 17:29:24 [Note] /home/shlomi/sandboxes/5.6.7/bin/mysqld: ready for connections.
Version: '5.6.7-rc-log'  socket: '/tmp/mysql_sandbox14701.sock'  port: 14701  MySQL Community Server (GPL)
121021 17:29:24 [Warning] Slave SQL: If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
121021 17:29:24 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000007' at position 2625575, relay log './mysql_sandbox14701-relay-bin.000150' position: 283

How to repeat:
Create weird() procedure and particular SELECT query:

DELIMITER $$

DROP FUNCTION IF EXISTS weird $$
CREATE FUNCTION weird(param1 TEXT CHARSET utf8, param2 VARCHAR(255) CHARSET utf8) 
  RETURNS TEXT CHARSET utf8 
DETERMINISTIC
NO SQL
SQL SECURITY INVOKER
COMMENT 'Return value of option in JS options format'

begin
  declare internal_var INT UNSIGNED DEFAULT 0;
  
  set internal_var := ifnull(@zzz, 0);
  return NULL;
end $$

DELIMITER ;

mysql> select weird('', 'z') = '3' or weird('', 'z') is null;
ERROR 2013 (HY000): Lost connection to MySQL server during query

===========
It is interesting to note that the following queries make no trouble:

mysql> select weird('', 'z') = '3' or weird('', 'z') <=> null;
+-------------------------------------------------+
| weird('', 'z') = '3' or weird('', 'z') <=> null |
+-------------------------------------------------+
|                                               1 |
+-------------------------------------------------+

mysql> select weird('', 'z') is null or weird('', 'z') is null;
+--------------------------------------------------+
| weird('', 'z') is null or weird('', 'z') is null |
+--------------------------------------------------+
|                                                1 |
+--------------------------------------------------+

It only happens when left side is not checked against NULL, and right side checked against IS NULL.

If you replace @zzz with some constant, for example 'hello', everything is fine. It is the reference to the user defined variable that causes the server crash.
[21 Oct 2012 15:34] Shlomi Noach
For completeness, the function I've described is of course a simplified form of a real function; I've simplified as best I can; you can see traces of the original function there.
[21 Oct 2012 16:00] Valeriy Kravchuk
Works with 5.5.28, so it seems this is a regression bug:

mysql> DELIMITER $$
mysql>
mysql> DROP FUNCTION IF EXISTS weird $$
Query OK, 0 rows affected, 1 warning (2.69 sec)

mysql> CREATE FUNCTION weird(param1 TEXT CHARSET utf8, param2 VARCHAR(255) CHARS
ET utf8)
    ->   RETURNS TEXT CHARSET utf8
    -> DETERMINISTIC
    -> NO SQL
    -> SQL SECURITY INVOKER
    -> COMMENT 'Return value of option in JS options format'
    ->
    -> begin
    ->   declare internal_var INT UNSIGNED DEFAULT 0;
    ->
    ->   set internal_var := ifnull(@zzz, 0);
    ->   return NULL;
    -> end $$
Query OK, 0 rows affected (0.53 sec)

mysql> DELIMITER ;
mysql> select weird('', 'z') = '3' or weird('', 'z') is null;
+------------------------------------------------+
| weird('', 'z') = '3' or weird('', 'z') is null |
+------------------------------------------------+
|                                              1 |
+------------------------------------------------+
1 row in set (0.27 sec)

mysql> select version();
+-----------+
| version() |
+-----------+
| 5.5.28    |
+-----------+
1 row in set (0.02 sec)
[21 Oct 2012 16:59] MySQL Verification Team
Whoever verifies this - you need --log-bin enabled to repeat it!
[21 Oct 2012 19:05] MySQL Verification Team
Thank you for the bug report.

d:\dbs>d:\dbs\5.7\bin\mysql -uroot --port=3540 --prompt="mysql 5.7 >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.7.0-m10-log Source distribution

Copyright (c) 2000, 2012, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

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

mysql 5.7 >use test
Database changed
mysql 5.7 >select weird('', 'z') = '3' or weird('', 'z') is null;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql 5.7 >

121021 17:00:48 [Note] 5.7\bin\mysqld: ready for connections.
Version: '5.7.0-m10-log'  socket: ''  port: 3540  Source distribution
20:01:02 UTC - 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=8388608
read_buffer_size=131072
max_used_connections=1
max_threads=151
thread_count=1
connection_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 68024 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x711a9d0
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...
13fb38398    mysqld.exe!alloc_root()[my_alloc.c:203]
13f925969    mysqld.exe!get_var_with_binlog()[item_func.cc:5448]
13f925a95    mysqld.exe!Item_func_get_user_var::fix_length_and_dec()[item_func.cc:5497]
13f91ffc1    mysqld.exe!Item_func::fix_fields()[item_func.cc:232]
13f91fed6    mysqld.exe!Item_func::fix_fields()[item_func.cc:203]
13fa22e98    mysqld.exe!sp_prepare_func_item()[sp.cc:2633]
13fa24262    mysqld.exe!sp_eval_expr()[sp.cc:2666]
13faad0a7    mysqld.exe!sp_instr_set::exec_core()[sp_instr.cc:904]
13faaddcf    mysqld.exe!sp_lex_instr::reset_lex_and_exec_core()[sp_instr.cc:352]
13faaf250    mysqld.exe!sp_lex_instr::validate_lex_and_execute_core()[sp_instr.cc:612]
13fa29592    mysqld.exe!sp_head::execute()[sp_head.cc:645]
13fa2a062    mysqld.exe!sp_head::execute_function()[sp_head.cc:1089]
13f9265c9    mysqld.exe!Item_func_sp::execute_impl()[item_func.cc:6807]
13f927657    mysqld.exe!Item_func_sp::execute()[item_func.cc:6736]
13f9278b7    mysqld.exe!Item_func_sp::val_str()[item_func.h:2122]
13f88e170    mysqld.exe!Arg_comparator::compare_string()[item_cmpfunc.cc:1370]
13f88f591    mysqld.exe!Item_func_eq::val_int()[item_cmpfunc.cc:2199]
13f908cb1    mysqld.exe!Item::val_bool()[item.cc:203]
13f89d3cc    mysqld.exe!Item_cond_or::val_int()[item_cmpfunc.cc:5122]
13f904a1f    mysqld.exe!Item::send()[item.cc:6786]
13f8b3abe    mysqld.exe!Protocol::send_result_set_row()[protocol.cc:847]
13f8abe31    mysqld.exe!select_send::send_data()[sql_class.cc:2446]
13fa99bf7    mysqld.exe!JOIN::exec()[sql_executor.cc:148]
13fa10829    mysqld.exe!mysql_execute_select()[sql_select.cc:1088]
13fa1718b    mysqld.exe!handle_select()[sql_select.cc:110]
13f8bb07e    mysqld.exe!execute_sqlcom_select()[sql_parse.cc:4947]
13f8bf47d    mysqld.exe!mysql_execute_command()[sql_parse.cc:2560]
13f8c50ea    mysqld.exe!mysql_parse()[sql_parse.cc:6081]
13f8c6041    mysqld.exe!dispatch_command()[sql_parse.cc:1318]
13f8c72c7    mysqld.exe!do_command()[sql_parse.cc:1035]
13f953fc9    mysqld.exe!do_handle_one_connection()[sql_connect.cc:969]
13f95406a    mysqld.exe!handle_one_connection()[sql_connect.cc:887]
13fd5c5fe    mysqld.exe!pfs_spawn_thread()[pfs.cc:1856]
13fb467be    mysqld.exe!pthread_start()[my_winthread.c:63]
13fe02f57    mysqld.exe!_callthreadstartex()[threadex.c:348]
13fe0300b    mysqld.exe!_threadstartex()[threadex.c:326]
770f652d    kernel32.dll!BaseThreadInitThunk()
777ec521    ntdll.dll!RtlUserThreadStart()

Trying to get some variables.
[12 Nov 2012 17:51] Paul DuBois
Noted in 5.6.9, 5.7.0 changelogs.

Execution of a stored program that included the ISNULL() function and
a user-defined variable could cause a server crash.