[MDEV-16039] Crash when selecting virtual columns generated using functions with DAYNAME() Created: 2018-04-26  Updated: 2021-05-27  Resolved: 2020-07-21

Status: Closed
Project: MariaDB Server
Component/s: Virtual Columns
Affects Version/s: 10.2.14, 10.2, 10.3, 10.4, 10.5
Fix Version/s: 10.2.33, 10.3.24, 10.4.14, 10.5.5

Type: Bug Priority: Critical
Reporter: Robert Humphries Assignee: Nikita Malyavin
Resolution: Fixed Votes: 3
Labels: None
Environment:

CentOS virtual machine running on XenServer

Attachments: File error.sql     Text File errorLog.txt    
Issue Links:
Duplicate
is duplicated by MDEV-17653 replace into generated columns is uns... Closed
is duplicated by MDEV-17986 crash when I insert on a table Closed
is duplicated by MDEV-19788 Interplay between function based defa... Closed
is duplicated by MDEV-20380 Server crash during update Closed
Relates
relates to MDEV-25672 table alias from previous statement i... Closed
relates to MDEV-25794 vcol_info refix during lock_tables() ... Open
Sprint: 10.4.0-1

 Description   

Good Afternoon,

I have encountered a crash on a number of operations after a small amount of time has passed, where that table has a virtual column, where in its expression it uses the JSON_VALUE function, with the JSON value selected by a CONCAT to get '$.'<Current Day Name>. (Please see example).

Commands crash occurs on:

  • SELECT on table
  • Insert/Update on table
  • DROP TABLE
  • SHOW FULL TABLES FROM <database table is in> WHERE table_type = 'BASE TABLE';

If I don't use both JSON_VALUE and DAYNAME(), it works fine.

I have attached my debug machine's error log, showing all the crashes occurred while testing

Thanks,
Robert

 Comments   
Comment by Elena Stepanova [ 2018-05-31 ]

From the error log:

10.2.14

 
180426 17:00:30 [ERROR] 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.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
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.
 
Server version: 10.2.14-MariaDB
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=2
 
max_threads=153
 
thread_count=9
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467245 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f77d4000e48
 
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 = 0x7f7b740e9d70 thread_stack 0x49000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55bf10adacce]
 
/usr/sbin/mysqld(handle_fatal_signal+0x355)[0x55bf10566605]
 
/lib64/libpthread.so.0(+0xf5e0)[0x7f7b916765e0]
 
/usr/sbin/mysqld(_Z14join_read_key2P3THDP13st_join_tableP5TABLEP12st_table_ref+0x21)[0x55bf10415e71]
 
/usr/sbin/mysqld(_ZN25Expression_cache_tmptable11check_valueEPP4Item+0x2e)[0x55bf104dd89e]
 
/usr/sbin/mysqld(_ZN16Item_func_or_sum4walkEM4ItemFbPvEbS1_+0x67)[0x55bf10393eb7]
 
/usr/sbin/mysqld(_ZN16Item_func_or_sum4walkEM4ItemFbPvEbS1_+0x67)[0x55bf10393eb7]
 
/usr/sbin/mysqld(_ZN16Item_func_or_sum4walkEM4ItemFbPvEbS1_+0x67)[0x55bf10393eb7]
 
sql/sql_select.cc:19321(join_read_key2(THD*, st_join_table*, TABLE*, st_table_ref*))[0x55bf1047e658]
 
sql/sql_expression_cache.cc:220(Expression_cache_tmptable::check_value(Item**))[0x55bf103910b0]
 
/usr/sbin/mysqld(_Z10setup_wildP3THDP10TABLE_LISTR4ListI4ItemEPS5_j+0x212)[0x55bf103916b2]
 
sql/item.h:3907(Item_args::walk_args(bool (Item::*)(void*), bool, void*))[0x55bf10419979]
 
sql/item.h:3907(Item_args::walk_args(bool (Item::*)(void*), bool, void*))[0x55bf10429e7c]
 
sql/table.cc:6576(TABLE::mark_virtual_col(Field*))[0x55bf1042a1e4]
 
sql/sql_base.cc:7577(insert_fields(THD*, Name_resolution_context*, char const*, char const*, List_iterator<Item>*, bool))[0x55bf1030bbd9]
 
sql/sql_select.cc:802(JOIN::prepare(TABLE_LIST*, unsigned int, Item*, unsigned int, st_order*, bool, st_order*, Item*, st_order*, st_select_lex*, st_select_lex_unit*))[0x55bf103d61ce]
 
sql/sql_parse.cc:6469(execute_sqlcom_select(THD*, TABLE_LIST*))[0x55bf103d8b2e]
 
sql/sql_parse.cc:3479(mysql_execute_command(THD*))[0x55bf103dbb33]
 
sql/sql_parse.cc:1815(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55bf103dc76b]
 
sql/sql_parse.cc:1371(do_command(THD*))[0x55bf104a3d3a]
 
sql/sql_connect.cc:1335(do_handle_one_connection(CONNECT*))[0x55bf104a3e5d]
 
/lib64/libpthread.so.0(+0x7e25)[0x7f7b9166ee25]
 
/lib64/libc.so.6(clone+0x6d)[0x7f7b8fc4634d]
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f77d4013270): select * from `bugTest`.`suppliers2` limit 0, 1000
 
Connection ID (thread ID): 28
 
Status: NOT_KILLED
 
Apr 26 17:00:34 CentOS-Test kernel: traps: mysqld[27753] general protection ip:55bf10415e71 sp:7f7b740e6df0 error:0 in mysqld[55bf0fef3000+111d000]
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on


180426 17:19:44 [ERROR] 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.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
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.
 
Server version: 10.2.14-MariaDB
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=2
 
max_threads=153
 
thread_count=9
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467245 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f787c0009a8
 
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 = 0x7f7c18048d70 thread_stack 0x49000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x56147bf84cce]
 
/usr/sbin/mysqld(handle_fatal_signal+0x355)[0x56147ba10605]
 
/lib64/libpthread.so.0(+0xf5e0)[0x7f7c358135e0]
 
/usr/sbin/mysqld(_ZN9Item_func10print_argsEP6Stringj15enum_query_type+0x49)[0x56147ba7e029]
 
/usr/sbin/mysqld(_ZN9Item_func5printEP6String15enum_query_type+0x4d)[0x56147ba7e11d]
 
/usr/sbin/mysqld(_ZN9Item_func10print_argsEP6Stringj15enum_query_type+0x4f)[0x56147ba7e02f]
 
/usr/sbin/mysqld(_ZN9Item_func5printEP6String15enum_query_type+0x4d)[0x56147ba7e11d]
 
/usr/sbin/mysqld(_ZN9Item_func10print_argsEP6Stringj15enum_query_type+0x4f)[0x56147ba7e02f]
 
/usr/sbin/mysqld(_ZN9Item_func5printEP6String15enum_query_type+0x4d)[0x56147ba7e11d]
 
/usr/sbin/mysqld(_Z17show_create_tableP3THDP10TABLE_LISTP6StringP22Table_specification_st17enum_with_db_name+0x58b)[0x56147b8dbb4b]
 
/usr/sbin/mysqld(_Z29mysqld_show_create_get_fieldsP3THDP10TABLE_LISTP4ListI4ItemEP6String+0x51b)[0x56147b8dd74b]
 
/usr/sbin/mysqld(_Z18mysqld_show_createP3THDP10TABLE_LIST+0xc3)[0x56147b8dd913]
 
sql/item_func.cc:470(Item_func::print_args(String*, unsigned int, enum_query_type))[0x56147b87d42d]
 
sql/sql_string.h:485(String::append(char))[0x56147b882b2e]
 
sql/sql_show.cc:1986(show_create_table(THD*, TABLE_LIST*, String*, Table_specification_st*, enum_with_db_name))[0x56147b885b33]
 
sql/sql_parse.cc:4237(mysql_execute_command(THD*))[0x56147b88676b]
 
sql/sql_parse.cc:1815(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x56147b94dd3a]
 
sql/sql_parse.cc:1371(do_command(THD*))[0x56147b94de5d]
 
/lib64/libpthread.so.0(+0x7e25)[0x7f7c3580be25]
 
/lib64/libc.so.6(clone+0x6d)[0x7f7c33de334d]
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Apr 26 17:19:50 CentOS-Test kernel: mysqld[28388]: segfault at 1f8 ip 000056147ba7e029 sp 00007f7c180451d0 error 4 in mysqld[56147b39d000+111d000]
 
Query (0x7f787c00f040): show create table `bugTest`.`jsonDateCrash`
 
Connection ID (thread ID): 11
 
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on


180426 17:22:52 [ERROR] 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.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
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.
 
Server version: 10.2.14-MariaDB
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=2
 
max_threads=153
 
thread_count=9
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467245 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f94a80009a8
 
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 = 0x7f98300d9d70 thread_stack 0x49000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x557f7516acce]
 
/usr/sbin/mysqld(handle_fatal_signal+0x355)[0x557f74bf6605]
 
/lib64/libpthread.so.0(+0xf5e0)[0x7f984a8115e0]
 
/usr/sbin/mysqld(_ZN16Item_func_or_sum4walkEM4ItemFbPvEbS1_+0x60)[0x557f74a23eb0]
 
/usr/sbin/mysqld(_ZN16Item_func_or_sum4walkEM4ItemFbPvEbS1_+0x67)[0x557f74a23eb7]
 
/usr/sbin/mysqld(_ZN16Item_func_or_sum4walkEM4ItemFbPvEbS1_+0x67)[0x557f74a23eb7]
 
/usr/sbin/mysqld(_Z21fix_session_vcol_exprP3THDP19Virtual_column_info+0x3c)[0x557f74b053ec]
 
/usr/sbin/mysqld(_Z11lock_tablesP3THDP10TABLE_LISTjj+0x3ff)[0x557f74a1d08f]
 
/usr/sbin/mysqld(_Z20open_and_lock_tablesP3THDRK14DDL_options_stP10TABLE_LISTbjP19Prelocking_strategy+0x8a)[0x557f74a1e49a]
 
/usr/sbin/mysqld(_Z12mysql_insertP3THDP10TABLE_LISTR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb+0xfa)[0x557f74a4afca]
 
sql/item.h:3907(Item_args::walk_args(bool (Item::*)(void*), bool, void*))[0x557f74a61354]
 
sql/item.h:3907(Item_args::walk_args(bool (Item::*)(void*), bool, void*))[0x557f74a68b2e]
 
sql/table.cc:2773(fix_session_vcol_expr(THD*, Virtual_column_info*))[0x557f74a6bb33]
 
sql/sql_base.cc:4819(lock_tables(THD*, TABLE_LIST*, unsigned int, unsigned int))[0x557f74a6c76b]
 
sql/sql_insert.cc:753(mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool))[0x557f74b33d3a]
 
sql/sql_parse.cc:4430(mysql_execute_command(THD*))[0x557f74b33e5d]
 
/lib64/libpthread.so.0(+0x7e25)[0x7f984a809e25]
 
/lib64/libc.so.6(clone+0x6d)[0x7f9848de134d]
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Apr 26 17:22:59 CentOS-Test kernel: mysqld[28624]: segfault at 2d8 ip 0000557f74a23eb0 sp 00007f98300d7540 error 4 in mysqld[557f74583000+111d000]
 
Query (0x7f94a8010350): INSERT INTO `jsonDateCrash` (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', '{\"Thursday\":100}', '0')
 
Connection ID (thread ID): 9
 
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on

There are also some useless (empty) stack traces.

Comment by Elena Stepanova [ 2018-05-31 ]

Thanks for the report and provided data. At least some of the crashes are quite easily reproducible:

--source include/have_innodb.inc
 
 
 
SET NAMES utf8;
 
CREATE TABLE `jsonDateCrash` (
 
  `supplierId` SMALLINT(5) UNSIGNED NOT NULL AUTO_INCREMENT,
 
  `supplierName` VARCHAR(128) NOT NULL,
 
  `supplierCaps` TEXT NOT NULL,
 
  `supplierSentToday` SMALLINT(6) NOT NULL,
 
  `supplierCapToday` SMALLINT(6) GENERATED ALWAYS AS (COALESCE(json_value(`supplierCaps`,CONCAT('$.',DAYNAME("2018-04-26"))),0)) VIRTUAL,
 
  PRIMARY KEY (`supplierId`),
 
  CONSTRAINT `capsIsValidJson` CHECK (JSON_VALID(`supplierCaps`))
 
) ENGINE=INNODB AUTO_INCREMENT=2 DEFAULT CHARSET=latin1;
 
 
 
INSERT INTO `jsonDateCrash` (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', '{\"Thursday\":100}', '0');
 
INSERT INTO `jsonDateCrash` (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', '{\"Thursday\":100}', '0');
 
 
 
# Cleanup
 
DROP TABLE `jsonDateCrash`;

10.2 b8fdd56a4d

 
#3  <signal handler called>
 
#4  0x000055dd5fed3a54 in Item_args::walk_args (this=0x7f9c6814ad00, processor=&virtual table offset 776, walk_subquery=false, arg=0x0) at /data/src/10.2/sql/item.h:3908
 
#5  0x000055dd5fed3e83 in Item_func_or_sum::walk (this=0x7f9c6814ac78, processor=&virtual table offset 776, walk_subquery=false, arg=0x0) at /data/src/10.2/sql/item.h:4193
 
#6  0x000055dd5fed3a7d in Item_args::walk_args (this=0x7f9c6814adf0, processor=&virtual table offset 776, walk_subquery=false, arg=0x0) at /data/src/10.2/sql/item.h:3908
 
#7  0x000055dd5fed3e83 in Item_func_or_sum::walk (this=0x7f9c6814ad68, processor=&virtual table offset 776, walk_subquery=false, arg=0x0) at /data/src/10.2/sql/item.h:4193
 
#8  0x000055dd5fed3a7d in Item_args::walk_args (this=0x7f9c6814b530, processor=&virtual table offset 776, walk_subquery=false, arg=0x0) at /data/src/10.2/sql/item.h:3908
 
#9  0x000055dd5fed3e83 in Item_func_or_sum::walk (this=0x7f9c6814b4a8, processor=&virtual table offset 776, walk_subquery=false, arg=0x0) at /data/src/10.2/sql/item.h:4193
 
#10 0x000055dd60038060 in fix_session_vcol_expr (thd=0x7f9c68000b00, vcol=0x7f9c6814b388) at /data/src/10.2/sql/table.cc:2771
 
#11 0x000055dd5fec8a80 in fix_all_session_vcol_exprs (thd=0x7f9c68000b00, tables=0x7f9c68012608) at /data/src/10.2/sql/sql_base.cc:4843
 
#12 0x000055dd5fec91b1 in lock_tables (thd=0x7f9c68000b00, tables=0x7f9c68012608, count=1, flags=0) at /data/src/10.2/sql/sql_base.cc:5026
 
#13 0x000055dd5fec860a in open_and_lock_tables (thd=0x7f9c68000b00, options=..., tables=0x7f9c68012608, derived=true, flags=0, prelocking_strategy=0x7f9cc405c320) at /data/src/10.2/sql/sql_base.cc:4715
 
#14 0x000055dd5febb99b in open_and_lock_tables (thd=0x7f9c68000b00, tables=0x7f9c68012608, derived=true, flags=0) at /data/src/10.2/sql/sql_base.h:501
 
#15 0x000055dd5ff103b6 in mysql_insert (thd=0x7f9c68000b00, table_list=0x7f9c68012608, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at /data/src/10.2/sql/sql_insert.cc:758
 
#16 0x000055dd5ff38a63 in mysql_execute_command (thd=0x7f9c68000b00) at /data/src/10.2/sql/sql_parse.cc:4435
 
#17 0x000055dd5ff43e0f in mysql_parse (thd=0x7f9c68000b00, rawbuf=0x7f9c68012448 "INSERT INTO `jsonDateCrash` (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', '{\\\"Thursday\\\":100}', '0')", length=128, parser_state=0x7f9cc405d200, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:8002
 
#18 0x000055dd5ff318b8 in dispatch_command (command=COM_QUERY, thd=0x7f9c68000b00, packet=0x7f9c680088a1 "INSERT INTO `jsonDateCrash` (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', '{\\\"Thursday\\\":100}', '0')", packet_length=128, is_com_multi=false, is_next_command=false) at /data/src/10.2/sql/sql_parse.cc:1821
 
#19 0x000055dd5ff3021b in do_command (thd=0x7f9c68000b00) at /data/src/10.2/sql/sql_parse.cc:1375
 
#20 0x000055dd6007f930 in do_handle_one_connection (connect=0x55dd62b54230) at /data/src/10.2/sql/sql_connect.cc:1335
 
#21 0x000055dd6007f6bd in handle_one_connection (arg=0x55dd62b54230) at /data/src/10.2/sql/sql_connect.cc:1241
 
#22 0x000055dd604a0b78 in pfs_spawn_thread (arg=0x55dd62a9f7a0) at /data/src/10.2/storage/perfschema/pfs.cc:1862
 
#23 0x00007f9ccbaa2494 in start_thread (arg=0x7f9cc405e700) at pthread_create.c:333
 
#24 0x00007f9cc9e8893f in clone () from /lib/x86_64-linux-gnu/libc.so.6

10.2 ASAN 13c241c64f4

 
==20156==ERROR: AddressSanitizer: use-after-poison on address 0x62b000001198 at pc 0x55a53524448b bp 0x7f73d8197190 sp 0x7f73d8197188
 
READ of size 8 at 0x62b000001198 thread T28
 
    #0 0x55a53524448a in Item_args::walk_args(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:3908
 
    #1 0x55a535244fe2 in Item_func_or_sum::walk(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:4193
 
    #2 0x55a535244504 in Item_args::walk_args(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:3908
 
    #3 0x55a535244fe2 in Item_func_or_sum::walk(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:4193
 
    #4 0x55a535244504 in Item_args::walk_args(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:3908
 
    #5 0x55a535244fe2 in Item_func_or_sum::walk(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:4193
 
    #6 0x55a5355b65c5 in fix_session_vcol_expr(THD*, Virtual_column_info*) /data/src/10.2/sql/table.cc:2771
 
    #7 0x55a53522a55f in fix_all_session_vcol_exprs /data/src/10.2/sql/sql_base.cc:4843
 
    #8 0x55a53522b716 in lock_tables(THD*, TABLE_LIST*, unsigned int, unsigned int) /data/src/10.2/sql/sql_base.cc:5026
 
    #9 0x55a535229944 in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /data/src/10.2/sql/sql_base.cc:4715
 
    #10 0x55a53520b62c in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /data/src/10.2/sql/sql_base.h:501
 
    #11 0x55a5352d26c8 in mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool) /data/src/10.2/sql/sql_insert.cc:758
 
    #12 0x55a53533652e in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:4435
 
    #13 0x55a53534d834 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8002
 
    #14 0x55a5353283a4 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1821
 
    #15 0x55a535325448 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1375
 
    #16 0x55a5356626af in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335
 
    #17 0x55a5356620c4 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #18 0x55a53607113b in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
 
    #19 0x7f73e8bff493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #20 0x7f73e6fe593e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
 
 
0x62b000001198 is located 3992 bytes inside of 24716-byte region [0x62b000000200,0x62b00000628c)
 
allocated by thread T28 here:
 
    #0 0x7f73e8e6973f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
 
    #1 0x55a536990d61 in sf_malloc /data/src/10.2/mysys/safemalloc.c:118
 
    #2 0x55a53695ffca in my_malloc /data/src/10.2/mysys/my_malloc.c:101
 
    #3 0x55a53694061d in reset_root_defaults /data/src/10.2/mysys/my_alloc.c:146
 
    #4 0x55a53527bc07 in THD::init_for_queries() /data/src/10.2/sql/sql_class.cc:1403
 
    #5 0x55a535661a81 in prepare_new_connection_state(THD*) /data/src/10.2/sql/sql_connect.cc:1172
 
    #6 0x55a53566210a in thd_prepare_connection(THD*) /data/src/10.2/sql/sql_connect.cc:1256
 
    #7 0x55a535662685 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1326
 
    #8 0x55a5356620c4 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #9 0x55a53607113b in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
 
 
 
Thread T28 created by T0 here:
 
    #0 0x7f73e8e38bba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
 
    #1 0x55a536071703 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1912
 
    #2 0x55a53512244e in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1239
 
    #3 0x55a535137339 in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6451
 
    #4 0x55a535137a3e in create_new_thread /data/src/10.2/sql/mysqld.cc:6521
 
    #5 0x55a535138a4f in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6796
 
    #6 0x55a53513688e in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6070
 
    #7 0x55a5351207ef in main /data/src/10.2/sql/main.cc:25
 
    #8 0x7f73e6f1d2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
 
 
SUMMARY: AddressSanitizer: use-after-poison /data/src/10.2/sql/item.h:3908 Item_args::walk_args(bool (Item::*)(void*), bool, void*)
 
Shadow bytes around the buggy address:
 
  0x0c567fff81e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff81f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff8200: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff8210: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff8220: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
=>0x0c567fff8230: 00 00 00[f7]f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8240: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8250: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8260: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8270: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8280: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Heap right redzone:      fb
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack partial redzone:   f4
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Contiguous container OOB:fc
 
  ASan internal:           fe
 
==20156==ABORTING

Same thing, but without any JSON:

SET NAMES utf8;
 
CREATE TABLE t1 (
 
  `supplierId` SMALLINT(5) UNSIGNED NOT NULL AUTO_INCREMENT,
 
  `supplierName` VARCHAR(128) NOT NULL,
 
  `supplierCaps` TEXT NOT NULL,
 
  `supplierSentToday` SMALLINT(6) NOT NULL,
 
  `supplierCapToday` SMALLINT(6) GENERATED ALWAYS AS (CONCAT('x',DAYNAME("2018-04-26"))) VIRTUAL,
 
  PRIMARY KEY (`supplierId`)
 
);
 
 
 
INSERT INTO t1 (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', 'foo', '0');
 
INSERT INTO t1 (`supplierName`, `supplierCaps`, `supplierSentToday`) VALUES ('TFLI Ltd', 'bar', '0');
 
 
 
# Cleanup
 
DROP TABLE t1;

10.2 ASAN 13c241c64f4

 
==21174==ERROR: AddressSanitizer: use-after-poison on address 0x62b000001140 at pc 0x55f09621f48b bp 0x7fcdc05722b0 sp 0x7fcdc05722a8
 
READ of size 8 at 0x62b000001140 thread T6
 
    #0 0x55f09621f48a in Item_args::walk_args(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:3908
 
    #1 0x55f09621ffe2 in Item_func_or_sum::walk(bool (Item::*)(void*), bool, void*) /data/src/10.2/sql/item.h:4193
 
    #2 0x55f0965915c5 in fix_session_vcol_expr(THD*, Virtual_column_info*) /data/src/10.2/sql/table.cc:2771
 
    #3 0x55f09620555f in fix_all_session_vcol_exprs /data/src/10.2/sql/sql_base.cc:4843
 
    #4 0x55f096206716 in lock_tables(THD*, TABLE_LIST*, unsigned int, unsigned int) /data/src/10.2/sql/sql_base.cc:5026
 
    #5 0x55f096204944 in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) /data/src/10.2/sql/sql_base.cc:4715
 
    #6 0x55f0961e662c in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) /data/src/10.2/sql/sql_base.h:501
 
    #7 0x55f0962ad6c8 in mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool) /data/src/10.2/sql/sql_insert.cc:758
 
    #8 0x55f09631152e in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:4435
 
    #9 0x55f096328834 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8002
 
    #10 0x55f0963033a4 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1821
 
    #11 0x55f096300448 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1375
 
    #12 0x55f09663d6af in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335
 
    #13 0x55f09663d0c4 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #14 0x55f09704c13b in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
 
    #15 0x7fcdccd47493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #16 0x7fcdcb12d93e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
 
 
0x62b000001140 is located 3904 bytes inside of 24716-byte region [0x62b000000200,0x62b00000628c)
 
allocated by thread T6 here:
 
    #0 0x7fcdccfb173f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
 
    #1 0x55f09796bd61 in sf_malloc /data/src/10.2/mysys/safemalloc.c:118
 
    #2 0x55f09793afca in my_malloc /data/src/10.2/mysys/my_malloc.c:101
 
    #3 0x55f09791b61d in reset_root_defaults /data/src/10.2/mysys/my_alloc.c:146
 
    #4 0x55f096256c07 in THD::init_for_queries() /data/src/10.2/sql/sql_class.cc:1403
 
    #5 0x55f09663ca81 in prepare_new_connection_state(THD*) /data/src/10.2/sql/sql_connect.cc:1172
 
    #6 0x55f09663d10a in thd_prepare_connection(THD*) /data/src/10.2/sql/sql_connect.cc:1256
 
    #7 0x55f09663d685 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1326
 
    #8 0x55f09663d0c4 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
 
    #9 0x55f09704c13b in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
 
 
 
Thread T6 created by T0 here:
 
    #0 0x7fcdccf80bba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
 
    #1 0x55f09704c703 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1912
 
    #2 0x55f0960fd44e in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1239
 
    #3 0x55f096112339 in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6451
 
    #4 0x55f096112a3e in create_new_thread /data/src/10.2/sql/mysqld.cc:6521
 
    #5 0x55f096113a4f in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6796
 
    #6 0x55f09611188e in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6070
 
    #7 0x55f0960fb7ef in main /data/src/10.2/sql/main.cc:25
 
    #8 0x7fcdcb0652b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
 
 
SUMMARY: AddressSanitizer: use-after-poison /data/src/10.2/sql/item.h:3908 Item_args::walk_args(bool (Item::*)(void*), bool, void*)
 
Shadow bytes around the buggy address:
 
  0x0c567fff81d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff81e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff81f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff8200: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c567fff8210: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
=>0x0c567fff8220: 00 00 00 00 00 00 00 00[f7]f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8230: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8240: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8250: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8260: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c567fff8270: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
Shadow byte legend (one shadow byte represents 8 application bytes):
 
  Addressable:           00
 
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
 
  Heap right redzone:      fb
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack partial redzone:   f4
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Contiguous container OOB:fc
 
  ASan internal:           fe
 
==21174==ABORTING

Comment by Alice Sherepa [ 2018-11-09 ]

After fixing this bug, please check also the test case from MDEV-17653, MDEV-17986, MDEV-19788

Comment by Elena Stepanova [ 2019-08-19 ]

Importantly, also check the test case from MDEV-20380, as it produces the identical stack trace without having any virtual columns. If the patch doesn't fix the problem in MDEV-20380, please re-open it.

Comment by Alexander Barkov [ 2019-09-11 ]

Also repeatable with a DEFAULT expression (instead of a vcol expression):

SET NAMES latin1;
 
CREATE OR REPLACE TABLE t1 (
 
  a CHAR(10) DEFAULT (CONCAT('',DAYNAME('2018-04-26')))
 
) COLLATE utf8_bin;
 
INSERT INTO t1 VALUES (DEFAULT);
 
INSERT INTO t1 VALUES (DEFAULT);
 
DROP TABLE t1;

Comment by Alexander Barkov [ 2019-09-11 ]

This patch https://github.com/MariaDB/server/compare/bb-10.5-nikita-expr-arena fixes the crash, however introduces a memory leak with PS in this scenario:

SET NAMES latin1;
 
CREATE OR REPLACE TABLE t1 (
 
  a CHAR(10) DEFAULT (CONCAT('',DAYNAME('2018-04-26')))
 
) COLLATE utf8_bin;
 
PREPARE stmt FROM 'INSERT INTO t1 VALUES (DEFAULT)';
 
EXECUTE stmt;
 
EXECUTE stmt;
 
EXECUTE stmt;
 
FLUSH TABLES:

Every EXECUTE stmt statement creates its own Item_func_conv_charset and they all get stuck in TABLE::expr_arena until the table is completely closed, e.g. by a FLUSH TABLES statement.

This shell script demonstrates the problem:

#!/bin/bash
 
(
 
echo "SET NAMES latin1;"
 
echo "CREATE OR REPLACE TABLE t1 ("
 
echo "  a CHAR(10) DEFAULT (CONCAT('',DAYNAME('2018-04-26')))"
 
echo ") COLLATE utf8_bin;"
 
echo "flush tables;"
 
echo "SHOW GLOBAL STATUS LIKE 'Memory_used';"
 
 
 
echo "PREPARE stmt FROM 'INSERT INTO t1 VALUES (DEFAULT)';"
 
for i in {1..10}
 
do
 
   echo "EXECUTE stmt;"
 
   echo "SHOW GLOBAL STATUS LIKE 'Memory_used';"
 
done
 
echo "flush tables;"
 
echo "SHOW GLOBAL STATUS LIKE 'Memory_used';"
 
) | mysql --socket=/tmp/mysql.sock -uroot test


Variable_name	Value
 
Memory_used	273868240
 
Variable_name	Value
 
Memory_used	273902792
 
Variable_name	Value
 
Memory_used	273903816
 
Variable_name	Value
 
Memory_used	273904840
 
Variable_name	Value
 
Memory_used	273905864
 
Variable_name	Value
 
Memory_used	273906888
 
Variable_name	Value
 
Memory_used	273907912
 
Variable_name	Value
 
Memory_used	273908936
 
Variable_name	Value
 
Memory_used	273909960
 
Variable_name	Value
 
Memory_used	273910984
 
Variable_name	Value
 
Memory_used	273912008
 
Variable_name	Value
 
Memory_used	273891104

Notice, global memory grows on every iteration and releases only after FLUSH (the last Memory_used value).

Comment by Nikita Malyavin [ 2019-09-11 ]

barthank you! Will go through soon

Comment by Alexander Barkov [ 2019-09-13 ]

nikitamalyavin, please also add a test for expressions in DEFAULT clause (instead of virtual columns). See above. Thanks.

Comment by Nikita Malyavin [ 2019-09-27 ]

bar the commit has following:

--echo # (duplicate) MDEV-20380 Server crash during update
 
CREATE TABLE gafld (
 
  nuigafld INTEGER NOT NULL,
 
  ucrgafld VARCHAR(30) COLLATE UTF8_BIN NOT NULL
 
           DEFAULT SUBSTRING_INDEX(USER(),'@',1)
 
);
 
EXPLAIN UPDATE gafld SET nuigafld = 0 WHERE nuigafld = 10;
 
EXPLAIN UPDATE gafld SET nuigafld = 0 WHERE nuigafld = 10;
 
DROP TABLE gafld;

it uses DEFAULT expression

and another one has DEFAULT (REVERSE(SUBSTRING_INDEX(REVERSE(user()), '@', 1)))

Comment by Nikita Malyavin [ 2019-10-03 ]

bar I have managed to make the leak fix, it's here https://github.com/MariaDB/server/commit/6621be137f1807303c967329f536231a510ee3c0

Comment by Oleksandr Byelkin [ 2019-10-09 ]

IMHO all approach to set arena before fixing (i.e. prepare phase is incorrect)

All works like this:

  1. set arena to some permanent (statement/table etc.)
  2. make parse/allocate
  3. reset arena to run-time arena
  4. make prepare
  5. make execute and so on...

So here it should be the same.

When items during prepare need to make some permanent changes they refer thd->stmt_arena, maybe you should assign it, but also there are other tests (leke if it is prepared statements) so it is better to check all such cases.

Also I think Field::set_default() arena switching is a memory leak.

Comment by Oleksandr Byelkin [ 2020-07-21 ]

OK to push

Comment by Aleksey Midenkov [ 2021-05-27 ]

nikitamalyavin you made expr_arena usage in fix_all_session_vcol_exprs(). Did you care that it is memory leak until table flush? I'm just preoccupied with similar problem of MDEV-25672 but I don't like continuous allocations on TABLE::mem_root.

The proper fix is to make expr_arena a separate mem_root and reallocate it each time of expr refresh. But this is a lot of various problems like delayed insert, items clone (with String::copy() for all properties), cached_table cleanup, proper name resolution context and what else (no one can tell the complete list).

Generated at Thu Feb 08 08:25:54 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.