[MDEV-32640] ASAN heap-use-after-free when running second execution of PS to view relay log events after setting default_master_connection Created: 2023-11-01  Updated: 2024-02-07

Status: In Review
Project: MariaDB Server
Component/s: Prepared Statements
Affects Version/s: 11.3
Fix Version/s: 11.3

Type: Bug Priority: Critical
Reporter: Ramesh Sivaraman Assignee: Sergei Golubchik
Resolution: Unresolved Votes: 0
Labels: regression


 Description    

PREPARE s_1 FROM 'SHOW RELAYLOG EVENTS';
 
SET default_master_connection='MASTER';
 
EXECUTE s_1;
 
SET default_master_connection='MASTER';
 
EXECUTE s_1;

Leads to:

11.3.0 126157061b4376496c034a809ea4943e863d1465 (Optimized)

 
==1082493==ERROR: AddressSanitizer: heap-use-after-free on address 0x603000019108 at pc 0x558d608e721a bp 0x14a6cd7e3e20 sp 0x14a6cd7e3e10
 
READ of size 1 at 0x603000016198 thread T12
 
    #0 0x55f1d72a7219 in my_mb_wc_utf8mb3_quick /test/11.3_opt_san/strings/ctype-utf8.h:102
 
    #1 0x55f1d72a7219 in my_utf8mb3_uni /test/11.3_opt_san/strings/ctype-utf8.c:564
 
    #2 0x55f1d72a7219 in my_casedn_utf8mb3 /test/11.3_opt_san/strings/ctype-utf8.c:760
 
    #3 0x55f1d3cf7e16 in CharBuffer<192ul>::copy_casedn(charset_info_st const*, st_mysql_const_lex_string const&) /test/11.3_opt_san/sql/char_buffer.h:65
 
    #4 0x55f1d3cf7e16 in IdentBuffer<192ul>::copy_casedn(st_mysql_const_lex_string const&) /test/11.3_opt_san/sql/lex_ident.h:109
 
    #5 0x55f1d3cf7e16 in IdentBufferCasedn<192ul>::IdentBufferCasedn(st_mysql_const_lex_string const&) /test/11.3_opt_san/sql/lex_ident.h:121
 
    #6 0x55f1d3cf7e16 in Master_info_index::get_master_info(st_mysql_const_lex_string const*, Sql_state_errno_level::enum_warning_level) /test/11.3_opt_san/sql/rpl_mi.cc:1378
 
    #7 0x55f1d3cf8387 in get_master_info(st_mysql_const_lex_string const*, Sql_state_errno_level::enum_warning_level) /test/11.3_opt_san/sql/rpl_mi.cc:1324
 
    #8 0x55f1d353049a in mysql_show_binlog_events(THD*) /test/11.3_opt_san/sql/sql_repl.cc:4178
 
    #9 0x55f1d33e8311 in mysql_execute_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:4041
 
    #10 0x55f1d34e8152 in Prepared_statement::execute(String*, bool) /test/11.3_opt_san/sql/sql_prepare.cc:5071
 
    #11 0x55f1d34eae78 in Prepared_statement::execute_loop(String*, bool, unsigned char*, unsigned char*) /test/11.3_opt_san/sql/sql_prepare.cc:4455
 
    #12 0x55f1d34ed4bb in mysql_sql_stmt_execute(THD*) /test/11.3_opt_san/sql/sql_prepare.cc:3480
 
    #13 0x55f1d33ec1ce in mysql_execute_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:3939
 
    #14 0x55f1d3371bd0 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/11.3_opt_san/sql/sql_parse.cc:7742
 
    #15 0x55f1d33c8cb8 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/11.3_opt_san/sql/sql_parse.cc:1893
 
    #16 0x55f1d33d451d in do_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:1406
 
    #17 0x55f1d3d2547d in do_handle_one_connection(CONNECT*, bool) /test/11.3_opt_san/sql/sql_connect.cc:1418
 
    #18 0x55f1d3d27aec in handle_one_connection /test/11.3_opt_san/sql/sql_connect.cc:1320
 
    #19 0x1473249d0608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
    #20 0x147323c45132 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f132)
 
 
 
0x603000016198 is located 24 bytes inside of 32-byte region [0x603000016180,0x6030000161a0)
 
freed by thread T12 here:
 
    #0 0x55f1d2b4d9df in __interceptor_free (/test/UBASAN_MD311023-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7d539df)
 
    #1 0x55f1d3e0fe29 in Sys_var_charptr::session_update(THD*, set_var*) /test/11.3_opt_san/sql/sys_vars.inl:597
 
    #2 0x55f1d3e0fe29 in Sys_var_lexstring::session_update(THD*, set_var*) /test/11.3_opt_san/sql/sys_vars.inl:900
 
    #3 0x55f1d2d97991 in sys_var::update(THD*, set_var*) /test/11.3_opt_san/sql/set_var.cc:212
 
    #4 0x55f1d2d9b3d1 in set_var::update(THD*) /test/11.3_opt_san/sql/set_var.cc:851
 
    #5 0x55f1d2da3879 in sql_set_variables(THD*, List<set_var_base>*, bool) /test/11.3_opt_san/sql/set_var.cc:733
 
    #6 0x55f1d33e8c7f in mysql_execute_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:4782
 
    #7 0x55f1d3371bd0 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/11.3_opt_san/sql/sql_parse.cc:7742
 
    #8 0x55f1d33c8cb8 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/11.3_opt_san/sql/sql_parse.cc:1893
 
    #9 0x55f1d33d451d in do_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:1406
 
    #10 0x55f1d3d2547d in do_handle_one_connection(CONNECT*, bool) /test/11.3_opt_san/sql/sql_connect.cc:1418
 
    #11 0x55f1d3d27aec in handle_one_connection /test/11.3_opt_san/sql/sql_connect.cc:1320
 
    #12 0x1473249d0608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
previously allocated by thread T12 here:
 
    #0 0x55f1d2b4ddd8 in __interceptor_malloc (/test/UBASAN_MD311023-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7d53dd8)
 
    #1 0x55f1d70804d4 in my_malloc /test/11.3_opt_san/mysys/my_malloc.c:93
 
    #2 0x55f1d7080c12 in my_memdup /test/11.3_opt_san/mysys/my_malloc.c:231
 
    #3 0x55f1d3e0fceb in Sys_var_charptr::update_prepare(set_var*, unsigned long) /test/11.3_opt_san/sql/sys_vars.inl:585
 
    #4 0x55f1d3e0fceb in Sys_var_charptr::session_update(THD*, set_var*) /test/11.3_opt_san/sql/sys_vars.inl:596
 
    #5 0x55f1d3e0fceb in Sys_var_lexstring::session_update(THD*, set_var*) /test/11.3_opt_san/sql/sys_vars.inl:900
 
    #6 0x55f1d2d97991 in sys_var::update(THD*, set_var*) /test/11.3_opt_san/sql/set_var.cc:212
 
    #7 0x55f1d2d9b3d1 in set_var::update(THD*) /test/11.3_opt_san/sql/set_var.cc:851
 
    #8 0x55f1d2da3879 in sql_set_variables(THD*, List<set_var_base>*, bool) /test/11.3_opt_san/sql/set_var.cc:733
 
    #9 0x55f1d33e8c7f in mysql_execute_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:4782
 
    #10 0x55f1d3371bd0 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/11.3_opt_san/sql/sql_parse.cc:7742
 
    #11 0x55f1d33c8cb8 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/11.3_opt_san/sql/sql_parse.cc:1893
 
    #12 0x55f1d33d451d in do_command(THD*, bool) /test/11.3_opt_san/sql/sql_parse.cc:1406
 
    #13 0x55f1d3d2547d in do_handle_one_connection(CONNECT*, bool) /test/11.3_opt_san/sql/sql_connect.cc:1418
 
    #14 0x55f1d3d27aec in handle_one_connection /test/11.3_opt_san/sql/sql_connect.cc:1320
 
    #15 0x1473249d0608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T12 created by T0 here:
 
    #0 0x55f1d2a7ae15 in __interceptor_pthread_create (/test/UBASAN_MD311023-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7c80e15)
 
    #1 0x55f1d2b9e9c3 in create_thread_to_handle_connection(CONNECT*) /test/11.3_opt_san/sql/mysqld.cc:6152
 
    #2 0x55f1d2bb00bf in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /test/11.3_opt_san/sql/mysqld.cc:6276
 
    #3 0x55f1d2bb10d7 in handle_connections_sockets() /test/11.3_opt_san/sql/mysqld.cc:6400
 
    #4 0x55f1d2bb406c in mysqld_main(int, char**) /test/11.3_opt_san/sql/mysqld.cc:6047
 
    #5 0x147323b4a082 in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /test/11.3_opt_san/strings/ctype-utf8.h:102 in my_mb_wc_utf8mb3_quick

Setup:

Compiled with GCC >=7.5.0 (I use GCC 11.4.0) and:
 
    -DWITH_ASAN=ON -DWITH_ASAN_SCOPE=ON -DWITH_UBSAN=ON -DWSREP_LIB_WITH_ASAN=ON
 
Set before execution:
 
    export ASAN_OPTIONS=quarantine_size_mb=512:atexit=0:detect_invalid_pointer_pairs=3:dump_instruction_bytes=1:abort_on_error=1:allocator_may_return_null=1

Bug confirmed present in:
MariaDB: 11.3.0 (dbg), 11.3.0 (opt)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.4.32 (dbg), 10.4.32 (opt), 10.5.23 (dbg), 10.5.23 (opt), 10.6.16 (dbg), 10.6.16 (opt), 10.9.8 (dbg), 10.9.8 (opt), 10.10.7 (dbg), 10.10.7 (opt), 10.11.6 (dbg), 10.11.6 (opt), 11.0.4 (dbg), 11.0.4 (opt), 11.1.3 (dbg), 11.1.3 (opt), 11.2.2 (dbg), 11.2.2 (opt)

 Comments   
Comment by Roel Van de Paar [ 2023-11-02 ]

shulga Elkin This looks like a new regression. Please check if this is in replication or PS code. Thank you

Comment by Roel Van de Paar [ 2024-01-23 ]

Confirmed present in 11.3 only. I could only reproduce in optimized build, not debug.

Comment by Andrei Elkin [ 2024-01-31 ]

Probably relates to MDEV-30176.

Comment by Brandon Nesterenko [ 2024-02-02 ]

Looks to be caused by

commit 6151bde48c8edac078300af0827c026b7b8d4894
 
Author: Yuchen Pei <ycp@mariadb.com>
 
Date:   Thu Sep 14 10:32:42 2023 +1000
 
 
    cleanup: string sys_var types

which changed the type of the default_master_type variable.

ycp, can you take a look?

Comment by Yuchen Pei [ 2024-02-06 ]

The problem is that the culprit commit above changed the update
mechanism of default_master_connection from strmake that mutates the
char* in-place to free+memdup which creates a new char*, and the former way
updates automatically stmt->lex.mi.connection_name.str, but the latter
causes the stmt->lex.mi.connection_name to hold the freed str.

Comment by Yuchen Pei [ 2024-02-06 ]

Hi serg, ptal thanks

upstream/bb-11.3-mdev-32640 67030e486bc20018f4611983dc01d8ebed3c37bf
 
MDEV-32640 allow sys_var_charptr to update session value inplace
 
 
 
If true, it allocates the session value once, and updates it with
 
strmake(), instead of freeing existing char* and creating new ones.
 
 
 
Make default_master_connection such a variable, so that the session
 
updates syncs automatically with statement ones. This fixes a
 
regression introduced by MDEV-15935.

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