[MDEV-24665] ASAN errors, assertion failures, corrupt values after failed LOAD DATA into table with virtual/stored column - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Duplicate
Affects Version/s: 10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6
Fix Version/s: 10.2.38, 10.3.29, 10.4.19, 10.5.10
Component/s: Virtual Columns
Labels:
None

Description

There are a lot of similarity in the test case with ~~MDEV-24656~~. However, the big difference there, apart from the completely differently-looking failure, is that this variant affects not only virtual (generated) columns, but also persistent (stored) columns, which are considered much more stable – so much so new functionality is planned to be based upon them.

CREATE TABLE t1 (id INT PRIMARY KEY, ts TIMESTAMP DEFAULT '1971-01-01 00:00:00', c VARBINARY(8) DEFAULT '', vc VARCHAR(3) AS (c) STORED);

INSERT IGNORE INTO t1 (id,c) VALUES (1,'foobar');

SELECT id, ts, vc INTO OUTFILE 'load_t1' FROM t1;

--error 0,ER_DATA_TOO_LONG

LOAD DATA INFILE 'load_t1' REPLACE INTO TABLE t1 (id, ts, vc);

INSERT IGNORE INTO t1 (id) VALUES (2);

# Cleanup

DROP TABLE t1;

--let $datadir= `select @@datadir`

--remove_file $datadir/test/load_t1

10.2 59e6d14c
==2965509==ERROR: AddressSanitizer: use-after-poison on address 0x619000087c47 at pc 0x55be8e22e411 bp 0x7fb01c9ccae0 sp 0x7fb01c9ccad0
READ of size 1 at 0x619000087c47 thread T5
#0 0x55be8e22e410 in my_timestamp_from_binary(timeval, unsigned char const, unsigned int) /data/src/10.2/sql/compat56.cc:392
#1 0x55be8e265f44 in Field_timestampf::get_timestamp(unsigned char const, unsigned long) const /data/src/10.2/sql/field.cc:5683
#2 0x55be8e2621d1 in Field_timestamp::validate_value_in_record(THD, unsigned char const) const /data/src/10.2/sql/field.cc:5392
#3 0x55be8e29b108 in Field::validate_value_in_record_with_warn(THD, unsigned char const) /data/src/10.2/sql/field.cc:11171
#4 0x55be8df6e8ad in TABLE::validate_default_values_of_unset_fields(THD*) const /data/src/10.2/sql/table.cc:7984
#5 0x55be8dc263e0 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:940
#6 0x55be8dc8db91 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:4194
#7 0x55be8dca67eb in mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7763
#8 0x55be8dc7f830 in dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1827
#9 0x55be8dc7c5ef in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1381
#10 0x55be8e004b1e in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
#11 0x55be8e0043e1 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
#12 0x55be8f3a05d9 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
#13 0x7fb02771e608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
#14 0x7fb0272f8292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)

0x619000087c47 is located 455 bytes inside of 1100-byte region [0x619000087a80,0x619000087ecc)
allocated by thread T5 here:
#0 0x7fb027c85bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
#1 0x55be8f4bd12c in sf_malloc /data/src/10.2/mysys/safemalloc.c:118
#2 0x55be8f489091 in my_malloc /data/src/10.2/mysys/my_malloc.c:101
#3 0x55be8f466703 in alloc_root /data/src/10.2/mysys/my_alloc.c:243
#4 0x55be8f468139 in memdup_root /data/src/10.2/mysys/my_alloc.c:464
#5 0x55be8df3b777 in TABLE_SHARE::init_from_binary_frm_image(THD, bool, unsigned char const, unsigned long) /data/src/10.2/sql/table.cc:1288
#6 0x55be8df37143 in open_table_def(THD, TABLE_SHARE, unsigned int) /data/src/10.2/sql/table.cc:684
#7 0x55be8e189065 in tdc_acquire_share(THD, TABLE_LIST, unsigned int, TABLE**) /data/src/10.2/sql/table_cache.cc:826
#8 0x55be8db607f0 in open_table(THD, TABLE_LIST, Open_table_context*) /data/src/10.2/sql/sql_base.cc:1797
#9 0x55be8db69344 in open_and_process_table /data/src/10.2/sql/sql_base.cc:3614
#10 0x55be8db6b71e in open_tables(THD, DDL_options_st const&, TABLE_LIST, unsigned int, unsigned int, Prelocking_strategy*) /data/src/10.2/sql/sql_base.cc:4081
#11 0x55be8db6f2a4 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:4880
#12 0x55be8dae646d in open_and_lock_tables(THD, TABLE_LIST, bool, unsigned int) /data/src/10.2/sql/sql_base.h:507
#13 0x55be8dc2515d 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
#14 0x55be8dc8db91 in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:4194
#15 0x55be8dca67eb in mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:7763
#16 0x55be8dc7f830 in dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1827
#17 0x55be8dc7c5ef in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1381
#18 0x55be8e004b1e in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1336
#19 0x55be8e0043e1 in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
#20 0x55be8f3a05d9 in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1869
#21 0x7fb02771e608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477

Thread T5 created by T0 here:
#0 0x7fb027bb2805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
#1 0x55be8f3a09ca in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1919
#2 0x55be8da21083 in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1246
#3 0x55be8da38c2b in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6567
#4 0x55be8da393c6 in create_new_thread /data/src/10.2/sql/mysqld.cc:6637
#5 0x55be8da3a558 in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6895
#6 0x55be8da37f7c in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6186
#7 0x55be8da1f93c in main /data/src/10.2/sql/main.cc:25
#8 0x7fb0271fd0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)

SUMMARY: AddressSanitizer: use-after-poison /data/src/10.2/sql/compat56.cc:392 in my_timestamp_from_binary(timeval, unsigned char const, unsigned int)
Shadow bytes around the buggy address:
0x0c3280008f30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fa
0x0c3280008f40: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c3280008f50: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3280008f60: 00 f7 00 00 f7 01 f7 00 00 00 00 00 00 00 00 00
0x0c3280008f70: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c3280008f80: 00 02 f7 00 f7 00 00 06[f7]01 f7 00 00 00 00 00
0x0c3280008f90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3280008fa0: 00 00 00 00 00 f7 00 00 00 00 00 00 00 00 00 00
0x0c3280008fb0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f7
0x0c3280008fc0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3280008fd0: 00 00 00 00 00 00 00 00 00 04 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
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
==2965509==ABORTING

Reproducible on 10.2+, both with stored and virtual columns, with at least MyISAM and InnoDB.
Non-debug ASAN builds of all (10.2-10.6) versions return the failure above, as well as debug ASAN builds of 10.2-10.4.
Debug builds of 10.5-10.6 produce an assertion failure before they have a chance to fail with the ASAN error:

10.5 bf1f9b59
mariadbd: /data/src/10.5/sql/field.h:1155: const uchar* Field::ptr_in_record(const uchar*) const: Assertion `l_offset >= 0 && table->s->rec_buff_length - l_offset > 0' failed.
210124 2:19:33 [ERROR] mysqld got signal 6 ;

#7 0x00007fbc3ae04f36 in __GI___assert_fail (assertion=0x563a23cde1c8 "l_offset >= 0 && table->s->rec_buff_length - l_offset > 0", file=0x563a23cde0b6 "/data/src/10.5/sql/field.h", line=1155, function=0x563a23cde208 "const uchar* Field::ptr_in_record(const uchar*) const") at assert.c:101
#8 0x0000563a2303605b in Field::ptr_in_record (this=0x7fbc242201d0, record=0x7fbc240f9e90 "\376") at /data/src/10.5/sql/field.h:1155
#9 0x0000563a232144cc in Field_timestamp::validate_value_in_record (this=0x7fbc242201d0, thd=0x7fbc24000db8, record=0x7fbc240f9e90 "\376") at /data/src/10.5/sql/field.cc:5433
#10 0x0000563a2322a36a in Field::validate_value_in_record_with_warn (this=0x7fbc242201d0, thd=0x7fbc24000db8, record=0x7fbc240f9e90 "\376") at /data/src/10.5/sql/field.cc:11164
#11 0x0000563a230319d4 in TABLE::validate_default_values_of_unset_fields (this=0x7fbc2421fbe8, thd=0x7fbc24000db8) at /data/src/10.5/sql/table.cc:8989
#12 0x0000563a22e897bd in mysql_insert (thd=0x7fbc24000db8, table_list=0x7fbc24014020, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=true, result=0x0) at /data/src/10.5/sql/sql_insert.cc:957
#13 0x0000563a22edd596 in mysql_execute_command (thd=0x7fbc24000db8) at /data/src/10.5/sql/sql_parse.cc:4596
#14 0x0000563a22ee92b0 in mysql_parse (thd=0x7fbc24000db8, rawbuf=0x7fbc24013f30 "INSERT IGNORE INTO t1 (id) VALUES (2)", length=37, parser_state=0x7fbc357bf510, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:8062
#15 0x0000563a22ed5237 in dispatch_command (command=COM_QUERY, thd=0x7fbc24000db8, packet=0x7fbc240090a9 "INSERT IGNORE INTO t1 (id) VALUES (2)", packet_length=37, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1889
#16 0x0000563a22ed3a2b in do_command (thd=0x7fbc24000db8) at /data/src/10.5/sql/sql_parse.cc:1370
#17 0x0000563a2308172b in do_handle_one_connection (connect=0x563a26852848, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1410
#18 0x0000563a2308148e in handle_one_connection (arg=0x563a268bf208) at /data/src/10.5/sql/sql_connect.cc:1312
#19 0x0000563a235e0449 in pfs_spawn_thread (arg=0x563a26852488) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#20 0x00007fbc3b31c609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#21 0x00007fbc3aef0293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Here is another ASAN failure which I get in very similar circumstances. I won't clean up a test case for it, but I want the failure to be searchable and associatable with this class of problem, so I'll add it here.

10.3 4e503aec
==2966966==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x61e00001a3e5 at pc 0x56285e991fae bp 0x7f1cc9766f60 sp 0x7f1cc9766f50
READ of size 1 at 0x61e00001a3e5 thread T5
#0 0x56285e991fad in Field_newdate::get_TIME(st_mysql_time, unsigned char const, unsigned long long) const /data/src/10.3/sql/field.cc:6590
#1 0x56285e984a28 in Field_temporal_with_date::validate_value_in_record(THD, unsigned char const) const /data/src/10.3/sql/field.cc:5743
#2 0x56285e9c7f28 in Field::validate_value_in_record_with_warn(THD, unsigned char const) /data/src/10.3/sql/field.cc:11501
#3 0x56285e5a143b in TABLE::validate_default_values_of_unset_fields(THD*) const /data/src/10.3/sql/table.cc:8231
#4 0x56285e1e8f1c in mysql_insert(THD, TABLE_LIST, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool) /data/src/10.3/sql/sql_insert.cc:940
#5 0x56285e290473 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4481
#6 0x56285e2a8a81 in mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7840
#7 0x56285e27f8c5 in dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1852
#8 0x56285e27c3fc in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1398
#9 0x56285e646e4d in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
#10 0x56285e646707 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
#11 0x56285fc602fa in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
#12 0x7f1cd461e608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477
#13 0x7f1cd41f8292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)

0x61e00001a3e5 is located 1 bytes to the right of 2916-byte region [0x61e000019880,0x61e00001a3e4)
allocated by thread T5 here:
#0 0x7f1cd4b85bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
#1 0x56285fdaaa9b in sf_malloc /data/src/10.3/mysys/safemalloc.c:118
#2 0x56285fd78903 in my_malloc /data/src/10.3/mysys/my_malloc.c:101
#3 0x56285fd54970 in alloc_root /data/src/10.3/mysys/my_alloc.c:251
#4 0x56285e56b2aa in TABLE_SHARE::init_from_binary_frm_image(THD, bool, unsigned char const, unsigned long) /data/src/10.3/sql/table.cc:1657
#5 0x56285e563f2d in open_table_def(THD, TABLE_SHARE, unsigned int) /data/src/10.3/sql/table.cc:687
#6 0x56285e82e70e in tdc_acquire_share(THD, TABLE_LIST, unsigned int, TABLE**) /data/src/10.3/sql/table_cache.cc:840
#7 0x56285e11357d in open_table(THD, TABLE_LIST, Open_table_context*) /data/src/10.3/sql/sql_base.cc:1847
#8 0x56285e11d764 in open_and_process_table /data/src/10.3/sql/sql_base.cc:3730
#9 0x56285e11fd87 in open_tables(THD, DDL_options_st const&, TABLE_LIST, unsigned int, unsigned int, Prelocking_strategy*) /data/src/10.3/sql/sql_base.cc:4199
#10 0x56285e124e7f in open_and_lock_tables(THD, DDL_options_st const&, TABLE_LIST, bool, unsigned int, Prelocking_strategy*) /data/src/10.3/sql/sql_base.cc:5128
#11 0x56285e0892a7 in open_and_lock_tables(THD, TABLE_LIST, bool, unsigned int) /data/src/10.3/sql/sql_base.h:503
#12 0x56285e1e7b1b in mysql_insert(THD, TABLE_LIST, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool) /data/src/10.3/sql/sql_insert.cc:760
#13 0x56285e290473 in mysql_execute_command(THD*) /data/src/10.3/sql/sql_parse.cc:4481
#14 0x56285e2a8a81 in mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool) /data/src/10.3/sql/sql_parse.cc:7840
#15 0x56285e27f8c5 in dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool) /data/src/10.3/sql/sql_parse.cc:1852
#16 0x56285e27c3fc in do_command(THD*) /data/src/10.3/sql/sql_parse.cc:1398
#17 0x56285e646e4d in do_handle_one_connection(CONNECT*) /data/src/10.3/sql/sql_connect.cc:1403
#18 0x56285e646707 in handle_one_connection /data/src/10.3/sql/sql_connect.cc:1308
#19 0x56285fc602fa in pfs_spawn_thread /data/src/10.3/storage/perfschema/pfs.cc:1869
#20 0x7f1cd461e608 in start_thread /build/glibc-ZN95T4/glibc-2.31/nptl/pthread_create.c:477

Thread T5 created by T0 here:
#0 0x7f1cd4ab2805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
#1 0x56285fc606eb in spawn_thread_v1 /data/src/10.3/storage/perfschema/pfs.cc:1919
#2 0x56285dfa715e in inline_mysql_thread_create /data/src/10.3/include/mysql/psi/mysql_thread.h:1275
#3 0x56285dfbfb2d in create_thread_to_handle_connection(CONNECT*) /data/src/10.3/sql/mysqld.cc:6658
#4 0x56285dfc02c8 in create_new_thread /data/src/10.3/sql/mysqld.cc:6728
#5 0x56285dfc145a in handle_connections_sockets() /data/src/10.3/sql/mysqld.cc:6986
#6 0x56285dfbee1e in mysqld_main(int, char**) /data/src/10.3/sql/mysqld.cc:6280
#7 0x56285dfa595c in main /data/src/10.3/sql/main.cc:25
#8 0x7f1cd40fd0b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)

SUMMARY: AddressSanitizer: heap-buffer-overflow /data/src/10.3/sql/field.cc:6590 in Field_newdate::get_TIME(st_mysql_time, unsigned char const, unsigned long long) const
Shadow bytes around the buggy address:
0x0c3c7fffb420: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb430: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb440: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb450: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb460: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c3c7fffb470: 00 00 00 00 00 00 00 00 00 00 00 01[04]fa fa fa
0x0c3c7fffb480: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c3c7fffb490: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb4a0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb4b0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
0x0c3c7fffb4c0: 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
==2966966==ABORTING

Attachments

Issue Links

duplicates

MDEV-24583 ASAN use-after-poison in create_tmp_table or assertion failures after failed REPLACE into table with virtual/stored column

Closed

relates to

MDEV-24782 ASAN use-after-poison in Field::pack_int / THD::binlog_update_row

Closed

MDEV-24656 [FATAL] InnoDB: Data field type 0, len 0, ASAN heap-buffer-overflow upon LOAD DATA with virtual columns

Closed

ASAN errors, assertion failures, corrupt values after failed LOAD DATA into table with virtual/stored column

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration