[MDEV-29716] Server crash or ASAN errors in Protocol::valid_handler / _ma_check_print_msg - Jira

XML

Word

Printable

Details

Type: Bug
Status: Open (View Workflow)
Priority: Minor
Resolution: Unresolved
Affects Version/s: 10.5
Fix Version/s: 10.5
Component/s: Storage Engine - Aria
Labels:
- not-10.6+

Description

Set to Minor and left unassigned for now because I can only reproduce it on 10.5 including previous 10.5 releases, the use case is unlikely to be of great importance, and the failure is non-deterministic.

Run with big enough --repeat. For me it usually fails within ~20-50 attempts, but it can vary a lot depending on the build and machine. The failure is rr-able.

--source include/have_partition.inc

call mtr.add_suppression("Checking table");

call mtr.add_suppression("Recovering table");

CREATE TABLE t1 (

  c51 set('Connecticut', 'Idaho'),

  c73 decimal,

  c4 bit,

  c40 enum('Wisconsin', 'Idaho'),

  c80 decimal,

  c55 blob,

  c59 blob,

  c45 set('Idaho', 'New York'),

  c42 set('Idaho', 'Minnesota'),

  c13 int,

  c33 enum('Idaho', 'New Hampshire'),

  c82 decimal,

  c19 char(1),

  c39 enum('Idaho', 'South Carolina'),

  c58 blob,

  c61 float,

  c53 set('Idaho', 'West Virginia'),

  c75 decimal,

  c18 char(1),

  c24 char(1),

  c78 decimal,

  c6 int,

  c32 enum('Idaho', 'Arizona'),

  c67 float,

  c57 blob,

  c0 bit,

  c76 decimal,

  c34 enum('Idaho', 'Arizona'),

  c41 enum('Idaho', 'Arizona'),

  c77 decimal,

  c70 float,

  c31 enum('Idaho', 'Kansas'),

  c62 float,

  c66 float,

  c29 char(1),

  c28 char(1),

  c8 int,

  c20 char(1),

  c15 int,

  c44 set('Indiana', 'Idaho'),

  c60 float,

  c7 int,

  c35 enum('Idaho', 'New York'),

  c49 set('Idaho', 'South Dakota'),

  c25 char(1),

  c5 bit,

  c1 bit,

  c50 set('Idaho', 'Tennessee'),

  c47 set('Idaho', 'Kentucky'),

  c52 set('Idaho', 'Alabama'),

  c65 float,

  pk int auto_increment,

  c10 int,

  c14 int,

  c72 decimal,

  c69 float,

  c12 int,

  c54 blob,

  c11 int,

  c79 decimal,

  c74 decimal,

  c63 float,

  c56 blob,

  c68 float,

  c23 char(1),

  c26 char(1),

  c43 set('Idaho', 'North Dakota'),

  c38 enum('Idaho', 'Arkansas'),

  c22 char(1),

  c9 int,

  c48 set('Idaho', 'Tennessee'),

  c27 char(1),

  c46 set('Idaho', 'Kentucky'),

  c64 float,

  c17 int,

  c2 bit,

  c83 decimal,

  c81 decimal,

  c37 enum('Idaho', 'Hawaii'),

  c30 enum('Idaho', 'Alabama'),

  c21 char(1),

  c3 bit,

  c71 float,

  c36 enum('Idaho', 'Alabama'),

  c16 int,

  primary key (pk)

) ENGINE=Aria PARTITION BY key (pk) PARTITIONS 2;

INSERT INTO t1 VALUES (

  'Idaho', 9, 0, 'Idaho', 5, 'inflation', REPEAT('a',5198), 'Idaho',

  'Idaho', null, 'Idaho', 0, 't', 'Idaho', 'tremendous', null, 'Idaho',

  null, 'k', 'c', null, 1, 'Idaho', 0, 'university', null, 0, 'Idaho',

  'Idaho', 0, 3, 'Idaho', 0, 0, 't', 's', 2, 't', 4, 'Idaho', 8, 1,

  'Idaho', 'Idaho', 'n', 0, 1, 'Idaho', 'Idaho', 'Idaho', 0, NULL, null,

  1, 6, 1, null, REPEAT('b',3557), 9, null, 0, null, REPEAT('c',16111),

  2, 't', 'i', 'Idaho', 'Idaho', 'a', 1, 'Idaho', 'm', 'Idaho', 4, 0,

  null, 6, 0, 'Idaho', 'Idaho', 'n', 0, 5, 'Idaho', 6);

CREATE TABLE t2 (

 c54 blob,

 c24 char(1),

 c48 set('Florida', 'Tennessee'),

 c13 int,

 c49 set('Indiana', 'South Dakota'),

 c20 char(1),

 c69 float,

 c45 set('South Carolina', 'New York'),

 c38 enum('North Carolina', 'Georgia'),

 c70 float,

 c10 int,

 c23 char(1),

 c34 enum('Maryland', 'Arizona'),

 c18 char(1),

 c61 float,

 c4 bit,

 c15 int,

 c50 set('Oklahoma', 'Tennessee'),

 c5 bit,

 c27 char(1),

 c22 char(1),

 c12 int,

 c57 blob,

 c40 enum('Wisconsin', 'Idaho'),

 c55 blob,

 c78 decimal,

 c16 int,

 c56 blob,

 c41 enum('New York', 'Arizona'),

 c77 decimal,

 c39 enum('Tennessee', 'South Carolina'),

 c42 set('Mississippi', 'Minnesota'),

 c71 float,

 c59 blob,

 c11 int,

 c2 bit,

 c66 float,

 c46 set('South Dakota', 'Kentucky'),

 c17 int,

 c82 decimal,

 c47 set('Tennessee', 'North Dakota'),

 pk int auto_increment,

 c67 float,

 c43 set('Massachusetts', 'North Dakota'),

 c25 char(1),

 c58 blob,

 c7 int,

 c53 set('Iowa', 'West Virginia'),

 c68 float,

 c29 char(1),

 c21 char(1),

 c14 int,

 c52 set('Idaho', 'Alabama'),

 c1 bit,

 c63 float,

 c19 char(1),

 c3 bit,

 c60 float,

 c35 enum('Indiana', 'New York'),

 c9 int,

 c81 decimal,

 c83 decimal,

 c44 set('Georgia', 'Florida'),

 c33 enum('Maryland', 'New Hampshire'),

 c79 decimal,

 c26 char(1),

 c31 enum('Maryland', 'Kansas'),

 key (c71),

 primary key (pk)

) ENGINE=Aria;

CREATE TABLE t3 LIKE t2;

--connect (con1,localhost,root,,test)

CREATE TEMPORARY TABLE tmp AS SELECT * FROM t1;

--connection default

--send

  INSERT INTO t2 SELECT * FROM t3;

--connection con1

TRUNCATE t1;

INSERT INTO t1 SELECT * FROM tmp;

--connection default

--reap

TRUNCATE t1;

# Cleanup

DROP TABLE t1, t2, t3;

--disconnect con1

10.5 2154a1fc
==595350==ERROR: AddressSanitizer: use-after-poison on address 0x62b0000a71f8 at pc 0x558dfc4e6a12 bp 0x7f0c7d109890 sp 0x7f0c7d109888
READ of size 8 at 0x62b0000a71f8 thread T6
#0 0x558dfc4e6a11 in Protocol::valid_handler(unsigned int, protocol_send_type_t) const (/mnt8t/bld/10.5-asan-nightly/bin/mariadbd+0x17b5a11)
#1 0x558dfc4df2fa in Protocol_text::store_str(char const, unsigned long, charset_info_st const, charset_info_st const*) /data/src/10.5/sql/protocol.cc:1225
#2 0x558dfc4e6d32 in Protocol::store(char const, unsigned long, charset_info_st const) /data/src/10.5/sql/protocol.h:150
#3 0x558dfd5570f5 in _ma_check_print_msg /data/src/10.5/storage/maria/ha_maria.cc:472
#4 0x558dfd55c5a8 in _ma_check_print_info /data/src/10.5/storage/maria/ha_maria.cc:929
#5 0x558dfd56153c in ha_maria::repair(THD, st_ha_check_opt) /data/src/10.5/storage/maria/ha_maria.cc:1482
#6 0x558dfd568a05 in ha_maria::check_and_repair(THD*) /data/src/10.5/storage/maria/ha_maria.cc:2388
#7 0x558dfcfbcf54 in handler::ha_check_and_repair(THD*) /data/src/10.5/sql/handler.cc:4826
#8 0x558dfd79bcf7 in ha_partition::check_and_repair(THD*) /data/src/10.5/sql/ha_partition.cc:1601
#9 0x558dfcfbcf54 in handler::ha_check_and_repair(THD*) /data/src/10.5/sql/handler.cc:4826
#10 0x558dfc615376 in auto_repair_table /data/src/10.5/sql/sql_base.cc:3026
#11 0x558dfc616181 in Open_table_context::recover_from_failed_open() /data/src/10.5/sql/sql_base.cc:3238
#12 0x558dfc61b7cc in open_tables(THD, DDL_options_st const&, TABLE_LIST, unsigned int, unsigned int, Prelocking_strategy*) /data/src/10.5/sql/sql_base.cc:4320
#13 0x558dfc62079a in open_and_lock_tables(THD, DDL_options_st const&, TABLE_LIST, bool, unsigned int, Prelocking_strategy*) /data/src/10.5/sql/sql_base.cc:5237
#14 0x558dfc579ab4 in open_and_lock_tables(THD, TABLE_LIST, bool, unsigned int) /data/src/10.5/sql/sql_base.h:507
#15 0x558dfcc651d5 in Sql_cmd_truncate_table::handler_truncate(THD, TABLE_LIST, bool) /data/src/10.5/sql/sql_truncate.cc:230
#16 0x558dfcc66e69 in Sql_cmd_truncate_table::truncate_table(THD, TABLE_LIST) /data/src/10.5/sql/sql_truncate.cc:475
#17 0x558dfcc67479 in Sql_cmd_truncate_table::execute(THD*) /data/src/10.5/sql/sql_truncate.cc:540
#18 0x558dfc7bbf3a in mysql_execute_command(THD*) /data/src/10.5/sql/sql_parse.cc:6057
#19 0x558dfc7c9201 in mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool) /data/src/10.5/sql/sql_parse.cc:8087
#20 0x558dfc79f8cb in dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool) /data/src/10.5/sql/sql_parse.cc:1891
#21 0x558dfc79c2e8 in do_command(THD*) /data/src/10.5/sql/sql_parse.cc:1375
#22 0x558dfcbd76c0 in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1416
#23 0x558dfcbd705d in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1318
#24 0x558dfd7fbf21 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
#25 0x7f0c875abea6 in start_thread nptl/pthread_create.c:477
#26 0x7f0c87198aee in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xfcaee)

0x62b0000a71f8 is located 24568 bytes inside of 24624-byte region [0x62b0000a1200,0x62b0000a7230)
allocated by thread T6 here:
#0 0x7f0c87b40e8f in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:145
#1 0x558dfe411718 in my_malloc /data/src/10.5/mysys/my_malloc.c:90
#2 0x558dfe3edaac in reset_root_defaults /data/src/10.5/mysys/my_alloc.c:148
#3 0x558dfc67b312 in THD::init_for_queries() /data/src/10.5/sql/sql_class.cc:1400
#4 0x558dfcbd69ad in prepare_new_connection_state(THD*) /data/src/10.5/sql/sql_connect.cc:1246
#5 0x558dfcbd70d8 in thd_prepare_connection(THD*) /data/src/10.5/sql/sql_connect.cc:1339
#6 0x558dfcbd75ee in do_handle_one_connection(CONNECT*, bool) /data/src/10.5/sql/sql_connect.cc:1406
#7 0x558dfcbd705d in handle_one_connection /data/src/10.5/sql/sql_connect.cc:1318
#8 0x558dfd7fbf21 in pfs_spawn_thread /data/src/10.5/storage/perfschema/pfs.cc:2201
#9 0x7f0c875abea6 in start_thread nptl/pthread_create.c:477

Thread T6 created by T0 here:
#0 0x7f0c87aec2a2 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cpp:214
#1 0x558dfd7f7c82 in my_thread_create /data/src/10.5/storage/perfschema/my_thread.h:52
#2 0x558dfd7fc310 in pfs_spawn_thread_v1 /data/src/10.5/storage/perfschema/pfs.cc:2252
#3 0x558dfc49cd54 in inline_mysql_thread_create /data/src/10.5/include/mysql/psi/mysql_thread.h:1323
#4 0x558dfc4b2965 in create_thread_to_handle_connection(CONNECT*) /data/src/10.5/sql/mysqld.cc:6058
#5 0x558dfc4b2fae in create_new_thread(CONNECT*) /data/src/10.5/sql/mysqld.cc:6117
#6 0x558dfc4b32e0 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /data/src/10.5/sql/mysqld.cc:6182
#7 0x558dfc4b3eb5 in handle_connections_sockets() /data/src/10.5/sql/mysqld.cc:6309
#8 0x558dfc4b21d4 in mysqld_main(int, char**) /data/src/10.5/sql/mysqld.cc:5704
#9 0x558dfc49b8f4 in main /data/src/10.5/sql/main.cc:25
#10 0x7f0c870bfd09 in __libc_start_main ../csu/libc-start.c:308

SUMMARY: AddressSanitizer: use-after-poison (/mnt8t/bld/10.5-asan-nightly/bin/mariadbd+0x17b5a11) in Protocol::valid_handler(unsigned int, protocol_send_type_t) const
Shadow bytes around the buggy address:
0x0c568000cde0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
0x0c568000cdf0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
0x0c568000ce00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
0x0c568000ce10: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
0x0c568000ce20: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
=>0x0c568000ce30: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]
0x0c568000ce40: f7 f7 f7 f7 f7 f7 fa fa fa fa fa fa fa fa fa fa
0x0c568000ce50: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c568000ce60: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c568000ce70: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
0x0c568000ce80: 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
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
==595350==ABORTING
221005 23:48:06 [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.5.18-MariaDB-debug-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=2
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63761 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x62b00009a218
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 = 0x7f0c7d10cc70 thread_stack 0x100000
sanitizer_common/sanitizer_common_interceptors.inc:4101(__interceptor_backtrace.part.0)[0x7f0c87adadf1]
mysys/stacktrace.c:212(my_print_stacktrace)[0x558dfe42139a]
sql/signal_handler.cc:235(handle_fatal_signal)[0x558dfcf92716]
sigaction.c:0(__restore_rt)[0x7f0c875b7140]
linux/raise.c:51(__GI_raise)[0x7f0c870d4ce1]
stdlib/abort.c:81(__GI_abort)[0x7f0c870be537]
sanitizer_common/sanitizer_posix_libcdep.cpp:149(__sanitizer::Abort())[0x7f0c87b5c11b]
sanitizer_common/sanitizer_termination.cpp:59(__sanitizer::Die())[0x7f0c87b66ce8]
asan/asan_report.cpp:186(__asan::ScopedInErrorReport::~ScopedInErrorReport())[0x7f0c87b4944c]
asan/asan_report.cpp:474(__asan::ReportGenericError(unsigned long, unsigned long, unsigned long, unsigned long, bool, unsigned long, unsigned int, bool))[0x7f0c87b48d47]
asan/asan_rtl.cpp:120(__asan_report_load8)[0x7f0c87b49938]
sql/protocol.h:49(Protocol::valid_handler(unsigned int, protocol_send_type_t) const)[0x558dfc4e6a12]
sql/protocol.cc:1225(Protocol_text::store_str(char const, unsigned long, charset_info_st const, charset_info_st const*))[0x558dfc4df2fb]
sql/protocol.h:151(Protocol::store(char const, unsigned long, charset_info_st const))[0x558dfc4e6d33]
maria/ha_maria.cc:473(_ma_check_print_msg(st_handler_check_param, char const, char const, __va_list_tag))[0x558dfd5570f6]
maria/ha_maria.cc:931(_ma_check_print_info)[0x558dfd55c5a9]
maria/ha_maria.cc:1483(ha_maria::repair(THD, st_ha_check_opt))[0x558dfd56153d]
maria/ha_maria.cc:2388(ha_maria::check_and_repair(THD*))[0x558dfd568a06]
sql/handler.cc:4827(handler::ha_check_and_repair(THD*))[0x558dfcfbcf55]
sql/ha_partition.cc:1601(ha_partition::check_and_repair(THD*))[0x558dfd79bcf8]
sql/handler.cc:4827(handler::ha_check_and_repair(THD*))[0x558dfcfbcf55]
sql/sql_base.cc:3026(auto_repair_table(THD, TABLE_LIST))[0x558dfc615377]
sql/sql_base.cc:3238(Open_table_context::recover_from_failed_open())[0x558dfc616182]
sql/sql_base.cc:4320(open_tables(THD, DDL_options_st const&, TABLE_LIST, unsigned int, unsigned int, Prelocking_strategy*))[0x558dfc61b7cd]
sql/sql_base.cc:5237(open_and_lock_tables(THD, DDL_options_st const&, TABLE_LIST, bool, unsigned int, Prelocking_strategy*))[0x558dfc62079b]
sql/sql_base.h:507(open_and_lock_tables(THD, TABLE_LIST, bool, unsigned int))[0x558dfc579ab5]
sql/sql_truncate.cc:230(Sql_cmd_truncate_table::handler_truncate(THD, TABLE_LIST, bool))[0x558dfcc651d6]
sql/sql_truncate.cc:475(Sql_cmd_truncate_table::truncate_table(THD, TABLE_LIST))[0x558dfcc66e6a]
sql/sql_truncate.cc:540(Sql_cmd_truncate_table::execute(THD*))[0x558dfcc6747a]
sql/sql_parse.cc:6057(mysql_execute_command(THD*))[0x558dfc7bbf3b]
sql/sql_parse.cc:8087(mysql_parse(THD, char, unsigned int, Parser_state*, bool, bool))[0x558dfc7c9202]
sql/sql_parse.cc:1894(dispatch_command(enum_server_command, THD, char, unsigned int, bool, bool))[0x558dfc79f8cc]
sql/sql_parse.cc:1375(do_command(THD*))[0x558dfc79c2e9]
sql/sql_connect.cc:1416(do_handle_one_connection(CONNECT*, bool))[0x558dfcbd76c1]
sql/sql_connect.cc:1320(handle_one_connection)[0x558dfcbd705e]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x558dfd7fbf22]
nptl/pthread_create.c:478(start_thread)[0x7f0c875abea7]
x86_64/clone.S:97(__GI___clone)[0x7f0c87198aef]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x61b00009ec4d): t1

Connection ID (thread ID): 269
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_pTQO/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 385880 385880 processes
Max open files 1024 1024 files
Max locked memory 12659543552 12659543552 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 385880 385880 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

Kernel version: Linux version 5.10.0-18-amd64 (debian-kernel@lists.debian.org) (gcc-10 (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Debian 5.10.140-1 (2022-09-02)

Attachments

Activity

People

Assignee:: Unassigned

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 1 Start watching this issue

Dates

Created:: 2022-10-05 20:55

Updated:: 2022-10-05 20:56

Git Integration

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