[MDEV-29434] ASAN: use-after-poison and heap-use-after-free in ha_discover_table on dummy INSERT query and removing general_log table Created: 2022-09-01  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Data Definition - Create Table, Data Manipulation - Insert, Server
Affects Version/s: 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: ASAN, memory_corruption, not-10.3, regression-10.4


 Description    

SET GLOBAL general_log=ON;
 
DROP DATABASE mysql;
 
SET GLOBAL log_output='TABLE';
 
INSERT INTO dummy;

Leads to:

10.11.0 fe1f8f2c6b6f3b8e3383168225f9ae7853028947 (Debug)

 
==3867994==ERROR: AddressSanitizer: use-after-poison on address 0x6290000d7769 at pc 0x55b9e26662f3 bp 0x15104b162e90 sp 0x15104b162e80

10.11.0 fe1f8f2c6b6f3b8e3383168225f9ae7853028947 (Debug)

 
2022-09-01 16:38:18 0 [Note] /test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mysqld: ready for connections.
 
Version: '10.11.0-MariaDB-debug'  socket: '/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/socket.sock'  port: 12676  MariaDB Server
 
2022-09-01 16:38:20 4 [ERROR] Failed to write to mysql.general_log: Table 'mysql.general_log' doesn't exist
 
=================================================================
 
==3867994==ERROR: AddressSanitizer: use-after-poison on address 0x6290000d7769 at pc 0x55b9e26662f3 bp 0x15104b162e90 sp 0x15104b162e80
 
READ of size 1 at 0x6290000d7769 thread T13
 
    #0 0x55b9e26662f2 in ha_discover_table(THD*, TABLE_SHARE*) /test/10.11_dbg_san/sql/handler.cc:6133
 
    #1 0x55b9e17528ff in open_table_def(THD*, TABLE_SHARE*, unsigned int) /test/10.11_dbg_san/sql/table.cc:650
 
    #2 0x55b9e201d314 in tdc_acquire_share(THD*, TABLE_LIST*, unsigned int, TABLE**) /test/10.11_dbg_san/sql/table_cache.cc:836
 
    #3 0x55b9e09a3c99 in open_table(THD*, TABLE_LIST*, Open_table_context*) /test/10.11_dbg_san/sql/sql_base.cc:2028
 
    #4 0x55b9e09b221e in open_ltable(THD*, TABLE_LIST*, thr_lock_type, unsigned int) /test/10.11_dbg_san/sql/sql_base.cc:5468
 
    #5 0x55b9e09f85a8 in open_log_table(THD*, TABLE_LIST*, Open_tables_backup*) /test/10.11_dbg_san/sql/sql_base.cc:9556
 
    #6 0x55b9e348de91 in Log_to_csv_event_handler::log_general(THD*, my_hrtime_t, char const*, unsigned long, unsigned long long, char const*, unsigned long, char const*, unsigned long, charset_info_st const*) /test/10.11_dbg_san/sql/log.cc:862
 
    #7 0x55b9e349e08e in LOGGER::general_log_write(THD*, enum_server_command, char const*, unsigned long) /test/10.11_dbg_san/sql/log.cc:1510
 
    #8 0x55b9e349e3ec in LOGGER::general_log_print(THD*, enum_server_command, char const*, __va_list_tag*) /test/10.11_dbg_san/sql/log.cc:1535
 
    #9 0x55b9e349e662 in general_log_print(THD*, enum_server_command, char const*, ...) /test/10.11_dbg_san/sql/log.cc:7032
 
    #10 0x55b9e0e45c52 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.11_dbg_san/sql/sql_parse.cc:2115
 
    #11 0x55b9e0e51a70 in do_command(THD*, bool) /test/10.11_dbg_san/sql/sql_parse.cc:1407
 
    #12 0x55b9e18c2b41 in do_handle_one_connection(CONNECT*, bool) /test/10.11_dbg_san/sql/sql_connect.cc:1418
 
    #13 0x55b9e18c532c in handle_one_connection /test/10.11_dbg_san/sql/sql_connect.cc:1312
 
    #14 0x15106e08e608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
    #15 0x15106d303132 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f132)
 
 
 
0x6290000d7769 is located 1385 bytes inside of 16516-byte region [0x6290000d7200,0x6290000db284)
 
allocated by thread T13 here:
 
    #0 0x55b9e0463258 in malloc (/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mariadbd+0x7ee2258)
 
    #1 0x55b9e5077ad5 in sf_malloc /test/10.11_dbg_san/mysys/safemalloc.c:126
 
    #2 0x55b9e5045102 in my_malloc /test/10.11_dbg_san/mysys/my_malloc.c:90
 
    #3 0x55b9e502306d in root_alloc /test/10.11_dbg_san/mysys/my_alloc.c:66
 
    #4 0x55b9e5023aa4 in reset_root_defaults /test/10.11_dbg_san/mysys/my_alloc.c:243
 
    #5 0x55b9e0a590bd in THD::init_for_queries() /test/10.11_dbg_san/sql/sql_class.cc:1385
 
    #6 0x55b9e18be231 in prepare_new_connection_state(THD*) /test/10.11_dbg_san/sql/sql_connect.cc:1240
 
    #7 0x55b9e18bfd1d in thd_prepare_connection(THD*) /test/10.11_dbg_san/sql/sql_connect.cc:1333
 
    #8 0x55b9e18c3862 in do_handle_one_connection(CONNECT*, bool) /test/10.11_dbg_san/sql/sql_connect.cc:1408
 
    #9 0x55b9e18c532c in handle_one_connection /test/10.11_dbg_san/sql/sql_connect.cc:1312
 
    #10 0x15106e08e608 in start_thread /build/glibc-SzIz7B/glibc-2.31/np
 
 
 
Thread T13 created by T0 here:
 
    #0 0x55b9e0390295 in __interceptor_pthread_create (/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mariadbd+0x7e0f295)
 
    #1 0x55b9e04b79d3 in create_thread_to_handle_connection(CONNECT*) /test/10.11_dbg_san/sql/mysqld.cc:6018
 
    #2 0x55b9e04c9d12 in create_new_thread(CONNECT*) /test/10.11_dbg_san/sql/mysqld.cc:6077
 
    #3 0x55b9e04ca660 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /test/10.11_dbg_san/sql/mysqld.cc:6139
 
    #4 0x55b9e04cbaef in handle_connections_sockets() /test/10.11_dbg_san/sql/mysqld.cc:6263
 
    #5 0x55b9e04d0463 in mysqld_main(int, char**) /test/10.11_dbg_san/sql/mysqld.cc:5913
 
    #6 0x55b9e04a481a in main /test/10.11_dbg_san/sql/main.cc:34
 
    #7 0x15106d208082 in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: use-after-poison /test/10.11_dbg_san/sql/handler.cc:6133 in ha_discover_table(THD*, TABLE_SHARE*)
 
Shadow bytes around the buggy address:
 
  0x0c5280012e90: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012ea0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012eb0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012ec0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012ed0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
=>0x0c5280012ee0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7[f7]f7 f7
 
  0x0c5280012ef0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012f00: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012f10: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012f20: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
  0x0c5280012f30: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
 
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
 
==3867994==ABORTING

Setup:

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

Bug confirmed present in:
MariaDB: 10.4.27 (dbg), 10.4.27 (opt), 10.5.18 (dbg), 10.5.18 (opt), 10.6.10 (dbg), 10.6.10 (opt), 10.7.6 (dbg), 10.7.6 (opt), 10.8.5 (dbg), 10.8.5 (opt), 10.9.2 (opt), 10.9.2 (dbg), 10.10.2 (dbg), 10.10.2 (opt), 10.11.0 (dbg), 10.11.0 (opt)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.3.37 (dbg), 10.3.37 (opt)

 Comments   
Comment by Roel Van de Paar [ 2022-09-21 ]

An additional related heap-use-after-free issue:

SET SESSION query_alloc_block_size=100;
 
SET GLOBAL general_log=1;
 
DROP TABLE mysql.general_log;
 
SET GLOBAL log_output='TABLE';
 
CREATE TABLE t1 (i INT) ENGINE MyISAM;

Leads to:

10.11.0 fe1f8f2c6b6f3b8e3383168225f9ae7853028947 (Debug)

 
==806066==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0002034f1 at pc 0x55fa4f9ab2f3 bp 0x152a75ab8e90 sp 0x152a75ab8e80

10.11.0 fe1f8f2c6b6f3b8e3383168225f9ae7853028947 (Debug)

 
2022-09-21 17:48:47 0 [Note] /test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mysqld: ready for connections.
 
Version: '10.11.0-MariaDB-debug'  socket: '/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/socket.sock'  port: 12921  MariaDB Server
 
2022-09-21 17:48:48 4 [ERROR] Failed to write to mysql.general_log: Table 'mysql.general_log' doesn't exist
 
=================================================================
 
==806066==ERROR: AddressSanitizer: heap-use-after-free on address 0x61d0002034f1 at pc 0x55fa4f9ab2f3 bp 0x152a75ab8e90 sp 0x152a75ab8e80
 
READ of size 1 at 0x61d0002034f1 thread T14
 
    #0 0x55fa4f9ab2f2 in ha_discover_table(THD*, TABLE_SHARE*) /test/10.11_dbg_san/sql/handler.cc:6133
 
    #1 0x55fa4ea978ff in open_table_def(THD*, TABLE_SHARE*, unsigned int) /test/10.11_dbg_san/sql/table.cc:650
 
    #2 0x55fa4f362314 in tdc_acquire_share(THD*, TABLE_LIST*, unsigned int, TABLE**) /test/10.11_dbg_san/sql/table_cache.cc:836
 
    #3 0x55fa4dce8c99 in open_table(THD*, TABLE_LIST*, Open_table_context*) /test/10.11_dbg_san/sql/sql_base.cc:2028
 
    #4 0x55fa4dcf721e in open_ltable(THD*, TABLE_LIST*, thr_lock_type, unsigned int) /test/10.11_dbg_san/sql/sql_base.cc:5468
 
    #5 0x55fa4dd3d5a8 in open_log_table(THD*, TABLE_LIST*, Open_tables_backup*) /test/10.11_dbg_san/sql/sql_base.cc:9556
 
    #6 0x55fa507d2e91 in Log_to_csv_event_handler::log_general(THD*, my_hrtime_t, char const*, unsigned long, unsigned long long, char const*, unsigned long, char const*, unsigned long, charset_info_st const*) /test/10.11_dbg_san/sql/log.cc:862
 
    #7 0x55fa507e308e in LOGGER::general_log_write(THD*, enum_server_command, char const*, unsigned long) /test/10.11_dbg_san/sql/log.cc:1510
 
    #8 0x55fa507e33ec in LOGGER::general_log_print(THD*, enum_server_command, char const*, __va_list_tag*) /test/10.11_dbg_san/sql/log.cc:1535
 
    #9 0x55fa507e3662 in general_log_print(THD*, enum_server_command, char const*, ...) /test/10.11_dbg_san/sql/log.cc:7032
 
    #10 0x55fa4e18ac52 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.11_dbg_san/sql/sql_parse.cc:2115
 
    #11 0x55fa4e196a70 in do_command(THD*, bool) /test/10.11_dbg_san/sql/sql_parse.cc:1407
 
    #12 0x55fa4ec07b41 in do_handle_one_connection(CONNECT*, bool) /test/10.11_dbg_san/sql/sql_connect.cc:1418
 
    #13 0x55fa4ec0a32c in handle_one_connection /test/10.11_dbg_san/sql/sql_connect.cc:1312
 
    #14 0x152a98bfb608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
    #15 0x152a97e70132 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f132)
 
 
 
0x61d0002034f1 is located 1137 bytes inside of 1940-byte region [0x61d000203080,0x61d000203814)
 
freed by thread T14 here:
 
    #0 0x55fa4d7a7e5f in free (/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mariadbd+0x7ee1e5f)
 
    #1 0x55fa523bc7ea in free_memory /test/10.11_dbg_san/mysys/safemalloc.c:297
 
    #2 0x55fa523bd299 in sf_free /test/10.11_dbg_san/mysys/safemalloc.c:203
 
    #3 0x55fa5238a4ad in my_free /test/10.11_dbg_san/mysys/my_malloc.c:211
 
    #4 0x55fa523681e1 in root_free /test/10.11_dbg_san/mysys/my_alloc.c:78
 
    #5 0x55fa5236a3cc in free_root /test/10.11_dbg_san/mysys/my_alloc.c:495
 
    #6 0x55fa4e1923ce in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.11_dbg_san/sql/sql_parse.cc:2449
 
    #7 0x55fa4e196a70 in do_command(THD*, bool) /test/10.11_dbg_san/sql/sql_parse.cc:1407
 
    #8 0x55fa4ec07b41 in do_handle_one_connection(CONNECT*, bool) /test/10.11_dbg_san/sql/sql_connect.cc:1418
 
    #9 0x55fa4ec0a32c in handle_one_connection /test/10.11_dbg_san/sql/sql_connect.cc:1312
 
    #10 0x152a98bfb608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
previously allocated by thread T14 here:
 
    #0 0x55fa4d7a8258 in malloc (/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mariadbd+0x7ee2258)
 
    #1 0x55fa523bcad5 in sf_malloc /test/10.11_dbg_san/mysys/safemalloc.c:126
 
    #2 0x55fa5238a102 in my_malloc /test/10.11_dbg_san/mysys/my_malloc.c:90
 
    #3 0x55fa5236806d in root_alloc /test/10.11_dbg_san/mysys/my_alloc.c:66
 
    #4 0x55fa523692e4 in alloc_root /test/10.11_dbg_san/mysys/my_alloc.c:332
 
    #5 0x55fa4e11a468 in Query_arena::calloc(unsigned long) /test/10.11_dbg_san/sql/sql_class.h:1192
 
    #6 0x55fa4e11a468 in st_select_lex::add_table_to_list(THD*, Table_ident*, st_mysql_const_lex_string*, unsigned long, thr_lock_type, enum_mdl_type, List<Index_hint>*, List<String>*, st_mysql_lex_string*) /test/10.11_dbg_san/sql/sql_parse.cc:8224
 
    #7 0x55fa4f3cbf10 in MYSQLparse(THD*) /test/10.11_dbg_san/sql/sql_yacc.yy:2369
 
    #8 0x55fa4e141444 in parse_sql(THD*, Parser_state*, Object_creation_ctx*, bool) /test/10.11_dbg_san/sql/sql_parse.cc:10426
 
    #9 0x55fa4e11722b in mysql_parse(THD*, char*, unsigned int, Parser_state*) /test/10.11_dbg_san/sql/sql_parse.cc:7987
 
    #10 0x55fa4e18485f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /test/10.11_dbg_san/sql/sql_parse.cc:1894
 
    #11 0x55fa4e196a70 in do_command(THD*, bool) /test/10.11_dbg_san/sql/sql_parse.cc:1407
 
    #12 0x55fa4ec07b41 in do_handle_one_connection(CONNECT*, bool) /test/10.11_dbg_san/sql/sql_connect.cc:1418
 
    #13 0x55fa4ec0a32c in handle_one_connection /test/10.11_dbg_san/sql/sql_connect.cc:1312
 
    #14 0x152a98bfb608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
 
 
Thread T14 created by T0 here:
 
    #0 0x55fa4d6d5295 in __interceptor_pthread_create (/test/UBASAN_MD010922-mariadb-10.11.0-linux-x86_64-dbg/bin/mariadbd+0x7e0f295)
 
    #1 0x55fa4d7fc9d3 in create_thread_to_handle_connection(CONNECT*) /test/10.11_dbg_san/sql/mysqld.cc:6018
 
    #2 0x55fa4d80ed12 in create_new_thread(CONNECT*) /test/10.11_dbg_san/sql/mysqld.cc:6077
 
    #3 0x55fa4d80f660 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /test/10.11_dbg_san/sql/mysqld.cc:6139
 
    #4 0x55fa4d810aef in handle_connections_sockets() /test/10.11_dbg_san/sql/mysqld.cc:6263
 
    #5 0x55fa4d815463 in mysqld_main(int, char**) /test/10.11_dbg_san/sql/mysqld.cc:5913
 
    #6 0x55fa4d7e981a in main /test/10.11_dbg_san/sql/main.cc:34
 
    #7 0x152a97d75082 in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free /test/10.11_dbg_san/sql/handler.cc:6133 in ha_discover_table(THD*, TABLE_SHARE*)
 
Shadow bytes around the buggy address:
 
  0x0c3a80038640: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a80038650: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a80038660: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a80038670: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a80038680: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c3a80038690: fd fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd
 
  0x0c3a800386a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a800386b0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a800386c0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a800386d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c3a800386e0: 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

Setup:

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

Bug confirmed present in:
MariaDB: 10.4.27 (dbg), 10.4.27 (opt), 10.5.18 (dbg), 10.5.18 (opt), 10.6.10 (dbg), 10.6.10 (opt), 10.7.6 (dbg), 10.7.6 (opt), 10.8.5 (dbg), 10.8.5 (opt), 10.9.2 (dbg), 10.9.2 (opt), 10.10.2 (dbg), 10.11.0 (dbg), 10.11.0 (opt)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.3.37 (dbg), 10.3.37 (opt)

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