[MDEV-31041] [draft] Server crashes in Cache_flip_event_log::acquire/binlog_setup_cache_data Created: 2023-04-12  Updated: 2023-04-25

Status: Open
Project: MariaDB Server
Component/s: None
Affects Version/s: N/A
Fix Version/s: None

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


 Description   

Version: '11.0.1-MariaDB-debug-log'  
230412 11:14:07 [ERROR] mysqld got signal 11 ;
 
 
Server version: 11.0.1-MariaDB-debug-log source revision: c600951df9850c1c8e5d067e854983a084b67db3
 
mysys/stacktrace.c:215(my_print_stacktrace)[0x55631793744a]
sql/signal_handler.cc:238(handle_fatal_signal)[0x5563164e85d6]
bits/atomic_base.h:514(Cache_flip_event_log::acquire())[0x556316871f14]
sql/log.cc:6405(binlog_setup_cache_data(st_mem_root*, TABLE_SHARE*))[0x55631684acdf]
sql/log.cc:6426(online_alter_binlog_get_cache_data(THD*, TABLE*))[0x55631684b0c1]
sql/log.cc:2277(binlog_log_row_online_alter(TABLE*, unsigned char const*, unsigned char const*, bool (*)(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*)))[0x556316830b8a]
sql/handler.cc:7274(handler::binlog_log_row(unsigned char const*, unsigned char const*, bool (*)(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*)))[0x556316525216]
sql/handler.cc:7822(handler::ha_write_row(unsigned char const*))[0x55631652b5f9]
sql/sql_insert.cc:2203(write_record(THD*, TABLE*, st_copy_info*, select_result*))[0x556315b550d7]
sql/sql_insert.cc:1153(mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool, select_result*))[0x556315b4c50a]
sql/sql_parse.cc:4569(mysql_execute_command(THD*, bool))[0x556315c162f0]
sql/sql_parse.cc:8000(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x556315c2e393]
sql/sql_parse.cc:1896(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x556315c04c81]
sql/sql_parse.cc:1407(do_command(THD*, bool))[0x556315c0198a]
sql/sql_connect.cc:1416(do_handle_one_connection(CONNECT*, bool))[0x5563160ba430]
sql/sql_connect.cc:1320(handle_one_connection)[0x5563160b9d86]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x556316d4f897]
nptl/pthread_create.c:487(start_thread)[0x7f305827cfa3]
 
Query (0x6290008162a8): INSERT  IGNORE INTO `A` ( `altcol0` ) VALUES ( NULL ),( NULL ),( NULL ),( NULL )

2023-04-19 14:36:47 11 [ERROR] mysqld: Error writing file 'online-alter-binlog' (errno: 27 "File too large")
230419 14:36:47 [ERROR] mysqld got signal 11 ;
 
Server version: 11.0.2-MariaDB-log source revision: 1ada8608c4f5642da604bb78eaffb714b6902e11
 
sql/signal_handler.cc:238(handle_fatal_signal)[0x5555fef0bd75]
??:0(__restore_rt)[0x7f400d409730]
multiarch/memmove-vec-unaligned-erms.S:384(__nss_passwd_lookup)[0x7f400d06d5d0]
mysys/mf_iocache.c:557(_my_b_write)[0x5555ff3a4761]
sql/log_event_server.cc:766(Log_event_writer::write_internal(unsigned char const*, unsigned long))[0x5555ff018366]
sql/log_event_server.cc:861(Log_event_writer::write_header(unsigned char*, unsigned long))[0x5555ff018608]
sql/log_event_server.cc:953(Log_event::write_header(unsigned long))[0x5555ff018b44]
sql/log_event.h:1440(Log_event::write())[0x5555ff01046d]
sql/log_event.h:5317(Event_log::flush_and_set_pending_rows_event(THD*, Rows_log_event*, binlog_cache_data*, bool))[0x5555feff574c]
sql/log.cc:6630(Event_log::prepare_pending_rows_event(THD*, TABLE*, binlog_cache_data*, unsigned int, unsigned long, bool, Rows_event_factory))[0x5555feff5911]
sql/sql_class.cc:7019(THD::binlog_write_row(TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*))[0x5555fec8950a]
sql/log_event.h:4889(Write_rows_log_event::binlog_row_logging_function(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*))[0x5555fef1c241]
sql/log.cc:2292(binlog_log_row_online_alter(TABLE*, unsigned char const*, unsigned char const*, bool (*)(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*)))[0x5555feff4f45]
sql/handler.cc:7833(handler::ha_write_row(unsigned char const*))[0x5555fef19eb8]
sql/sql_insert.cc:2203(write_record(THD*, TABLE*, st_copy_info*, select_result*))[0x5555feca0195]
sql/sql_insert.cc:1153(mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool, select_result*))[0x5555feca9c67]
sql/sql_parse.cc:4569(mysql_execute_command(THD*, bool))[0x5555fecdf18c]
sql/sql_parse.cc:8014(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x5555feccf3df]
sql/sql_parse.cc:1896(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool))[0x5555fecd9e56]
sql/sql_parse.cc:1407(do_command(THD*, bool))[0x5555fecdb511]
sql/sql_connect.cc:1416(do_handle_one_connection(CONNECT*, bool))[0x5555fede738f]
sql/sql_connect.cc:1318(handle_one_connection)[0x5555fede76cd]
perfschema/pfs.cc:2204(pfs_spawn_thread)[0x5555ff10f485]
nptl/pthread_create.c:487(start_thread)[0x7f400d3fefa3]
x86_64/clone.S:97(clone)[0x7f400d00a06f]
 
Query (0x7f3e5c010990): INSERT IGNORE INTO `t1` ( `pk` ) VALUES ( NULL ),( NULL ),( NULL ),( NULL )

2023-04-19 14:55:49 19 [ERROR] mysqld: Error writing file 'online-alter-binlog' (errno: 27 "File too large")
=================================================================
==492597==ERROR: AddressSanitizer: use-after-poison on address 0x62500083e330 at pc 0x560ef4f25e37 bp 0x7ff76725d090 sp 0x7ff76725d080
READ of size 8 at 0x62500083e330 thread T19
    #0 0x560ef4f25e36 in binlog_cache_data::pending() const `/11.0/sql/log.cc:312
    #1 0x560ef4efbb0d in Event_log::prepare_pending_rows_event(THD*, TABLE*, binlog_cache_data*, unsigned int, unsigned long, bool, Rows_event_factory) `/11.0/sql/log.cc:6597
    #2 0x560ef415b736 in THD::binlog_write_row(TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*) `/11.0/sql/sql_class.cc:7019
    #3 0x560ef4bd6062 in Write_rows_log_event::binlog_row_logging_function(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*) `/11.0/sql/log_event.h:4887
    #4 0x560ef4edfb75 in binlog_log_row_online_alter(TABLE*, unsigned char const*, unsigned char const*, bool (*)(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*)) `/11.0/sql/log.cc:2288
    #5 0x560ef4bc250c in handler::binlog_log_row(unsigned char const*, unsigned char const*, bool (*)(THD*, TABLE*, Event_log*, binlog_cache_data*, bool, unsigned char const*, unsigned char const*)) `/11.0/sql/handler.cc:7285
    #6 0x560ef4bc8a28 in handler::ha_write_row(unsigned char const*) `/11.0/sql/handler.cc:7833
    #7 0x560ef41bf384 in write_record(THD*, TABLE*, st_copy_info*, select_result*) `/11.0/sql/sql_insert.cc:2203
    #8 0x560ef41b658e in mysql_insert(THD*, TABLE_LIST*, List<Item>&, List<List<Item> >&, List<Item>&, List<Item>&, enum_duplicates, bool, select_result*) `/11.0/sql/sql_insert.cc:1153
    #9 0x560ef4283b98 in mysql_execute_command(THD*, bool) `/11.0/sql/sql_parse.cc:4569
    #10 0x560ef429c0bd in mysql_parse(THD*, char*, unsigned int, Parser_state*) `/11.0/sql/sql_parse.cc:7997
    #11 0x560ef4272313 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) `/11.0/sql/sql_parse.cc:1894
    #12 0x560ef426f04f in do_command(THD*, bool) `/11.0/sql/sql_parse.cc:1407
    #13 0x560ef4740c66 in do_handle_one_connection(CONNECT*, bool) `/11.0/sql/sql_connect.cc:1416
    #14 0x560ef47405c3 in handle_one_connection `/11.0/sql/sql_connect.cc:1318
    #15 0x560ef535c137 in pfs_spawn_thread `/11.0/storage/perfschema/pfs.cc:2201
    #16 0x7ff791789608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
    #17 0x7ff79135a132 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x11f132)
 
0x62500083e330 is located 560 bytes inside of 8324-byte region [0x62500083e100,0x625000840184)
allocated by thread T19 here:
    #0 0x7ff791d17808 in __interceptor_malloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cc:144
    #1 0x560ef5f95e17 in sf_malloc `/11.0/mysys/safemalloc.c:126
    #2 0x560ef5f630f5 in my_malloc `/11.0/mysys/my_malloc.c:91
    #3 0x560ef5f3db6f in root_alloc `/11.0/mysys/my_alloc.c:71
    #4 0x560ef5f3eaa0 in reset_root_defaults `/11.0/mysys/my_alloc.c:248
    #5 0x560ef4132700 in THD::init_for_queries() `/11.0/sql/sql_class.cc:1388
    #6 0x560ef473fe76 in prepare_new_connection_state(THD*) `/11.0/sql/sql_connect.cc:1245
    #7 0x560ef4740642 in thd_prepare_connection(THD*) `/11.0/sql/sql_connect.cc:1339
    #8 0x560ef4740b8c in do_handle_one_connection(CONNECT*, bool) `/11.0/sql/sql_connect.cc:1406
    #9 0x560ef47405c3 in handle_one_connection `/11.0/sql/sql_connect.cc:1318
    #10 0x560ef535c137 in pfs_spawn_thread `/11.0/storage/perfschema/pfs.cc:2201
    #11 0x7ff791789608 in start_thread /build/glibc-SzIz7B/glibc-2.31/nptl/pthread_create.c:477
 
Thread T19 created by T0 here:
    #0 0x7ff791c44815 in __interceptor_pthread_create ../../../../src/libsanitizer/asan/asan_interceptors.cc:208
    #1 0x560ef5357d14 in my_thread_create `/11.0/storage/perfschema/my_thread.h:52
    #2 0x560ef535c52a in pfs_spawn_thread_v1 `/11.0/storage/perfschema/pfs.cc:2252
    #3 0x560ef3ea7f07 in inline_mysql_thread_create `/11.0/include/mysql/psi/mysql_thread.h:1139
    #4 0x560ef3ec06ff in create_thread_to_handle_connection(CONNECT*) `/11.0/sql/mysqld.cc:6126
    #5 0x560ef3ec0d8f in create_new_thread(CONNECT*) `/11.0/sql/mysqld.cc:6188
    #6 0x560ef3ec10fc in handle_accepted_socket(st_mysql_socket, st_mysql_socket) `/11.0/sql/mysqld.cc:6250
    #7 0x560ef3ec1af2 in handle_connections_sockets() `/11.0/sql/mysqld.cc:6374
    #8 0x560ef3ebff0c in mysqld_main(int, char**) `/11.0/sql/mysqld.cc:6021
    #9 0x560ef3ea700c in main `/11.0/sql/main.cc:34
    #10 0x7ff79125f082 in __libc_start_main ../csu/libc-start.c:308
 
SUMMARY: AddressSanitizer: use-after-poison `/11.0/sql/log.cc:312 in binlog_cache_data::pending() const
Shadow bytes around the buggy address:
  0x0c4a800ffc10: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c4a800ffc20: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c4a800ffc30: 00 00 00 00 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffc40: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffc50: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
=>0x0c4a800ffc60: f7 f7 f7 f7 f7 f7[f7]f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffc70: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffc80: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffc90: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffca0: f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7 f7
  0x0c4a800ffcb0: 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
==492597==ABORTING


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