[MDEV-17869] AddressSanitizer: use-after-poison in Item_change_list::rollback_item_tree_changes Created: 2018-11-29  Updated: 2023-03-29  Resolved: 2023-01-09

Status: Closed
Project: MariaDB Server
Component/s: Prepared Statements, Stored routines
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10
Fix Version/s: 10.11.2, 10.4.28, 10.5.19, 10.6.12, 10.7.8, 10.8.7, 10.9.5, 10.10.3

Type: Bug Priority: Critical
Reporter: Alice Sherepa Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Duplicate
duplicates MDEV-18744 ASAN use-after-poison in Item_change_... Closed
Relates
relates to MDEV-15746 ASAN heap-use-after-free in Item_chan... Closed
relates to MDEV-30957 AddressSanitizer: use-after-poison in... Open
relates to MDEV-29895 prepared view crash server (unit.conc... Closed

 Description   

CREATE TABLE t1 ( pk int, v1 varchar(1)) ENGINE=MyISAM;
INSERT INTO t1 VALUES (1,'v'),(2,'v'),(3,'c');
 
CREATE TABLE t2 ( pk int, v1 varchar(1)) ENGINE=MyISAM;
INSERT INTO t2 VALUES (1,'x');
 
CREATE TABLE t3 ( pk int, i1 int, v1 varchar(1)) ENGINE=MyISAM;
INSERT INTO t3 VALUES (10,8,9);
 
execute immediate 'SELECT STRAIGHT_JOIN 1 FROM (t1 JOIN t2 ON (t1.v1 = t2.v1))
WHERE (3, 6) IN (SELECT tC.pk,  t3.i1 FROM (t3 JOIN t1 AS tC ON (tC.v1 = t3.v1)) HAVING tC.pk > 1 );';

built as cmake . -DPLUGIN_TOKUDB=NO -DCMAKE_BUILD_TYPE=Debug -DWITH_ASAN=ON :

10.4 17e371fffe3d0a2593

==2451==ERROR: AddressSanitizer: use-after-poison on address 0x62b000082e88 at pc 0x55c8f38b19d5 bp 0x7fb0a6f24090 sp 0x7fb0a6f24080
WRITE of size 8 at 0x62b000082e88 thread T27
    #0 0x55c8f38b19d4 in Item_change_list::rollback_item_tree_changes() /git/10.4/sql/sql_class.cc:2824
    #1 0x55c8f39fb580 in Prepared_statement::cleanup_stmt() /git/10.4/sql/sql_prepare.cc:3854
    #2 0x55c8f3a02360 in Prepared_statement::execute(String*, bool) /git/10.4/sql/sql_prepare.cc:4818
    #3 0x55c8f39fd82a in Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) /git/10.4/sql/sql_prepare.cc:4218
    #4 0x55c8f3a03014 in Prepared_statement::execute_immediate(char const*, unsigned int) /git/10.4/sql/sql_prepare.cc:4914
    #5 0x55c8f39f5c1f in mysql_sql_stmt_execute_immediate(THD*) /git/10.4/sql/sql_prepare.cc:2894
    #6 0x55c8f39a1b50 in mysql_execute_command(THD*) /git/10.4/sql/sql_parse.cc:3780
    #7 0x55c8f39bb97e in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /git/10.4/sql/sql_parse.cc:8092
    #8 0x55c8f399682a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /git/10.4/sql/sql_parse.cc:1851
    #9 0x55c8f39939c2 in do_command(THD*) /git/10.4/sql/sql_parse.cc:1396
    #10 0x55c8f3ceb128 in do_handle_one_connection(CONNECT*) /git/10.4/sql/sql_connect.cc:1402
    #11 0x55c8f3ceab05 in handle_one_connection /git/10.4/sql/sql_connect.cc:1308
    #12 0x55c8f5029ca5 in pfs_spawn_thread /git/10.4/storage/perfschema/pfs.cc:1862
    #13 0x7fb0be4726b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
    #14 0x7fb0bd90741c in clone (/lib/x86_64-linux-gnu/libc.so.6+0x10741c)
 
0x62b000082e88 is located 19592 bytes inside of 24716-byte region [0x62b00007e200,0x62b00008428c)
allocated by thread T27 here:
    #0 0x7fb0bf6d1602 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x98602)
    #1 0x55c8f5169fe5 in sf_malloc /git/10.4/mysys/safemalloc.c:118
    #2 0x55c8f513c188 in my_malloc /git/10.4/mysys/my_malloc.c:101
    #3 0x55c8f511c3e3 in reset_root_defaults /git/10.4/mysys/my_alloc.c:151
    #4 0x55c8f38a6f83 in THD::init_for_queries() /git/10.4/sql/sql_class.cc:1337
    #5 0x55c8f3cea4c2 in prepare_new_connection_state(THD*) /git/10.4/sql/sql_connect.cc:1239
    #6 0x55c8f3ceab4b in thd_prepare_connection(THD*) /git/10.4/sql/sql_connect.cc:1323
    #7 0x55c8f3ceb0f0 in do_handle_one_connection(CONNECT*) /git/10.4/sql/sql_connect.cc:1393
    #8 0x55c8f3ceab05 in handle_one_connection /git/10.4/sql/sql_connect.cc:1308
    #9 0x55c8f5029ca5 in pfs_spawn_thread /git/10.4/storage/perfschema/pfs.cc:1862
    #10 0x7fb0be4726b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
 
Thread T27 created by T0 here:
    #0 0x7fb0bf66f253 in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x36253)
    #1 0x55c8f502a092 in spawn_thread_v1 /git/10.4/storage/perfschema/pfs.cc:1912
    #2 0x55c8f370ab14 in inline_mysql_thread_create /git/10.4/include/mysql/psi/mysql_thread.h:1268
    #3 0x55c8f371fcf7 in create_thread_to_handle_connection(CONNECT*) /git/10.4/sql/mysqld.cc:6330
    #4 0x55c8f37203f7 in create_new_thread(CONNECT*) /git/10.4/sql/mysqld.cc:6400
    #5 0x55c8f3720782 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /git/10.4/sql/mysqld.cc:6517
    #6 0x55c8f37213ff in handle_connections_sockets() /git/10.4/sql/mysqld.cc:6682
    #7 0x55c8f371f1b7 in mysqld_main(int, char**) /git/10.4/sql/mysqld.cc:5952
    #8 0x55c8f370923f in main /git/10.4/sql/main.cc:25
    #9 0x7fb0bd82082f in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2082f)
 
SUMMARY: AddressSanitizer: use-after-poison /git/10.4/sql/sql_class.cc:2824 Item_change_list::rollback_item_tree_changes()
Shadow bytes around the buggy address:
  0x0c5680008580: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c5680008590: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c56800085a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c56800085b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c56800085c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c56800085d0: f7[f7]00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c56800085e0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c56800085f0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c5680008600: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c5680008610: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c5680008620: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
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
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
==2451==ABORTING
----------SERVER LOG END-------------



 Comments   
Comment by Alice Sherepa [ 2019-02-21 ]

Also with sp:

  CREATE TABLE t1 ( pk int, v1 varchar(1)) ENGINE=MyISAM;
INSERT INTO t1 VALUES (1,'v'),(2,'v'),(3,'c');
 
CREATE TABLE t2 ( pk int, v1 varchar(1)) ENGINE=MyISAM;
INSERT INTO t2 VALUES (1,'x');
 
CREATE TABLE t3 ( pk int, i1 int, v1 varchar(1)) ENGINE=MyISAM;
INSERT INTO t3 VALUES (10,8,9);
 
create procedure sp ()  
    SELECT STRAIGHT_JOIN 1 FROM (t1 JOIN t2 ON (t1.v1 = t2.v1))
WHERE (3, 6) IN (SELECT tC.pk,  t3.i1 FROM (t3 JOIN t1 AS tC ON (tC.v1 = t3.v1)) HAVING tC.pk > 1 );
 
call sp();

10.2 945c748adc5475e59e5d224

    #0 0x55ad3bf6f69c in Item_change_list::rollback_item_tree_changes() /10.2/sql/sql_class.cc:2597
    #1 0x55ad3c972ce1 in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /10.2/sql/sp_head.cc:3063
    #2 0x55ad3c9734d8 in sp_instr_stmt::execute(THD*, unsigned int*) /10.2/sql/sp_head.cc:3162
    #3 0x55ad3c968e79 in sp_head::execute(THD*, bool) /10.2/sql/sp_head.cc:1327
    #4 0x55ad3c96ccd0 in sp_head::execute_procedure(THD*, List<Item>*) /10.2/sql/sp_head.cc:2116
    #5 0x55ad3c014458 in do_execute_sp /10.2/sql/sql_parse.cc:2918
    #6 0x55ad3c02620d in mysql_execute_command(THD*) /10.2/sql/sql_parse.cc:5831
    #7 0x55ad3c0334f0 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /10.2/sql/sql_parse.cc:8018
    #8 0x55ad3c00e9dc in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /10.2/sql/sql_parse.cc:1829
    #9 0x55ad3c00bb0b in do_command(THD*) /10.2/sql/sql_parse.cc:1379
    #10 0x55ad3c333ff6 in do_handle_one_connection(CONNECT*) /10.2/sql/sql_connect.cc:1336
    #11 0x55ad3c3339fe in handle_one_connection /10.2/sql/sql_connect.cc:1242
    #12 0x55ad3d4e2dbd in pfs_spawn_thread /10.2/storage/perfschema/pfs.cc:1862
    #13 0x7f20a44bf6b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
    #14 0x7f20a395441c in clone (/lib/x86_64-linux-gnu/libc.so.6+0x10741c)
 
    

Comment by Alice Sherepa [ 2019-02-26 ]

The test case from MDEV-18744 (only fails on 10.4):

CREATE TABLE t1 (a INT) ENGINE=MyISAM;
INSERT INTO t1 VALUES (1),(2);
 
CREATE TABLE t2 (b INT) ENGINE=MyISAM;
INSERT INTO t2 VALUES (3);
 
PREPARE stmt FROM "SELECT * FROM t1 JOIN t2 HAVING NOT (t1.a IS NULL AND t2.b <> 1)";
EXECUTE stmt;
 
# Cleanup
DEALLOCATE PREPARE stmt;
DROP TABLE t1, t2;

Comment by Alice Sherepa [ 2020-11-25 ]

./mtr main.opt_tvc --ps-protocol

10.5

 
CURRENT_TEST: main.opt_tvc
mysqltest: At line 77: query '$query' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
3	DERIVED	NULL	NULL	NULL	NULL	NULL	NULL	NULL	NULL	No tables used
Warnings:
Note	1003	/* select#1 */ select `test`.`t1`.`a` AS `a`,`test`.`t1`.`b` AS `b` from `test`.`t1` semi join ((values (1),(2)) `tvc_0`) where 1
explain extended select * from t1
where a in
(
select *
from (values (1),(2)) as tvc_0
);
id	select_type	table	type	possible_keys	key	key_len	ref	rows	filtered	Extra
1	PRIMARY	t1	ALL	NULL	NULL	NULL	NULL	6	100.00	
1	PRIMARY	<subquery2>	eq_ref	distinct_key	distinct_key	4	func	1	100.00	
2	MATERIALIZED	<derived3>	ALL	NULL	NULL	NULL	NULL	2	100.00	
3	DERIVED	NULL	NULL	NULL	NULL	NULL	NULL	NULL	NULL	No tables used
Warnings:
Note	1003	/* select#1 */ select `test`.`t1`.`a` AS `a`,`test`.`t1`.`b` AS `b` from `test`.`t1` semi join ((values (1),(2)) `tvc_0`) where 1
# AND-condition with IN-predicates in WHERE-part
select * from t1
where a in (1,2) and
b in (1,5);
 
More results from queries before failure can be found in /mysql-test/var/log/opt_tvc.log
 
 
Server [mysqld.1 - pid: 266702, winpid: 266702, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2020-11-25 14:35:29 0 [Note] /sql/mariadbd (mysqld 10.5.9-MariaDB-debug-log) starting as process 266703 ...
2020-11-25 14:35:29 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
2020-11-25 14:35:29 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2020-11-25 14:35:29 0 [Warning] setrlimit could not change the size of core files to 'infinity';  We may not be able to generate a core file on signals
2020-11-25 14:35:29 0 [Note] Plugin 'partition' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'CONNECT' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'InnoDB' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_TRX' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_METRICS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_CMP' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_LOCKS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'user_variables' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
2020-11-25 14:35:29 0 [Note] Plugin 'unix_socket' is disabled.
2020-11-25 14:35:29 0 [Warning] /sql/mariadbd: unknown option '--loose-pam-debug'
2020-11-25 14:35:29 0 [Warning] /sql/mariadbd: unknown option '--loose-aria'
2020-11-25 14:35:29 0 [Note] Server socket created on IP: '127.0.0.1'.
2020-11-25 14:35:29 0 [Note] Reading of all Master_info entries succeeded
2020-11-25 14:35:29 0 [Note] Added new Master_info '' to hash table
2020-11-25 14:35:29 0 [Note] /sql/mariadbd: ready for connections.
Version: '10.5.9-MariaDB-debug-log'  socket: '/mysql-test/var/tmp/mysqld.1.sock'  port: 16000  Source distribution
=================================================================
==266703==ERROR: AddressSanitizer: use-after-poison on address 0x62b0000383f0 at pc 0x562cfd62d214 bp 0x7f7535510c40 sp 0x7f7535510c30
WRITE of size 8 at 0x62b0000383f0 thread T5
    #0 0x562cfd62d213 in Item_change_list::rollback_item_tree_changes() /src/sql/sql_class.cc:2921
    #1 0x562cfd7be31a in Prepared_statement::cleanup_stmt() /src/sql/sql_prepare.cc:4090
    #2 0x562cfd7c5ac7 in Prepared_statement::execute(String*, bool) /src/sql/sql_prepare.cc:5024
    #3 0x562cfd7c0caa in Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) /src/sql/sql_prepare.cc:4460
    #4 0x562cfd7ba02e in mysql_stmt_execute_common /src/sql/sql_prepare.cc:3448
    #5 0x562cfd7b921d in mysqld_stmt_execute(THD*, char*, unsigned int) /src/sql/sql_prepare.cc:3229
    #6 0x562cfd746fd2 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /src/sql/sql_parse.cc:1796
    #7 0x562cfd744071 in do_command(THD*) /src/sql/sql_parse.cc:1353
    #8 0x562cfdb8559d in do_handle_one_connection(CONNECT*, bool) /src/sql/sql_connect.cc:1410
    #9 0x562cfdb84f01 in handle_one_connection /src/sql/sql_connect.cc:1312
    #10 0x562cfe88fbc0 in pfs_spawn_thread /src/storage/perfschema/pfs.cc:2201
    #11 0x7f7540ab1608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
    #12 0x7f7540687292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
 
0x62b0000383f0 is located 496 bytes inside of 24740-byte region [0x62b000038200,0x62b00003e2a4)
allocated by thread T5 here:
    #0 0x7f75415cdbc8 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
    #1 0x562cff856f97 in sf_malloc /src/mysys/safemalloc.c:118
    #2 0x562cff82440b in my_malloc /src/mysys/my_malloc.c:88
    #3 0x562cff7ff9b0 in reset_root_defaults /src/mysys/my_alloc.c:148
    #4 0x562cfd620f62 in THD::init_for_queries() /src/sql/sql_class.cc:1409
    #5 0x562cfdb84836 in prepare_new_connection_state(THD*) /src/sql/sql_connect.cc:1240
    #6 0x562cfdb84f80 in thd_prepare_connection(THD*) /src/sql/sql_connect.cc:1333
    #7 0x562cfdb854c8 in do_handle_one_connection(CONNECT*, bool) /src/sql/sql_connect.cc:1400
    #8 0x562cfdb84f01 in handle_one_connection /src/sql/sql_connect.cc:1312
    #9 0x562cfe88fbc0 in pfs_spawn_thread /src/storage/perfschema/pfs.cc:2201
    #10 0x7f7540ab1608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
 
Thread T5 created by T0 here:
    #0 0x7f75414fa805 in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
    #1 0x562cfe88ab64 in my_thread_create /src/storage/perfschema/my_thread.h:38
    #2 0x562cfe88ffb3 in pfs_spawn_thread_v1 /src/storage/perfschema/pfs.cc:2252
    #3 0x562cfd4393ce in inline_mysql_thread_create /src/include/mysql/psi/mysql_thread.h:1323
    #4 0x562cfd44f3c1 in create_thread_to_handle_connection(CONNECT*) /src/sql/mysqld.cc:6022
    #5 0x562cfd44fa40 in create_new_thread(CONNECT*) /src/sql/mysqld.cc:6081
    #6 0x562cfd44fd9d in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /src/sql/mysqld.cc:6146
    #7 0x562cfd4509cd in handle_connections_sockets() /src/sql/mysqld.cc:6273
    #8 0x562cfd44ebbd in mysqld_main(int, char**) /src/sql/mysqld.cc:5668
    #9 0x562cfd437c6c in main /src/sql/main.cc:25
    #10 0x7f754058c0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
SUMMARY: AddressSanitizer: use-after-poison /src/sql/sql_class.cc:2921 in Item_change_list::rollback_item_tree_changes()
Shadow bytes around the buggy address:
  0x0c567ffff020: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c567ffff030: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c567ffff040: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c567ffff050: 00 00 00 00 f7 00 00 00 00 00 00 00 00 00 00 00
  0x0c567ffff060: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c567ffff070: 00 00 00 00 00 00 00 00 00 f7 00 00 f7 f7[f7]f7
  0x0c567ffff080: 00 00 00 00 00 f7 00 00 00 00 00 00 00 00 00 00
  0x0c567ffff090: 00 00 00 00 00 00 00 00 00 f7 00 f7 00 00 00 00
  0x0c567ffff0a0: 00 00 00 f7 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c567ffff0b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c567ffff0c0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
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
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==266703==ABORTING

main.having_cond_pushdown +ps-protocol:

main.having_cond_pushdown                 [ fail ]
        Test ended at 2020-11-25 14:00:36
 
CURRENT_TEST: main.having_cond_pushdown
mysqltest: At line 557: query '$query' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
          "rows": 5,
          "filtered": 100,
          "attached_condition": "(t1.a = 1 or t1.b > 10) and (t1.b < 14 or t1.b > 15)"
        }
      }
    }
  }
}
# extracted AND formula : equality in the inner AND formula
set statement optimizer_switch='condition_pushdown_from_having=off' for SELECT t1.a,t1.b,MAX(t1.c)
FROM t1
GROUP BY t1.a,t1.b
HAVING (t1.a = 1 OR t1.b > 10) AND (t1.b < 14 OR (t1.b > 15 AND t1.a = 2));
a	b	MAX(t1.c)
2	13	2
3	13	4
SELECT t1.a,t1.b,MAX(t1.c)
FROM t1
GROUP BY t1.a,t1.b
HAVING (t1.a = 1 OR t1.b > 10) AND (t1.b < 14 OR (t1.b > 15 AND t1.a = 2));
 
More results from queries before failure can be found in /git/10.5/mysql-test/var/31/log/having_cond_pushdown.log
 
 
Server [mysqld.1 - pid: 19135, winpid: 19135, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
=================================================================
==19140==ERROR: AddressSanitizer: use-after-poison on address 0x62b000039638 at pc 0x563b1816b31b bp 0x7f77b3d12d70 sp 0x7f77b3d12d68
WRITE of size 8 at 0x62b000039638 thread T5
    #0 0x563b1816b31a in Item_change_list::rollback_item_tree_changes() /git/10.5/sql/sql_class.cc:2921
    #1 0x563b182f3cbc in Prepared_statement::cleanup_stmt() /git/10.5/sql/sql_prepare.cc:4090
    #2 0x563b182fb21e in Prepared_statement::execute(String*, bool) /git/10.5/sql/sql_prepare.cc:5024
    #3 0x563b182f656b in Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) /git/10.5/sql/sql_prepare.cc:4460
    #4 0x563b182efc4c in mysql_stmt_execute_common /git/10.5/sql/sql_prepare.cc:3448
    #5 0x563b182eeeb3 in mysqld_stmt_execute(THD*, char*, unsigned int) /git/10.5/sql/sql_prepare.cc:3229
    #6 0x563b1827f28b in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /git/10.5/sql/sql_parse.cc:1796
    #7 0x563b1827c309 in do_command(THD*) /git/10.5/sql/sql_parse.cc:1353
    #8 0x563b186a99d9 in do_handle_one_connection(CONNECT*, bool) /git/10.5/sql/sql_connect.cc:1410
    #9 0x563b186a9336 in handle_one_connection /git/10.5/sql/sql_connect.cc:1312
    #10 0x563b1936b48d in pfs_spawn_thread /git/10.5/storage/perfschema/pfs.cc:2201
    #11 0x7f77bd193fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
    #12 0x7f77bc79a4ce in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf94ce)
 
0x62b000039638 is located 5176 bytes inside of 24740-byte region [0x62b000038200,0x62b00003e2a4)
allocated by thread T5 here:
    #0 0x7f77bd296330 in __interceptor_malloc (/usr/lib/x86_64-linux-gnu/libasan.so.5+0xe9330)
    #1 0x563b19fc4ec3 in sf_malloc /git/10.5/mysys/safemalloc.c:118
    #2 0x563b19f93a8b in my_malloc /git/10.5/mysys/my_malloc.c:88
    #3 0x563b19f6fdc6 in reset_root_defaults /git/10.5/mysys/my_alloc.c:148
    #4 0x563b1815f60e in THD::init_for_queries() /git/10.5/sql/sql_class.cc:1409
    #5 0x563b186a8ca1 in prepare_new_connection_state(THD*) /git/10.5/sql/sql_connect.cc:1240
    #6 0x563b186a93b1 in thd_prepare_connection(THD*) /git/10.5/sql/sql_connect.cc:1333
    #7 0x563b186a9904 in do_handle_one_connection(CONNECT*, bool) /git/10.5/sql/sql_connect.cc:1400
    #8 0x563b186a9336 in handle_one_connection /git/10.5/sql/sql_connect.cc:1312
    #9 0x563b1936b48d in pfs_spawn_thread /git/10.5/storage/perfschema/pfs.cc:2201
    #10 0x7f77bd193fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
 
Thread T5 created by T0 here:
    #0 0x7f77bd1fddb0 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
    #1 0x563b19366384 in my_thread_create /git/10.5/storage/perfschema/my_thread.h:38
    #2 0x563b1936b87c in pfs_spawn_thread_v1 /git/10.5/storage/perfschema/pfs.cc:2252
    #3 0x563b17f84f94 in inline_mysql_thread_create /git/10.5/include/mysql/psi/mysql_thread.h:1323
    #4 0x563b17f9a6a8 in create_thread_to_handle_connection(CONNECT*) /git/10.5/sql/mysqld.cc:6022
    #5 0x563b17f9ad16 in create_new_thread(CONNECT*) /git/10.5/sql/mysqld.cc:6081
    #6 0x563b17f9b07a in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /git/10.5/sql/mysqld.cc:6146
    #7 0x563b17f9bcb9 in handle_connections_sockets() /git/10.5/sql/mysqld.cc:6273
    #8 0x563b17f99f0f in mysqld_main(int, char**) /git/10.5/sql/mysqld.cc:5668
    #9 0x563b17f83774 in main /git/10.5/sql/main.cc:25
    #10 0x7f77bc6c509a in __libc_start_main ../csu/libc-start.c:308

Comment by Dmitry Shulga [ 2021-10-21 ]

Execution in PS mode of the original query listed in the bug report

SELECT STRAIGHT_JOIN 1 FROM (t1 JOIN t2 ON (t1.v1 = t2.v1)) WHERE (3, 6) IN (SELECT tC.pk,  t3.i1 FROM (t3 JOIN t1 AS tC ON (tC.v1 = t3.v1)) HAVING tC.pk > 1 )

results in ASAN error report regardless whether the query was run using the statement
EXECUTE IMMEDIATE or as a pair of statements PREPARE FROM / EXECUTE

On executing the prepared statement, constant expressions in WHERE, HAVING, ON clauses
is cached by invoking the method JOIN::cache_const_exprs(). This method compiles items
corresponding to constant condition expressions. On compilation of Item_cond the method
THD::change_item_tree is invoked to substitute old item by a new one if requested

st_select_lex::optimize_unflattened_subqueries
  JOIN::optimize
    JOIN::optimize_inner  <== at line ~1792
      JOIN::cache_const_exprs
        Item_cond::compile
          THD::change_item_tree
            Item_change_list::nocheck_register_item_tree_change

Reference to the substituted item is stored as pointer to a pointer into the class
Item_change_list. Later the method JOIN::optimize_inner invokes
Item_cond::remove_eq_conds that iterates along an arguments list, calls
item->remove_eq_conds() for every argument and remove the item in case
item->remove_eq_conds() returns nullptr. For every instance of Item class that is removed the operator delete of the class Sql_alloc is called. Implementation of the method Sql_alloc::operator delete(void *, size)
calls the macros TRASH_FREE(ptr, size) that fills the deallocated memory region with
the pattern 0x8F and calls the macros MEM_NOACCESS, that for the case when MariaDB
server built with ASAN, results in invocation of the macros ASAN_POISON_MEMORY_REGION (that is translated to the function __asan_poison_memory_region) to mark the deallocated memory as unaddressable.

st_select_lex::optimize_unflattened_subqueries
  JOIN::optimize (sql_select.cc:1127)
    JOIN::optimize_inner  <== at line ~2078
      Item_cond::remove_eq_conds (sql_select.cc:15800)
        List_iterator<Item>::remove (sql_list.h:585)
          base_list_iterator::remove (sql_list.h:511)
            base_list::remove (sql_list.h:263)
              Sql_alloc::operator delete (sql_list.h:46)

On the other hand, the pointer to a deallocated item still does exist in Item_change_list
and later when the statement

EXECUTE stmt;

is run the second time the method Prepared_statement::cleanup_stmt() is called that invokes
the thd->rollback_item_tree_changes() and for every Item stored in the internal list
the statement

  *change->place= change->old_value;

is executed including the item that has just been deallocated that leads to crash.

So, the main question here is who should remove a reference on the deallocated Item
from the Item_change_list.

Comment by Oleksandr Byelkin [ 2022-07-05 ]

It looks like this can fix the problem:

diff --git a/sql/item.h b/sql/item.h
index a6de33c0c3a..9b7551e8399 100644
--- a/sql/item.h
+++ b/sql/item.h
@@ -6904,6 +6904,7 @@ class Item_cache: public Item_fixed_hybrid,
   {
     clear();
     Item_fixed_hybrid::cleanup();
+    example= 0;
   }
   /**
      Check if saved item has a non-NULL value.

Comment by Oleksandr Byelkin [ 2022-10-28 ]

Probably has the same problem as MDEV-29895

Comment by Oleksandr Byelkin [ 2022-11-29 ]

OK to push

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