[MDEV-28886] heap-use-after-free in DDL error handling - Jira

XML

Word

Printable

Details

Type: Bug
Status: Confirmed (View Workflow)
Priority: Major
Resolution: Unresolved
Affects Version/s: 10.6, 10.5(EOL), 10.7(EOL), 10.8(EOL), 10.9(EOL)
Fix Version/s: 10.11, 11.4, 11.8
Component/s: Data Definition - Alter Table, Locking, Partitioning, Storage Engine - InnoDB
Labels:
- ASAN
- heap-use-after-free

Description

Contrary to its appearance, the test case is quite non-deterministic. It fails with different probability and with different errors depending on the version and build. Run with --repeat=N. Sometimes the first error causes further effects, some of which are shown below.

On 10.5 the issue appeared after this commit:

commit ea37b144094a0c2ebfc6774047fd473c1b2a8658

Author: Marko Mäkelä

Date:   Tue Dec 10 15:42:50 2019 +0200

    MDEV-16678 Prefer MDL to dict_sys.latch for innodb background tasks

--source include/have_innodb.inc

--source include/have_partition.inc

CREATE TABLE t (a INT, b INT) ENGINE=InnoDB PARTITION BY KEY(b) PARTITIONS 2;

INSERT INTO t VALUES (0,9),(1,8),(2,7),(3,6),(4,5),(5,4),(6,3),(7,2),(8,1),(9,0);

ALTER TABLE t NOWAIT REBUILD PARTITION p0;

ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;

DROP TABLE t;

10.5 debug builds usually fail for me like this:

10.5 674842be
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
mysqltest: At line 8: query 'ALTER TABLE t NOWAIT TRUNCATE PARTITION p0' failed: 1205: Lock wait timeout exceeded; try restarting transaction

10.6 more often fails on the first ALTER already:

10.6 0e4cf497
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
mysqltest: At line 7: query 'ALTER TABLE t NOWAIT REBUILD PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
DROP TABLE t;

or on both:

CREATE TABLE t (a INT, b INT) ENGINE=InnoDB PARTITION BY KEY(b) PARTITIONS 2;

INSERT INTO t VALUES (0,9),(1,8),(2,7),(3,6),(4,5),(5,4),(6,3),(7,2),(8,1),(9,0);

ALTER TABLE t NOWAIT REBUILD PARTITION p0;

mysqltest: At line 7: query 'ALTER TABLE t NOWAIT REBUILD PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction

ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;

mysqltest: At line 8: query 'ALTER TABLE t NOWAIT TRUNCATE PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction

DROP TABLE t;

10.8 adds more variety. It must be coming from the per-partition options, but for now I will consider it all side-effects of the same problem:

10.8 cb19e211
ALTER TABLE t NOWAIT REBUILD PARTITION p0;
mysqltest: At line 7: query 'ALTER TABLE t NOWAIT REBUILD PARTITION p0' failed: ER_LOCK_WAIT_TIMEOUT (1205): Lock wait timeout exceeded; try restarting transaction
ALTER TABLE t NOWAIT TRUNCATE PARTITION p0;
mysqltest: At line 8: query 'ALTER TABLE t NOWAIT TRUNCATE PARTITION p0' failed: ER_GET_ERRNO (1030): Got error 140 "Wrong create options" from storage engine InnoDB
SHOW WARNINGS;
Level Code Message
Warning 140 InnoDB: invalid PAGE_COMPRESSION_LEVEL = 11936128518282651045. Valid values are [1, 2, 3, 4, 5, 6, 7, 8, 9]
Error 1030 Got error 140 "Wrong create options" from storage engine InnoDB
DROP TABLE t;

10.8 cb19e211 ASAN
==1726155==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0000b75bc at pc 0x557d30ea37c3 bp 0x7f3d25931800 sp 0x7f3d259317f8
READ of size 4 at 0x61d0000b75bc thread T11
#0 0x557d30ea37c2 in create_table_info_t::check_table_options() /data/src/10.8/storage/innobase/handler/ha_innodb.cc:11249
#1 0x557d30ef07ad in create_table_info_t::prepare_create_table(char const*, bool) /data/src/10.8/storage/innobase/handler/ha_innodb.cc:12020
#2 0x557d30ef07ad in ha_innobase::create(char const, TABLE, HA_CREATE_INFO, bool, trx_t) /data/src/10.8/storage/innobase/handler/ha_innodb.cc:13194
#3 0x557d30edfaaf in ha_innobase::truncate() /data/src/10.8/storage/innobase/handler/ha_innodb.cc:13962
#4 0x557d30c91ab1 in ha_partition::truncate_partition(Alter_info, bool) /data/src/10.8/sql/ha_partition.cc:4918
#5 0x557d301e2060 in Sql_cmd_alter_table_truncate_partition::execute(THD*) /data/src/10.8/sql/sql_partition_admin.cc:958
#6 0x557d2fe07c07 in mysql_execute_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:5988
#7 0x557d2fe14c0a in mysql_parse(THD, char, unsigned int, Parser_state*) /data/src/10.8/sql/sql_parse.cc:8027
#8 0x557d2fe1a274 in dispatch_command(enum_server_command, THD, char, unsigned int, bool) /data/src/10.8/sql/sql_parse.cc:1894
#9 0x557d2fe1fc75 in do_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:1407
#10 0x557d301da83d in do_handle_one_connection(CONNECT*, bool) /data/src/10.8/sql/sql_connect.cc:1418
#11 0x557d301dad7c in handle_one_connection /data/src/10.8/sql/sql_connect.cc:1312
#12 0x557d30cb3a6b in pfs_spawn_thread /data/src/10.8/storage/perfschema/pfs.cc:2201
#13 0x7f3d344faea6 in start_thread nptl/pthread_create.c:477
#14 0x7f3d340f9dee in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xfddee)

0x61d0000b75bc is located 828 bytes inside of 2064-byte region [0x61d0000b7280,0x61d0000b7a90)
freed by thread T11 here:
#0 0x7f3d34a00b6f in __interceptor_free ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:123
#1 0x557d315a3454 in root_free /data/src/10.8/mysys/my_alloc.c:78
#2 0x557d315a3454 in free_root /data/src/10.8/mysys/my_alloc.c:501
#3 0x557d301240e9 in closefrm(TABLE*) /data/src/10.8/sql/table.cc:4540
#4 0x557d30402a1f in intern_close_table /data/src/10.8/sql/table_cache.cc:220
#5 0x557d30402a1f in tc_remove_table /data/src/10.8/sql/table_cache.cc:258
#6 0x557d2fe2e505 in handle_alter_part_error /data/src/10.8/sql/sql_partition.cc:7073
#7 0x557d2fe4c5be in fast_alter_partition_table(THD, TABLE, Alter_info, Alter_table_ctx, HA_CREATE_INFO, TABLE_LIST) /data/src/10.8/sql/sql_partition.cc:7773
#8 0x557d30091285 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, bool) /data/src/10.8/sql/sql_table.cc:10408
#9 0x557d301eca63 in Sql_cmd_alter_table::execute(THD*) /data/src/10.8/sql/sql_alter.cc:547
#10 0x557d2fe07c07 in mysql_execute_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:5988
#11 0x557d2fe14c0a in mysql_parse(THD, char, unsigned int, Parser_state*) /data/src/10.8/sql/sql_parse.cc:8027
#12 0x557d2fe1a274 in dispatch_command(enum_server_command, THD, char, unsigned int, bool) /data/src/10.8/sql/sql_parse.cc:1894
#13 0x557d2fe1fc75 in do_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:1407
#14 0x557d301da83d in do_handle_one_connection(CONNECT*, bool) /data/src/10.8/sql/sql_connect.cc:1418
#15 0x557d301dad7c in handle_one_connection /data/src/10.8/sql/sql_connect.cc:1312
#16 0x557d30cb3a6b in pfs_spawn_thread /data/src/10.8/storage/perfschema/pfs.cc:2201
#17 0x7f3d344faea6 in start_thread nptl/pthread_create.c:477

previously allocated by thread T11 here:
#0 0x7f3d34a00e8f in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:145
#1 0x557d315b5968 in my_malloc /data/src/10.8/mysys/my_malloc.c:90
#2 0x557d315a2b45 in alloc_root /data/src/10.8/mysys/my_alloc.c:332
#3 0x557d2fe3eb33 in Sql_alloc::operator new(unsigned long) /data/src/10.8/sql/sql_alloc.h:28
#4 0x557d2fe3eb33 in mysql_unpack_partition(THD, char, unsigned int, TABLE, bool, handlerton, bool*) /data/src/10.8/sql/sql_partition.cc:4428
#5 0x557d30147545 in open_table_from_share(THD, TABLE_SHARE, st_mysql_const_lex_string const, unsigned int, unsigned int, unsigned int, TABLE, bool, List<String>*) /data/src/10.8/sql/table.cc:4312
#6 0x557d2fc8d0c5 in open_table(THD, TABLE_LIST, Open_table_context*) /data/src/10.8/sql/sql_base.cc:2016
#7 0x557d2fc963c1 in open_and_process_table /data/src/10.8/sql/sql_base.cc:3826
#8 0x557d2fc963c1 in open_tables(THD, DDL_options_st const&, TABLE_LIST, unsigned int, unsigned int, Prelocking_strategy*) /data/src/10.8/sql/sql_base.cc:4309
#9 0x557d2fc9802e in open_and_lock_tables(THD, DDL_options_st const&, TABLE_LIST, bool, unsigned int, Prelocking_strategy*) /data/src/10.8/sql/sql_base.cc:5282
#10 0x557d2fd4fd7a in open_and_lock_tables(THD, TABLE_LIST, bool, unsigned int) /data/src/10.8/sql/sql_base.h:509
#11 0x557d2fd4fd7a in mysql_insert(THD, TABLE_LIST, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool, select_result*) /data/src/10.8/sql/sql_insert.cc:758
#12 0x557d2fe093dd in mysql_execute_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:4562
#13 0x557d2fe14c0a in mysql_parse(THD, char, unsigned int, Parser_state*) /data/src/10.8/sql/sql_parse.cc:8027
#14 0x557d2fe1a274 in dispatch_command(enum_server_command, THD, char, unsigned int, bool) /data/src/10.8/sql/sql_parse.cc:1894
#15 0x557d2fe1fc75 in do_command(THD*, bool) /data/src/10.8/sql/sql_parse.cc:1407
#16 0x557d301da83d in do_handle_one_connection(CONNECT*, bool) /data/src/10.8/sql/sql_connect.cc:1418
#17 0x557d301dad7c in handle_one_connection /data/src/10.8/sql/sql_connect.cc:1312
#18 0x557d30cb3a6b in pfs_spawn_thread /data/src/10.8/storage/perfschema/pfs.cc:2201
#19 0x7f3d344faea6 in start_thread nptl/pthread_create.c:477

Thread T11 created by T0 here:
#0 0x7f3d349ac2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
#1 0x557d30cb3ce9 in my_thread_create /data/src/10.8/storage/perfschema/my_thread.h:52
#2 0x557d30cb3ce9 in pfs_spawn_thread_v1 /data/src/10.8/storage/perfschema/pfs.cc:2252
#3 0x557d2fae56ad in inline_mysql_thread_create /data/src/10.8/include/mysql/psi/mysql_thread.h:1139
#4 0x557d2fae56ad in create_thread_to_handle_connection(CONNECT*) /data/src/10.8/sql/mysqld.cc:6014
#5 0x557d2faf1447 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.8/sql/mysqld.cc:6135
#6 0x557d2faf1fbf in handle_connections_sockets() /data/src/10.8/sql/mysqld.cc:6259
#7 0x557d2faf38d0 in mysqld_main(int, char**) /data/src/10.8/sql/mysqld.cc:5909
#8 0x7f3d34022d09 in __libc_start_main ../csu/libc-start.c:308

SUMMARY: AddressSanitizer: heap-use-after-free /data/src/10.8/storage/innobase/handler/ha_innodb.cc:11249 in create_table_info_t::check_table_options()
Shadow bytes around the buggy address:
0x0c3a8000ee60: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000ee70: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000ee80: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000ee90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000eea0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
=>0x0c3a8000eeb0: fd fd fd fd fd fd fd[fd]fd fd fd fd fd fd fd fd
0x0c3a8000eec0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000eed0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000eee0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000eef0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
0x0c3a8000ef00: fd fd fd fd fd fd fd fd fd fd fd fd 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
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
==1726155==ABORTING
220619 1:48:36 [ERROR] mysqld got signal 6 ;
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.8.4-MariaDB-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63773 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x62b00017a218
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 = 0x7f3d25934990 thread_stack 0x5fc00
sanitizer_common/sanitizer_common_interceptors.inc:4101(__interceptor_backtrace.part.0)[0x7f3d3499adf1]
mysys/stacktrace.c:213(my_print_stacktrace)[0x557d315be436]
sql/signal_handler.cc:223(handle_fatal_signal)[0x557d3056af44]
sigaction.c:0(__restore_rt)[0x7f3d34506140]
linux/raise.c:51(__GI_raise)[0x7f3d34037ce1]
stdlib/abort.c:81(__GI_abort)[0x7f3d34021537]
sanitizer_common/sanitizer_posix_libcdep.cpp:149(__sanitizer::Abort())[0x7f3d34a1c11b]
sanitizer_common/sanitizer_termination.cpp:59(__sanitizer::Die())[0x7f3d34a26ce8]
asan/asan_report.cpp:186(__asan::ScopedInErrorReport::~ScopedInErrorReport())[0x7f3d34a0944c]
asan/asan_report.cpp:474(__asan::ReportGenericError(unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long, unsigned int, bool))[0x7f3d34a08d47]
asan/asan_rtl.cpp:119(__asan_report_load4)[0x7f3d34a098a8]
handler/ha_innodb.cc:11314(create_table_info_t::check_table_options())[0x557d30ea37c3]
handler/ha_innodb.cc:12020(create_table_info_t::prepare_create_table(char const*, bool))[0x557d30ef07ae]
handler/ha_innodb.cc:13965(ha_innobase::truncate())[0x557d30edfab0]
sql/ha_partition.cc:4920(ha_partition::truncate_partition(Alter_info, bool))[0x557d30c91ab2]
sql/sql_partition_admin.cc:958(Sql_cmd_alter_table_truncate_partition::execute(THD*))[0x557d301e2061]
sql/sql_parse.cc:5988(mysql_execute_command(THD*, bool))[0x557d2fe07c08]
sql/sql_parse.cc:8044(mysql_parse(THD, char, unsigned int, Parser_state*))[0x557d2fe14c0b]
sql/sql_parse.cc:1896(dispatch_command(enum_server_command, THD, char, unsigned int, bool))[0x557d2fe1a275]
sql/sql_parse.cc:1409(do_command(THD*, bool))[0x557d2fe1fc76]
sql/sql_connect.cc:1418(do_handle_one_connection(CONNECT*, bool))[0x557d301da83e]
sql/sql_connect.cc:1312(handle_one_connection)[0x557d301dad7d]
perfschema/pfs.cc:2204(pfs_spawn_thread)[0x557d30cb3a6c]
nptl/pthread_create.c:478(start_thread)[0x7f3d344faea7]
x86_64/clone.S:97(__GI___clone)[0x7f3d340f9def]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x6290000b9238): ALTER TABLE t NOWAIT TRUNCATE PARTITION p0

Connection ID (thread ID): 4
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=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on,not_null_range_scan=off

The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
information that should help you find out what is causing the crash.
Writing a core file...
Working directory at /dev/shm/var_auto_oY1f/mysqld.1/data
Resource Limits:
Limit Soft Limit Hard Limit Units
Max cpu time unlimited unlimited seconds
Max file size unlimited unlimited bytes
Max data size unlimited unlimited bytes
Max stack size 8388608 unlimited bytes
Max core file size unlimited unlimited bytes
Max resident set unlimited unlimited bytes
Max processes 385885 385885 processes
Max open files 1024 1024 files
Max locked memory 12659513344 12659513344 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 385885 385885 signals
Max msgqueue size 819200 819200 bytes
Max nice priority 0 0
Max realtime priority 0 0
Max realtime timeout unlimited unlimited us
Core pattern: core

Attachments

Activity

People

Assignee:: Oleksandr Byelkin

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: 2022-06-18 22:51

Updated:: 2025-06-04 10:03

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.