[MDEV-10713] signal 11 error on multi-table update - crash in handler::increment_statistics or in make_select or assertion failure pfs_thread == ((PFS_thread*) pthread_getspecific((THR_PFS))) Created: 2016-08-31  Updated: 2016-12-08  Resolved: 2016-12-06

Status: Closed
Project: MariaDB Server
Component/s: Optimizer, Storage Engine - InnoDB
Affects Version/s: 10.0.20, 10.1.13, 5.5, 10.0, 10.1
Fix Version/s: 5.5.54, 10.0.29, 10.1.20, 10.2.3

Type: Bug Priority: Critical
Reporter: sungwon.han Assignee: Oleksandr Byelkin
Resolution: Fixed Votes: 1
Labels: upstream-fixed
Environment:

CentOS 6.7
HeidiSQL


Attachments: Text File fortestquery.sql     Text File my_cnf.txt     Text File mysqld_err.txt    
Sprint: 10.1.18, 10.1.20

 Description   

I got signal 11 error, when I execute the query through HeidiSQL tool.
But It didn't happen error executing through mysql client in server and toad tool.
I attached my.cnf , mysqld.err log and the query for test.
Why did it happen in HeidiSQL ? This tool version is 9.3.0.4984.
Thanks.



 Comments   
Comment by Elena Stepanova [ 2016-08-31 ]

Thanks for the report and test case.
Reproducible on current 5.5-10.2, and also on MySQL 5.5, but not MySQL 5.6-5.7.

Same test case, but MTR-style:

--source include/have_innodb.inc
 
CREATE TABLE `test_table1` (
  `CLOSE_YN` varchar(10) COLLATE utf8_bin DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin ;
 
 
CREATE TABLE `test_table2` (
  `ap_close_to` varchar(8) COLLATE utf8_bin DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin ;
 
drop function if exists FC_LD_SYSTOLOC_TEST;
 
--delimiter $$
CREATE  FUNCTION `FC_LD_SYSTOLOC_TEST`(`P_DC_CD` VARBINARY(50), `P_SYS_DATE` DATETIME) RETURNS datetime
    DETERMINISTIC
    SQL SECURITY INVOKER
BEGIN
  DECLARE V_SYS_DATE DATETIME;
 
 
SELECT now()   AS LOC_DATE
INTO V_SYS_DATE
;
 
  RETURN v_sys_date ;
 
END $$
 
--delimiter ;
 
update test_table1 S 
JOIN
(
SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'
										ELSE '' END ACCOUNT_APPLY_YYYYMMDD
										FROM (
										      select  case  when  'AP'='AP' then  ap_close_to   end  AS CLOSE_YMD
											 	from test_table2
										     ) A 
) X  			
 SET S.CLOSE_YN = ''
where 1=1;

Stack trace from 5.5 ee97274ca debug build

#2  0x00000000007b0afd in handle_fatal_signal (sig=11) at /data/src/5.5/sql/signal_handler.cc:262
#3  <signal handler called>
#4  0x000000000059d870 in handler::increment_statistics (this=0x7f6b0a1ee078, offset=&system_status_var::ha_read_rnd_next_count) at /data/src/5.5/sql/sql_class.h:4220
#5  0x000000000059dc1b in handler::ha_rnd_next (this=0x7f6b0a1ee078, buf=0x7f6b0a059978 "\377") at /data/src/5.5/sql/sql_class.h:4358
#6  0x00000000008d5861 in rr_sequential (info=0x7f6b0a1a0cf0) at /data/src/5.5/sql/records.cc:467
#7  0x000000000065d523 in join_init_read_record (tab=0x7f6b0a1a0c40) at /data/src/5.5/sql/sql_select.cc:17866
#8  0x000000000065b4bd in sub_select (join=0x7f6b0a229e08, join_tab=0x7f6b0a1a0c40, end_of_records=false) at /data/src/5.5/sql/sql_select.cc:16964
#9  0x000000000065ad8b in do_select (join=0x7f6b0a229e08, fields=0x7f6b1be24da0, table=0x0, procedure=0x0) at /data/src/5.5/sql/sql_select.cc:16629
#10 0x00000000006395e9 in JOIN::exec (this=0x7f6b0a229e08) at /data/src/5.5/sql/sql_select.cc:2873
#11 0x0000000000639db4 in mysql_select (thd=0x7f6b0c2cb060, rref_pointer_array=0x7f6b0c2cece0, tables=0x7f6b0a1913b8, wild_num=0, fields=..., conds=0x7f6b0a0f54b8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=1342177408, result=0x7f6b0a229d48, unit=0x7f6b0c2ce390, select_lex=0x7f6b0c2cea70) at /data/src/5.5/sql/sql_select.cc:3094
#12 0x00000000006b915a in mysql_multi_update (thd=0x7f6b0c2cb060, table_list=0x7f6b0a1913b8, fields=0x7f6b0c2ceb88, values=0x7f6b0c2ceff8, conds=0x7f6b0a0f54b8, options=0, handle_duplicates=DUP_ERROR, ignore=false, unit=0x7f6b0c2ce390, select_lex=0x7f6b0c2cea70, result=0x7f6b1be25338) at /data/src/5.5/sql/sql_update.cc:1452
#13 0x0000000000604803 in mysql_execute_command (thd=0x7f6b0c2cb060) at /data/src/5.5/sql/sql_parse.cc:2915
#14 0x000000000060c768 in mysql_parse (thd=0x7f6b0c2cb060, rawbuf=0x7f6b0a191078 "update test_table1 S \nJOIN\n(\nSELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'\n\t\t\t\t\t\t\t\t\t\tELSE '' END ACCOUNT_APPLY_YYYYMMDD\nFROM (\nselect  case  "..., length=314, parser_state=0x7f6b1be25650) at /data/src/5.5/sql/sql_parse.cc:5934
#15 0x000000000060047d in dispatch_command (command=COM_QUERY, thd=0x7f6b0c2cb060, packet=0x7f6b15b39061 "update test_table1 S \nJOIN\n(\nSELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'\n\t\t\t\t\t\t\t\t\t\tELSE '' END ACCOUNT_APPLY_YYYYMMDD\nFROM (\nselect  case  "..., packet_length=314) at /data/src/5.5/sql/sql_parse.cc:1079
#16 0x00000000005ff637 in do_command (thd=0x7f6b0c2cb060) at /data/src/5.5/sql/sql_parse.cc:793
#17 0x00000000007018a3 in do_handle_one_connection (thd_arg=0x7f6b0c2cb060) at /data/src/5.5/sql/sql_connect.cc:1270
#18 0x0000000000701630 in handle_one_connection (arg=0x7f6b0c2cb060) at /data/src/5.5/sql/sql_connect.cc:1186
#19 0x0000000000943ad7 in pfs_spawn_thread (arg=0x7f6b15b3fd40) at /data/src/5.5/storage/perfschema/pfs.cc:1015
#20 0x00007f6b1ba6c0a4 in start_thread (arg=0x7f6b1be26700) at pthread_create.c:309
#21 0x00007f6b19e9287d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Stack trace from 10.0 f81f985f3 debug build

mysqld: /data/src/10.0/storage/perfschema/pfs.cc:2566: PSI_table_locker* start_table_io_wait_v1(PSI_table_locker_state*, PSI_table*, PSI_table_io_operation, uint, const char*, uint): Assertion `pfs_thread == ((PFS_thread*) pthread_getspecific((THR_PFS)))' failed.
160831 16:39:54 [ERROR] mysqld got signal 6 ;
 
#7  0x00007fcd76474312 in __GI___assert_fail (assertion=0xf84cb0 "pfs_thread == ((PFS_thread*) pthread_getspecific((THR_PFS)))", file=0xf84728 "/data/src/10.0/storage/perfschema/pfs.cc", line=2566, function=0xf859c0 <start_table_io_wait_v1::__PRETTY_FUNCTION__> "PSI_table_locker* start_table_io_wait_v1(PSI_table_locker_state*, PSI_table*, PSI_table_io_operation, uint, const char*, uint)") at assert.c:101
#8  0x00000000009fc231 in start_table_io_wait_v1 (state=0x7fcd7872e790, table=0x7fcd73c00000, op=PSI_TABLE_FETCH_ROW, index=64, src_file=0xf368b9 "/data/src/10.0/sql/handler.cc", src_line=2599) at /data/src/10.0/storage/perfschema/pfs.cc:2565
#9  0x0000000000837112 in handler::ha_rnd_next (this=0x7fcd6307e888, buf=0x7fcd70260888 "\377") at /data/src/10.0/sql/handler.cc:2598
#10 0x00000000009668ee in rr_sequential (info=0x7fcd633916e8) at /data/src/10.0/sql/records.cc:469
#11 0x00000000006a9431 in join_init_read_record (tab=0x7fcd63391640) at /data/src/10.0/sql/sql_select.cc:18748
#12 0x00000000006a7374 in sub_select (join=0x7fcd631be118, join_tab=0x7fcd63391640, end_of_records=false) at /data/src/10.0/sql/sql_select.cc:17840
#13 0x00000000006a6c49 in do_select (join=0x7fcd631be118, fields=0x7fcd7872ebe0, table=0x0, procedure=0x0) at /data/src/10.0/sql/sql_select.cc:17505
#14 0x0000000000683d40 in JOIN::exec_inner (this=0x7fcd631be118) at /data/src/10.0/sql/sql_select.cc:3084
#15 0x0000000000681216 in JOIN::exec (this=0x7fcd631be118) at /data/src/10.0/sql/sql_select.cc:2373
#16 0x000000000068457e in mysql_select (thd=0x7fcd6cbf3070, rref_pointer_array=0x7fcd6cbf7378, tables=0x7fcd631a43c8, wild_num=0, fields=..., conds=0x7fcd631f08d8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=1342177408, result=0x7fcd631be058, unit=0x7fcd6cbf6a10, select_lex=0x7fcd6cbf7100) at /data/src/10.0/sql/sql_select.cc:3308
#17 0x0000000000713c0f in mysql_multi_update (thd=0x7fcd6cbf3070, table_list=0x7fcd631a43c8, fields=0x7fcd6cbf7218, values=0x7fcd6cbf76a0, conds=0x7fcd631f08d8, options=0, handle_duplicates=DUP_ERROR, ignore=false, unit=0x7fcd6cbf6a10, select_lex=0x7fcd6cbf7100, result=0x7fcd7872f2f0) at /data/src/10.0/sql/sql_update.cc:1601
#18 0x000000000064965b in mysql_execute_command (thd=0x7fcd6cbf3070) at /data/src/10.0/sql/sql_parse.cc:3379
#19 0x0000000000651e18 in mysql_parse (thd=0x7fcd6cbf3070, rawbuf=0x7fcd631a4088 "update test_table1 S \nJOIN\n(\nSELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'\n\t\t\t\t\t\t\t\t\t\tELSE '' END ACCOUNT_APPLY_YYYYMMDD\nFROM (\nselect  case  "..., length=314, parser_state=0x7fcd7872f650) at /data/src/10.0/sql/sql_parse.cc:6576
#20 0x0000000000644918 in dispatch_command (command=COM_QUERY, thd=0x7fcd6cbf3070, packet=0x7fcd65108071 "update test_table1 S \nJOIN\n(\nSELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'\n\t\t\t\t\t\t\t\t\t\tELSE '' END ACCOUNT_APPLY_YYYYMMDD\nFROM (\nselect  case  "..., packet_length=314) at /data/src/10.0/sql/sql_parse.cc:1309
#21 0x0000000000643bdb in do_command (thd=0x7fcd6cbf3070) at /data/src/10.0/sql/sql_parse.cc:999
#22 0x0000000000761efa in do_handle_one_connection (thd_arg=0x7fcd6cbf3070) at /data/src/10.0/sql/sql_connect.cc:1378
#23 0x0000000000761c6c in handle_one_connection (arg=0x7fcd6cbf3070) at /data/src/10.0/sql/sql_connect.cc:1293
#24 0x00000000009faa88 in pfs_spawn_thread (arg=0x7fcd701d41f0) at /data/src/10.0/storage/perfschema/pfs.cc:1860
#25 0x00007fcd783760a4 in start_thread (arg=0x7fcd78730700) at pthread_create.c:309
#26 0x00007fcd7652e87d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Stack trace from 10.1 f6e47c0031 debug build

#2  0x00007fab9ed02c01 in handle_fatal_signal (sig=11) at /data/src/10.1/sql/signal_handler.cc:294
#3  <signal handler called>
#4  0x00007fab9ee203f6 in make_select (head=0x7fab864af470, const_tables=0, read_tables=0, conds=0x0, allow_null_cond=true, error=0x7fab865cd230) at /data/src/10.1/sql/opt_range.cc:1178
#5  0x00007fab9eb096c5 in JOIN::optimize_inner (this=0x7fab865cce08) at /data/src/10.1/sql/sql_select.cc:1426
#6  0x00007fab9eb080c8 in JOIN::optimize (this=0x7fab865cce08) at /data/src/10.1/sql/sql_select.cc:1040
#7  0x00007fab9eaa1c6d in mysql_derived_optimize (thd=0x7fab93376070, lex=0x7fab933799f0, derived=0x7fab865cb088) at /data/src/10.1/sql/sql_derived.cc:807
#8  0x00007fab9eaa0ab3 in mysql_handle_single_derived (lex=0x7fab933799f0, derived=0x7fab865cb088, phases=4) at /data/src/10.1/sql/sql_derived.cc:195
#9  0x00007fab9ebc622a in TABLE_LIST::handle_derived (this=0x7fab865cb088, lex=0x7fab933799f0, phases=4) at /data/src/10.1/sql/table.cc:7128
#10 0x00007fab9eabecec in st_select_lex::handle_derived (this=0x7fab86597038, lex=0x7fab933799f0, phases=4) at /data/src/10.1/sql/sql_lex.cc:3823
#11 0x00007fab9ebc61e4 in TABLE_LIST::handle_derived (this=0x7fab865cbcd0, lex=0x7fab933799f0, phases=4) at /data/src/10.1/sql/table.cc:7126
#12 0x00007fab9eabecec in st_select_lex::handle_derived (this=0x7fab9337a1b8, lex=0x7fab933799f0, phases=4) at /data/src/10.1/sql/sql_lex.cc:3823
#13 0x00007fab9eb082e7 in JOIN::optimize_inner (this=0x7fab865ce168) at /data/src/10.1/sql/sql_select.cc:1085
#14 0x00007fab9eb080c8 in JOIN::optimize (this=0x7fab865ce168) at /data/src/10.1/sql/sql_select.cc:1040
#15 0x00007fab9eb10704 in mysql_select (thd=0x7fab93376070, rref_pointer_array=0x7fab9337a430, tables=0x7fab865963c8, wild_num=0, fields=..., conds=0x7fab8659bec8, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=1342177408, result=0x7fab865ce0a0, unit=0x7fab93379ab8, select_lex=0x7fab9337a1b8) at /data/src/10.1/sql/sql_select.cc:3424
#16 0x00007fab9eba9a2a in mysql_multi_update (thd=0x7fab93376070, table_list=0x7fab865963c8, fields=0x7fab9337a2d0, values=0x7fab9337a710, conds=0x7fab8659bec8, options=0, handle_duplicates=DUP_ERROR, ignore=false, unit=0x7fab93379ab8, select_lex=0x7fab9337a1b8, result=0x7fab9fa14d60) at /data/src/10.1/sql/sql_update.cc:1629
#17 0x00007fab9eace9de in mysql_execute_command (thd=0x7fab93376070) at /data/src/10.1/sql/sql_parse.cc:3817
#18 0x00007fab9ead9c0e in mysql_parse (thd=0x7fab93376070, rawbuf=0x7fab86596088 "update test_table1 S \nJOIN\n(\nSELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'\n\t\t\t\t\t\t\t\t\t\tELSE '' END ACCOUNT_APPLY_YYYYMMDD\nFROM (\nselect  case  "..., length=314, parser_state=0x7fab9fa155e0) at /data/src/10.1/sql/sql_parse.cc:7319
#19 0x00007fab9eac8617 in dispatch_command (command=COM_QUERY, thd=0x7fab93376070, packet=0x7fab932a4071 "update test_table1 S \nJOIN\n(\nSELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'\n\t\t\t\t\t\t\t\t\t\tELSE '' END ACCOUNT_APPLY_YYYYMMDD\nFROM (\nselect  case  "..., packet_length=314) at /data/src/10.1/sql/sql_parse.cc:1487
#20 0x00007fab9eac734e in do_command (thd=0x7fab93376070) at /data/src/10.1/sql/sql_parse.cc:1108
#21 0x00007fab9ebfd1a5 in do_handle_one_connection (thd_arg=0x7fab93376070) at /data/src/10.1/sql/sql_connect.cc:1350
#22 0x00007fab9ebfcf09 in handle_one_connection (arg=0x7fab93376070) at /data/src/10.1/sql/sql_connect.cc:1262
#23 0x00007fab9eedf9cc in pfs_spawn_thread (arg=0x7fab9328cd70) at /data/src/10.1/storage/perfschema/pfs.cc:1860
#24 0x00007fab9e1c80a4 in start_thread (arg=0x7fab9fa16b00) at pthread_create.c:309
#25 0x00007fab9c38087d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Comment by sungwon.han [ 2016-09-01 ]

Thanks for your answer.
I found that the results according to the different tools (mysql client, heidiSQL, toad)
First, set global general_log=1;
Second, Execute each tool. The results were as below.

1) HeidiSQL.
160901 13:28:03     5 Connect   glap_mgr@% as anonymous on
                    5 Query     SELECT CONNECTION_ID()
{color:red}*                    5 Query     SET NAMES utf8mb4*{color}
                    5 Query     SHOW STATUS
                    5 Query     SHOW VARIABLES
                    5 Query     USE `glaptest`
                    5 Query     update test_table1 S
JOIN
(
SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'
                                                                                ELSE '' END ACCOUNT_APPLY_YYYYMMDD
                                                                                FROM (
                                                                                      select  case  when  'AP'='AP' then  ap_close_to   end  AS CLOSE_YMD
                                                                                                from test_table2
                                                                                     ) A
) X
 SET S.CLOSE_YN = ''
where 1=1
                    5 Query     SELECT now()   AS LOC_DATE
INTO V_SYS_DATE

2) toad
 160901 13:39:34            6 Query     SELECT DATABASE()
                    6 Query     update test_table1 S
JOIN
(
SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'
ELSE '' END ACCOUNT_APPLY_YYYYMMDD
FROM (
select  case  when  'AP'='AP' then  ap_close_to   end  AS CLOSE_YMD
from test_table2
) A
) X
SET S.CLOSE_YN = ''
where 1=1
                    6 Query     SELECT DATABASE()

When connected to the HeidiSQL set to utf8mb4.("SET NAMES utf8mb4")

I execute the query with "set names utf8mb4" using mysql client tool(not heidiSQL). Then the DBMS also was killed.

SET NAMES utf8mb4 ;
use glaptest;
update test_table1 S
JOIN
(
SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'
ELSE '' END ACCOUNT_APPLY_YYYYMMDD
FROM (
      select  case  when  'AP'='AP' then  ap_close_to   end  AS CLOSE_YMD
 from test_table2
     ) A
) X
 SET S.CLOSE_YN = ''
where 1=1 ; 
SELECT now()   AS LOC_DATE ;

The mariadb server configuration about character-set is below :

+--------------------------+-----------------------------------------------------------------------+
| Variable_name            | Value                                                                 |
+--------------------------+-----------------------------------------------------------------------+
| character_set_client     | utf8                                                                  |
| character_set_connection | utf8                                                                  |
| character_set_database   | utf8                                                                  |
| character_set_filesystem | binary                                                                |
| character_set_results    | utf8                                                                  |
| character_set_server     | utf8                                                                  |
| character_set_system     | utf8                                                                  |
| character_sets_dir       | /data001/engn001/masvc01/mariadb-10.0.20-linux-x86_64/share/charsets/ |
+--------------------------+-----------------------------------------------------------------------+

I changed mariadb config and create table using utf8mb4. Then the server was not killed.

+--------------------------+-----------------------------------------------------------------------+
| Variable_name            | Value                                                                 |
+--------------------------+-----------------------------------------------------------------------+
| character_set_client     | utf8mb4                                                               |
| character_set_connection | utf8mb4                                                               |
| character_set_database   | utf8mb4                                                               |
| character_set_filesystem | binary                                                                |
| character_set_results    | utf8mb4                                                               |
| character_set_server     | utf8mb4                                                               |
| character_set_system     | utf8                                                                  |
| character_sets_dir       | /data001/engn001/masvc01/mariadb-10.0.20-linux-x86_64/share/charsets/ |
+--------------------------+-----------------------------------------------------------------------+
 
 
CREATE TABLE `test_table1` (
  `CLOSE_YN` varchar(10) COLLATE utf8mb4_bin DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
;
CREATE TABLE `test_table2` (
  `ap_close_to` varchar(8) COLLATE utf8mb4_bin DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin
 
update test_table1 S
JOIN
(
SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231'
ELSE '' END ACCOUNT_APPLY_YYYYMMDD
FROM (
      select  case  when  'AP'='AP' then  ap_close_to   end  AS CLOSE_YMD
 from test_table2
     ) A
) X
 SET S.CLOSE_YN = ''
where 1=1 ; 
SELECT now()   AS LOC_DATE ;

So, I think that this bug is caused by another character-set. The HeidiSQL tool use utf8mb4 character-set.
How do I change HeidiSQL config ?

Comment by Sergei Petrunia [ 2016-09-10 ]

(I have no idea about HeidiSQL, so I'm unable to answer the last question, sorry).

The crash in 5.5 and 10.0 happens when we try to access TABLE::in_use for table "S". It is in_use ==NULL. This should not be happening for a table that's open and being accessed.

I put a breakpoint to see who sets in_use=NULL and I catch this:

(gdb)  wher
  #0  tc_release_table (table=0x7fffcbc8ec70) at /home/psergey/dev-git/10.0/sql/table_cache.cc:399
  #1  0x00000000005eb4bd in close_thread_table (thd=0x7ffff54c4070, table_ptr=0x7ffff54c4130) at /home/psergey/dev-git/10.0/sql/sql_base.cc:1046
  #2  0x00000000005eac48 in close_open_tables (thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/sql_base.cc:769
  #3  0x00000000005eb226 in close_thread_tables (thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/sql_base.cc:993
  #4  0x00000000009afbc1 in sp_lex_keeper::reset_lex_and_exec_core (this=0x7fffcbd2a398, thd=0x7ffff54c4070, nextp=0x7ffff7f69d74, open_tables=true, instr=0x7fffcbd2a350) at /home/psergey/dev-git/10.0/sql/sp_head.cc:2992
  #5  0x00000000009b048e in sp_instr_set::execute (this=0x7fffcbd2a350, thd=0x7ffff54c4070, nextp=0x7ffff7f69d74) at /home/psergey/dev-git/10.0/sql/sp_head.cc:3223
  #6  0x00000000009aba3b in sp_head::execute (this=0x7fffcbd29088, thd=0x7ffff54c4070, merge_da_on_success=true) at /home/psergey/dev-git/10.0/sql/sp_head.cc:1373
  #7  0x00000000009acd14 in sp_head::execute_function (this=0x7fffcbd29088, thd=0x7ffff54c4070, argp=0x7fffcbc23f50, argcount=2, return_value_fld=0x7fffcbc2ed60) at /home/psergey/dev-git/10.0/sql/sp_head.cc:1915
  #8  0x00000000008d82bc in Item_func_sp::execute_impl (this=0x7fffcbc23eb8, thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/item_func.cc:6763
  #9  0x00000000008d803c in Item_func_sp::execute (this=0x7fffcbc23eb8) at /home/psergey/dev-git/10.0/sql/item_func.cc:6696
  #10 0x00000000008db6c4 in Item_func_sp::val_str (this=0x7fffcbc23eb8, str=0x7ffff7f6a570) at /home/psergey/dev-git/10.0/sql/item_func.h:2122
  #11 0x00000000008737ff in Item::get_date (this=0x7fffcbc23eb8, ltime=0x7ffff7f6a710, fuzzydate=0) at /home/psergey/dev-git/10.0/sql/item.cc:1374
  #12 0x00000000008704f0 in Item::get_date_with_conversion (this=0x7fffcbc23eb8, ltime=0x7ffff7f6a710, fuzzydate=0) at /home/psergey/dev-git/10.0/sql/item.cc:251
  #13 0x000000000092a1e7 in Item_func::get_arg0_date (this=0x7fffcbc28110, ltime=0x7ffff7f6a710, fuzzy_date=0) at /home/psergey/dev-git/10.0/sql/item_func.h:166
  #14 0x0000000000925c99 in Item_func_date_format::val_str (this=0x7fffcbc28110, str=0x7ffff7f6a780) at /home/psergey/dev-git/10.0/sql/item_timefunc.cc:1937
  #15 0x000000000088f25b in Item_func_conv_charset::Item_func_conv_charset (this=0x7fffcbc2ee20, a=0x7fffcbc28110, cs=0x1857980 <my_charset_utf8_bin>, cache_if_const=true) at /home/psergey/dev-git/10.0/sql/item_strfunc.h:944
  #16 0x0000000000872f2b in Item::safe_charset_converter (this=0x7fffcbc28110, tocs=0x1857980 <my_charset_utf8_bin>) at /home/psergey/dev-git/10.0/sql/item.cc:1176
  #17 0x0000000000875a0a in agg_item_set_converter (coll=..., fname=0x1000a08 "<=", args=0x7fffcbc283b8, nargs=2, flags=7, item_sep=1) at /home/psergey/dev-git/10.0/sql/item.cc:2188
  #18 0x0000000000875c65 in agg_item_charsets (coll=..., fname=0x1000a08 "<=", args=0x7fffcbc283b8, nargs=2, flags=7, item_sep=1) at /home/psergey/dev-git/10.0/sql/item.cc:2271
  #19 0x00000000008a6f0f in agg_item_charsets_for_comparison (c=..., name=0x1000a08 "<=", items=0x7fffcbc283b8, nitems=2, item_sep=1) at /home/psergey/dev-git/10.0/sql/item.h:2094
  #20 0x00000000008a70b3 in Item_func::agg_arg_charsets_for_comparison (this=0x7fffcbc28320, c=..., items=0x7fffcbc283b8, nitems=2, item_sep=1) at /home/psergey/dev-git/10.0/sql/item_func.h:226
  #21 0x0000000000893dda in Item_bool_func2::fix_length_and_dec (this=0x7fffcbc28320) at /home/psergey/dev-git/10.0/sql/item_cmpfunc.cc:562
  #22 0x00000000008c1bea in Item_func::fix_fields (this=0x7fffcbc28320, thd=0x7ffff54c4070, ref=0x7fffcbc28790) at /home/psergey/dev-git/10.0/sql/item_func.cc:229
  #23 0x00000000008c194c in Item_func::fix_fields (this=0x7fffcbc28638, thd=0x7ffff54c4070, ref=0x7fffcbc287c8) at /home/psergey/dev-git/10.0/sql/item_func.cc:202
  #24 0x000000000089ca81 in Item_func_case::fix_fields (this=0x7fffcbc28638, thd=0x7ffff54c4070, ref=0x7fffcbc287c8) at /home/psergey/dev-git/10.0/sql/item_cmpfunc.cc:3077
  #25 0x00000000005f9573 in setup_fields (thd=0x7ffff54c4070, ref_pointer_array=0x7fffcbc2eb58, fields=..., mark_used_columns=MARK_COLUMNS_READ, sum_func_list=0x7fffcbc2e948, allow_sum_func=true) at /home/psergey/dev-git/10.0/sql/sql_base.cc:7862
  #26 0x000000000068bfa7 in JOIN::prepare (this=0x7fffcbc2e600, rref_pointer_array=0x7fffcbc23290, tables_init=0x7fffcbc2c088, wild_num=0, conds_init=0x0, og_num=0, order_init=0x0, skip_order_by=false, group_init=0x0, having_init=0x0, proc_param_init=0x0, select_lex_arg=0x7fffcbc23018, unit_arg=0x7fffcbc23378) at /home/psergey/dev-git/10.0/sql/sql_select.cc:785
  #27 0x0000000000728059 in st_select_lex_unit::prepare (this=0x7fffcbc23378, thd_arg=0x7ffff54c4070, sel_result=0x7fffcbc2e510, additional_options=0) at /home/psergey/dev-git/10.0/sql/sql_union.cc:330
  #28 0x000000000062bea4 in mysql_derived_prepare (thd=0x7ffff54c4070, lex=0x7ffff54c7948, derived=0x7fffcbc2ccb0) at /home/psergey/dev-git/10.0/sql/sql_derived.cc:671
  #29 0x000000000062b9e4 in mysql_derived_merge_for_insert (thd=0x7ffff54c4070, lex=0x7ffff54c7948, derived=0x7fffcbc2ccb0) at /home/psergey/dev-git/10.0/sql/sql_derived.cc:521
  #30 0x000000000062aeda in mysql_handle_derived (lex=0x7ffff54c7948, phases=16) at /home/psergey/dev-git/10.0/sql/sql_derived.cc:119
  #31 0x000000000072e5ed in mysql_multi_update_prepare (thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/sql_update.cc:1392
  #32 0x00000000006563f7 in mysql_execute_command (thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/sql_parse.cc:3332
  #33 0x000000000065f2ed in mysql_parse (thd=0x7ffff54c4070, rawbuf=0x7fffcbc22088 "update test_table1 S  JOIN ( SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231' ELSE '' END ACCOUNT_APPLY_YYYYMMDD FROM (       select  case  when"..., length=314, parser_state=0x7ffff7f6c6c0) at /home/psergey/dev-git/10.0/sql/sql_parse.cc:6576
  #34 0x00000000006515d7 in dispatch_command (command=COM_QUERY, thd=0x7ffff54c4070, packet=0x7fffe32b9071 "update test_table1 S  JOIN ( SELECT CASE WHEN DATE_FORMAT( FC_LD_SYSTOLOC_TEST('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD THEN '99991231' ELSE '' END ACCOUNT_APPLY_YYYYMMDD FROM (       select  case  when"..., packet_length=314) at /home/psergey/dev-git/10.0/sql/sql_parse.cc:1309

Comment by Sergei Petrunia [ 2016-09-10 ]

Ok, I think I get what is the reason for the crash. It goes as follows:

1. Multi-update (the parent query) opens its tables. It hasn't called
lock_tables() for them, yet.

2. Multi-update calls mysql_handle_derived (see the "who sets in_use=NULL" stack
trace right above)

3. It enters into Item_func::fix_fields(), which attempts to execute the SP

4. SP executes the "SET .." instruction. We didn't enter "pre-locked mode",
so when SP closes its tables, it actually closes parent statement's
(multi-update's) tables.
This is why we get table->in_use= NULL.

5. Eventually multi-update reaches the point where it tries to lock its tables:

  #0  lock_tables (thd=0x7ffff54c4070, tables=0x7fffcbc224b0, count=2, flags=0) at /home/psergey/dev-git/10.0/sql/sql_base.cc:5364
  #1  0x000000000072ec53 in mysql_multi_update_prepare (thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/sql_update.cc:1513
  #2  0x00000000006563f7 in mysql_execute_command (thd=0x7ffff54c4070) at /home/psergey/dev-git/10.0/sql/sql_parse.cc:3332
  #3  0x000000000065f2ed in mysql_parse (thd=0x7ffff54c4070, rawbuf=0x7fffcbc22088 "update test_table1 S  JOIN (   SELECT CASE WHEN", ' ' <repeats

this succeeds (despite that close_thread_table() has already been called on the
table)

6. Multi-update enters execution phase. It attempts to access table->in_use, which has been set to NULL at step #4, and crashes.

Comment by Sergei Petrunia [ 2016-09-10 ]

The reason that it crashes on some charsets but not others has to do with step #3. Charset aggregation rules depend on the charsets. I guess for some of the charsets it doesn't try to compute the value and convert it to another charset in fix_fields.

Comment by Sergei Petrunia [ 2016-09-10 ]

SELECT statements first open tables and lock them, and then they call fix_fields().
Multi-table UPDATE seems to be a special kind of statement, it opens tables, then does fix_fields calls, then calls lock_tables(). I suppose, the reason for doing things in this order is that it needs to figure out which of the tables should be locked for writing.

Comment by Sergei Petrunia [ 2016-09-10 ]

Need to discuss with igor and/or sanja.

Comment by Oleksandr Byelkin [ 2016-09-13 ]

I've checked that fixing Item_func_conv_charset fixes the bug.

Real fix is to make Item_func_conv_charset storing result on first execute (do not forget constant reporting earlier, and cleaning on cleanup()).

Comment by Oleksandr Byelkin [ 2016-09-26 ]

CREATE TABLE `t1` (
  `CLOSE_YN` varchar(10) COLLATE utf8_bin DEFAULT NULL
) DEFAULT CHARSET=utf8 COLLATE=utf8_bin ;
 
 
CREATE TABLE `t2` (
  `ap_close_to` varchar(8) COLLATE utf8_bin DEFAULT NULL
) DEFAULT CHARSET=utf8 COLLATE=utf8_bin ;
 
 
--delimiter $$
 
CREATE  FUNCTION `f1`(`P_DC_CD` VARBINARY(50), `P_SYS_DATE` DATETIME) RETURNS datetime
    DETERMINISTIC
    SQL SECURITY INVOKER
BEGIN
  DECLARE V_SYS_DATE DATETIME;
  SELECT now() AS LOC_DATE INTO V_SYS_DATE ;
  RETURN v_sys_date ;
END $$
 
--delimiter ;
 
update t1 S 
JOIN
(
  SELECT CASE
           WHEN DATE_FORMAT( f1('F01', NOW()) , '%Y%m%d') <= CLOSE_YMD
             THEN '99991231'
	     ELSE '' END ACCOUNT_APPLY_YYYYMMDD
  FROM (
        select case
                 when 'AP'='AP'
                   then ap_close_to
                   end AS CLOSE_YMD
	from t2
       ) A 
) X  			
SET S.CLOSE_YN = ''
where 1=1;
 
drop function if exists f1;
drop table t1,t2;

Comment by Alexander Barkov [ 2016-12-06 ]

This patch is OK to push:

Date: Tue, 06 Dec 2016 15:43:37 +0100
To: commits@mariadb.org
Subject: [Commits] 0b4f89a: MDEV-10713: signal 11 error on multi-table
update - crash in handler::increment_statistics or in
make_select or assertion failure pfs_thread == ((PFS_thread*)
pthread_getspecific((THR_PFS)))

Perhaps we should change the non-caching constructor to set is_expensive_cache to -1, so the non-caching function works like a regular string function, for example REVERSE.

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