-
-
Notifications
You must be signed in to change notification settings - Fork 1.7k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
MDEV 6766 #8
MDEV 6766 #8
Conversation
Step #7 (mostly preparatory for the next step #8): Splitting the function get_mm_parts() into a virtual method in Item. This changes a virtual call for item->type() into a virtual call for item->get_mm_tree(), but also *removes* one virtual call Item_cond::functype(), which used to distinguish between COND_AND_FUNC vs COND_OR_FUNC.
Step #8: Adding get_mm_tree() in Item_func, Item_func_between, Item_func_in, Item_equal. This removes one virtual call item->type() in queries like: SELECT * FROM t1 WHERE c BETWEEN const1 AND const2; SELECT * FROM t1 WHERE c>const; SELECT * FROM t1 WHERE c IN (const_list);
Binlog is rotated too early because of additional annotate events. Preserve old logic by adjusting max_binlog_size for the test
Binlog is rotated too early because of additional annotate events. Preserve old logic by adjusting max_binlog_size for the test
Adding manual backfill ability in pulse_actions
Fixes this report: ==3165==ERROR: AddressSanitizer: use-after-poison on address 0x61e0000270a0 at pc 0x00000114b78c bp 0x7f15d65fe120 sp 0x7f15d65fd8d0 WRITE of size 1366 at 0x61e0000270a0 thread T28 #0 0x114b78b in __asan_memcpy fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/asan/asan_interceptors_memintrinsics.cc:23 #1 0x208208d in TABLE::init(THD*, TABLE_LIST*) work/mariadb/sql/table.cc:4662:3 #2 0x19df85b in open_table(THD*, TABLE_LIST*, Open_table_context*) work/mariadb/sql/sql_base.cc:1993:10 #3 0x19eb968 in open_and_process_table(THD*, LEX*, TABLE_LIST*, unsigned int*, unsigned int, Prelocking_strategy*, bool, Open_table_context*) work/mariadb/sql/sql_base.cc:3483:14 #4 0x19e7c05 in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) work/mariadb/sql/sql_base.cc:4001:14 #5 0x19f4dac in open_and_lock_tables(THD*, DDL_options_st const&, TABLE_LIST*, bool, unsigned int, Prelocking_strategy*) work/mariadb/sql/sql_base.cc:4879:7 #6 0x1627263 in open_and_lock_tables(THD*, TABLE_LIST*, bool, unsigned int) work/mariadb/sql/sql_base.h:487:10 #7 0x1c3839c in mysql_execute_command(THD*) work/mariadb/sql/sql_parse.cc:5113:13 #8 0x1c1b72c in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) work/mariadb/sql/sql_parse.cc:7980:18 #9 0x1c13464 in handle_bootstrap_impl(THD*) work/mariadb/sql/sql_parse.cc:1044:5 #10 0x1c11ff7 in do_handle_bootstrap(THD*) work/mariadb/sql/sql_parse.cc:1096:3 #11 0x1c11d14 in handle_bootstrap work/mariadb/sql/sql_parse.cc:1079:3 #12 0x115a6ae in __asan::AsanThread::ThreadStart(unsigned long, __sanitizer::atomic_uintptr_t*) fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/asan/asan_thread.cc:259 #13 0x7f15fe1407fb in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x77fb) #14 0x7f15fbb64b5e in clone /build/glibc-itYbWN/glibc-2.26/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Can one of the admins verify this patch? |
srv_last_monitor_time: make all accesses relaxed atomical WARNING: ThreadSanitizer: data race (pid=12041) Write of size 8 at 0x000003949278 by thread T26 (mutexes: write M226445748578513120): #0 thd_destructor_proxy storage/innobase/handler/ha_innodb.cc:314:14 (mysqld+0x19b5505) Previous read of size 8 at 0x000003949278 by main thread: #0 innobase_init(void*) storage/innobase/handler/ha_innodb.cc:4180:11 (mysqld+0x1a03404) #1 ha_initialize_handlerton(st_plugin_int*) sql/handler.cc:522:31 (mysqld+0xc5ec73) #2 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) sql/sql_plugin.cc:1447:9 (mysqld+0x134908d) #3 plugin_init(int*, char**, int) sql/sql_plugin.cc:1729:15 (mysqld+0x13484f0) #4 init_server_components() sql/mysqld.cc:5345:7 (mysqld+0xbf720f) #5 mysqld_main(int, char**) sql/mysqld.cc:5940:7 (mysqld+0xbf107d) #6 main sql/main.cc:25:10 (mysqld+0xbe971b) Location is global 'srv_running' of size 8 at 0x000003949278 (mysqld+0x000003949278) WARNING: ThreadSanitizer: data race (pid=27869) Atomic write of size 4 at 0x7b4800000c00 by thread T8: #0 __tsan_atomic32_exchange llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interface_atomic.cc:589 (mysqld+0xbd4eac) #1 TTASEventMutex<GenericPolicy>::exit() storage/innobase/include/ib0mutex.h:467:7 (mysqld+0x1a8d4cb) #2 PolicyMutex<TTASEventMutex<GenericPolicy> >::exit() storage/innobase/include/ib0mutex.h:609:10 (mysqld+0x1a7839e) #3 fil_validate() storage/innobase/fil/fil0fil.cc:5535:2 (mysqld+0x1abd913) #4 fil_validate_skip() storage/innobase/fil/fil0fil.cc:204:9 (mysqld+0x1aba601) #5 fil_aio_wait(unsigned long) storage/innobase/fil/fil0fil.cc:5296:2 (mysqld+0x1abbae6) #6 io_handler_thread storage/innobase/srv/srv0start.cc:340:3 (mysqld+0x21abe1e) Previous read of size 4 at 0x7b4800000c00 by main thread (mutexes: write M1273, write M1271): #0 TTASEventMutex<GenericPolicy>::state() const storage/innobase/include/ib0mutex.h:530:10 (mysqld+0x21c66e2) #1 sync_array_detect_deadlock(sync_array_t*, sync_cell_t*, sync_cell_t*, unsigned long) storage/innobase/sync/sync0arr.cc:746:14 (mysqld+0x21c1c7a) #2 sync_array_wait_event(sync_array_t*, sync_cell_t*&) storage/innobase/sync/sync0arr.cc:465:6 (mysqld+0x21c1708) #3 TTASEventMutex<GenericPolicy>::enter(unsigned int, unsigned int, char const*, unsigned int) storage/innobase/include/ib0mutex.h:516:6 (mysqld+0x1a8c206) #4 PolicyMutex<TTASEventMutex<GenericPolicy> >::enter(unsigned int, unsigned int, char const*, unsigned int) storage/innobase/include/ib0mutex.h:635:10 (mysqld+0x1a782c3) #5 fil_mutex_enter_and_prepare_for_io(unsigned long) storage/innobase/fil/fil0fil.cc:1131:3 (mysqld+0x1a9a92e) #6 fil_io(IORequest const&, bool, page_id_t const&, page_size_t const&, unsigned long, unsigned long, void*, void*, bool) storage/innobase/fil/fil0fil.cc:5082:2 (mysqld+0x1ab8de2) #7 buf_flush_write_block_low(buf_page_t*, buf_flush_t, bool) storage/innobase/buf/buf0flu.cc:1112:3 (mysqld+0x1cb970a) #8 buf_flush_page(buf_pool_t*, buf_page_t*, buf_flush_t, bool) storage/innobase/buf/buf0flu.cc:1270:3 (mysqld+0x1cb7d70) #9 buf_flush_try_neighbors(page_id_t const&, buf_flush_t, unsigned long, unsigned long) storage/innobase/buf/buf0flu.cc:1493:9 (mysqld+0x1cc9674) #10 buf_flush_page_and_try_neighbors(buf_page_t*, buf_flush_t, unsigned long, unsigned long*) storage/innobase/buf/buf0flu.cc:1565:13 (mysqld+0x1cbadf3) #11 buf_do_flush_list_batch(buf_pool_t*, unsigned long, unsigned long) storage/innobase/buf/buf0flu.cc:1825:3 (mysqld+0x1cbbcb8) #12 buf_flush_batch(buf_pool_t*, buf_flush_t, unsigned long, unsigned long, flush_counters_t*) storage/innobase/buf/buf0flu.cc:1895:16 (mysqld+0x1cbb459) #13 buf_flush_do_batch(buf_pool_t*, buf_flush_t, unsigned long, unsigned long, flush_counters_t*) storage/innobase/buf/buf0flu.cc:2065:2 (mysqld+0x1cbcfe1) #14 buf_flush_lists(unsigned long, unsigned long, unsigned long*) storage/innobase/buf/buf0flu.cc:2167:8 (mysqld+0x1cbd5a3) #15 log_preflush_pool_modified_pages(unsigned long) storage/innobase/log/log0log.cc:1400:13 (mysqld+0x1eefc3b) #16 log_make_checkpoint_at(unsigned long, bool) storage/innobase/log/log0log.cc:1751:10 (mysqld+0x1eefb16) #17 buf_dblwr_create() storage/innobase/buf/buf0dblwr.cc:335:2 (mysqld+0x1cd2141) #18 innobase_start_or_create_for_mysql() storage/innobase/srv/srv0start.cc:2539:10 (mysqld+0x21b4d8e) #19 innobase_init(void*) storage/innobase/handler/ha_innodb.cc:4193:8 (mysqld+0x1a5e3d7) #20 ha_initialize_handlerton(st_plugin_int*) sql/handler.cc:522:31 (mysqld+0xc74d33) #21 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) sql/sql_plugin.cc:1447:9 (mysqld+0x1376d5d) #22 plugin_init(int*, char**, int) sql/sql_plugin.cc:1729:15 (mysqld+0x13761c0) #23 init_server_components() sql/mysqld.cc:5348:7 (mysqld+0xc0d0ff) #24 mysqld_main(int, char**) sql/mysqld.cc:5943:7 (mysqld+0xc06f9d) #25 main sql/main.cc:25:10 (mysqld+0xbff71b) WARNING: ThreadSanitizer: data race (pid=29031) Write of size 8 at 0x0000039e48e0 by thread T15: #0 srv_monitor_thread storage/innobase/srv/srv0srv.cc:1699:24 (mysqld+0x21a254e) Previous write of size 8 at 0x0000039e48e0 by thread T14: #0 srv_refresh_innodb_monitor_stats() storage/innobase/srv/srv0srv.cc:1165:24 (mysqld+0x21a3124) #1 srv_error_monitor_thread storage/innobase/srv/srv0srv.cc:1836:3 (mysqld+0x21a2d40) Location is global 'srv_last_monitor_time' of size 8 at 0x0000039e48e0 (mysqld+0x0000039e48e0)
More signcode fixes (windows msi)
specific temporary errors The optimistic parallel slave's worker thread could face a run-time error due to the algorithm's specifics which allows for conflicts like the reported "Can't find record in 'table'". A typical stack is like {noformat} #0 handler::print_error (this=0x61c00008f8a0, error=149, errflag=0) at handler.cc:3650 #1 0x0000555555e95361 in write_record (thd=thd@entry=0x62a0000a2208, table=table@entry=0x61f00008ce88, info=info@entry=0x7fffdee356d0) at sql_insert.cc:1944 #2 0x0000555555ea7767 in mysql_insert (thd=thd@entry=0x62a0000a2208, table_list=0x61b00012ada0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at sql_insert.cc:1039 #3 0x0000555555efda90 in mysql_execute_command (thd=thd@entry=0x62a0000a2208) at sql_parse.cc:3927 #4 0x0000555555f0cc50 in mysql_parse (thd=0x62a0000a2208, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at sql_parse.cc:7449 #5 0x00005555566d4444 in Query_log_event::do_apply_event (this=0x61200005b9c8, rgi=<optimized out>, query_arg=<optimized out>, q_len_arg=<optimized out>) at log_event.cc:4508 #6 0x00005555566d639e in Query_log_event::do_apply_event (this=<optimized out>, rgi=<optimized out>) at log_event.cc:4185 #7 0x0000555555d738cf in Log_event::apply_event (rgi=0x61d0001ea080, this=0x61200005b9c8) at log_event.h:1343 #8 apply_event_and_update_pos_apply (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080, reason=<optimized out>) at slave.cc:3479 #9 0x0000555555d8596b in apply_event_and_update_pos_for_parallel (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080) at slave.cc:3623 #10 0x00005555562aca83 in rpt_handle_event (qev=qev@entry=0x6190000fa088, rpt=rpt@entry=0x62200002bd68) at rpl_parallel.cc:50 #11 0x00005555562bd04e in handle_rpl_parallel_thread (arg=arg@entry=0x62200002bd68) at rpl_parallel.cc:1258 {noformat} Here {{handler::print_error}} computes whether to error log the current error when --log-warnings > 1. The decision flag is consulted bu {{my_message_sql()}} which can be eventually called. In the bug case the decision is to log. However in the optimistic mode slave applier case any conflict is attempted to resolve with rollback and retry to success. Hence the logging is at least extraneous. The case is fixed with refining the flags computation for my_message_sql() to downgrade it to the warning level when the error comes from the *optimistically* {{rpl_group_info::SPECULATE_OPTIMISTIC}} running parallel slave thread. As this change has a side effect to stop poluting the slave worker's THD::main_da the slave warning reporting is slightly refined so that {{convert_handler_error()}} does not log any more warning message when there's one already. Secondly, post temporary error {{convert_kill_to_deadlock_error()}} is also refined to accept a "manual" (not being in THD da) error code. This change is necessary to force a pseudo-deadlock error reporting and consequent retry.
specific temporary errors The optimistic parallel slave's worker thread could face a run-time error due to the algorithm's specifics which allows for conflicts like the reported "Can't find record in 'table'". A typical stack is like {noformat} #0 handler::print_error (this=0x61c00008f8a0, error=149, errflag=0) at handler.cc:3650 #1 0x0000555555e95361 in write_record (thd=thd@entry=0x62a0000a2208, table=table@entry=0x61f00008ce88, info=info@entry=0x7fffdee356d0) at sql_insert.cc:1944 #2 0x0000555555ea7767 in mysql_insert (thd=thd@entry=0x62a0000a2208, table_list=0x61b00012ada0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at sql_insert.cc:1039 #3 0x0000555555efda90 in mysql_execute_command (thd=thd@entry=0x62a0000a2208) at sql_parse.cc:3927 #4 0x0000555555f0cc50 in mysql_parse (thd=0x62a0000a2208, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at sql_parse.cc:7449 #5 0x00005555566d4444 in Query_log_event::do_apply_event (this=0x61200005b9c8, rgi=<optimized out>, query_arg=<optimized out>, q_len_arg=<optimized out>) at log_event.cc:4508 #6 0x00005555566d639e in Query_log_event::do_apply_event (this=<optimized out>, rgi=<optimized out>) at log_event.cc:4185 #7 0x0000555555d738cf in Log_event::apply_event (rgi=0x61d0001ea080, this=0x61200005b9c8) at log_event.h:1343 #8 apply_event_and_update_pos_apply (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080, reason=<optimized out>) at slave.cc:3479 #9 0x0000555555d8596b in apply_event_and_update_pos_for_parallel (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080) at slave.cc:3623 #10 0x00005555562aca83 in rpt_handle_event (qev=qev@entry=0x6190000fa088, rpt=rpt@entry=0x62200002bd68) at rpl_parallel.cc:50 #11 0x00005555562bd04e in handle_rpl_parallel_thread (arg=arg@entry=0x62200002bd68) at rpl_parallel.cc:1258 {noformat} Here {{handler::print_error}} computes whether to error log the current error when --log-warnings > 1. The decision flag is consulted bu {{my_message_sql()}} which can be eventually called. In the bug case the decision is to log. However in the optimistic mode slave applier case any conflict is attempted to resolve with rollback and retry to success. Hence the logging is at least extraneous. The case is fixed with adding a new flag {{ME_LOG_AS_WARN}} which {{handler::print_error}} may propagate further on through {{my_error}} when the error comes from an optimistically running slave worker thread. The new flag effectively requests the warning level for the errlog record, while the thread's DA records the actual error (which is regarded as temporary one by the parallel slave error handler).
specific temporary errors The optimistic parallel slave's worker thread could face a run-time error due to the algorithm's specifics which allows for conflicts like the reported "Can't find record in 'table'". A typical stack is like {noformat} #0 handler::print_error (this=0x61c00008f8a0, error=149, errflag=0) at handler.cc:3650 #1 0x0000555555e95361 in write_record (thd=thd@entry=0x62a0000a2208, table=table@entry=0x61f00008ce88, info=info@entry=0x7fffdee356d0) at sql_insert.cc:1944 #2 0x0000555555ea7767 in mysql_insert (thd=thd@entry=0x62a0000a2208, table_list=0x61b00012ada0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at sql_insert.cc:1039 #3 0x0000555555efda90 in mysql_execute_command (thd=thd@entry=0x62a0000a2208) at sql_parse.cc:3927 #4 0x0000555555f0cc50 in mysql_parse (thd=0x62a0000a2208, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at sql_parse.cc:7449 #5 0x00005555566d4444 in Query_log_event::do_apply_event (this=0x61200005b9c8, rgi=<optimized out>, query_arg=<optimized out>, q_len_arg=<optimized out>) at log_event.cc:4508 #6 0x00005555566d639e in Query_log_event::do_apply_event (this=<optimized out>, rgi=<optimized out>) at log_event.cc:4185 #7 0x0000555555d738cf in Log_event::apply_event (rgi=0x61d0001ea080, this=0x61200005b9c8) at log_event.h:1343 #8 apply_event_and_update_pos_apply (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080, reason=<optimized out>) at slave.cc:3479 #9 0x0000555555d8596b in apply_event_and_update_pos_for_parallel (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080) at slave.cc:3623 #10 0x00005555562aca83 in rpt_handle_event (qev=qev@entry=0x6190000fa088, rpt=rpt@entry=0x62200002bd68) at rpl_parallel.cc:50 #11 0x00005555562bd04e in handle_rpl_parallel_thread (arg=arg@entry=0x62200002bd68) at rpl_parallel.cc:1258 {noformat} Here {{handler::print_error}} computes whether to error log the current error when --log-warnings > 1. The decision flag is consulted bu {{my_message_sql()}} which can be eventually called. In the bug case the decision is to log. However in the optimistic mode slave applier case any conflict is attempted to resolve with rollback and retry to success. Hence the logging is at least extraneous. The case is fixed with adding a new flag {{ME_LOG_AS_WARN}} which {{handler::print_error}} may propagate further on through {{my_error}} when the error comes from an optimistically running slave worker thread. The new flag effectively requests the warning level for the errlog record, while the thread's DA records the actual error (which is regarded as temporary one by the parallel slave error handler).
specific temporary errors The optimistic parallel slave's worker thread could face a run-time error due to the algorithm's specifics which allows for conflicts like the reported "Can't find record in 'table'". A typical stack is like {noformat} #0 handler::print_error (this=0x61c00008f8a0, error=149, errflag=0) at handler.cc:3650 #1 0x0000555555e95361 in write_record (thd=thd@entry=0x62a0000a2208, table=table@entry=0x61f00008ce88, info=info@entry=0x7fffdee356d0) at sql_insert.cc:1944 #2 0x0000555555ea7767 in mysql_insert (thd=thd@entry=0x62a0000a2208, table_list=0x61b00012ada0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=<optimized out>, ignore=<optimized out>) at sql_insert.cc:1039 #3 0x0000555555efda90 in mysql_execute_command (thd=thd@entry=0x62a0000a2208) at sql_parse.cc:3927 #4 0x0000555555f0cc50 in mysql_parse (thd=0x62a0000a2208, rawbuf=<optimized out>, length=<optimized out>, parser_state=<optimized out>) at sql_parse.cc:7449 #5 0x00005555566d4444 in Query_log_event::do_apply_event (this=0x61200005b9c8, rgi=<optimized out>, query_arg=<optimized out>, q_len_arg=<optimized out>) at log_event.cc:4508 #6 0x00005555566d639e in Query_log_event::do_apply_event (this=<optimized out>, rgi=<optimized out>) at log_event.cc:4185 #7 0x0000555555d738cf in Log_event::apply_event (rgi=0x61d0001ea080, this=0x61200005b9c8) at log_event.h:1343 #8 apply_event_and_update_pos_apply (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080, reason=<optimized out>) at slave.cc:3479 #9 0x0000555555d8596b in apply_event_and_update_pos_for_parallel (ev=ev@entry=0x61200005b9c8, thd=thd@entry=0x62a0000a2208, rgi=rgi@entry=0x61d0001ea080) at slave.cc:3623 #10 0x00005555562aca83 in rpt_handle_event (qev=qev@entry=0x6190000fa088, rpt=rpt@entry=0x62200002bd68) at rpl_parallel.cc:50 #11 0x00005555562bd04e in handle_rpl_parallel_thread (arg=arg@entry=0x62200002bd68) at rpl_parallel.cc:1258 {noformat} Here {{handler::print_error}} computes whether to error log the current error when --log-warnings > 1. The decision flag is consulted bu {{my_message_sql()}} which can be eventually called. In the bug case the decision is to log. However in the optimistic mode slave applier case any conflict is attempted to resolve with rollback and retry to success. Hence the logging is at least extraneous. The case is fixed with adding a new flag {{ME_LOG_AS_WARN}} which {{handler::print_error}} may propagate further on through {{my_error}} when the error comes from an optimistically running slave worker thread. The new flag effectively requests the warning level for the errlog record, while the thread's DA records the actual error (which is regarded as temporary one by the parallel slave error handler).
Close connection handler on connection failure. This fixes 14 failing tests in main suite under clang+ASAN build. ASAN report for main.connect looks like this: ================================================================= ==25495==ERROR: LeakSanitizer: detected memory leaks Direct leak of 146280 byte(s) in 115 object(s) allocated from: #0 0x4fba47 in calloc /fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:138 #1 0x5a7a02 in mysql_init /work/mariadb/libmariadb/libmariadb/mariadb_lib.c:977:26 #2 0x570a7a in do_connect(st_command*) /work/mariadb/client/mysqltest.cc:6096:26 #3 0x584c39 in main /work/mariadb/client/mysqltest.cc:9321:9 #4 0x7fd15514db96 in __libc_start_main /build/glibc-OTsEL5/glibc-2.27/csu/../csu/libc-start.c:310 Indirect leak of 7065600 byte(s) in 115 object(s) allocated from: #0 0x4fb80f in __interceptor_malloc /fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:129 #1 0x637a83 in my_context_init /work/mariadb/libmariadb/libmariadb/ma_context.c:367:23 #2 0x59fd16 in mysql_optionsv /work/mariadb/libmariadb/libmariadb/mariadb_lib.c:2738:9 #3 0x5bc1d4 in mysql_options /work/mariadb/libmariadb/libmariadb/mariadb_lib.c:3242:10 #4 0x570b94 in do_connect(st_command*) /work/mariadb/client/mysqltest.cc:6103:7 #5 0x584c39 in main /work/mariadb/client/mysqltest.cc:9321:9 #6 0x7fd15514db96 in __libc_start_main /build/glibc-OTsEL5/glibc-2.27/csu/../csu/libc-start.c:310 Indirect leak of 940240 byte(s) in 115 object(s) allocated from: #0 0x4fb80f in __interceptor_malloc /fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:129 #1 0x64386e in ma_init_dynamic_array /work/mariadb/libmariadb/libmariadb/ma_array.c:49:31 #2 0x649ead in _hash_init /work/mariadb/libmariadb/libmariadb/ma_hash.c:52:7 #3 0x5a3080 in mysql_optionsv /work/mariadb/libmariadb/libmariadb/mariadb_lib.c:2938:13 #4 0x5bc20c in mysql_options4 /work/mariadb/libmariadb/libmariadb/mariadb_lib.c:3248:10 #5 0x56f63b in connect_n_handle_errors(st_command*, st_mysql*, char const*, char const*, char const*, char const*, int, char const*) /work/mariadb/client/mysqltest.cc:5874:3 #6 0x57146b in do_connect(st_command*) /work/mariadb/client/mysqltest.cc:6193:7 #7 0x584c39 in main /work/mariadb/client/mysqltest.cc:9321:9 #8 0x7fd15514db96 in __libc_start_main /build/glibc-OTsEL5/glibc-2.27/csu/../csu/libc-start.c:310 ... Closes #809
IMHO similar variables should be named similarly, we have; also we could not change 10.1 variable list so maybe it can be in 10.4 or 10.5 for sure |
The patch was not fixed and we can not accept such code. |
Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled perform sequential scan of the requested log to validate the crazy offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled, perform scan(via reading event by event), to validate the requested FROM <pos> offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
MDEV-21839: Handle crazy offset to SHOW BINLOG EVENTS Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled, perform scan(via reading event by event), to validate the requested FROM <pos> offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled, perform scan(via reading event by event), to validate the requested FROM <pos> offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled, perform scan(via reading event by event), to validate the requested FROM <pos> offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled, perform scan(via reading event by event), to validate the requested FROM <pos> offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
Problem: ======= SHOW BINLOG EVENTS FROM <"random"-pos> caused a variety of failures as reported in MDEV-18046. They are fixed but that approach is not future-proof as well as is not optimal to create extra check for being constructed event parameters. Analysis: ========= "show binlog events from <pos>" code considers the user given position as a valid event start position. The code starts reading data from this event start position onwards and tries to map it to a set of known events. Each event has a specific event structure and asserts have been added to ensure that, read event data, satisfies the event specific requirements. When a random position is supplied to "show binlog events command" the event structure specific checks will fail and they result in assert. For example: https://jira.mariadb.org/browse/MDEV-18046 In the bug description user executes CREATE TABLE/INSERT and ALTER SQL commands. When a crazy offset like "SHOW BINLOG EVENTS FROM 365" is provided code assumes offset 365 as valid event begin and proceeds to EVENT_LEN_OFFSET reads some random length and comes up with a crazy event which didn't exits in the binary log. In this quoted example scenario, event read at offset 365 is considered as "Update_rows_log_event", which is not present in binary log. Since this is a random event its validation fails and code results in assert/segmentation fault, as shown below. mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event( const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event Since we are reading random data repeating the same command SHOW BINLOG EVENTS FROM 365 produces different types of crashes with different events. MDEV-18046 reported 10 such crashes. In order to avoid such scenarios user provided starting offset needs to be validated for its correctness. Best way of doing this is to make use of checksums if they are available. MDEV-18046 fix introduced the checksum based validation. The issue still remains in cases where binlog checksums are disabled. Please find the following bug reports. MDEV-22473: binlog.binlog_show_binlog_event_random_pos failed in buildbot, server crashed in read_log_event MDEV-22455: Server crashes in Table_map_log_event, binlog.binlog_invalid_read_in_rotate failed in buildbot Fix: ==== When binlog checksum is disabled, perform scan(via reading event by event), to validate the requested FROM <pos> offset. Starting from offset 4 read the event_length of next_event in the binary log. Using the next_event length advance current offset to point to next event. Repeat this process till the current offset is less than or equal to crazy offset. If current offset is higher than crazy offset provide appropriate invalid input offset error.
=============================================================================== I. If some record is deleted by rollback, it's lock is inherited as gap lock to the next record. And if the next record is then purged while the lock is still held, the debug check will fail. The scenario is the following: 1) Some thread executes "INSERT" and checks clustered index for duplicates, it sets shared lock for checked record(let's call it record A) converting implicit lock to explicit one. Note that the record's transaction id is the same as the current transaction id: ------------------- 0x000055f1e65c6bd6 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=1059, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1466 1466 lock->type_mode = (type_mode & ~LOCK_TYPE_MASK) | LOCK_REC; (rr) bt \#0 0x000055f1e65c6bd6 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=1059, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1466 \#1 0x000055f1e65c2b29 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=1059, block=0x2e1670080560, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=true) at ./storage/innobase/include/lock0lock.ic:133 \#2 0x000055f1e65c83fe in lock_rec_add_to_queue (type_mode=1059, block=0x2e1670080560, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1941 \#3 0x000055f1e65d228f in lock_rec_convert_impl_to_expl_for_trx (block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, trx=0x55522d18d188, heap_no=9) at ./storage/innobase/lock/lock0lock.cc:5832 \#4 0x000055f1e65d2537 in lock_rec_convert_impl_to_expl (block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0) at ./storage/innobase/lock/lock0lock.cc:5886 \#5 0x000055f1e65d32d9 in lock_clust_rec_read_check_and_lock (flags=0, block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0, mode=LOCK_S, gap_mode=1024, thr=0x611370025b88) at ./storage/innobase/lock/lock0lock.cc:6194 \#6 0x000055f1e666b03c in row_ins_set_shared_rec_lock (type=1024, block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:1427 \#7 0x000055f1e666cf4f in row_ins_duplicate_error_in_clust (flags=0, cursor=0x663f4cace9e0, entry=0x61137c044900, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:2360 \#8 0x000055f1e666db48 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x149444393cd0, n_uniq=1, entry=0x61137c044900, n_ext=0, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:2658 \#9 0x000055f1e666f0cb in row_ins_clust_index_entry (index=0x149444393cd0, entry=0x61137c044900, thr=0x611370025b88, n_ext=0) at ./storage/innobase/row/row0ins.cc:3146 \#10 0x000055f1e666f4a8 in row_ins_index_entry (index=0x149444393cd0, entry=0x61137c044900, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3265 \#11 0x000055f1e666f9a4 in row_ins_index_entry_step (node=0x611370025658, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3416 \#12 0x000055f1e666fd2a in row_ins (node=0x611370025658, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3553 \#13 0x000055f1e66700c6 in row_ins_step (thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3677 \#14 0x000055f1e668c7e0 in row_insert_for_mysql (mysql_rec=0x61137005c460 "\377", prebuilt=0x611370024d50) at ./storage/innobase/row/row0mysql.cc:1408 \#15 0x000055f1e6556c1f in ha_innobase::write_row (this=0x611370033a00, record=0x61137005c460 "\377") at ./storage/innobase/handler/ha_innodb.cc:8284 \#16 0x000055f1e6378051 in handler::ha_write_row (this=0x611370033a00, buf=0x61137005c460 "\377") at ./sql/handler.cc:6118 \#17 0x000055f1e60f21c4 in write_record (thd=0xa48640010a8, table=0x61137005b8c8, info=0x663f4cacfa00) at ./sql/sql_insert.cc:1939 \#18 0x000055f1e60f00f4 in mysql_insert (thd=0xa48640010a8, table_list=0xa4864010d40, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at ./sql/sql_insert.cc:1066 \#19 0x000055f1e61149d7 in mysql_execute_command (thd=0xa48640010a8) at ./sql/sql_parse.cc:4220 \#20 0x000055f1e611faf6 in mysql_parse (thd=0xa48640010a8, rawbuf=0xa48640109e0 "INSERT INTO t6 (col1,col2, col_int, col_string, col_text) VALUES /* NULL */ (NULL,NULL,NULL,REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), @fill_amount) ), (NULL,N"..., length=347, parser_state=0x663f4cad0670, is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7796 ------------------- 2) Then duplicate key is found in row_ins_duplicate_error_in_clust(), and the transaction is rolled back. When it's rolled back, the lock is inherited to the next record(let's call it record B) as a gap lock: ------------------- \#0 lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=547, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=false) at ./storage/innobase/lock/lock0lock.cc:1467 \#1 0x000055f1e65c2b29 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=547, block=0x2e1670080560, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=false) at ./storage/innobase/include/lock0lock.ic:133 \#2 0x000055f1e65c83fe in lock_rec_add_to_queue (type_mode=547, block=0x2e1670080560, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=false) at ./storage/innobase/lock/lock0lock.cc:1941 \#3 0x000055f1e65c9fee in lock_rec_inherit_to_gap (heir_block=0x2e1670080560, block=0x2e1670080560, heir_heap_no=33, heap_no=9) at ./storage/innobase/lock/lock0lock.cc:2580 \#4 0x000055f1e65cc057 in lock_update_delete (block=0x2e1670080560, rec=0x2e167079c299 "\200", from_purge=false) at ./storage/innobase/lock/lock0lock.cc:3559 \#5 0x000055f1e6788e57 in btr_cur_optimistic_delete (cursor=0xa486405aff0, flags=0, mtr=0x663f4cacf250, from_purge=false) at ./storage/innobase/btr/btr0cur.cc:5252 \#6 0x000055f1e68af6aa in row_undo_ins_remove_clust_rec (node=0xa486405af80) at ./storage/innobase/row/row0uins.cc:141 \#7 0x000055f1e68b05b5 in row_undo_ins (node=0xa486405af80, thr=0xa4864042d78) at ./storage/innobase/row/row0uins.cc:518 \#8 0x000055f1e66d7d80 in row_undo (node=0xa486405af80, thr=0xa4864042d78) at ./storage/innobase/row/row0undo.cc:298 \#9 0x000055f1e66d7f2d in row_undo_step (thr=0xa4864042d78) at ./storage/innobase/row/row0undo.cc:351 \#10 0x000055f1e663e6a0 in que_thr_step (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1039 \#11 0x000055f1e663e8c1 in que_run_threads_low (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1103 \#12 0x000055f1e663ea73 in que_run_threads (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1143 \#13 0x000055f1e6733cb9 in trx_rollback_to_savepoint_low (trx=0x55522d18d188, savept=0x55522d18e198) at ./storage/innobase/trx/trx0roll.cc:107 \#14 0x000055f1e6733f5f in trx_rollback_to_savepoint (trx=0x55522d18d188, savept=0x55522d18e198) at ./storage/innobase/trx/trx0roll.cc:148 \#15 0x000055f1e6734756 in trx_rollback_last_sql_stat_for_mysql (trx=0x55522d18d188) at ./storage/innobase/trx/trx0roll.cc:281 \#16 0x000055f1e654fb65 in innobase_rollback (hton=0x55f1e8c17968, thd=0xa48640010a8, rollback_trx=false) at ./storage/innobase/handler/ha_innodb.cc:4875 \#17 0x000055f1e636dfb4 in ha_rollback_trans (thd=0xa48640010a8, all=false) at ./sql/handler.cc:1708 \#18 0x000055f1e6262a1b in trans_rollback_stmt (thd=0xa48640010a8) at ./sql/transaction.cc:565 \#19 0x000055f1e611b5e4 in mysql_execute_command (thd=0xa48640010a8) at ./sql/sql_parse.cc:6067 \#20 0x000055f1e611faf6 in mysql_parse (thd=0xa48640010a8, rawbuf=0xa48640109e0 "INSERT INTO t6 (col1,col2, col_int, col_string, col_text) VALUES /* NULL */ (NULL,NULL,NULL,REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), @fill_amount) ), (NULL,N"..., length=347, parser_state=0x663f4cad0670, is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7796 ------------------- 3) purge is invoked, it tries to purge record B, record B has gap lock, but the record next to the record B does not have gap lock, the debug check is failed. But initially on step 1 the acquired lock is not gap lock: ----------------- dberr_t row_ins_duplicate_error_in_clust(...) { ... if (cursor->low_match >= n_unique) { ... if (flags & BTR_NO_LOCKING_FLAG) { /* Do nothing if no-locking is set */ err = DB_SUCCESS; } else if (trx->duplicates) { /* If the SQL-query will update or replace duplicate key we will take X-lock for duplicates ( REPLACE, LOAD DATAFILE REPLACE, INSERT ON DUPLICATE KEY UPDATE). */ err = row_ins_set_exclusive_rec_lock( LOCK_REC_NOT_GAP, btr_cur_get_block(cursor), rec, cursor->index, offsets, thr); } else { err = row_ins_set_shared_rec_lock( LOCK_REC_NOT_GAP, btr_cur_get_block(cursor), rec, cursor->index, offsets, thr); } } ... } ----------------- Then lock_rec_inherit_to_gap() copies this non-gap lock to gap lock to the next record when transaction is rolled back and the record is being deleted with btr_cur_optimistic_delete(). So, rollback converted that into a gap lock, what is wrong, the lock should simply be deleted. For this purpose convert_lock_to_gap flag is added to lock_rec_inherit_to_gap() function arguments. When this flag is not set, lock_rec_inherit_to_gap() ignores non-gap locks, and this flag is set when lock_rec_inherit_to_gap() is invoked from rollback. =============================================================================== II. When locking read is in progress, and requested ordinary-lock can not be granted for delete-marked record due to conflicting lock, mtr is committed, page latch is released, and purge thread can try to purge the record. The debug check will fail as the record next to delete-marked ordinary- locked one is not ordinary-locked. To solve this issue hash-table of scanned record ids(page_id, heap_no pairs) is stored in trx_t. After locking read is finished at the end of row_search_mvcc() and rol_sel(), the hash-table is cleaned-up. When permanent cursor is restored after the lock is granted and the transaction thread is woken up, and the record stored in the cursor is purged, then the position will be set to the previous or next record dependin on the direction of scanning. =============================================================================== Warning: the current implementation for row_sel() is wrong, because the behaviour when there is conflicting lock is not the same as in row_search_mvcc(), i.e. when transaction is suspended/woken up, the execution does not leave row_search_mvcc(), while for row_sel() all necessary steps to suspend/wake-up the thread are executed outside on row_sel(), at the higher layer.
…========== This is the initial patch to show how gap lock is inherited during purge. The tests are for debugging. The code can be used to remove gap lock inherit code from purge process. =============================================================================== Extend gap locks in row_search_mvcc(). This is preliminary code without a good testing. The general logic is the following: 1) Use two directions to extend gap locks - FORWARD and BACKWARD only if "direction" argument of row_search_mvcc() is 0, otherwise use only FORWARD. 2) FORWARD and BACKWARD does not really mean forward or backward iteration through B-tree leafs, FORWARD corresponds to the same direction which was choosen in row_search_mvcc() when "moves_up" variables is set, while BACKWARD means opposite direction. 3) If "direction" argument of row_search_mvcc() is 0 then cursor position is stored in local cursor object before going to the next record in BACKWARD direction. 4) When the first non-delete-marked record is reached in BACKWARD scan, mini-transaction is committed, the cursor position is restored from local cursor object and scan direction is changed. Currently all innodb tests are passed. Things to do: 1) Copy changes in row_sel(), 2) Remove gap lock inheritance from purge process, 3) Add more cases in mtr test: a) spatial indexes b) tests for row_sel() c) ... d) PROFIT!!! Notes for code reviewer: I count on the preliminary review to be sure I am moving in the correct direction and did not make some obvoius errors, so please please don't pay attention on code format and non-full testing. =============================================================================== row_sel() changes =============================================================================== do not inherit gap locks on purge =============================================================================== Test for row_search_mvcc =============================================================================== Foreign keys constraints check fix. The problem of the current fix is that it's complexity is n*m. Because there will be one pass of parent gap for each record in childs gap. Duplicates check is not implemented. =============================================================================== This is a try to implement the way of row_sel() testing. The idea is to have special debug variable innobase_debug_que_eval_sql, when this variable is set, the inernal innodb query parser is invoked, and the result is sent to user. =============================================================================== Add forward scan and insert intention locking for insert operation. Removed backward scan from foreign key contraints check. Removed backward scan from row_search_mvcc(), leave it only for the case of ROW_SEL_EXACT_PREFIX(i.e. for ORDER BY ... DESC). Removed backward scan from rol_sel() (except ORDER BY ... DESC). Added forward scan for secondary indexes duplicates check. =============================================================================== Add debug check. If purgeable record has gap, the next record must has gap too. =============================================================================== Some debug tests. Can be useful for research. =============================================================================== Code cleanup. =============================================================================== Revert "This is a try to implement the way of row_sel() testing." This reverts commit dc33c72c3ba69989e11f377aa902ed9b32f8854a. =============================================================================== Do not set LOCK_REC_NOT_GAP for delete-marked records in row_search_mvcc() =============================================================================== Check if lock_update_delete() is invoked from purge process, the deleted record must be delete-marked. =============================================================================== Do not take into account insert intention locks on debug check. =============================================================================== The current commit solves the following issues: ------------------------------------------------------------------------------- I. If some record is deleted by rollback, it's lock is inherited as gap lock to the next record. And if the next record is then purged while the lock is still held, the debug check will fail. The scenario is the following: 1) Some thread executes "INSERT" and checks clustered index for duplicates, it sets shared lock for checked record(let's call it record A) converting implicit lock to explicit one. Note that the record's transaction id is the same as the current transaction id: ------------------- 0x000055f1e65c6bd6 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=1059, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1466 1466 lock->type_mode = (type_mode & ~LOCK_TYPE_MASK) | LOCK_REC; (rr) bt \#0 0x000055f1e65c6bd6 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=1059, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1466 \#1 0x000055f1e65c2b29 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=1059, block=0x2e1670080560, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=true) at ./storage/innobase/include/lock0lock.ic:133 \#2 0x000055f1e65c83fe in lock_rec_add_to_queue (type_mode=1059, block=0x2e1670080560, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1941 \#3 0x000055f1e65d228f in lock_rec_convert_impl_to_expl_for_trx (block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, trx=0x55522d18d188, heap_no=9) at ./storage/innobase/lock/lock0lock.cc:5832 \#4 0x000055f1e65d2537 in lock_rec_convert_impl_to_expl (block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0) at ./storage/innobase/lock/lock0lock.cc:5886 \#5 0x000055f1e65d32d9 in lock_clust_rec_read_check_and_lock (flags=0, block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0, mode=LOCK_S, gap_mode=1024, thr=0x611370025b88) at ./storage/innobase/lock/lock0lock.cc:6194 \#6 0x000055f1e666b03c in row_ins_set_shared_rec_lock (type=1024, block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:1427 \#7 0x000055f1e666cf4f in row_ins_duplicate_error_in_clust (flags=0, cursor=0x663f4cace9e0, entry=0x61137c044900, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:2360 \#8 0x000055f1e666db48 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x149444393cd0, n_uniq=1, entry=0x61137c044900, n_ext=0, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:2658 \#9 0x000055f1e666f0cb in row_ins_clust_index_entry (index=0x149444393cd0, entry=0x61137c044900, thr=0x611370025b88, n_ext=0) at ./storage/innobase/row/row0ins.cc:3146 \#10 0x000055f1e666f4a8 in row_ins_index_entry (index=0x149444393cd0, entry=0x61137c044900, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3265 \#11 0x000055f1e666f9a4 in row_ins_index_entry_step (node=0x611370025658, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3416 \#12 0x000055f1e666fd2a in row_ins (node=0x611370025658, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3553 \#13 0x000055f1e66700c6 in row_ins_step (thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3677 \#14 0x000055f1e668c7e0 in row_insert_for_mysql (mysql_rec=0x61137005c460 "\377", prebuilt=0x611370024d50) at ./storage/innobase/row/row0mysql.cc:1408 \#15 0x000055f1e6556c1f in ha_innobase::write_row (this=0x611370033a00, record=0x61137005c460 "\377") at ./storage/innobase/handler/ha_innodb.cc:8284 \#16 0x000055f1e6378051 in handler::ha_write_row (this=0x611370033a00, buf=0x61137005c460 "\377") at ./sql/handler.cc:6118 \#17 0x000055f1e60f21c4 in write_record (thd=0xa48640010a8, table=0x61137005b8c8, info=0x663f4cacfa00) at ./sql/sql_insert.cc:1939 \#18 0x000055f1e60f00f4 in mysql_insert (thd=0xa48640010a8, table_list=0xa4864010d40, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at ./sql/sql_insert.cc:1066 \#19 0x000055f1e61149d7 in mysql_execute_command (thd=0xa48640010a8) at ./sql/sql_parse.cc:4220 \#20 0x000055f1e611faf6 in mysql_parse (thd=0xa48640010a8, rawbuf=0xa48640109e0 "INSERT INTO t6 (col1,col2, col_int, col_string, col_text) VALUES /* NULL */ (NULL,NULL,NULL,REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), @fill_amount) ), (NULL,N"..., length=347, parser_state=0x663f4cad0670, is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7796 ------------------- 2) Then duplicate key is found in row_ins_duplicate_error_in_clust(), and the transaction is rolled back. When it's rolled back, the lock is inherited to the next record(let's call it record B) as a gap lock: ------------------- \#0 lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=547, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=false) at ./storage/innobase/lock/lock0lock.cc:1467 \#1 0x000055f1e65c2b29 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=547, block=0x2e1670080560, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=false) at ./storage/innobase/include/lock0lock.ic:133 \#2 0x000055f1e65c83fe in lock_rec_add_to_queue (type_mode=547, block=0x2e1670080560, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=false) at ./storage/innobase/lock/lock0lock.cc:1941 \#3 0x000055f1e65c9fee in lock_rec_inherit_to_gap (heir_block=0x2e1670080560, block=0x2e1670080560, heir_heap_no=33, heap_no=9) at ./storage/innobase/lock/lock0lock.cc:2580 \#4 0x000055f1e65cc057 in lock_update_delete (block=0x2e1670080560, rec=0x2e167079c299 "\200", from_purge=false) at ./storage/innobase/lock/lock0lock.cc:3559 \#5 0x000055f1e6788e57 in btr_cur_optimistic_delete (cursor=0xa486405aff0, flags=0, mtr=0x663f4cacf250, from_purge=false) at ./storage/innobase/btr/btr0cur.cc:5252 \#6 0x000055f1e68af6aa in row_undo_ins_remove_clust_rec (node=0xa486405af80) at ./storage/innobase/row/row0uins.cc:141 \#7 0x000055f1e68b05b5 in row_undo_ins (node=0xa486405af80, thr=0xa4864042d78) at ./storage/innobase/row/row0uins.cc:518 \#8 0x000055f1e66d7d80 in row_undo (node=0xa486405af80, thr=0xa4864042d78) at ./storage/innobase/row/row0undo.cc:298 \#9 0x000055f1e66d7f2d in row_undo_step (thr=0xa4864042d78) at ./storage/innobase/row/row0undo.cc:351 \#10 0x000055f1e663e6a0 in que_thr_step (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1039 \#11 0x000055f1e663e8c1 in que_run_threads_low (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1103 \#12 0x000055f1e663ea73 in que_run_threads (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1143 \#13 0x000055f1e6733cb9 in trx_rollback_to_savepoint_low (trx=0x55522d18d188, savept=0x55522d18e198) at ./storage/innobase/trx/trx0roll.cc:107 \#14 0x000055f1e6733f5f in trx_rollback_to_savepoint (trx=0x55522d18d188, savept=0x55522d18e198) at ./storage/innobase/trx/trx0roll.cc:148 \#15 0x000055f1e6734756 in trx_rollback_last_sql_stat_for_mysql (trx=0x55522d18d188) at ./storage/innobase/trx/trx0roll.cc:281 \#16 0x000055f1e654fb65 in innobase_rollback (hton=0x55f1e8c17968, thd=0xa48640010a8, rollback_trx=false) at ./storage/innobase/handler/ha_innodb.cc:4875 \#17 0x000055f1e636dfb4 in ha_rollback_trans (thd=0xa48640010a8, all=false) at ./sql/handler.cc:1708 \#18 0x000055f1e6262a1b in trans_rollback_stmt (thd=0xa48640010a8) at ./sql/transaction.cc:565 \#19 0x000055f1e611b5e4 in mysql_execute_command (thd=0xa48640010a8) at ./sql/sql_parse.cc:6067 \#20 0x000055f1e611faf6 in mysql_parse (thd=0xa48640010a8, rawbuf=0xa48640109e0 "INSERT INTO t6 (col1,col2, col_int, col_string, col_text) VALUES /* NULL */ (NULL,NULL,NULL,REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), @fill_amount) ), (NULL,N"..., length=347, parser_state=0x663f4cad0670, is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7796 ------------------- 3) purge is invoked, it tries to purge record B, record B has gap lock, but the record next to the record B does not have gap lock, the debug check is failed. But initially on step 1 the acquired lock is not gap lock: ----------------- dberr_t row_ins_duplicate_error_in_clust(...) { ... if (cursor->low_match >= n_unique) { ... if (flags & BTR_NO_LOCKING_FLAG) { /* Do nothing if no-locking is set */ err = DB_SUCCESS; } else if (trx->duplicates) { /* If the SQL-query will update or replace duplicate key we will take X-lock for duplicates ( REPLACE, LOAD DATAFILE REPLACE, INSERT ON DUPLICATE KEY UPDATE). */ err = row_ins_set_exclusive_rec_lock( LOCK_REC_NOT_GAP, btr_cur_get_block(cursor), rec, cursor->index, offsets, thr); } else { err = row_ins_set_shared_rec_lock( LOCK_REC_NOT_GAP, btr_cur_get_block(cursor), rec, cursor->index, offsets, thr); } } ... } ----------------- Then lock_rec_inherit_to_gap() copies this non-gap lock to gap lock to the next record when transaction is rolled back and the record is being deleted with btr_cur_optimistic_delete(). So, rollback converted that into a gap lock, what is wrong, the lock should simply be deleted. For this purpose convert_lock_to_gap flag is added to lock_rec_inherit_to_gap() function arguments. When this flag is not set, lock_rec_inherit_to_gap() ignores non-gap locks, and this flag is set when lock_rec_inherit_to_gap() is invoked from rollback. ------------------------------------------------------------------------------- II. When locking read is in progress, and requested ordinary-lock can not be granted for delete-marked record due to conflicting lock, mtr is committed, page latch is released, and purge thread can try to purge the record. The debug check will fail as the record next to delete-marked ordinary- locked one is not ordinary-locked. To solve this issue hash-table of scanned record ids(page_id, heap_no pairs) is stored in trx_t. After locking read is finished at the end of row_search_mvcc() and rol_sel(), the hash-table is cleaned-up. When permanent cursor is restored after the lock is granted and the transaction thread is woken up, and the record stored in the cursor is purged, then the position will be set to the previous or next record dependin on the direction of scanning. ------------------------------------------------------------------------------- Warning: the current implementation for row_sel() is wrong, because the behaviour when there is conflicting lock is not the same as in row_search_mvcc(), i.e. when transaction is suspended/woken up, the execution does not leave row_search_mvcc(), while for row_sel() all necessary steps to suspend/wake-up the thread are executed outside on row_sel(), at the higher layer. =============================================================================== The new system variable is added to test row_sel(). Some initial test is also added.
…========== This is the initial patch to show how gap lock is inherited during purge. The tests are for debugging. The code can be used to remove gap lock inherit code from purge process. =============================================================================== Extend gap locks in row_search_mvcc(). This is preliminary code without a good testing. The general logic is the following: 1) Use two directions to extend gap locks - FORWARD and BACKWARD only if "direction" argument of row_search_mvcc() is 0, otherwise use only FORWARD. 2) FORWARD and BACKWARD does not really mean forward or backward iteration through B-tree leafs, FORWARD corresponds to the same direction which was choosen in row_search_mvcc() when "moves_up" variables is set, while BACKWARD means opposite direction. 3) If "direction" argument of row_search_mvcc() is 0 then cursor position is stored in local cursor object before going to the next record in BACKWARD direction. 4) When the first non-delete-marked record is reached in BACKWARD scan, mini-transaction is committed, the cursor position is restored from local cursor object and scan direction is changed. Currently all innodb tests are passed. Things to do: 1) Copy changes in row_sel(), 2) Remove gap lock inheritance from purge process, 3) Add more cases in mtr test: a) spatial indexes b) tests for row_sel() c) ... d) PROFIT!!! Notes for code reviewer: I count on the preliminary review to be sure I am moving in the correct direction and did not make some obvoius errors, so please please don't pay attention on code format and non-full testing. =============================================================================== row_sel() changes =============================================================================== do not inherit gap locks on purge =============================================================================== Test for row_search_mvcc =============================================================================== Foreign keys constraints check fix. The problem of the current fix is that it's complexity is n*m. Because there will be one pass of parent gap for each record in childs gap. Duplicates check is not implemented. =============================================================================== This is a try to implement the way of row_sel() testing. The idea is to have special debug variable innobase_debug_que_eval_sql, when this variable is set, the inernal innodb query parser is invoked, and the result is sent to user. =============================================================================== Add forward scan and insert intention locking for insert operation. Removed backward scan from foreign key contraints check. Removed backward scan from row_search_mvcc(), leave it only for the case of ROW_SEL_EXACT_PREFIX(i.e. for ORDER BY ... DESC). Removed backward scan from rol_sel() (except ORDER BY ... DESC). Added forward scan for secondary indexes duplicates check. =============================================================================== Add debug check. If purgeable record has gap, the next record must has gap too. =============================================================================== Some debug tests. Can be useful for research. =============================================================================== Code cleanup. =============================================================================== Revert "This is a try to implement the way of row_sel() testing." This reverts commit dc33c72c3ba69989e11f377aa902ed9b32f8854a. =============================================================================== Do not set LOCK_REC_NOT_GAP for delete-marked records in row_search_mvcc() =============================================================================== Check if lock_update_delete() is invoked from purge process, the deleted record must be delete-marked. =============================================================================== Do not take into account insert intention locks on debug check. =============================================================================== The current commit solves the following issues: ------------------------------------------------------------------------------- I. If some record is deleted by rollback, it's lock is inherited as gap lock to the next record. And if the next record is then purged while the lock is still held, the debug check will fail. The scenario is the following: 1) Some thread executes "INSERT" and checks clustered index for duplicates, it sets shared lock for checked record(let's call it record A) converting implicit lock to explicit one. Note that the record's transaction id is the same as the current transaction id: ------------------- 0x000055f1e65c6bd6 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=1059, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1466 1466 lock->type_mode = (type_mode & ~LOCK_TYPE_MASK) | LOCK_REC; (rr) bt \#0 0x000055f1e65c6bd6 in lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=1059, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1466 \#1 0x000055f1e65c2b29 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=1059, block=0x2e1670080560, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=true) at ./storage/innobase/include/lock0lock.ic:133 \#2 0x000055f1e65c83fe in lock_rec_add_to_queue (type_mode=1059, block=0x2e1670080560, heap_no=9, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=true) at ./storage/innobase/lock/lock0lock.cc:1941 \#3 0x000055f1e65d228f in lock_rec_convert_impl_to_expl_for_trx (block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, trx=0x55522d18d188, heap_no=9) at ./storage/innobase/lock/lock0lock.cc:5832 \#4 0x000055f1e65d2537 in lock_rec_convert_impl_to_expl (block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0) at ./storage/innobase/lock/lock0lock.cc:5886 \#5 0x000055f1e65d32d9 in lock_clust_rec_read_check_and_lock (flags=0, block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0, mode=LOCK_S, gap_mode=1024, thr=0x611370025b88) at ./storage/innobase/lock/lock0lock.cc:6194 \#6 0x000055f1e666b03c in row_ins_set_shared_rec_lock (type=1024, block=0x2e1670080560, rec=0x2e167079c299 "\200", index=0x149444393cd0, offsets=0x663f4cace6d0, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:1427 \#7 0x000055f1e666cf4f in row_ins_duplicate_error_in_clust (flags=0, cursor=0x663f4cace9e0, entry=0x61137c044900, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:2360 \#8 0x000055f1e666db48 in row_ins_clust_index_entry_low (flags=0, mode=2, index=0x149444393cd0, n_uniq=1, entry=0x61137c044900, n_ext=0, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:2658 \#9 0x000055f1e666f0cb in row_ins_clust_index_entry (index=0x149444393cd0, entry=0x61137c044900, thr=0x611370025b88, n_ext=0) at ./storage/innobase/row/row0ins.cc:3146 \#10 0x000055f1e666f4a8 in row_ins_index_entry (index=0x149444393cd0, entry=0x61137c044900, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3265 \#11 0x000055f1e666f9a4 in row_ins_index_entry_step (node=0x611370025658, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3416 \#12 0x000055f1e666fd2a in row_ins (node=0x611370025658, thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3553 \#13 0x000055f1e66700c6 in row_ins_step (thr=0x611370025b88) at ./storage/innobase/row/row0ins.cc:3677 \#14 0x000055f1e668c7e0 in row_insert_for_mysql (mysql_rec=0x61137005c460 "\377", prebuilt=0x611370024d50) at ./storage/innobase/row/row0mysql.cc:1408 \#15 0x000055f1e6556c1f in ha_innobase::write_row (this=0x611370033a00, record=0x61137005c460 "\377") at ./storage/innobase/handler/ha_innodb.cc:8284 \#16 0x000055f1e6378051 in handler::ha_write_row (this=0x611370033a00, buf=0x61137005c460 "\377") at ./sql/handler.cc:6118 \#17 0x000055f1e60f21c4 in write_record (thd=0xa48640010a8, table=0x61137005b8c8, info=0x663f4cacfa00) at ./sql/sql_insert.cc:1939 \#18 0x000055f1e60f00f4 in mysql_insert (thd=0xa48640010a8, table_list=0xa4864010d40, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_ERROR, ignore=false) at ./sql/sql_insert.cc:1066 \#19 0x000055f1e61149d7 in mysql_execute_command (thd=0xa48640010a8) at ./sql/sql_parse.cc:4220 \#20 0x000055f1e611faf6 in mysql_parse (thd=0xa48640010a8, rawbuf=0xa48640109e0 "INSERT INTO t6 (col1,col2, col_int, col_string, col_text) VALUES /* NULL */ (NULL,NULL,NULL,REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), @fill_amount) ), (NULL,N"..., length=347, parser_state=0x663f4cad0670, is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7796 ------------------- 2) Then duplicate key is found in row_ins_duplicate_error_in_clust(), and the transaction is rolled back. When it's rolled back, the lock is inherited to the next record(let's call it record B) as a gap lock: ------------------- \#0 lock_rec_create_low (c_lock=0x0, thr=0x0, type_mode=547, space=11, page_no=3, page=0x2e167079c000 "l\206", <incomplete sequence \372\221>, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, holds_trx_mutex=false) at ./storage/innobase/lock/lock0lock.cc:1467 \#1 0x000055f1e65c2b29 in lock_rec_create (c_lock=0x0, thr=0x0, type_mode=547, block=0x2e1670080560, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=false) at ./storage/innobase/include/lock0lock.ic:133 \#2 0x000055f1e65c83fe in lock_rec_add_to_queue (type_mode=547, block=0x2e1670080560, heap_no=33, index=0x149444393cd0, trx=0x55522d18d188, caller_owns_trx_mutex=false) at ./storage/innobase/lock/lock0lock.cc:1941 \#3 0x000055f1e65c9fee in lock_rec_inherit_to_gap (heir_block=0x2e1670080560, block=0x2e1670080560, heir_heap_no=33, heap_no=9) at ./storage/innobase/lock/lock0lock.cc:2580 \#4 0x000055f1e65cc057 in lock_update_delete (block=0x2e1670080560, rec=0x2e167079c299 "\200", from_purge=false) at ./storage/innobase/lock/lock0lock.cc:3559 \#5 0x000055f1e6788e57 in btr_cur_optimistic_delete (cursor=0xa486405aff0, flags=0, mtr=0x663f4cacf250, from_purge=false) at ./storage/innobase/btr/btr0cur.cc:5252 \#6 0x000055f1e68af6aa in row_undo_ins_remove_clust_rec (node=0xa486405af80) at ./storage/innobase/row/row0uins.cc:141 \#7 0x000055f1e68b05b5 in row_undo_ins (node=0xa486405af80, thr=0xa4864042d78) at ./storage/innobase/row/row0uins.cc:518 \#8 0x000055f1e66d7d80 in row_undo (node=0xa486405af80, thr=0xa4864042d78) at ./storage/innobase/row/row0undo.cc:298 \#9 0x000055f1e66d7f2d in row_undo_step (thr=0xa4864042d78) at ./storage/innobase/row/row0undo.cc:351 \#10 0x000055f1e663e6a0 in que_thr_step (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1039 \#11 0x000055f1e663e8c1 in que_run_threads_low (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1103 \#12 0x000055f1e663ea73 in que_run_threads (thr=0xa4864042d78) at ./storage/innobase/que/que0que.cc:1143 \#13 0x000055f1e6733cb9 in trx_rollback_to_savepoint_low (trx=0x55522d18d188, savept=0x55522d18e198) at ./storage/innobase/trx/trx0roll.cc:107 \#14 0x000055f1e6733f5f in trx_rollback_to_savepoint (trx=0x55522d18d188, savept=0x55522d18e198) at ./storage/innobase/trx/trx0roll.cc:148 \#15 0x000055f1e6734756 in trx_rollback_last_sql_stat_for_mysql (trx=0x55522d18d188) at ./storage/innobase/trx/trx0roll.cc:281 \#16 0x000055f1e654fb65 in innobase_rollback (hton=0x55f1e8c17968, thd=0xa48640010a8, rollback_trx=false) at ./storage/innobase/handler/ha_innodb.cc:4875 \#17 0x000055f1e636dfb4 in ha_rollback_trans (thd=0xa48640010a8, all=false) at ./sql/handler.cc:1708 \#18 0x000055f1e6262a1b in trans_rollback_stmt (thd=0xa48640010a8) at ./sql/transaction.cc:565 \#19 0x000055f1e611b5e4 in mysql_execute_command (thd=0xa48640010a8) at ./sql/sql_parse.cc:6067 \#20 0x000055f1e611faf6 in mysql_parse (thd=0xa48640010a8, rawbuf=0xa48640109e0 "INSERT INTO t6 (col1,col2, col_int, col_string, col_text) VALUES /* NULL */ (NULL,NULL,NULL,REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), 10),REPEAT(SUBSTR(CAST( NULL AS CHAR),1,1), @fill_amount) ), (NULL,N"..., length=347, parser_state=0x663f4cad0670, is_com_multi=false, is_next_command=false) at ./sql/sql_parse.cc:7796 ------------------- 3) purge is invoked, it tries to purge record B, record B has gap lock, but the record next to the record B does not have gap lock, the debug check is failed. But initially on step 1 the acquired lock is not gap lock: ----------------- dberr_t row_ins_duplicate_error_in_clust(...) { ... if (cursor->low_match >= n_unique) { ... if (flags & BTR_NO_LOCKING_FLAG) { /* Do nothing if no-locking is set */ err = DB_SUCCESS; } else if (trx->duplicates) { /* If the SQL-query will update or replace duplicate key we will take X-lock for duplicates ( REPLACE, LOAD DATAFILE REPLACE, INSERT ON DUPLICATE KEY UPDATE). */ err = row_ins_set_exclusive_rec_lock( LOCK_REC_NOT_GAP, btr_cur_get_block(cursor), rec, cursor->index, offsets, thr); } else { err = row_ins_set_shared_rec_lock( LOCK_REC_NOT_GAP, btr_cur_get_block(cursor), rec, cursor->index, offsets, thr); } } ... } ----------------- Then lock_rec_inherit_to_gap() copies this non-gap lock to gap lock to the next record when transaction is rolled back and the record is being deleted with btr_cur_optimistic_delete(). So, rollback converted that into a gap lock, what is wrong, the lock should simply be deleted. For this purpose convert_lock_to_gap flag is added to lock_rec_inherit_to_gap() function arguments. When this flag is not set, lock_rec_inherit_to_gap() ignores non-gap locks, and this flag is set when lock_rec_inherit_to_gap() is invoked from rollback. ------------------------------------------------------------------------------- II. When locking read is in progress, and requested ordinary-lock can not be granted for delete-marked record due to conflicting lock, mtr is committed, page latch is released, and purge thread can try to purge the record. The debug check will fail as the record next to delete-marked ordinary- locked one is not ordinary-locked. To solve this issue hash-table of scanned record ids(page_id, heap_no pairs) is stored in trx_t. After locking read is finished at the end of row_search_mvcc() and rol_sel(), the hash-table is cleaned-up. When permanent cursor is restored after the lock is granted and the transaction thread is woken up, and the record stored in the cursor is purged, then the position will be set to the previous or next record dependin on the direction of scanning. ------------------------------------------------------------------------------- Warning: the current implementation for row_sel() is wrong, because the behaviour when there is conflicting lock is not the same as in row_search_mvcc(), i.e. when transaction is suspended/woken up, the execution does not leave row_search_mvcc(), while for row_sel() all necessary steps to suspend/wake-up the thread are executed outside on row_sel(), at the higher layer. =============================================================================== The new system variable is added to test row_sel(). Some initial test is also added.
Read of size 8 at 0x7fecf2e75fc8 by thread T2 (mutexes: write M1318): #0 tpool::thread_pool_generic::submit_task(tpool::task*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/tpool_generic.cc:823:9 (mariadbd+0x25fd2d2) #1 (anonymous namespace)::aio_uring::thread_routine((anonymous namespace)::aio_uring*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/aio_liburing.cc:173:20 (mariadbd+0x260b21b) #2 void std::__invoke_impl<void, void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(std::__invoke_other, void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x260c62a) #3 std::__invoke_result<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>::type std::__invoke<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x260c4ba) #4 void std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x260c442) #5 std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x260c3c5) #6 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x260c189) #7 <null> <null> (libstdc++.so.6+0xd230f) Previous write of size 8 at 0x7fecf2e75fc8 by main thread: #0 tpool::task::task(void (*)(void*), void*, tpool::task_group*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/task.cc:40:46 (mariadbd+0x260a138) #1 tpool::aiocb::aiocb() /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/tpool.h:147:13 (mariadbd+0x2355943) #2 void std::_Construct<tpool::aiocb>(tpool::aiocb*) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_construct.h:109:38 (mariadbd+0x2355845) #3 tpool::aiocb* std::__uninitialized_default_n_1<false>::__uninit_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:579:3 (mariadbd+0x235576c) #4 tpool::aiocb* std::__uninitialized_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:638:14 (mariadbd+0x23556e9) #5 tpool::aiocb* std::__uninitialized_default_n_a<tpool::aiocb*, unsigned long, tpool::aiocb>(tpool::aiocb*, unsigned long, std::allocator<tpool::aiocb>&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:704:14 (mariadbd+0x2355641) #6 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::_M_default_initialize(unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:1606:4 (mariadbd+0x2354f3d) #7 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::vector(unsigned long, std::allocator<tpool::aiocb> const&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:512:9 (mariadbd+0x2354a19) #8 tpool::cache<tpool::aiocb>::cache(unsigned long, tpool::cache_notification_mode) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/tpool_structs.h:73:20 (mariadbd+0x2354784) #9 io_slots::io_slots(int, int) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/os/os0file.cc:93:3 (mariadbd+0x235343b) #10 os_aio_init() /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/os/os0file.cc:3780:22 (mariadbd+0x234ebce) #11 srv_start(bool) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/srv/srv0start.cc:1190:6 (mariadbd+0x256720c) #12 innodb_init(void*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed3bda) #13 ha_initialize_handlerton(st_plugin_int*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/handler.cc:659:31 (mariadbd+0xf7be06) #14 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/sql_plugin.cc:1463:9 (mariadbd+0x160fa1b) #15 plugin_init(int*, char**, int) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/sql_plugin.cc:1756:15 (mariadbd+0x160f07f) #16 init_server_components() /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/mysqld.cc:5043:7 (mariadbd+0xd70fb2) #17 mysqld_main(int, char**) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/mysqld.cc:5655:7 (mariadbd+0xd6a9d7) #18 main /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/main.cc:34:10 (mariadbd+0xd65d18) Here T2 accesses tpool::task while the main thread still initializes it! aio_uring accesses io_slots and thus io_slots should be initialized before it. So, fixing by changing the order or initialization.
Read of size 8 at 0x7fecf2e75fc8 by thread T2 (mutexes: write M1318): #0 tpool::thread_pool_generic::submit_task(tpool::task*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/tpool_generic.cc:823:9 (mariadbd+0x25fd2d2) #1 (anonymous namespace)::aio_uring::thread_routine((anonymous namespace)::aio_uring*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/aio_liburing.cc:173:20 (mariadbd+0x260b21b) #2 void std::__invoke_impl<void, void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(std::__invoke_other, void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x260c62a) #3 std::__invoke_result<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>::type std::__invoke<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x260c4ba) #4 void std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x260c442) #5 std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x260c3c5) #6 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x260c189) #7 <null> <null> (libstdc++.so.6+0xd230f) Previous write of size 8 at 0x7fecf2e75fc8 by main thread: #0 tpool::task::task(void (*)(void*), void*, tpool::task_group*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/task.cc:40:46 (mariadbd+0x260a138) #1 tpool::aiocb::aiocb() /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/tpool.h:147:13 (mariadbd+0x2355943) #2 void std::_Construct<tpool::aiocb>(tpool::aiocb*) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_construct.h:109:38 (mariadbd+0x2355845) #3 tpool::aiocb* std::__uninitialized_default_n_1<false>::__uninit_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:579:3 (mariadbd+0x235576c) #4 tpool::aiocb* std::__uninitialized_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:638:14 (mariadbd+0x23556e9) #5 tpool::aiocb* std::__uninitialized_default_n_a<tpool::aiocb*, unsigned long, tpool::aiocb>(tpool::aiocb*, unsigned long, std::allocator<tpool::aiocb>&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:704:14 (mariadbd+0x2355641) #6 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::_M_default_initialize(unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:1606:4 (mariadbd+0x2354f3d) #7 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::vector(unsigned long, std::allocator<tpool::aiocb> const&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:512:9 (mariadbd+0x2354a19) #8 tpool::cache<tpool::aiocb>::cache(unsigned long, tpool::cache_notification_mode) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../tpool/tpool_structs.h:73:20 (mariadbd+0x2354784) #9 io_slots::io_slots(int, int) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/os/os0file.cc:93:3 (mariadbd+0x235343b) #10 os_aio_init() /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/os/os0file.cc:3780:22 (mariadbd+0x234ebce) #11 srv_start(bool) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/srv/srv0start.cc:1190:6 (mariadbd+0x256720c) #12 innodb_init(void*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed3bda) #13 ha_initialize_handlerton(st_plugin_int*) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/handler.cc:659:31 (mariadbd+0xf7be06) #14 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/sql_plugin.cc:1463:9 (mariadbd+0x160fa1b) #15 plugin_init(int*, char**, int) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/sql_plugin.cc:1756:15 (mariadbd+0x160f07f) #16 init_server_components() /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/mysqld.cc:5043:7 (mariadbd+0xd70fb2) #17 mysqld_main(int, char**) /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/mysqld.cc:5655:7 (mariadbd+0xd6a9d7) #18 main /home/kevgs/work/m/bb-10.6-kevgs/build_tsan/../sql/main.cc:34:10 (mariadbd+0xd65d18) Here T2 accesses tpool::task while the main thread still initializes it! aio_uring accesses io_slots and thus io_slots should be initialized before it. So, fixing by changing the order or initialization.
Read of size 8 at 0x7fecf2e75fc8 by thread T2 (mutexes: write M1318): #0 tpool::thread_pool_generic::submit_task(tpool::task*) /tpool/tpool_generic.cc:823:9 (mariadbd+0x25fd2d2) #1 (anonymous namespace)::aio_uring::thread_routine((anonymous namespace)::aio_uring*) /tpool/aio_liburing.cc:173:20 (mariadbd+0x260b21b) #2 void std::__invoke_impl<void, void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(std::__invoke_other, void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x260c62a) #3 std::__invoke_result<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>::type std::__invoke<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x260c4ba) #4 void std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x260c442) #5 std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x260c3c5) #6 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x260c189) #7 <null> <null> (libstdc++.so.6+0xd230f) Previous write of size 8 at 0x7fecf2e75fc8 by main thread: #0 tpool::task::task(void (*)(void*), void*, tpool::task_group*) /tpool/task.cc:40:46 (mariadbd+0x260a138) #1 tpool::aiocb::aiocb() /tpool/tpool.h:147:13 (mariadbd+0x2355943) #2 void std::_Construct<tpool::aiocb>(tpool::aiocb*) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_construct.h:109:38 (mariadbd+0x2355845) #3 tpool::aiocb* std::__uninitialized_default_n_1<false>::__uninit_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:579:3 (mariadbd+0x235576c) #4 tpool::aiocb* std::__uninitialized_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:638:14 (mariadbd+0x23556e9) #5 tpool::aiocb* std::__uninitialized_default_n_a<tpool::aiocb*, unsigned long, tpool::aiocb>(tpool::aiocb*, unsigned long, std::allocator<tpool::aiocb>&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:704:14 (mariadbd+0x2355641) #6 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::_M_default_initialize(unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:1606:4 (mariadbd+0x2354f3d) #7 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::vector(unsigned long, std::allocator<tpool::aiocb> const&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:512:9 (mariadbd+0x2354a19) #8 tpool::cache<tpool::aiocb>::cache(unsigned long, tpool::cache_notification_mode) /tpool/tpool_structs.h:73:20 (mariadbd+0x2354784) #9 io_slots::io_slots(int, int) /storage/innobase/os/os0file.cc:93:3 (mariadbd+0x235343b) #10 os_aio_init() /storage/innobase/os/os0file.cc:3780:22 (mariadbd+0x234ebce) #11 srv_start(bool) /storage/innobase/srv/srv0start.cc:1190:6 (mariadbd+0x256720c) #12 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed3bda) #13 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7be06) #14 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fa1b) #15 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f07f) #16 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd70fb2) #17 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6a9d7) #18 main /sql/main.cc:34:10 (mariadbd+0xd65d18) I think the report is incorrect: it's not possible to have such a race condition. I've checked it by reading the code and putting assertions. Namely, no aio I/O is possible before the end of os_aio_init(). Most probably it's some bug in TSAN. But the patch fixes around 5 related reports and this is a step toward TSAN usefullness. Currently it reports too much noise. std::unique_ptr is a step toward https://isocpp.github.io/CppCoreGuidelines/CppCoreGuidelines#r11-avoid-calling-new-and-delete-explicitly There is no std::make_unique() in C++11, however.
Read of size 8 at 0x7fecf2e75fc8 by thread T2 (mutexes: write M1318): #0 tpool::thread_pool_generic::submit_task(tpool::task*) /tpool/tpool_generic.cc:823:9 (mariadbd+0x25fd2d2) #1 (anonymous namespace)::aio_uring::thread_routine((anonymous namespace)::aio_uring*) /tpool/aio_liburing.cc:173:20 (mariadbd+0x260b21b) #2 void std::__invoke_impl<void, void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(std::__invoke_other, void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x260c62a) #3 std::__invoke_result<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>::type std::__invoke<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*>(void (*&&)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x260c4ba) #4 void std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::_M_invoke<0ul, 1ul>(std::_Index_tuple<0ul, 1ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x260c442) #5 std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x260c3c5) #6 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)((anonymous namespace)::aio_uring*), (anonymous namespace)::aio_uring*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x260c189) #7 <null> <null> (libstdc++.so.6+0xd230f) Previous write of size 8 at 0x7fecf2e75fc8 by main thread: #0 tpool::task::task(void (*)(void*), void*, tpool::task_group*) /tpool/task.cc:40:46 (mariadbd+0x260a138) #1 tpool::aiocb::aiocb() /tpool/tpool.h:147:13 (mariadbd+0x2355943) #2 void std::_Construct<tpool::aiocb>(tpool::aiocb*) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_construct.h:109:38 (mariadbd+0x2355845) #3 tpool::aiocb* std::__uninitialized_default_n_1<false>::__uninit_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:579:3 (mariadbd+0x235576c) #4 tpool::aiocb* std::__uninitialized_default_n<tpool::aiocb*, unsigned long>(tpool::aiocb*, unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:638:14 (mariadbd+0x23556e9) #5 tpool::aiocb* std::__uninitialized_default_n_a<tpool::aiocb*, unsigned long, tpool::aiocb>(tpool::aiocb*, unsigned long, std::allocator<tpool::aiocb>&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_uninitialized.h:704:14 (mariadbd+0x2355641) #6 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::_M_default_initialize(unsigned long) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:1606:4 (mariadbd+0x2354f3d) #7 std::vector<tpool::aiocb, std::allocator<tpool::aiocb> >::vector(unsigned long, std::allocator<tpool::aiocb> const&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/stl_vector.h:512:9 (mariadbd+0x2354a19) #8 tpool::cache<tpool::aiocb>::cache(unsigned long, tpool::cache_notification_mode) /tpool/tpool_structs.h:73:20 (mariadbd+0x2354784) #9 io_slots::io_slots(int, int) /storage/innobase/os/os0file.cc:93:3 (mariadbd+0x235343b) #10 os_aio_init() /storage/innobase/os/os0file.cc:3780:22 (mariadbd+0x234ebce) #11 srv_start(bool) /storage/innobase/srv/srv0start.cc:1190:6 (mariadbd+0x256720c) #12 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed3bda) #13 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7be06) #14 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fa1b) #15 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f07f) #16 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd70fb2) #17 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6a9d7) #18 main /sql/main.cc:34:10 (mariadbd+0xd65d18) I think the report is incorrect: it's not possible to have such a race condition. I've checked it by reading the code and putting assertions. Namely, no aio I/O is possible before the end of os_aio_init(). Most probably it's some bug in TSAN. But the patch fixes around 5 related reports and this is a step toward TSAN usefullness. Currently it reports too much noise. std::unique_ptr is a step toward https://isocpp.github.io/CppCoreGuidelines/CppCoreGuidelines#r11-avoid-calling-new-and-delete-explicitly There is no std::make_unique() in C++11, however.
WARNING: ThreadSanitizer: data race (pid=1503350) Write of size 8 at 0x0000067b1f20 by thread T3: #0 os_file_sync_posix(int) /storage/innobase/os/os0file.cc:895:5 (mariadbd+0x23493f6) #1 os_file_flush_func(int) /storage/innobase/os/os0file.cc:983:8 (mariadbd+0x2349204) #2 file_os_io::flush() /storage/innobase/log/log0log.cc:326:10 (mariadbd+0x22eaaa9) #3 log_file_t::flush() /storage/innobase/log/log0log.cc:440:18 (mariadbd+0x22eb2d0) #4 log_t::file::flush() /storage/innobase/log/log0log.cc:507:29 (mariadbd+0x22ebe69) #5 log_write_flush_to_disk_low(unsigned long) /storage/innobase/log/log0log.cc:629:17 (mariadbd+0x22ed3f3) #6 log_write_up_to(unsigned long, bool, bool, completion_callback const*) /storage/innobase/log/log0log.cc:829:3 (mariadbd+0x22ecb04) #7 log_checkpoint_low(unsigned long, unsigned long) /storage/innobase/buf/buf0flu.cc:1734:5 (mariadbd+0x20d37f1) #8 buf_flush_sync_for_checkpoint(unsigned long) /storage/innobase/buf/buf0flu.cc:1947:7 (mariadbd+0x20d4193) #9 buf_flush_page_cleaner() /storage/innobase/buf/buf0flu.cc:2186:9 (mariadbd+0x20cdad7) #10 void std::__invoke_impl<void, void (*)()>(std::__invoke_other, void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x20c3aaa) #11 std::__invoke_result<void (*)()>::type std::__invoke<void (*)()>(void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x20c39bd) #12 void std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x20c3965) #13 std::thread::_Invoker<std::tuple<void (*)()> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x20c3905) #14 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x20c37f9) #15 <null> <null> (libstdc++.so.6+0xd230f) Previous write of size 8 at 0x0000067b1f20 by main thread: #0 os_file_sync_posix(int) /storage/innobase/os/os0file.cc:895:5 (mariadbd+0x23493f6) #1 os_file_flush_func(int) /storage/innobase/os/os0file.cc:983:8 (mariadbd+0x2349204) #2 fil_space_t::flush_low() /storage/innobase/fil/fil0fil.cc:504:5 (mariadbd+0x205cad5) #3 fil_flush_file_spaces() /storage/innobase/fil/fil0fil.cc:2947:13 (mariadbd+0x206523f) #4 log_checkpoint() /storage/innobase/buf/buf0flu.cc:1777:5 (mariadbd+0x20cd069) #5 buf_flush_wait_flushed(unsigned long) /storage/innobase/buf/buf0flu.cc:1867:5 (mariadbd+0x20ccf95) #6 log_make_checkpoint() /storage/innobase/buf/buf0flu.cc:1793:3 (mariadbd+0x20cc4c9) #7 buf_dblwr_t::create() /storage/innobase/buf/buf0dblwr.cc:216:3 (mariadbd+0x209076a) #8 srv_start(bool) /storage/innobase/srv/srv0start.cc:1685:20 (mariadbd+0x256b514) #9 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed406a) #10 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7c246) #11 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fe6b) #12 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f4cf) #13 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd713f2) #14 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6ae17) #15 main /sql/main.cc:34:10 (mariadbd+0xd66158) This is a correct report by TSAN for an obvious case: unprotected global counter. Fix it by making counter std::atomic.
WARNING: ThreadSanitizer: data race (pid=1506937) Write of size 8 at 0x0000067ab740 by thread T6: #0 buf_page_get_low(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:2946:8 (mariadbd+0x2014c7f) #1 buf_page_get_gen(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:3047:10 (mariadbd+0x2016216) #2 btr_cur_search_to_nth_level_func(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_cur_t*, ssux_lock_impl<true>*, mtr_t*, unsigned long) /storage/innobase/btr/btr0cur.cc:1613:10 (mariadbd+0x1fb5bff) #3 btr_pcur_open_low(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_pcur_t*, unsigned long, mtr_t*) /storage/innobase/include/btr0pcur.ic:439:8 (mariadbd+0x24ddead) #4 row_search_on_row_ref(btr_pcur_t*, unsigned long, dict_table_t const*, dtuple_t const*, mtr_t*) /storage/innobase/row/row0row.cc:1215:7 (mariadbd+0x24dd537) #5 row_purge_reposition_pcur(unsigned long, purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:81:23 (mariadbd+0x24c5369) #6 row_purge_reset_trx_id(purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:748:6 (mariadbd+0x24c90c7) #7 row_purge_record_func(purge_node_t*, unsigned char*, que_thr_t const*, bool) /storage/innobase/row/row0purge.cc:1174:4 (mariadbd+0x24c8262) #8 row_purge(purge_node_t*, unsigned char*, que_thr_t*) /storage/innobase/row/row0purge.cc:1218:18 (mariadbd+0x24c5af3) #9 row_purge_step(que_thr_t*) /storage/innobase/row/row0purge.cc:1267:3 (mariadbd+0x24c5996) #10 que_thr_step(que_thr_t*) /storage/innobase/que/que0que.cc:653:9 (mariadbd+0x23d5298) #11 que_run_threads_low(que_thr_t*) /storage/innobase/que/que0que.cc:709:25 (mariadbd+0x23d3f29) #12 que_run_threads(que_thr_t*) /storage/innobase/que/que0que.cc:729:2 (mariadbd+0x23d3bdf) #13 srv_task_execute() /storage/innobase/srv/srv0srv.cc:1692:3 (mariadbd+0x2562841) #14 purge_worker_callback(void*) /storage/innobase/srv/srv0srv.cc:1864:10 (mariadbd+0x255f361) #15 tpool::task_group::execute(tpool::task*) /tpool/task_group.cc:55:9 (mariadbd+0x260a5ca) #16 tpool::task::execute() /tpool/task.cc:47:16 (mariadbd+0x260adf6) #17 tpool::thread_pool_generic::worker_main(tpool::worker_data*) /tpool/tpool_generic.cc:550:11 (mariadbd+0x25fc590) #18 void std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(std::__invoke_memfun_deref, void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:74:14 (mariadbd+0x26061b5) #19 std::__invoke_result<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>::type std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x2605f57) #20 void std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul>(std::_Index_tuple<0ul, 1ul, 2ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x2605ecb) #21 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x2605e35) #22 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x2605ac9) #23 <null> <null> (libstdc++.so.6+0xd230f) Previous write of size 8 at 0x0000067ab740 by thread T8: #0 buf_page_get_low(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:2946:8 (mariadbd+0x2014c7f) #1 buf_page_get_gen(page_id_t, unsigned long, unsigned long, buf_block_t*, unsigned long, mtr_t*, dberr_t*, bool) /storage/innobase/buf/buf0buf.cc:3047:10 (mariadbd+0x2016216) #2 btr_cur_search_to_nth_level_func(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_cur_t*, ssux_lock_impl<true>*, mtr_t*, unsigned long) /storage/innobase/btr/btr0cur.cc:1613:10 (mariadbd+0x1fb5bff) #3 btr_pcur_open_low(dict_index_t*, unsigned long, dtuple_t const*, page_cur_mode_t, unsigned long, btr_pcur_t*, unsigned long, mtr_t*) /storage/innobase/include/btr0pcur.ic:439:8 (mariadbd+0x24ddead) #4 row_search_on_row_ref(btr_pcur_t*, unsigned long, dict_table_t const*, dtuple_t const*, mtr_t*) /storage/innobase/row/row0row.cc:1215:7 (mariadbd+0x24dd537) #5 row_purge_reposition_pcur(unsigned long, purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:81:23 (mariadbd+0x24c5369) #6 row_purge_reset_trx_id(purge_node_t*, mtr_t*) /storage/innobase/row/row0purge.cc:748:6 (mariadbd+0x24c90c7) #7 row_purge_record_func(purge_node_t*, unsigned char*, que_thr_t const*, bool) /storage/innobase/row/row0purge.cc:1174:4 (mariadbd+0x24c8262) #8 row_purge(purge_node_t*, unsigned char*, que_thr_t*) /storage/innobase/row/row0purge.cc:1218:18 (mariadbd+0x24c5af3) #9 row_purge_step(que_thr_t*) /storage/innobase/row/row0purge.cc:1267:3 (mariadbd+0x24c5996) #10 que_thr_step(que_thr_t*) /storage/innobase/que/que0que.cc:653:9 (mariadbd+0x23d5298) #11 que_run_threads_low(que_thr_t*) /storage/innobase/que/que0que.cc:709:25 (mariadbd+0x23d3f29) #12 que_run_threads(que_thr_t*) /storage/innobase/que/que0que.cc:729:2 (mariadbd+0x23d3bdf) #13 trx_purge(unsigned long, bool) /storage/innobase/trx/trx0purge.cc:1271:2 (mariadbd+0x25841b4) #14 srv_do_purge(unsigned long*) /storage/innobase/srv/srv0srv.cc:1784:20 (mariadbd+0x2563224) #15 purge_coordinator_callback_low() /storage/innobase/srv/srv0srv.cc:1881:35 (mariadbd+0x2562b3b) #16 purge_coordinator_callback(void*) /storage/innobase/srv/srv0srv.cc:1910:3 (mariadbd+0x255f4ab) #17 tpool::task_group::execute(tpool::task*) /tpool/task_group.cc:55:9 (mariadbd+0x260a5ca) #18 tpool::task::execute() /tpool/task.cc:47:16 (mariadbd+0x260adf6) #19 tpool::thread_pool_generic::worker_main(tpool::worker_data*) /tpool/tpool_generic.cc:550:11 (mariadbd+0x25fc590) #20 void std::__invoke_impl<void, void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(std::__invoke_memfun_deref, void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:74:14 (mariadbd+0x26061b5) #21 std::__invoke_result<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>::type std::__invoke<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*>(void (tpool::thread_pool_generic::*&&)(tpool::worker_data*), tpool::thread_pool_generic*&&, tpool::worker_data*&&) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x2605f57) #22 void std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::_M_invoke<0ul, 1ul, 2ul>(std::_Index_tuple<0ul, 1ul, 2ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x2605ecb) #23 std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x2605e35) #24 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (tpool::thread_pool_generic::*)(tpool::worker_data*), tpool::thread_pool_generic*, tpool::worker_data*> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x2605ac9) #25 <null> <null> (libstdc++.so.6+0xd230f) Location is global 'buf_dbg_counter' of size 8 at 0x0000067ab740 (mariadbd+0x67ab740) The obvious fix is to make counter atomic.
Write of size 1 at 0x0000067abe08 by thread T3 (mutexes: write M1372): #0 buf_flush_page_cleaner() /storage/innobase/buf/buf0flu.cc:2366:29 (mariadbd+0x20cea7c) #1 void std::__invoke_impl<void, void (*)()>(std::__invoke_other, void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x20c3a8a) #2 std::__invoke_result<void (*)()>::type std::__invoke<void (*)()>(void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x20c399d) #3 void std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x20c3945) #4 std::thread::_Invoker<std::tuple<void (*)()> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x20c38e5) #5 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x20c37d9) #6 <null> <null> (libstdc++.so.6+0xd230f) Previous read of size 1 at 0x0000067abe08 by main thread: #0 logs_empty_and_mark_files_at_shutdown() /storage/innobase/log/log0log.cc:1094:6 (mariadbd+0x22eeff3) #1 innodb_shutdown() /storage/innobase/srv/srv0start.cc:1970:3 (mariadbd+0x256ffd6) #2 innobase_end(handlerton*, ha_panic_function) /storage/innobase/handler/ha_innodb.cc:4265:3 (mariadbd+0x1ee3fc4) #3 ha_finalize_handlerton(st_plugin_int*) /sql/handler.cc:595:5 (mariadbd+0xf7bac9) #4 plugin_deinitialize(st_plugin_int*, bool) /sql/sql_plugin.cc:1266:9 (mariadbd+0x1611789) #5 reap_plugins() /sql/sql_plugin.cc:1342:7 (mariadbd+0x160e17d) #6 plugin_shutdown() /sql/sql_plugin.cc:2050:7 (mariadbd+0x1611f42) #7 clean_up(bool) /sql/mysqld.cc:1923:3 (mariadbd+0xd67a4c) #8 unireg_abort /sql/mysqld.cc:1835:3 (mariadbd+0xd67605) #9 mysqld_main(int, char**) /sql/mysqld.cc:5741:7 (mariadbd+0xd6b36a) #10 main /sql/main.cc:34:10 (mariadbd+0xd661a8) Location is global 'buf_page_cleaner_is_active' of size 1 at 0x0000067abe08 (mariadbd+0x67abe08)
WARNING: ThreadSanitizer: data race (pid=1510842) Write of size 8 at 0x0000067b1e98 by main thread: #0 os_file_pwrite(IORequest const&, int, unsigned char const*, unsigned long, unsigned long, dberr_t*) /storage/innobase/os/os0file.cc:2928:2 (mariadbd+0x234c5ac) #1 os_file_write_func(IORequest const&, char const*, int, void const*, unsigned long, unsigned long) /storage/innobase/os/os0file.cc:2963:20 (mariadbd+0x234c019) #2 file_os_io::write(char const*, unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:320:10 (mariadbd+0x22eaa50) #3 log_file_t::write(unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:434:18 (mariadbd+0x22eb1d8) #4 log_t::file::write(unsigned long, st_::span<unsigned char>) /storage/innobase/log/log0log.cc:496:29 (mariadbd+0x22ebb55) #5 log_write_buf(unsigned char*, unsigned long, unsigned long, unsigned long, unsigned long) /storage/innobase/log/log0log.cc:614:14 (mariadbd+0x22f1b51) #6 log_write(bool) /storage/innobase/log/log0log.cc:755:2 (mariadbd+0x22ed2ec) #7 log_write_up_to(unsigned long, bool, bool, completion_callback const*) /storage/innobase/log/log0log.cc:817:5 (mariadbd+0x22eca44) #8 log_checkpoint_low(unsigned long, unsigned long) /storage/innobase/buf/buf0flu.cc:1734:5 (mariadbd+0x20d37c1) #9 log_checkpoint() /storage/innobase/buf/buf0flu.cc:1787:10 (mariadbd+0x20cd155) #10 buf_flush_wait_flushed(unsigned long) /storage/innobase/buf/buf0flu.cc:1867:5 (mariadbd+0x20ccf8f) #11 log_make_checkpoint() /storage/innobase/buf/buf0flu.cc:1793:3 (mariadbd+0x20cc4c9) #12 buf_dblwr_t::create() /storage/innobase/buf/buf0dblwr.cc:216:3 (mariadbd+0x209076a) #13 srv_start(bool) /storage/innobase/srv/srv0start.cc:1685:20 (mariadbd+0x256b4aa) #14 innodb_init(void*) /storage/innobase/handler/ha_innodb.cc:4188:8 (mariadbd+0x1ed40da) #15 ha_initialize_handlerton(st_plugin_int*) /sql/handler.cc:659:31 (mariadbd+0xf7c2b6) #16 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) /sql/sql_plugin.cc:1463:9 (mariadbd+0x160fedb) #17 plugin_init(int*, char**, int) /sql/sql_plugin.cc:1756:15 (mariadbd+0x160f53f) #18 init_server_components() /sql/mysqld.cc:5043:7 (mariadbd+0xd71462) #19 mysqld_main(int, char**) /sql/mysqld.cc:5655:7 (mariadbd+0xd6ae87) #20 main /sql/main.cc:34:10 (mariadbd+0xd661c8) Previous write of size 8 at 0x0000067b1e98 by thread T3: #0 os_file_pwrite(IORequest const&, int, unsigned char const*, unsigned long, unsigned long, dberr_t*) /storage/innobase/os/os0file.cc:2928:2 (mariadbd+0x234c5ac) #1 os_file_write_func(IORequest const&, char const*, int, void const*, unsigned long, unsigned long) /storage/innobase/os/os0file.cc:2963:20 (mariadbd+0x234c019) #2 file_os_io::write(char const*, unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:320:10 (mariadbd+0x22eaa50) #3 log_file_t::write(unsigned long, st_::span<unsigned char const>) /storage/innobase/log/log0log.cc:434:18 (mariadbd+0x22eb1d8) #4 log_t::file::write(unsigned long, st_::span<unsigned char>) /storage/innobase/log/log0log.cc:496:29 (mariadbd+0x22ebb55) #5 log_write_checkpoint_info(unsigned long) /storage/innobase/log/log0log.cc:911:14 (mariadbd+0x22edd4e) #6 log_checkpoint_low(unsigned long, unsigned long) /storage/innobase/buf/buf0flu.cc:1755:3 (mariadbd+0x20d3a3d) #7 buf_flush_sync_for_checkpoint(unsigned long) /storage/innobase/buf/buf0flu.cc:1947:7 (mariadbd+0x20d4163) #8 buf_flush_page_cleaner() /storage/innobase/buf/buf0flu.cc:2186:9 (mariadbd+0x20cdab1) #9 void std::__invoke_impl<void, void (*)()>(std::__invoke_other, void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:61:14 (mariadbd+0x20c3aaa) #10 std::__invoke_result<void (*)()>::type std::__invoke<void (*)()>(void (*&&)()) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/invoke.h:96:14 (mariadbd+0x20c39bd) #11 void std::thread::_Invoker<std::tuple<void (*)()> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:253:13 (mariadbd+0x20c3965) #12 std::thread::_Invoker<std::tuple<void (*)()> >::operator()() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:260:11 (mariadbd+0x20c3905) #13 std::thread::_State_impl<std::thread::_Invoker<std::tuple<void (*)()> > >::_M_run() /usr/lib/gcc/x86_64-linux-gnu/11/../../../../include/c++/11/bits/std_thread.h:211:13 (mariadbd+0x20c37f9) #14 <null> <null> (libstdc++.so.6+0xd230f) Location is global 'os_n_file_writes' of size 8 at 0x0000067b1e98 (mariadbd+0x67b1e98) Make variable atomic.
There seem to be 2 ASAN issues using mysqltest.cc (at least using test binlog.binlog_autocommit_off_no_hang): 1. (Fixed by this test) cur_con is not NULLed when freeing connections. At backtrace time, it can be read (though the backtrace is likely caused by point 2). 2. (Still to be fixed) There is a leak in mariadb_lib.c line 3863: ``` OPT_SET_EXTENDED_VALUE(&mysql->options, tls_verification_callback, arg1); ``` with stack ================================================================= ==288928==ERROR: LeakSanitizer: detected memory leaks Direct leak of 1568 byte(s) in 4 object(s) allocated from: #0 0x5ceaa4ebad7d in calloc (./server/build116_asan/client/mariadb-test+0x1dcd7d) (BuildId: 21b3097a37beada873a1eaa15c1ea1f16d3ad6d7) #1 0x5ceaa4f6457f in mysql_optionsv ./server/libmariadb/libmariadb/mariadb_lib.c:3863:7 #2 0x5ceaa4f698fd in mysql_init ./server/libmariadb/libmariadb/mariadb_lib.c:1320:3 #3 0x5ceaa4f5a06f in mariadb_reconnect ./server/libmariadb/libmariadb/mariadb_lib.c:2104:3 #4 0x5ceaa4f58c8b in mthd_my_send_cmd ./server/libmariadb/libmariadb/mariadb_lib.c:394:9 #5 0x5ceaa4f5add5 in ma_simple_command ./server/libmariadb/libmariadb/mariadb_lib.c:472:10 #6 0x5ceaa4f75044 in mysql_send_query ./server/libmariadb/libmariadb/mariadb_lib.c:2524:10 #7 0x5ceaa4efc226 in wrap_mysql_send_query(st_mysql*, char const*, unsigned long) ./server/client/../tests/nonblock-wrappers.h:211:1 #8 0x5ceaa4f2f8ce in run_query_normal(st_connection*, st_command*, int, char const*, unsigned long, st_dynamic_string*, st_dynamic_string*) ./server/client/mysqltest.cc:8230:9 #9 0x5ceaa4f36676 in run_query(st_connection*, st_command*, int) ./server/client/mysqltest.cc:9652:5 #10 0x5ceaa4f3a0ea in main ./server/client/mysqltest.cc:10484:2 #11 0x7efaf322a1c9 in __libc_start_call_main csu/../sysdeps/nptl/libc_start_call_main.h:58:16 #12 0x7efaf322a28a in __libc_start_main csu/../csu/libc-start.c:360:3 #13 0x5ceaa4e1fd44 in _start (./server/build116_asan/client/mariadb-test+0x141d44) (BuildId: 21b3097a37beada873a1eaa15c1ea1f16d3ad6d7)
first part of MDEV (timeout variables)