[MDEV-18805] ASAN heap-buffer-overflow in strmake_root on temporary table with indexed virtual column Created: 2019-03-04  Updated: 2020-05-15  Resolved: 2020-05-15

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Data Definition - Temporary, Virtual Columns
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: 10.2.23, 10.3.14, 10.4.4

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-18485 Server crash or AddressSanitizer: hea... Closed
relates to MDEV-18784 Server crashes in l_find, ASAN heap-u... Closed
relates to MDEV-20467 Multiple "Warning: Enabling keys got ... Open

 Description    

CREATE TEMPORARY TABLE t1 (a BINARY, b INT, c INT, d INT AS (b) PERSISTENT, KEY (d)) ENGINE MyISAM;
 
ALTER TABLE t1 ADD COLUMN e DOUBLE;
 
INSERT INTO t1 (a,b,c) VALUES (NULL,NULL,NULL);
 
--error WARN_DATA_TRUNCATED
 
ALTER TABLE t1 CHANGE c f BIGINT NOT NULL;
 
 
 
SELECT * FROM t1 INTO OUTFILE 'load_t1';
 
LOAD DATA INFILE 'load_t1' IGNORE INTO TABLE t1;
 
ALTER TABLE t1 FORCE;
 
 
 
# Cleanup
 
--let $datadir= `SELECT @@datadir`
 
--remove_file $datadir/test/load_t1

10.3 82da9855 ASAN

 
2019-03-04  2:34:24 4 [Warning] Warning: Enabling keys got errno 127 on test.t1, retrying
 
=================================================================
 
==19421==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x60e000071fa1 at pc 0x560b1b3c2ac4 bp 0x7f4b08a88f30 sp 0x7f4b08a88f28
 
READ of size 1 at 0x60e000071fa1 thread T5
 
    #0 0x560b1b3c2ac3 in strmake_root /data/src/10.3/mysys/my_alloc.c:481
 
    #1 0x560b1998df4f in Query_arena::strmake(char const*, unsigned long) /data/src/10.3/sql/sql_class.h:1028
 
    #2 0x560b1a2aa443 in Column_definition::Column_definition(THD*, Field*, Field*) /data/src/10.3/sql/field.cc:11016
 
    #3 0x560b19b50ddf in Create_field::Create_field(THD*, Field*, Field*) /data/src/10.3/sql/field.h:4754
 
    #4 0x560b19de5757 in mysql_prepare_alter_table(THD*, TABLE*, HA_CREATE_INFO*, Alter_info*, Alter_table_ctx*) /data/src/10.3/sql/sql_table.cc:8023
 
    #5 0x560b19dee264 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.3/sql/sql_table.cc:9445
 
    #6 0x560b19f3b155 in Sql_cmd_alter_table::execute(THD*) /data/src/10.3/sql/sql_alter.cc:497
 
    #7 0x560b19bd6911 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:6288
 
    #8 0x560b19be180e in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:8095
 
    #9 0x560b19bbb8e6 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1854
 
    #10 0x560b19bb88f8 in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1396
 
    #11 0x560b19f2c18d in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
 
    #12 0x560b19f2bb99 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1309
 
    #13 0x560b1aa61d5f in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1862
 
    #14 0x7f4b15062493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
 
    #15 0x7f4b1344893e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
 
 
 
0x60e000071fa1 is located 31 bytes to the left of 148-byte region [0x60e000071fc0,0x60e000072054)
 
freed by thread T5 here:
 
    #0 0x7f4b152cc527 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x54527)
 
    #1 0x560b1b41212b in free_memory /data/src/10.3/mysys/safemalloc.c:279
 
    #2 0x560b1b411731 in sf_free /data/src/10.3/mysys/safemalloc.c:197
 
    #3 0x560b1b3e217a in my_free /data/src/10.3/mysys/my_malloc.c:223
 
    #4 0x560b1a848a3c in info_remove_lock /data/src/10.3/storage/maria/ma_pagecache.c:2316
 
    #5 0x560b1a84d240 in make_lock_and_pin /data/src/10.3/storage/maria/ma_pagecache.c:2631
 
    #6 0x560b1a850c09 in pagecache_unlock_by_link /data/src/10.3/storage/maria/ma_pagecache.c:3091
 
    #7 0x560b1a8c41b3 in _ma_unpin_all_pages /data/src/10.3/storage/maria/ma_key_recover.c:71
 
    #8 0x560b1a8fb95a in write_block_record /data/src/10.3/storage/maria/ma_blockrec.c:3431
 
    #9 0x560b1a8fc86d in allocate_and_write_block_record /data/src/10.3/storage/maria/ma_blockrec.c:3565
 
    #10 0x560b1a8fcb40 in _ma_write_init_block_record /data/src/10.3/storage/maria/ma_blockrec.c:3605
 
    #11 0x560b1a92e66b in maria_write /data/src/10.3/storage/maria/ma_write.c:157
 
    #12 0x560b1a7e4f03 in ha_maria::write_row(unsigned char*) /data/src/10.3/storage/maria/ha_maria.cc:1291
 
    #13 0x560b19d22a05 in handler::ha_write_tmp_row(unsigned char*) /data/src/10.3/sql/sql_class.h:6426
 
    #14 0x560b19d4d53b in schema_table_store_record(THD*, TABLE*) /data/src/10.3/sql/sql_show.cc:3827
 
    #15 0x560b19d33d92 in show_plugins /data/src/10.3/sql/sql_show.cc:303
 
    #16 0x560b19c0202a in plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*) /data/src/10.3/sql/sql_plugin.cc:2420
 
    #17 0x560b19d33f12 in fill_plugins(THD*, TABLE_LIST*, Item*) /data/src/10.3/sql/sql_show.cc:312
 
    #18 0x560b19d8865d in get_schema_tables_result(JOIN*, enum_schema_table_state) /data/src/10.3/sql/sql_show.cc:8802
 
    #19 0x560b19c79c65 in JOIN::exec_inner() /data/src/10.3/sql/sql_select.cc:4003
 
    #20 0x560b19c77f79 in JOIN::exec() /data/src/10.3/sql/sql_select.cc:3834
 
    #21 0x560b19c7b492 in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /data/src/10.3/sql/sql_select.cc:4239
 
    #22 0x560b19c55fac in handle_select(THD*, LEX*, select_result*, unsigned long) /data/src/10.3/sql/sql_select.cc:385
 
    #23 0x560b19bd8976 in execute_sqlcom_select /data/src/10.3/sql/sql_parse.cc:6551
 
    #24 0x560b19bc6de7 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:3772
 
    #25 0x560b199d8669 in sp_instr_stmt::exec_core(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3594
 
    #26 0x560b199d6f5d in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /data/src/10.3/sql/sp_head.cc:3322
 
    #27 0x560b199d7e38 in sp_instr_stmt::execute(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3500
 
    #28 0x560b199cb0cd in sp_head::execute(THD*, bool) /data/src/10.3/sql/sp_head.cc:1354
 
    #29 0x560b199d0333 in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.3/sql/sp_head.cc:2294
 
 
 
previously allocated by thread T5 here:
 
    #0 0x7f4b152cc73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
 
    #1 0x560b1b410ea1 in sf_malloc /data/src/10.3/mysys/safemalloc.c:118
 
    #2 0x560b1b3e179c in my_malloc /data/src/10.3/mysys/my_malloc.c:101
 
    #3 0x560b1a848903 in info_add_lock /data/src/10.3/storage/maria/ma_pagecache.c:2302
 
    #4 0x560b1a84d1a8 in make_lock_and_pin /data/src/10.3/storage/maria/ma_pagecache.c:2608
 
    #5 0x560b1a851e8e in pagecache_read /data/src/10.3/storage/maria/ma_pagecache.c:3425
 
    #6 0x560b1a8efc2e in get_head_or_tail_page /data/src/10.3/storage/maria/ma_blockrec.c:1782
 
    #7 0x560b1a8fc37f in allocate_and_write_block_record /data/src/10.3/storage/maria/ma_blockrec.c:3544
 
    #8 0x560b1a8fcb40 in _ma_write_init_block_record /data/src/10.3/storage/maria/ma_blockrec.c:3605
 
    #9 0x560b1a92e66b in maria_write /data/src/10.3/storage/maria/ma_write.c:157
 
    #10 0x560b1a7e4f03 in ha_maria::write_row(unsigned char*) /data/src/10.3/storage/maria/ha_maria.cc:1291
 
    #11 0x560b19d22a05 in handler::ha_write_tmp_row(unsigned char*) /data/src/10.3/sql/sql_class.h:6426
 
    #12 0x560b19d4d53b in schema_table_store_record(THD*, TABLE*) /data/src/10.3/sql/sql_show.cc:3827
 
    #13 0x560b19d33d92 in show_plugins /data/src/10.3/sql/sql_show.cc:303
 
    #14 0x560b19c0202a in plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*) /data/src/10.3/sql/sql_plugin.cc:2420
 
    #15 0x560b19d33f12 in fill_plugins(THD*, TABLE_LIST*, Item*) /data/src/10.3/sql/sql_show.cc:312
 
    #16 0x560b19d8865d in get_schema_tables_result(JOIN*, enum_schema_table_state) /data/src/10.3/sql/sql_show.cc:8802
 
    #17 0x560b19c79c65 in JOIN::exec_inner() /data/src/10.3/sql/sql_select.cc:4003
 
    #18 0x560b19c77f79 in JOIN::exec() /data/src/10.3/sql/sql_select.cc:3834
 
    #19 0x560b19c7b492 in mysql_select(THD*, TABLE_LIST*, unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, Item*, st_order*, unsigned long long, select_result*, st_select_lex_unit*, st_select_lex*) /data/src/10.3/sql/sql_select.cc:4239
 
    #20 0x560b19c55fac in handle_select(THD*, LEX*, select_result*, unsigned long) /data/src/10.3/sql/sql_select.cc:385
 
    #21 0x560b19bd8976 in execute_sqlcom_select /data/src/10.3/sql/sql_parse.cc:6551
 
    #22 0x560b19bc6de7 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:3772
 
    #23 0x560b199d8669 in sp_instr_stmt::exec_core(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3594
 
    #24 0x560b199d6f5d in sp_lex_keeper::reset_lex_and_exec_core(THD*, unsigned int*, bool, sp_instr*) /data/src/10.3/sql/sp_head.cc:3322
 
    #25 0x560b199d7e38 in sp_instr_stmt::execute(THD*, unsigned int*) /data/src/10.3/sql/sp_head.cc:3500
 
    #26 0x560b199cb0cd in sp_head::execute(THD*, bool) /data/src/10.3/sql/sp_head.cc:1354
 
    #27 0x560b199d0333 in sp_head::execute_procedure(THD*, List<Item>*) /data/src/10.3/sql/sp_head.cc:2294
 
    #28 0x560b19bc16fc in do_execute_sp /data/src/10.3/sql/sql_parse.cc:2954
 
    #29 0x560b19bc315d in Sql_cmd_call::execute(THD*) /data/src/10.3/sql/sql_parse.cc:3194
 
 
 
Thread T5 created by T0 here:
 
    #0 0x7f4b1529bbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
 
    #1 0x560b1aa62327 in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1912
 
    #2 0x560b19923468 in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1268
 
    #3 0x560b199396e1 in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6587
 
    #4 0x560b19939de6 in create_new_thread /data/src/10.3/sql/mysqld.cc:6657
 
    #5 0x560b1993adfd in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6932
 
    #6 0x560b19938b9e in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6209
 
    #7 0x560b199214ef in main /data/src/10.3/sql/main.cc:25
 
    #8 0x7f4b133802b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
 
 
 
SUMMARY: AddressSanitizer: heap-buffer-overflow /data/src/10.3/mysys/my_alloc.c:481 strmake_root
 
Shadow bytes around the buggy address:
 
  0x0c1c800063a0: fa fa fa fa fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c1c800063b0: fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa
 
  0x0c1c800063c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c1c800063d0: fd fd fd fa fa fa fa fa fa fa fa fa fd fd fd fd
 
  0x0c1c800063e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fa
 
=>0x0c1c800063f0: fa fa fa fa[fa]fa fa fa fd fd fd fd fd fd fd fd
 
  0x0c1c80006400: fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa
 
  0x0c1c80006410: fa fa fa fa fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c1c80006420: fd fd fd fd fd fd fd fa fa fa fa fa fa fa fa fa
 
  0x0c1c80006430: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c1c80006440: fd fd fd fa fa fa fa fa fa fa fa fa fd fd fd fd
 
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
 
==19421==ABORTING

Same on 10.4 with ASAN.

On non-ASAN and on 10.2:

LOAD DATA INFILE 'load_t1' IGNORE INTO TABLE t1;
 
Warnings:
 
Error	1034	Key 1 - Found too many records; Can't continue
 
Error	1034	Number of rows changed from 0 to 1
 
ALTER TABLE t1 FORCE;
 
bug2.strmake_root1                       [ pass ]      3

On 10.4, non-deterministically:

10.4 3b47587f

 
#3  <signal handler called>
 
#4  0x000055b940a4ab6e in Field::is_null_in_record (this=0x7fc0c8042910, record=0x7fc0c814a570 "\377") at /data/src/10.4/sql/field.h:1173
 
#5  0x000055b940ce2462 in Column_definition::Column_definition (this=0x7fc0c8015c68, thd=0x7fc0c8000b00, old_field=0x7fc0c8042910, orig_field=0x7fc0c8042910) at /data/src/10.4/sql/field.cc:10779
 
#6  0x000055b94097c192 in Create_field::Create_field (this=0x7fc0c8015c68, thd=0x7fc0c8000b00, old_field=0x7fc0c8042910, orig_field=0x7fc0c8042910) at /data/src/10.4/sql/field.h:4939
 
#7  0x000055b940a9dba9 in mysql_prepare_alter_table (thd=0x7fc0c8000b00, table=0x7fc0c8008d10, create_info=0x7fc0da40acd0, alter_info=0x7fc0da40ac10, alter_ctx=0x7fc0da40a0e0) at /data/src/10.4/sql/sql_table.cc:8126
 
#8  0x000055b940aa213e in mysql_alter_table (thd=0x7fc0c8000b00, new_db=0x7fc0c8005290, new_name=0x7fc0c8005690, create_info=0x7fc0da40acd0, table_list=0x7fc0c8015580, alter_info=0x7fc0da40ac10, order_num=0, order=0x0, ignore=false) at /data/src/10.4/sql/sql_table.cc:9609
 
#9  0x000055b940b310ee in Sql_cmd_alter_table::execute (this=0x7fc0c8015c30, thd=0x7fc0c8000b00) at /data/src/10.4/sql/sql_alter.cc:499
 
#10 0x000055b9409c248e in mysql_execute_command (thd=0x7fc0c8000b00) at /data/src/10.4/sql/sql_parse.cc:6346
 
#11 0x000055b9409c7636 in mysql_parse (thd=0x7fc0c8000b00, rawbuf=0x7fc0c80154a8 "ALTER TABLE t1 FORCE", length=20, parser_state=0x7fc0da40c180, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8157
 
#12 0x000055b9409b2d24 in dispatch_command (command=COM_QUERY, thd=0x7fc0c8000b00, packet=0x7fc0c800a761 "ALTER TABLE t1 FORCE", packet_length=20, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1829
 
#13 0x000055b9409b14f8 in do_command (thd=0x7fc0c8000b00) at /data/src/10.4/sql/sql_parse.cc:1358
 
#14 0x000055b940b2b003 in do_handle_one_connection (connect=0x55b943db2ba0) at /data/src/10.4/sql/sql_connect.cc:1399
 
#15 0x000055b940b2ad74 in handle_one_connection (arg=0x55b943db2ba0) at /data/src/10.4/sql/sql_connect.cc:1302
 
#16 0x000055b941021d17 in pfs_spawn_thread (arg=0x55b943ea5210) at /data/src/10.4/storage/perfschema/pfs.cc:1862
 
#17 0x00007fc0e1f69494 in start_thread (arg=0x7fc0da40d700) at pthread_create.c:333
 
#18 0x00007fc0e034f93f in clone () from /lib/x86_64-linux-gnu/libc.so.6



 Comments   
Comment by Elena Stepanova [ 2020-05-15 ]

The failure disappeared in two steps.

First, after this merge

commit a2fc36989e13c6f322fd22791f67e0d1275461d7
 
Merge: 82da98556cf 74d648db12e
 
Author: Marko Mäkelä
 
Date:   Mon Mar 4 17:01:00 2019 +0200
 
 
 
    Merge 10.2 into 10.3

and particularly this patch

commit 4ca2079142e92f2ce682d463f2e175339e5d79bc
 
Author: Sergei Golubchik
 
Date:   Fri Mar 1 13:23:34 2019 -0500
 
 
 
    MDEV-18486 Database crash on a table with indexed virtual column

the ASAN error stopped happening on 10.3. However, ER_NOT_KEYFILE warnings remained, both in 10.2 and in 10.3:

+Warnings:
 
+Error	1034	Key 1 - Found too many records; Can't continue
 
+Error	1034	Number of rows changed from 0 to 1

Then, after this commit

commit 69abd43703fcf68c4cf1056bf5bd56c690de5b4e
 
Author: Sergei Golubchik
 
Date:   Sun Mar 10 18:55:35 2019 +0100
 
 
 
    MDEV-17070 Table corruption or Assertion `table->file->stats.records > 0 || error' or Assertion `!is_set() || (m_status == DA_OK_BULK && is_bulk_op())' failed upon actions on temporary table
 
    
    This was caused by a combination of factors:
 
    * MyISAM/Aria temporary tables historically never saved the state
 
      to disk (MYI/MAI), because the state never needed to persist
 
    * certain ALTER TABLE operations modify the original TABLE structure
 
      and if they fail, the original table has to be reopened to
 
      revert all changes (m_needs_reopen=1)
 
    
    as a result, when ALTER fails and MyISAM/Aria temp table gets reopened,
 
    it reads the stale state from the disk.
 
    
    As a fix, MyISAM/Aria tables now *always* write the state to disk
 
    on close, *unless* HA_EXTRA_PREPARE_FOR_DROP was done first. And
 
    the server now always does HA_EXTRA_PREPARE_FOR_DROP before dropping
 
    a temporary table.

the warnings also disappeared from 10.2 and then higher versions.

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