[MDEV-27845] ASAN use-after-poison in mysql_real_connect Created: 2022-02-15  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.9, 10.10, 10.11, 11.0, 11.1, 11.2, 11.3
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0, 11.1, 11.2

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Andrei Elkin
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-16812 Semisync slave io thread segfaults at... Closed

 Description    

--source include/master-slave.inc
 
 
--connection master
 
RESET MASTER;
 
SET @@GLOBAL.rpl_semi_sync_master_enabled = 1;
 
GRANT REPLICATION SLAVE ON *.* TO u1@localhost IDENTIFIED BY 'p';
 
 
--sync_slave_with_master
 
source include/stop_slave.inc;
 
SET @@GLOBAL.rpl_semi_sync_slave_enabled = 1;
 
 
 
--connection slave
 
CHANGE MASTER TO master_user='u1', master_host='localhost', master_password='p';
 
--source include/start_slave.inc
 
 
 
--connection master
 
DROP USER u1@localhost;
 
FLUSH PRIVILEGES;
 
--sync_slave_with_master
 
 
 
--source include/stop_slave.inc
 
START SLAVE;
 
--source include/wait_for_slave_io_to_stop.inc

10.3 e928fdbff1369036

 
2022-02-15 11:03:22 18 [ERROR] Slave I/O: error connecting to master 'u1@localhost:16000' - retry-time: 1  maximum-retries: 10  message: Access denied for user 'u1'@'localhost' (using password: YES), Internal MariaDB error code: 1045
 
2022-02-15 11:03:31 18 [Note] Slave I/O thread killed while connecting to master
 
2022-02-15 11:03:31 18 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 774
 
2022-02-15 11:03:31 18 [Note] master was localhost:16000
 
=================================================================
 
==1014350==ERROR: AddressSanitizer: heap-use-after-free on address 0x61100008e288 at pc 0x55de56f1b784 bp 0x7f2d157e4ed0 sp 0x7f2d157e4ec0
 
READ of size 1 at 0x61100008e288 thread T36
 
    #0 0x55de56f1b783 in mysql_real_connect /10.3/src/sql-common/client.c:2938
 
    #1 0x55de56d6a162 in Repl_semi_sync_slave::kill_connection(st_mysql*) /10.3/src/sql/semisync_slave.cc:141
 
    #2 0x55de56d69ec8 in Repl_semi_sync_slave::slave_stop(Master_info*) /10.3/src/sql/semisync_slave.cc:120
 
    #3 0x55de5661fca3 in handle_slave_io /10.3/src/sql/slave.cc:4898
 
    #4 0x55de5825ff0c in pfs_spawn_thread /10.3/src/storage/perfschema/pfs.cc:1869
 
    #5 0x7f2d2c29e608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
    #6 0x7f2d2c1c3292 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122292)
 
 
 
0x61100008e288 is located 136 bytes inside of 204-byte region [0x61100008e200,0x61100008e2cc)
 
freed by thread T36 here:
 
    #0 0x7f2d2cb7a7cf in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0x10d7cf)
 
    #1 0x55de583acbd1 in free_memory /10.3/src/mysys/safemalloc.c:279
 
    #2 0x55de583ac18d in sf_free /10.3/src/mysys/safemalloc.c:197
 
    #3 0x55de5837a4b8 in my_free /10.3/src/mysys/my_malloc.c:223
 
    #4 0x55de56f206e9 in mysql_close_free /10.3/src/sql-common/client.c:3644
 
    #5 0x55de56f1e71d in mysql_real_connect /10.3/src/sql-common/client.c:3451
 
    #6 0x55de5662f817 in connect_to_master /10.3/src/sql/slave.cc:7130
 
    #7 0x55de5662ed4f in safe_connect /10.3/src/sql/slave.cc:7042
 
    #8 0x55de5661db86 in handle_slave_io /10.3/src/sql/slave.cc:4580
 
    #9 0x55de5825ff0c in pfs_spawn_thread /10.3/src/storage/perfschema/pfs.cc:1869
 
    #10 0x7f2d2c29e608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
 
 
previously allocated by thread T36 here:
 
    #0 0x7f2d2cb7abc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
 
    #1 0x55de583abb41 in sf_malloc /10.3/src/mysys/safemalloc.c:118
 
    #2 0x55de583799c1 in my_malloc /10.3/src/mysys/my_malloc.c:101
 
    #3 0x55de58353678 in my_multi_malloc /10.3/src/mysys/mulalloc.c:51
 
    #4 0x55de56f1dd36 in mysql_real_connect /10.3/src/sql-common/client.c:3313
 
    #5 0x55de5662f817 in connect_to_master /10.3/src/sql/slave.cc:7130
 
    #6 0x55de5662ed4f in safe_connect /10.3/src/sql/slave.cc:7042
 
    #7 0x55de5661db86 in handle_slave_io /10.3/src/sql/slave.cc:4580
 
    #8 0x55de5825ff0c in pfs_spawn_thread /10.3/src/storage/perfschema/pfs.cc:1869
 
    #9 0x7f2d2c29e608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T36 created by T32 here:
 
    #0 0x7f2d2caa7805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x55de582602fd in spawn_thread_v1 /10.3/src/storage/perfschema/pfs.cc:1919
 
    #2 0x55de5660092a in inline_mysql_thread_create /10.3/src/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55de5660811d in start_slave_thread(unsigned int, void* (*)(void*), st_mysql_mutex*, st_mysql_mutex*, st_mysql_cond*, unsigned int volatile*, unsigned long volatile*, Master_info*) /10.3/src/sql/slave.cc:1114
 
    #4 0x55de56608bd2 in start_slave_threads(THD*, bool, bool, Master_info*, char const*, char const*, int) /10.3/src/sql/slave.cc:1230
 
    #5 0x55de569046c0 in start_slave(THD*, Master_info*, bool) /10.3/src/sql/sql_repl.cc:3208
 
    #6 0x55de56872142 in mysql_execute_command(THD*) /10.3/src/sql/sql_parse.cc:4183
 
    #7 0x55de5688c621 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /10.3/src/sql/sql_parse.cc:7870
 
    #8 0x55de568634fe in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /10.3/src/sql/sql_parse.cc:1852
 
    #9 0x55de56860041 in do_command(THD*) /10.3/src/sql/sql_parse.cc:1398
 
    #10 0x55de56c31adc in do_handle_one_connection(CONNECT*) /10.3/src/sql/sql_connect.cc:1403
 
    #11 0x55de56c31396 in handle_one_connection /10.3/src/sql/sql_connect.cc:1308
 
    #12 0x55de5825ff0c in pfs_spawn_thread /10.3/src/storage/perfschema/pfs.cc:1869
 
    #13 0x7f2d2c29e608 in start_thread /build/glibc-eX1tMB/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T32 created by T0 here:
 
    #0 0x7f2d2caa7805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x55de582602fd in spawn_thread_v1 /10.3/src/storage/perfschema/pfs.cc:1919
 
    #2 0x55de5658836e in inline_mysql_thread_create /10.3/src/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55de565a112b in create_thread_to_handle_connection(CONNECT*) /10.3/src/sql/mysqld.cc:6666
 
    #4 0x55de565a18c6 in create_new_thread /10.3/src/sql/mysqld.cc:6736
 
    #5 0x55de565a2a58 in handle_connections_sockets() /10.3/src/sql/mysqld.cc:6994
 
    #6 0x55de565a041c in mysqld_main(int, char**) /10.3/src/sql/mysqld.cc:6288
 
    #7 0x55de56586b6c in main /10.3/src/sql/main.cc:25
 
    #8 0x7f2d2c0c80b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /10.3/src/sql-common/client.c:2938 in mysql_real_connect
 
Shadow bytes around the buggy address:
 
  0x0c2280009c00: fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa
 
  0x0c2280009c10: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
 
  0x0c2280009c20: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2280009c30: fd fd fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2280009c40: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c2280009c50: fd[fd]fd fd fd fd fd fd fd fd fa fa fa fa fa fa
 
  0x0c2280009c60: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2280009c70: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2280009c80: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2280009c90: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c2280009ca0: 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
 
==1014350==ABORTING
 
----------SERVER LOG END-------------



 Comments   
Comment by Ramesh Sivaraman [ 2023-09-20 ]

Another test case ( AddressSanitizer: heap-use-after-free in server_mysql_real_connect)

CHANGE MASTER TO master_host='127.0.0.1', master_user='DOES NOT EXIST',master_password='DOES NOT EXIST';
 
SET GLOBAL rpl_semi_sync_slave_enabled=1;
 
START SLAVE;
 
SHUTDOWN;

Leads to

11.3.0 fa64a7a10cb23475c3008ff3d935d12659d2a81f (Optimized, UBASAN)

 
==3223442==ERROR: AddressSanitizer: heap-use-after-free on address 0x608000008050 at pc 0x55a9456b8e59 bp 0x14a5c2939b50 sp 0x14a5c2939b40
 
READ of size 1 at 0x608000008050 thread T27
 
    #0 0x55a9456b8e58 in server_mysql_real_connect /test/mtest/MDEV-31606/11.3_opt_san/sql-common/client.c:2714
 
    #1 0x55a94501be27 in Repl_semi_sync_slave::kill_connection(st_mysql*) /test/mtest/MDEV-31606/11.3_opt_san/sql/semisync_slave.cc:145
 
    #2 0x55a94501c13f in Repl_semi_sync_slave::slave_stop(Master_info*) /test/mtest/MDEV-31606/11.3_opt_san/sql/semisync_slave.cc:118
 
    #3 0x55a943cb8884 in handle_slave_io /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:5085
 
    #4 0x14a5e713d608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
    #5 0x14a5e63b2132 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f132)
 
 
 
0x608000008050 is located 48 bytes inside of 96-byte region [0x608000008020,0x608000008080)
 
freed by thread T27 here:
 
    #0 0x55a9439fc3cf in __interceptor_free (/test/mtest/MDEV-31606/UBASAN_MD180923-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7c173cf)
 
    #1 0x55a9456b6de1 in mysql_close_free /test/mtest/MDEV-31606/11.3_opt_san/sql-common/client.c:3321
 
    #2 0x55a9456b6de1 in server_mysql_real_connect /test/mtest/MDEV-31606/11.3_opt_san/sql-common/client.c:3188
 
    #3 0x55a943c66ce1 in connect_to_master /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:7144
 
    #4 0x55a943cb79e4 in safe_connect /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:7056
 
    #5 0x55a943cb79e4 in handle_slave_io /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:4773
 
    #6 0x14a5e713d608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
previously allocated by thread T27 here:
 
    #0 0x55a9439fc7c8 in __interceptor_malloc (/test/mtest/MDEV-31606/UBASAN_MD180923-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7c177c8)
 
    #1 0x55a947eeab74 in my_malloc /test/mtest/MDEV-31606/11.3_opt_san/mysys/my_malloc.c:89
 
    #2 0x55a947ec4552 in my_multi_malloc /test/mtest/MDEV-31606/11.3_opt_san/mysys/mulalloc.c:59
 
    #3 0x55a9456b74e3 in server_mysql_real_connect /test/mtest/MDEV-31606/11.3_opt_san/sql-common/client.c:3049
 
    #4 0x55a943c66ce1 in connect_to_master /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:7144
 
    #5 0x55a943cb79e4 in safe_connect /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:7056
 
    #6 0x55a943cb79e4 in handle_slave_io /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:4773
 
    #7 0x14a5e713d608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T27 created by T26 here:
 
    #0 0x55a943929805 in __interceptor_pthread_create (/test/mtest/MDEV-31606/UBASAN_MD180923-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7b44805)
 
    #1 0x55a943c7b1ba in start_slave_thread(void* (*)(void*), st_mysql_mutex*, st_mysql_mutex*, st_mysql_cond*, unsigned int volatile*, unsigned long volatile*, Master_info*) /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:1149
 
    #2 0x55a943c7c81f in start_slave_threads(THD*, bool, bool, Master_info*, char const*, char const*, int) /test/mtest/MDEV-31606/11.3_opt_san/sql/slave.cc:1265
 
    #3 0x55a9443c8271 in start_slave(THD*, Master_info*, bool) /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_repl.cc:3278
 
    #4 0x55a944296b60 in mysql_execute_command(THD*, bool) /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_parse.cc:4213
 
    #5 0x55a944211fb0 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_parse.cc:7732
 
    #6 0x55a944268d28 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_parse.cc:1893
 
    #7 0x55a94427442d in do_command(THD*, bool) /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_parse.cc:1406
 
    #8 0x55a944bb471d in do_handle_one_connection(CONNECT*, bool) /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_connect.cc:1445
 
    #9 0x55a944bb6d8c in handle_one_connection /test/mtest/MDEV-31606/11.3_opt_san/sql/sql_connect.cc:1347
 
    #10 0x14a5e713d608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T26 created by T0 here:
 
    #0 0x55a943929805 in __interceptor_pthread_create (/test/mtest/MDEV-31606/UBASAN_MD180923-mariadb-11.3.0-linux-x86_64-opt/bin/mariadbd+0x7b44805)
 
    #1 0x55a943a4d4c3 in create_thread_to_handle_connection(CONNECT*) /test/mtest/MDEV-31606/11.3_opt_san/sql/mysqld.cc:6169
 
    #2 0x55a943a5eccf in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /test/mtest/MDEV-31606/11.3_opt_san/sql/mysqld.cc:6293
 
    #3 0x55a943a5fce7 in handle_connections_sockets() /test/mtest/MDEV-31606/11.3_opt_san/sql/mysqld.cc:6417
 
    #4 0x55a943a62c64 in mysqld_main(int, char**) /test/mtest/MDEV-31606/11.3_opt_san/sql/mysqld.cc:6064
 
    #5 0x14a5e62b7082 in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /test/mtest/MDEV-31606/11.3_opt_san/sql-common/client.c:2714 in server_mysql_real_connect
 
Shadow bytes around the buggy address:
 
  0x0c107fff8fb0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c107fff8fc0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c107fff8fd0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c107fff8fe0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c107fff8ff0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
=>0x0c107fff9000: fa fa fa fa fd fd fd fd fd fd[fd]fd fd fd fd fd
 
  0x0c107fff9010: fa fa fa fa 00 00 00 00 00 00 00 00 00 00 00 fa
 
  0x0c107fff9020: fa fa fa fa 00 00 00 00 00 00 00 00 00 00 00 fa
 
  0x0c107fff9030: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c107fff9040: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
 
  0x0c107fff9050: 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
 
==3223442==ABORTING
 
230920 15:40:42 [ERROR] mysqld got signal 6 ;

Generated at Thu Feb 08 09:56:01 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.