Details
- 
    
Bug
 - 
    Status: Closed (View Workflow)
 - 
    
Major
 - 
    Resolution: Fixed
 - 
    10.1(EOL), 10.2(EOL), 10.3(EOL), 10.4(EOL)
 
Description
Example (applicable as of 10.4 c24ec3ce, it might stop being an example after the underlying server bug is fixed):
					--source include/have_innodb.inc
			 | 
		
| 
					 | 
		
					CREATE TABLE t1 (  | 
		
					col_timestamp TIMESTAMP,  | 
		
					 col_varchar VARBINARY(1000),
			 | 
		
					col_bit BIT(15),  | 
		
					 col_datetime DATETIME,
			 | 
		
					 col_blob BLOB,
			 | 
		
					col_year YEAR,  | 
		
					 col_int TINYINT,
			 | 
		
					col_dec DECIMAL(5,2),  | 
		
					col_char CHAR(125),  | 
		
					col_time TIME,  | 
		
					col_date DATE,  | 
		
					pk INT,  | 
		
					PRIMARY KEY(pk)  | 
		
					 ) ENGINE=InnoDB ;
			 | 
		
| 
					 | 
		
					INSERT INTO t1 VALUES  | 
		
					('2017-10-15 10:40:31','foo',NULL,'1981-06-28 00:00:00','bar',1977,3,0.1,'foobar','07:54:20','2029-06-13',1) ;  | 
		
| 
					 | 
		
					--connect (con1,localhost,root,,)
			 | 
		
					--send
			 | 
		
					ALTER TABLE t1 ADD COLUMN s BIGINT UNSIGNED AS ROW START, ADD COLUMN e BIGINT UNSIGNED AS ROW END, ADD PERIOD FOR SYSTEM_TIME(s,e), WITH SYSTEM VERSIONING;  | 
		
| 
					 | 
		
					--connection default
			 | 
		
					--source include/restart_mysqld.inc  | 
		
| 
				 Test output  | 
		
					...
			 | 
		
					ALTER TABLE t1 ADD COLUMN s BIGINT UNSIGNED AS ROW START, ADD COLUMN e BIGINT UNSIGNED AS ROW END, ADD PERIOD FOR SYSTEM_TIME(s,e), WITH SYSTEM VERSIONING;
			 | 
		
					connection default;
			 | 
		
					# restart
			 | 
		
					bug2.4772 'innodb'                       [ pass ]   2708
			 | 
		
| 
					 | 
		
					MTR's internal check of the test case 'bug2.4772' failed.
			 | 
		
					This means that the test case does not preserve the state that existed
			 | 
		
					before the test case was executed.  Most likely the test case did not
			 | 
		
					do a proper clean-up. It could also be caused by the previous test run
			 | 
		
					by this thread, if the server wasn't restarted.
			 | 
		
					This is the diff of the states of the servers before and after the
			 | 
		
					test case was executed:
			 | 
		
					mysqltest: Logging to '/data/bld/10.4-asan-nightly/mysql-test/var/tmp/check-mysqld_1.log'.
			 | 
		
					mysqltest: Results saved in '/data/bld/10.4-asan-nightly/mysql-test/var/tmp/check-mysqld_1.result'.
			 | 
		
					mysqltest: Connecting to server localhost:16020 (socket /data/bld/10.4-asan-nightly/mysql-test/var/tmp/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
			 | 
		
					mysqltest: ... Connected.
			 | 
		
					mysqltest: Start processing test commands from './include/check-testcase.test' ...
			 | 
		
					mysqltest: ... Done processing test commands.
			 | 
		
					--- /data/bld/10.4-asan-nightly/mysql-test/var/tmp/check-mysqld_1.result	2019-11-08 17:47:53.855973236 +0200
			 | 
		
					+++ /data/bld/10.4-asan-nightly/mysql-test/var/tmp/check-mysqld_1.reject	2019-11-08 17:47:56.931935331 +0200
			 | 
		
					@@ -727,6 +727,7 @@
			 | 
		
					 def	performance_schema	utf8	utf8_general_ci	NULL
			 | 
		
					 def	test	latin1	latin1_swedish_ci	NULL
			 | 
		
					 tables_in_test
			 | 
		
					+t1
			 | 
		
					 tables_in_mysql
			 | 
		
					 mysql.columns_priv
			 | 
		
					 mysql.column_stats
			 | 
		
					@@ -1101,3 +1102,4 @@
			 | 
		
					 partition	1.0	DISABLED	STORAGE ENGINE	100410.0	NULL	NULL	Mikael Ronstrom, MySQL AB	Partition Storage Engine Helper	GPL	OFF	Stable	1.0
			 | 
		
					 VARIABLE_NAME	VARIABLE_VALUE
			 | 
		
					 DEBUG_SYNC	ON - current signal: ''
			 | 
		
					+#sql-36ac_a.frm
			 | 
		
| 
					 | 
		
					mysqltest: Result length mismatch
			 | 
		
| 
					 | 
		
					not ok
			 | 
		
| 
				 Error log  | 
		
					CURRENT_TEST: bug2.4772
			 | 
		
					2019-11-08 17:47:53 0 [Note] /data/bld/10.4-asan-nightly/bin/mysqld (mysqld 10.4.10-MariaDB-debug-log) starting as process 13996 ...
			 | 
		
					2019-11-08 17:47:53 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4190)
			 | 
		
					...
			 | 
		
					Version: '10.4.10-MariaDB-debug-log'  socket: '/data/bld/10.4-asan-nightly/mysql-test/var/tmp/mysqld.1.sock'  port: 16020  Source distribution
			 | 
		
					2019-11-08 17:47:54 0 [Note] /data/bld/10.4-asan-nightly/bin/mysqld (initiated by: root[root] @ localhost []): Normal shutdown
			 | 
		
					2019-11-08 17:47:54 0 [Note] Event Scheduler: Purging the queue. 0 events
			 | 
		
					2019-11-08 17:47:54 0 [Note] InnoDB: FTS optimize thread exiting.
			 | 
		
					=================================================================
			 | 
		
					==13996==ERROR: AddressSanitizer: heap-use-after-free on address 0x619000049b80 at pc 0x563190e29597 bp 0x7f17656e3790 sp 0x7f17656e3788
			 | 
		
					WRITE of size 8 at 0x619000049b80 thread T28
			 | 
		
					    #0 0x563190e29596 in trx_update_mod_tables_timestamp /data/src/10.4/storage/innobase/trx/trx0trx.cc:1288
			 | 
		
					    #1 0x563190e2aab1 in trx_commit_in_memory /data/src/10.4/storage/innobase/trx/trx0trx.cc:1415
			 | 
		
					    #2 0x563190e2d04a in trx_commit_low(trx_t*, mtr_t*) /data/src/10.4/storage/innobase/trx/trx0trx.cc:1618
			 | 
		
					    #3 0x563190e2d173 in trx_commit(trx_t*) /data/src/10.4/storage/innobase/trx/trx0trx.cc:1642
			 | 
		
					    #4 0x563190e2dbda in trx_commit_for_mysql(trx_t*) /data/src/10.4/storage/innobase/trx/trx0trx.cc:1788
			 | 
		
					    #5 0x563190ab0579 in rollback_inplace_alter_table(Alter_inplace_info*, TABLE const*, row_prebuilt_t*) (/data/bld/10.4-asan-nightly/bin/mysqld+0x1fa5579)
			 | 
		
					    #6 0x563190a8dd3b in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/storage/innobase/handler/handler0alter.cc:10713
			 | 
		
					    #7 0x5631904c44b2 in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/sql/handler.cc:4567
			 | 
		
					    #8 0x56318ff6c413 in mysql_inplace_alter_table /data/src/10.4/sql/sql_table.cc:7871
			 | 
		
					    #9 0x56318ff7a01f in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /data/src/10.4/sql/sql_table.cc:10094
			 | 
		
					    #10 0x5631900d0f49 in Sql_cmd_alter_table::execute(THD*) /data/src/10.4/sql/sql_alter.cc:508
			 | 
		
					    #11 0x56318fd561b4 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6099
			 | 
		
					    #12 0x56318fd60bad in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:7898
			 | 
		
					    #13 0x56318fd39e6a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1842
			 | 
		
					    #14 0x56318fd36d5e in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1360
			 | 
		
					    #15 0x5631900bbc02 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1412
			 | 
		
					    #16 0x5631900bb5b6 in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1316
			 | 
		
					    #17 0x56319151addd in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
			 | 
		
					    #18 0x7f177d1574a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
			 | 
		
					    #19 0x7f177b69ed0e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe8d0e)
			 | 
		
| 
					 | 
		
					0x619000049b80 is located 1024 bytes inside of 1048-byte region [0x619000049780,0x619000049b98)
			 | 
		
					freed by thread T28 here:
			 | 
		
					    #0 0x7f177d42ea10 in free (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1a10)
			 | 
		
					    #1 0x563190b8ffa1 in mem_heap_block_free(mem_block_info_t*, mem_block_info_t*) /data/src/10.4/storage/innobase/mem/mem0mem.cc:426
			 | 
		
					    #2 0x563190fde8b7 in mem_heap_free /data/src/10.4/storage/innobase/include/mem0mem.ic:437
			 | 
		
					    #3 0x563190fe0f35 in dict_mem_table_free(dict_table_t*) /data/src/10.4/storage/innobase/dict/dict0mem.cc:234
			 | 
		
					    #4 0x563190fa4b72 in dict_sys_t::remove(dict_table_t*, bool, bool) /data/src/10.4/storage/innobase/dict/dict0dict.cc:1733
			 | 
		
					    #5 0x563190cd2cd7 in row_drop_table_from_cache /data/src/10.4/storage/innobase/row/row0mysql.cc:3275
			 | 
		
					    #6 0x563190cd4cc2 in row_drop_table_for_mysql(char const*, trx_t*, enum_sql_command, bool, bool) /data/src/10.4/storage/innobase/row/row0mysql.cc:3751
			 | 
		
					    #7 0x563190cb0d10 in row_merge_drop_table(trx_t*, dict_table_t*) /data/src/10.4/storage/innobase/row/row0merge.cc:4499
			 | 
		
					    #8 0x563190f9d49d in dict_table_close_and_drop(trx_t*, dict_table_t*) /data/src/10.4/storage/innobase/dict/dict0dict.cc:396
			 | 
		
					    #9 0x563190aaf7d6 in rollback_inplace_alter_table(Alter_inplace_info*, TABLE const*, row_prebuilt_t*) (/data/bld/10.4-asan-nightly/bin/mysqld+0x1fa47d6)
			 | 
		
					    #10 0x563190a8dd3b in ha_innobase::commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/storage/innobase/handler/handler0alter.cc:10713
			 | 
		
					    #11 0x5631904c44b2 in handler::ha_commit_inplace_alter_table(TABLE*, Alter_inplace_info*, bool) /data/src/10.4/sql/handler.cc:4567
			 | 
		
					    #12 0x56318ff6c413 in mysql_inplace_alter_table /data/src/10.4/sql/sql_table.cc:7871
			 | 
		
					    #13 0x56318ff7a01f in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /data/src/10.4/sql/sql_table.cc:10094
			 | 
		
					    #14 0x5631900d0f49 in Sql_cmd_alter_table::execute(THD*) /data/src/10.4/sql/sql_alter.cc:508
			 | 
		
					    #15 0x56318fd561b4 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6099
			 | 
		
					    #16 0x56318fd60bad in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:7898
			 | 
		
					    #17 0x56318fd39e6a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1842
			 | 
		
					    #18 0x56318fd36d5e in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1360
			 | 
		
					    #19 0x5631900bbc02 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1412
			 | 
		
					    #20 0x5631900bb5b6 in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1316
			 | 
		
					    #21 0x56319151addd in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
			 | 
		
					    #22 0x7f177d1574a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
			 | 
		
| 
					 | 
		
					previously allocated by thread T28 here:
			 | 
		
					    #0 0x7f177d42ed28 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.3+0xc1d28)
			 | 
		
					    #1 0x563190b8f4f1 in mem_heap_create_block_func(mem_block_info_t*, unsigned long, char const*, unsigned int, unsigned long) /data/src/10.4/storage/innobase/mem/mem0mem.cc:280
			 | 
		
					    #2 0x563190b8fc56 in mem_heap_add_block(mem_block_info_t*, unsigned long) /data/src/10.4/storage/innobase/mem/mem0mem.cc:386
			 | 
		
					    #3 0x563190fde532 in mem_heap_alloc /data/src/10.4/storage/innobase/include/mem0mem.ic:203
			 | 
		
					    #4 0x563190fde337 in mem_heap_zalloc /data/src/10.4/storage/innobase/include/mem0mem.ic:170
			 | 
		
					    #5 0x563190fe0376 in dict_mem_table_create(char const*, fil_space_t*, unsigned long, unsigned long, unsigned long, unsigned long) /data/src/10.4/storage/innobase/dict/dict0mem.cc:146
			 | 
		
					    #6 0x563190a70196 in prepare_inplace_alter_table_dict /data/src/10.4/storage/innobase/handler/handler0alter.cc:6332
			 | 
		
					    #7 0x563190a80e5f in ha_innobase::prepare_inplace_alter_table(TABLE*, Alter_inplace_info*) /data/src/10.4/storage/innobase/handler/handler0alter.cc:8150
			 | 
		
					    #8 0x5631904c41b5 in handler::ha_prepare_inplace_alter_table(TABLE*, Alter_inplace_info*) /data/src/10.4/sql/handler.cc:4547
			 | 
		
					    #9 0x56318ff6b78c in mysql_inplace_alter_table /data/src/10.4/sql/sql_table.cc:7694
			 | 
		
					    #10 0x56318ff7a01f in mysql_alter_table(THD*, st_mysql_const_lex_string const*, st_mysql_const_lex_string const*, HA_CREATE_INFO*, TABLE_LIST*, Alter_info*, unsigned int, st_order*, bool) /data/src/10.4/sql/sql_table.cc:10094
			 | 
		
					    #11 0x5631900d0f49 in Sql_cmd_alter_table::execute(THD*) /data/src/10.4/sql/sql_alter.cc:508
			 | 
		
					    #12 0x56318fd561b4 in mysql_execute_command(THD*) /data/src/10.4/sql/sql_parse.cc:6099
			 | 
		
					    #13 0x56318fd60bad in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.4/sql/sql_parse.cc:7898
			 | 
		
					    #14 0x56318fd39e6a in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.4/sql/sql_parse.cc:1842
			 | 
		
					    #15 0x56318fd36d5e in do_command(THD*) /data/src/10.4/sql/sql_parse.cc:1360
			 | 
		
					    #16 0x5631900bbc02 in do_handle_one_connection(CONNECT*) /data/src/10.4/sql/sql_connect.cc:1412
			 | 
		
					    #17 0x5631900bb5b6 in handle_one_connection /data/src/10.4/sql/sql_connect.cc:1316
			 | 
		
					    #18 0x56319151addd in pfs_spawn_thread /data/src/10.4/storage/perfschema/pfs.cc:1862
			 | 
		
					    #19 0x7f177d1574a3 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x74a3)
			 | 
		
| 
					 | 
		
					Thread T28 created by T0 here:
			 | 
		
					    #0 0x7f177d39df59 in __interceptor_pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.3+0x30f59)
			 | 
		
					    #1 0x56319151b1ca in spawn_thread_v1 /data/src/10.4/storage/perfschema/pfs.cc:1912
			 | 
		
					    #2 0x56318fa91bd8 in inline_mysql_thread_create /data/src/10.4/include/mysql/psi/mysql_thread.h:1268
			 | 
		
					    #3 0x56318faa617c in create_thread_to_handle_connection(CONNECT*) /data/src/10.4/sql/mysqld.cc:6234
			 | 
		
					    #4 0x56318faa685f in create_new_thread(CONNECT*) /data/src/10.4/sql/mysqld.cc:6304
			 | 
		
					    #5 0x56318faa6bea in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.4/sql/mysqld.cc:6402
			 | 
		
					    #6 0x56318faa783c in handle_connections_sockets() /data/src/10.4/sql/mysqld.cc:6560
			 | 
		
					    #7 0x56318faa59fd in mysqld_main(int, char**) /data/src/10.4/sql/mysqld.cc:5892
			 | 
		
					    #8 0x56318fa8fabf in main /data/src/10.4/sql/main.cc:25
			 | 
		
					    #9 0x7f177b5d62e0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202e0)
			 | 
		
| 
					 | 
		
					SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.4/storage/innobase/trx/trx0trx.cc:1288 in trx_update_mod_tables_timestamp
			 | 
		
					Shadow bytes around the buggy address:
			 | 
		
					  0x0c3280001320: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
			 | 
		
					  0x0c3280001330: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
			 | 
		
					  0x0c3280001340: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
			 | 
		
					  0x0c3280001350: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
			 | 
		
					  0x0c3280001360: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
			 | 
		
					=>0x0c3280001370:[fd]fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa
			 | 
		
					  0x0c3280001380: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
			 | 
		
					  0x0c3280001390: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
			 | 
		
					  0x0c32800013a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
			 | 
		
					  0x0c32800013b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
			 | 
		
					  0x0c32800013c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
			 | 
		
					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
			 | 
		
					  Left alloca redzone:     ca
			 | 
		
					  Right alloca redzone:    cb
			 | 
		
					==13996==ABORTING
			 | 
		
					2019-11-08 17:47:55 0 [Note] /data/bld/10.4-asan-nightly/bin/mysqld (mysqld 10.4.10-MariaDB-debug-log) starting as process 14039 ...
			 | 
		
					2019-11-08 17:47:55 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4190)
			 | 
		
					2019-11-08 17:47:55 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
			 | 
		
					2019-11-08 17:47:55 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
			 | 
		
					2019-11-08 17:47:55 0 [Note] Plugin 'partition' is disabled.
			 | 
		
					2019-11-08 17:47:55 0 [Note] Plugin 'SEQUENCE' is disabled.
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Using Linux native AIO
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Uses event mutexes
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Compressed tables use zlib 1.2.8
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Number of pools: 1
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Using SSE2 crc32 instructions
			 | 
		
					2019-11-08 17:47:55 0 [Note] mysqld: O_TMPFILE is not supported on /data/bld/10.4-asan-nightly/mysql-test/var/tmp/mysqld.1 (disabling future attempts)
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Completed initialization of buffer pool
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=152140
			 | 
		
					2019-11-08 17:47:55 0 [Note] InnoDB: Starting final batch to recover 14 pages from redo log.
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: Creating shared tablespace for temporary tables
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: 10.4.10 started; log sequence number 163295; transaction id 47
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: Loading buffer pool(s) from /data/bld/10.4-asan-nightly/mysql-test/var/mysqld.1/data/ib_buffer_pool
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: Buffer pool(s) load completed at 191108 17:47:56
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_CMP' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'FEEDBACK' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'user_variables' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Plugin 'unix_socket' is disabled.
			 | 
		
					2019-11-08 17:47:56 0 [Warning] /data/bld/10.4-asan-nightly/bin/mysqld: unknown option '--loose-pam-debug'
			 | 
		
					2019-11-08 17:47:56 0 [Warning] /data/bld/10.4-asan-nightly/bin/mysqld: unknown option '--loose-aria'
			 | 
		
					2019-11-08 17:47:56 0 [Note] Server socket created on IP: '127.0.0.1'.
			 | 
		
					2019-11-08 17:47:56 0 [Note] Reading of all Master_info entries succeeded
			 | 
		
					2019-11-08 17:47:56 0 [Note] Added new Master_info '' to hash table
			 | 
		
					2019-11-08 17:47:56 0 [Note] /data/bld/10.4-asan-nightly/bin/mysqld: ready for connections.
			 | 
		
					Version: '10.4.10-MariaDB-debug-log'  socket: '/data/bld/10.4-asan-nightly/mysql-test/var/tmp/mysqld.1.sock'  port: 16020  Source distribution
			 | 
		
					2019-11-08 17:47:56 0 [Note] /data/bld/10.4-asan-nightly/bin/mysqld (initiated by: root[root] @ localhost [127.0.0.1]): Normal shutdown
			 | 
		
					2019-11-08 17:47:56 0 [Note] Event Scheduler: Purging the queue. 0 events
			 | 
		
					2019-11-08 17:47:56 0 [Note] InnoDB: FTS optimize thread exiting.
			 | 
		
					2019-11-08 17:47:57 0 [Note] InnoDB: Starting shutdown...
			 | 
		
					2019-11-08 17:47:57 0 [Note] InnoDB: Dumping buffer pool(s) to /data/bld/10.4-asan-nightly/mysql-test/var/mysqld.1/data/ib_buffer_pool
			 | 
		
					2019-11-08 17:47:57 0 [Note] InnoDB: Instance 0, restricted to 123 pages due to innodb_buf_pool_dump_pct=25
			 | 
		
					2019-11-08 17:47:57 0 [Note] InnoDB: Buffer pool(s) dump completed at 191108 17:47:57
			 | 
		
					2019-11-08 17:47:58 0 [Note] InnoDB: Shutdown completed; log sequence number 163474; transaction id 47
			 | 
		
					2019-11-08 17:47:58 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
			 | 
		
					2019-11-08 17:47:58 0 [Note] Debug sync points hit:                   1317
			 | 
		
					2019-11-08 17:47:58 0 [Note] Debug sync points executed:              0
			 | 
		
					2019-11-08 17:47:58 0 [Note] Debug sync points max active per thread: 0
			 | 
		
					2019-11-08 17:47:58 0 [Note] /data/bld/10.4-asan-nightly/bin/mysqld: Shutdown complete
			 | 
		
Providing explicit ASAN_OPTIONS="abort_on_error=1" helps a bit, but only to the extent that it causes SIGABRT, upon which the line Attempting backtrace is printed, and that is actually noticed by MTR:
| 
				 Test output with ASAN_OPTIONS=abort_on_error=1"  | 
		
					...
			 | 
		
					ALTER TABLE t1 ADD COLUMN s BIGINT UNSIGNED AS ROW START, ADD COLUMN e BIGINT UNSIGNED AS ROW END, ADD PERIOD FOR SYSTEM_TIME(s,e), WITH SYSTEM VERSIONING;
			 | 
		
					connection default;
			 | 
		
					# restart
			 | 
		
					bug2.4772 'innodb'                       [ fail ]  Found warnings/errors in server log file!
			 | 
		
					        Test ended at 2019-11-08 17:51:49
			 | 
		
					line
			 | 
		
					Attempting backtrace. You can use the following information to find out
			 | 
		
					^ Found warnings in /data/bld/10.4-asan-nightly/mysql-test/var/log/mysqld.1.err
			 | 
		
					ok
			 | 
		
Still, it says nothing about actual ASAN errors.
The simplest fix would be to add a line to MTR warning patterns:
					diff --git a/data/src/10.4/mysql-test/mysql-test-run.pl b/mysql-test-run.pl
			 | 
		
					index 6d4549d..a1b11c3 100755
			 | 
		
					--- a/data/src/10.4/mysql-test/mysql-test-run.pl
			 | 
		
					+++ b/mysql-test-run.pl
			 | 
		
					@@ -4651,6 +4651,7 @@ sub extract_warning_lines ($$) {
			 | 
		
					      qr/missing DBUG_RETURN/,
			 | 
		
					      qr/Attempting backtrace/,
			 | 
		
					      qr/Assertion .* failed/,
			 | 
		
					+     qr/ERROR: AddressSanitizer/,
			 | 
		
					     );
			 | 
		
					   # These are taken from the include/mtr_warnings.sql global suppression
			 | 
		
					   # list. They occur delayed, so they can be parsed during shutdown rather
			 | 
		
Then the output would look like this:
| 
				 Test output without explicit ASAN_OPTIONS  | 
		
					...
			 | 
		
					ALTER TABLE t1 ADD COLUMN s BIGINT UNSIGNED AS ROW START, ADD COLUMN e BIGINT UNSIGNED AS ROW END, ADD PERIOD FOR SYSTEM_TIME(s,e), WITH SYSTEM VERSIONING;
			 | 
		
					connection default;
			 | 
		
					# restart
			 | 
		
					bug2.4772 'innodb'                       [ fail ]  Found warnings/errors in server log file!
			 | 
		
					        Test ended at 2019-11-08 17:57:45
			 | 
		
					line
			 | 
		
					==15059==ERROR: AddressSanitizer: heap-use-after-free on address 0x619000049b80 at pc 0x56250ff56597 bp 0x7f135cf49790 sp 0x7f135cf49788
			 | 
		
					^ Found warnings in /data/bld/10.4-asan-nightly/mysql-test/var/log/mysqld.1.err
			 | 
		
					ok
			 | 
		
or
| 
				 Test output with ASAN_OPTIONS="abort_on_error=1"  | 
		
					...
			 | 
		
					ALTER TABLE t1 ADD COLUMN s BIGINT UNSIGNED AS ROW START, ADD COLUMN e BIGINT UNSIGNED AS ROW END, ADD PERIOD FOR SYSTEM_TIME(s,e), WITH SYSTEM VERSIONING;
			 | 
		
					connection default;
			 | 
		
					# restart
			 | 
		
					bug2.4772 'innodb'                       [ fail ]  Found warnings/errors in server log file!
			 | 
		
					        Test ended at 2019-11-08 17:56:44
			 | 
		
					line
			 | 
		
					==14876==ERROR: AddressSanitizer: heap-use-after-free on address 0x61900006ee80 at pc 0x55875d2ae597 bp 0x7f728dad6790 sp 0x7f728dad6788
			 | 
		
					Attempting backtrace. You can use the following information to find out
			 | 
		
					^ Found warnings in /data/bld/10.4-asan-nightly/mysql-test/var/log/mysqld.1.err
			 | 
		
					ok
			 | 
		
But possibly you want to print more in the test output than just that, so I'm passing it over.
Attachments
Issue Links
- links to