Bug #3535 Server crushes after executing UDF in second time
Submitted: 22 Apr 2004 7:11 Modified: 20 Apr 2005 10:04
Reporter: Sergey Gurin Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S2 (Serious)
Version:5.0.0alpha/5.0.,1 OS:Windows (WinXP)
Assigned to: Bugs System CPU Architecture:Any

[22 Apr 2004 7:11] Sergey Gurin
Description:
1 step: Create Table "frut_t_osttov".
------------------------------------
CREATE TABLE FRUT_T_OSTTOV
(
  DATA DATE  NOT NULL,
  KODTOV VARCHAR(20)  NOT NULL,
  KODSKL VARCHAR(20)  NOT NULL,
  KOL DECIMAL(10,3)  NOT NULL,
  ZENA DECIMAL(10,6),
  USERS VARCHAR(20),
  USERDATA DATE,
  ZTRANS DECIMAL(12,6),
  PRIMARY KEY (DATA,KODTOV,KODSKL)
);
CREATE      INDEX T_OSTTOVFORK_SKLIDX ON FRUT_T_OSTTOV
(KODSKL ) ;

ALTER TABLE FRUT_T_OSTTOV ADD  FOREIGN KEY (KODSKL)
REFERENCES FRUT_T_SKL (KODSKL)     ;

CREATE      INDEX T_OSTTOVFORK_TOVIDX ON FRUT_T_OSTTOV
(KODTOV ) ;

ALTER TABLE FRUT_T_OSTTOV ADD  FOREIGN KEY (KODTOV)
REFERENCES FRUT_T_TOV (KODTOV)     ;

2 step: Inserting 180000 records.

3 step: Create Function.
-----------------------
CREATE FUNCTION FRUT_FOSTTOV32 (KODTOV1 CHAR, DATA1 DATE, KODSKL1 CHAR) RETURNS FLOAT
BEGIN
  DECLARE Ostatok FLOAT;
  DECLARE c1 cursor FOR  
select kol ostatok from 
frut_t_osttov A,
(select MAX(DATA) maxdata from frut_t_osttov A   
Where KODTOV=KODTOV1
and Data<DATA1
and A.KODSKL= KODSKL1
) p
Where KODTOV=KODTOV1  and data=p.maxdata
and Data<DATA1
and A.KODSKL= KODSKL1;
Open c1;
FETCH c1 into Ostatok;
Close c1; 
return(Ostatok); 
END;

4 step: Executing function.
---------------------------
mysql> select FRUT_FOSTTOV32('1/11514',str_to_date('01.03.2004','%d.%m.%Y'),'11');
---------------------------------------------------------------------
|FRUT_FOSTTOV32('1/11514',str_to_date('01.03.2004','%d.%m.%Y'),'11')|
|-------------------------------------------------------------------|
|                                                           4006.000|
|-------------------------------------------------------------------|

5 step: Executing function one more time.
-----------------------------------------
mysql> select FRUT_FOSTTOV32('1/11514',str_to_date('01.03.2004','%d.%m.%Y'),'11');
ERROR 2013 (HY000): Lost connection to MySQL server during query

Windows show error dialog "error in mysqld-nt.exe..."

How to repeat:
All time (first execution Ok, second - ERROR)

Suggested fix:
Maybe I have wrote function incorrectly?
[12 May 2004 23:49] MySQL Verification Team
Thank you for the bug report I was able to repeat with version
5.0.0. I will test it with latest 5.0 BK tree.
[13 May 2004 5:30] MySQL Verification Team
Tested against latest 5.0 BK tree.

sql/sql_select.cc
--5939--
 while ((item=li++))
  {
    Item::Type type=item->type();
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    if (not_all_columns)

CALL STACK:

>	mysqld.exe!create_tmp_table(THD * thd=0x02f32c20, TMP_TABLE_PARAM * param=0x00e8b0e0, List<Item> & fields={...}, st_order * group=0x00000000, int distinct=0, int save_sum_fields=1, unsigned long select_options=277109248, unsigned long rows_limit=4294967295, char * table_alias=0x02f409a8)  Line 5939 + 0x6	C++
 	mysqld.exe!mysql_derived(THD * thd=0x02f32c20, st_lex * lex=0x02f41cb0, st_select_lex_unit * unit=0x02f40128, st_table_list * org_table_list=0x02f409d0)  Line 144 + 0x62	C++
 	mysqld.exe!mysql_handle_derived(st_lex * lex=0x02f41cb0)  Line 60 + 0x27	C++
 	mysqld.exe!open_and_lock_tables(THD * thd=0x02f32c20, st_table_list * tables=0x00e8afd0)  Line 1651 + 0x28	C++
 	mysqld.exe!mysql_execute_command(THD * thd=0x02f32c20)  Line 1931 + 0xd	C++
 	mysqld.exe!sp_instr_stmt::exec_stmt(THD * thd=0x02f32c20, st_lex * lex=0x02f41cb0)  Line 977 + 0x9	C++
 	mysqld.exe!sp_instr_copen::execute(THD * thd=0x02f32c20, unsigned int * nextp=0x03e3ea68)  Line 1276 + 0x10	C++
 	mysqld.exe!sp_head::execute(THD * thd=0x02f32c20)  Line 404 + 0x19	C++
 	mysqld.exe!sp_head::execute_function(THD * thd=0x02f32c20, Item * * argp=0x00e89a9c, unsigned int argcount=3, Item * * resp=0x03e3eb84)  Line 494 + 0xc	C++
 	mysqld.exe!Item_func_sp::execute(Item * * itp=0x03e3eb84)  Line 3259 + 0x21	C++
 	mysqld.exe!Item_func_sp::val()  Line 1130 + 0xc	C++
 	mysqld.exe!Item::send(Protocol * protocol=0x02f33470, String * buffer=0x03e3ec58)  Line 1562 + 0x11	C++
 	mysqld.exe!select_send::send_data(List<Item> & items={...})  Line 655 + 0x19	C++
 	mysqld.exe!JOIN::exec()  Line 1120 + 0x96	C++
 	mysqld.exe!mysql_select(THD * thd=0x02f32c20, Item * * * rref_pointer_array=0x02f32e34, st_table_list * tables=0x00000000, unsigned int wild_num=0, List<Item> & fields={...}, Item * conds=0x00000000, unsigned int og_num=0, st_order * order=0x00000000, st_order * group=0x00000000, Item * having=0x00000000, st_order * proc_param=0x00000000, unsigned long select_options=8669696, select_result * result=0x00e89bc0, st_select_lex_unit * unit=0x02f32c44, st_select_lex * select_lex=0x02f32d38)  Line 1646	C++
 	mysqld.exe!handle_select(THD * thd=0x02f32c20, st_lex * lex=0x02f32c38, select_result * result=0x00e89bc0)  Line 214 + 0x80	C++
 	mysqld.exe!mysql_execute_command(THD * thd=0x02f32c20)  Line 1969 + 0x11	C++
 	mysqld.exe!mysql_parse(THD * thd=0x02f32c20, char * inBuf=0x00e895c8, unsigned int length=99)  Line 4284 + 0x9	C++
 	mysqld.exe!dispatch_command(enum_server_command command=COM_QUERY, THD * thd=0x02f32c20, char * packet=0x00e85561, unsigned int packet_length=100)  Line 1471 + 0x1d	C++
 	mysqld.exe!do_command(THD * thd=0x02f32c20)  Line 1287 + 0x31	C++
 	mysqld.exe!handle_one_connection(void * arg=0x02f32c20)  Line 1031 + 0x9	C++
 	mysqld.exe!pthread_start(void * param=0x02f35930)  Line 63 + 0x7	C
 	mysqld.exe!_threadstart(void * ptd=0x02f35f78)  Line 173 + 0xd	C
 	kernel32.dll!77e6d33b()
[27 May 2004 16:47] Timothy Crider
I can confirm this problem also exists on Fedora Core 2.

My Function:

CREATE FUNCTION `is_email` (email CHAR(100)) RETURNS TINYINT(3)
   IF (SELECT `email` REGEXP("^([-!#\$%&'*+./0-9=?A-Z^_a-z{|}~ ])+@([-!#\$%&'*+/0-9=?A-Z^_a-z{|}~]+\\.)+[a-zA-Z]{2,5}\$")) THEN
      RETURN 1;
   ELSE
      RETURN 0;
   END IF;

RESULT:

mysql> SELECT is_email('x');
    -> //
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> delimiter ;
mysql> SELECT is_email('x');
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    1
Current database: *** NONE ***

+---------------+
| is_email('x') |
+---------------+
|             0 |
+---------------+
1 row in set (0.00 sec)

mysql> SELECT is_email('example@email.com');
ERROR 2013 (HY000): Lost connection to MySQL server during query

I will try this again, and post the strace results.

 Tim
[27 May 2004 16:50] Timothy Crider
Here is the stack trace:

/root@LB0001 mysql_sp/ strace -p 3456
Process 3518 attached with 3 threads - interrupt to quit
[pid  3457] rt_sigtimedwait([HUP QUIT ALRM TERM TSTP],  <unfinished ...>
[pid  3456] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] read(8,  <unfinished ...>
[pid  3456] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] <... read resumed> 0x8ddcd78, 4) = ? ERESTARTSYS (To be restarted)
[pid  3456] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3518] --- SIGSTOP (Stopped (signal)) @ 0 (0) ---
[pid  3456] select(5, [3 4], NULL, NULL, NULL <unfinished ...>
[pid  3518] read(8, "\363\0\0\0", 4)    = 4
[pid  3518] read(8, "\3CREATE FUNCTION `is_email` (ema"..., 243) = 243
[pid  3518] rt_sigprocmask(SIG_BLOCK, ~[RTMIN], [HUP INT QUIT PIPE TERM TSTP], 8) = 0
[pid  3518] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM TSTP], NULL, 8) = 0
[pid  3518] fcntl64(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid  3518] time([1085669295])          = 1085669295
[pid  3518] sched_setscheduler(3518, SCHED_OTHER, { 6 }) = -1 EINVAL (Invalid argument)
[pid  3518] time([1085669295])          = 1085669295
[pid  3518] _llseek(10, 964, [964], SEEK_SET) = 0
[pid  3518] read(10, "\0\0\1H\377\377\377\377\377\377\377\377\377\377\377\377"..., 20) = 20
[pid  3518] pwrite(10, "\3\0\376\16\327\1\0\10is_email\1\10is_email\1\1\2\2\17"..., 292, 964) = 292
[pid  3518] pwrite(9, "\0]\0\nerror_test\2\0\0\3|\0\10if_regex\2\0\0"..., 1024, 1024) = 1024
[pid  3518] pwrite(9, "\376\376\7\1\0\3\1\342\0\260\0d\0\314\0\3\0\0\1\0\10\1"..., 140, 0) = 140
[pid  3518] write(8, "\7\0\0\1\0\0\0\2\0\0\0", 11) = 11
[pid  3518] sched_setscheduler(3518, SCHED_OTHER, { 8 }) = -1 EINVAL (Invalid argument)
[pid  3518] time([1085669295])          = 1085669295
[pid  3518] read(8, 0x8ddcd78, 4)       = -1 EAGAIN (Resource temporarily unavailable)
[pid  3518] time(NULL)                  = 1085669295
[pid  3518] rt_sigprocmask(SIG_BLOCK, ~[RTMIN], [HUP INT QUIT PIPE TERM TSTP], 8) = 0
[pid  3518] tgkill(3456, 3457, SIGALRM <unfinished ...>
[pid  3457] <... rt_sigtimedwait resumed> 0, 0, 8) = 14
[pid  3518] <... tgkill resumed> )      = 0
[pid  3457] rt_sigprocmask(SIG_SETMASK, ~[RTMIN],  <unfinished ...>
[pid  3518] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM TSTP],  <unfinished ...>
[pid  3457] <... rt_sigprocmask resumed> [HUP INT QUIT PIPE ALRM TERM TSTP], 8) = 0
[pid  3518] <... rt_sigprocmask resumed> NULL, 8) = 0
[pid  3457] time( <unfinished ...>
[pid  3518] fcntl64(8, F_SETFL, O_RDWR <unfinished ...>
[pid  3457] <... time resumed> NULL)    = 1085669295
[pid  3518] <... fcntl64 resumed> )     = 0
[pid  3457] alarm(28800 <unfinished ...>
[pid  3518] read(8,  <unfinished ...>
[pid  3457] <... alarm resumed> )       = 28791
[pid  3457] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE ALRM TERM TSTP], NULL, 8) = 0
[pid  3457] rt_sigtimedwait([HUP QUIT ALRM TERM TSTP],  <unfinished ...>
[pid  3518] <... read resumed> "\25\0\0\0", 4) = 4
[pid  3518] read(8, "\3SELECT is_email(\'x\')", 21) = 21
[pid  3518] rt_sigprocmask(SIG_BLOCK, ~[RTMIN], [HUP INT QUIT PIPE TERM TSTP], 8) = 0
[pid  3518] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM TSTP], NULL, 8) = 0
[pid  3518] fcntl64(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid  3518] time([1085669301])          = 1085669301
[pid  3518] sched_setscheduler(3518, SCHED_OTHER, { 6 }) = -1 EINVAL (Invalid argument)
[pid  3518] time([1085669301])          = 1085669301
[pid  3518] _llseek(10, 964, [964], SEEK_SET) = 0
[pid  3518] read(10, "\3\0\376\16\327\1\0\10is_email\1\10is", 20) = 20
[pid  3518] pread(10, "\327\1\0\10is_email\1\10is_email\1\1\2\2\17\0emai"..., 254, 968) = 254
[pid  3518] time([1085669301])          = 1085669301
[pid  3518] _llseek(10, 964, [964], SEEK_SET) = 0
[pid  3518] read(10, "\3\0\376\16\327\1\0\10is_email\1\10is", 20) = 20
[pid  3518] pread(10, "\327\1\0\10is_email\1\10is_email\1\1\2\2\17\0emai"..., 254, 968) = 254
[pid  3518] brk(0)                      = 0x8e0c000
[pid  3518] brk(0x8e36000)              = 0x8e36000
[pid  3518] write(8, "\1\0\0\1\1#\0\0\2\3def\0\0\0\ris_email(\'x\')\0\f"..., 64) = 64
[pid  3518] sched_setscheduler(3518, SCHED_OTHER, { 8 }) = -1 EINVAL (Invalid argument)
[pid  3518] time([1085669301])          = 1085669301
[pid  3518] read(8, 0x8ddcd78, 4)       = -1 EAGAIN (Resource temporarily unavailable)
[pid  3518] time(NULL)                  = 1085669301
[pid  3518] rt_sigprocmask(SIG_BLOCK, ~[RTMIN], [HUP INT QUIT PIPE TERM TSTP], 8) = 0
[pid  3518] tgkill(3456, 3457, SIGALRM) = 0
[pid  3518] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM TSTP], NULL, 8) = 0
[pid  3518] fcntl64(8, F_SETFL, O_RDWR) = 0
[pid  3518] read(8,  <unfinished ...>
[pid  3457] <... rt_sigtimedwait resumed> 0, 0, 8) = 14
[pid  3457] rt_sigprocmask(SIG_SETMASK, ~[RTMIN], [HUP INT QUIT PIPE ALRM TERM TSTP], 8) = 0
[pid  3457] time(NULL)                  = 1085669301
[pid  3457] alarm(28800)                = 28794
[pid  3457] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE ALRM TERM TSTP], NULL, 8) = 0
[pid  3457] rt_sigtimedwait([HUP QUIT ALRM TERM TSTP],  <unfinished ...>
[pid  3518] <... read resumed> "&\0\0\0", 4) = 4
[pid  3518] read(8, "\3SELECT is_email(\'example@email."..., 38) = 38
[pid  3518] rt_sigprocmask(SIG_BLOCK, ~[RTMIN], [HUP INT QUIT PIPE TERM TSTP], 8) = 0
[pid  3518] rt_sigprocmask(SIG_SETMASK, [HUP INT QUIT PIPE TERM TSTP], NULL, 8) = 0
[pid  3518] fcntl64(8, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid  3518] time([1085669329])          = 1085669329
[pid  3518] sched_setscheduler(3518, SCHED_OTHER, { 6 }) = -1 EINVAL (Invalid argument)
[pid  3518] --- SIGSEGV (Segmentation fault) @ 0 (0) ---
[pid  3518] write(2, "mysqld got signal 11;\nThis could"..., 248) = 248
[pid  3518] write(2, "We will try our best to scrape u"..., 176) = 176
[pid  3518] write(2, "key_buffer_size=8388600\n", 24) = 24
[pid  3518] write(2, "read_buffer_size=131072\n", 24) = 24
[pid  3518] write(2, "max_used_connections=0\n", 23) = 23
[pid  3518] write(2, "max_connections=100\n", 20) = 20
[pid  3518] write(2, "threads_connected=1\n", 20) = 20
[pid  3518] write(2, "It is possible that mysqld could"..., 143) = 143
[pid  3518] write(2, "Hope that\'s ok; if not, decrease"..., 66) = 66
[pid  3518] write(2, "thd=0x8dd7f88\n", 14) = 14
[pid  3518] write(2, "Attempting backtrace. You can us"..., 159) = 159
[pid  3518] write(2, "Cannot determine thread, fp=0xf6"..., 70) = 70
[pid  3518] write(2, "Stack range sanity check OK, bac"..., 48) = 48
[pid  3518] write(2, "0x812bcba\n", 10) = 10
[pid  3518] write(2, "0x378420\n", 9)   = 9
[pid  3518] write(2, "0x80c7ffa\n", 10) = 10
[pid  3518] write(2, "0x8109170\n", 10) = 10
[pid  3518] write(2, "0x81dab0c\n", 10) = 10
[pid  3518] write(2, "0x81dc9b1\n", 10) = 10
[pid  3518] write(2, "0x81db27f\n", 10) = 10
[pid  3518] write(2, "0x81db491\n", 10) = 10
[pid  3518] write(2, "0x80dd93a\n", 10) = 10
[pid  3518] write(2, "0x80e2ea6\n", 10) = 10
[pid  3518] write(2, "0x80caecd\n", 10) = 10
[pid  3518] write(2, "0x81207dd\n", 10) = 10
[pid  3518] write(2, "0x8163a3f\n", 10) = 10
[pid  3518] write(2, "0x8164ed6\n", 10) = 10
[pid  3518] write(2, "0x8161cac\n", 10) = 10
[pid  3518] write(2, "0x813b803\n", 10) = 10
[pid  3518] write(2, "0x81414e5\n", 10) = 10
[pid  3518] write(2, "0x813a726\n", 10) = 10
[pid  3518] write(2, "0x813a330\n", 10) = 10
[pid  3518] write(2, "0x8139a15\n", 10) = 10
[pid  3518] write(2, "0x84798c\n", 9)   = 9
[pid  3518] write(2, "0x6c916a\n", 9)   = 9
[pid  3518] write(2, "New value of fp=(nil) failed san"..., 68) = 68
[pid  3518] write(2, "Please read http://www.mysql.com"..., 216) = 216
[pid  3518] write(2, "Trying to get some variables.\nSo"..., 90) = 90
[pid  3518] brk(0)                      = 0x8e36000
[pid  3518] write(2, "thd->query at 0x8ddad70 ", 24) = 24
[pid  3518] write(2, "= ", 2)           = 2
[pid  3518] write(2, "S", 1)            = 1
[pid  3518] write(2, "E", 1)            = 1
[pid  3518] write(2, "L", 1)            = 1
[pid  3518] write(2, "E", 1)            = 1
[pid  3518] write(2, "C", 1)            = 1
[pid  3518] write(2, "T", 1)            = 1
[pid  3518] write(2, " ", 1)            = 1
[pid  3518] write(2, "i", 1)            = 1
[pid  3518] write(2, "s", 1)            = 1
[pid  3518] write(2, "_", 1)            = 1
[pid  3518] write(2, "e", 1)            = 1
[pid  3518] write(2, "m", 1)            = 1
[pid  3518] write(2, "a", 1)            = 1
[pid  3518] write(2, "i", 1)            = 1
[pid  3518] write(2, "l", 1)            = 1
[pid  3518] write(2, "(", 1)            = 1
[pid  3518] write(2, "\'", 1)           = 1
[pid  3518] write(2, "e", 1)            = 1
[pid  3518] write(2, "x", 1)            = 1
[pid  3518] write(2, "a", 1)            = 1
[pid  3518] write(2, "m", 1)            = 1
[pid  3518] write(2, "p", 1)            = 1
[pid  3518] write(2, "l", 1)            = 1
[pid  3518] write(2, "e", 1)            = 1
[pid  3518] write(2, "@", 1)            = 1
[pid  3518] write(2, "e", 1)            = 1
[pid  3518] write(2, "m", 1)            = 1
[pid  3518] write(2, "a", 1)            = 1
[pid  3518] write(2, "i", 1)            = 1
[pid  3518] write(2, "l", 1)            = 1
[pid  3518] write(2, ".", 1)            = 1
[pid  3518] write(2, "c", 1)            = 1
[pid  3518] write(2, "o", 1)            = 1
[pid  3518] write(2, "m", 1)            = 1
[pid  3518] write(2, "\'", 1)           = 1
[pid  3518] write(2, ")", 1)            = 1
[pid  3518] write(2, "\n", 1)           = 1
[pid  3518] write(2, "thd->thread_id=1\n", 17) = 17
[pid  3518] write(2, "The manual page at http://www.my"..., 139) = 139
[pid  3518] close(6)                    = 0
[pid  3518] close(7)                    = 0
[pid  3518] close(5)                    = 0
[pid  3518] munmap(0xf67f5000, 4096)    = 0
[pid  3518] exit_group(1)               = ?
Process 3456 detached
Process 3518 detached
unknown pid: 3457
[20 Apr 2005 10:04] Per-Erik Martin
No longer repeatable.