From 4a2b79b0be36edc345f263048d7216edb7c5edff Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Thu, 11 Jan 2018 19:41:29 +0300 Subject: [PATCH 1/3] fix simple InnoDB data race ================== 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) Mutex M226445748578513120 is already destroyed. Thread T26 (tid=12070, running) created by main thread at: #0 pthread_create /home/kevg/fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:992 (mysqld+0xb7a016) #1 spawn_thread_noop mysys/psi_noop.c:187:10 (mysqld+0x26fe403) #2 inline_mysql_thread_create(unsigned int, unsigned long*, pthread_attr_t const*, void* (*)(void*), void*) include/mysql/psi/mysql_thread.h:1239:11 (mysqld+0x1a1136d) #3 innobase_init(void*) storage/innobase/handler/ha_innodb.cc:4177:3 (mysqld+0x1a033e5) #4 ha_initialize_handlerton(st_plugin_int*) sql/handler.cc:522:31 (mysqld+0xc5ec73) #5 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) sql/sql_plugin.cc:1447:9 (mysqld+0x134908d) #6 plugin_init(int*, char**, int) sql/sql_plugin.cc:1729:15 (mysqld+0x13484f0) #7 init_server_components() sql/mysqld.cc:5345:7 (mysqld+0xbf720f) #8 mysqld_main(int, char**) sql/mysqld.cc:5940:7 (mysqld+0xbf107d) #9 main sql/main.cc:25:10 (mysqld+0xbe971b) SUMMARY: ThreadSanitizer: data race storage/innobase/handler/ha_innodb.cc:314:14 in thd_destructor_proxy ================== --- storage/innobase/handler/ha_innodb.cc | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 42062e452ee4b..fdc5a55a1c700 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -311,7 +311,8 @@ thd_destructor_proxy(void *) myvar->current_cond = &thd_destructor_cond; mysql_mutex_lock(&thd_destructor_mutex); - srv_running = myvar; + my_atomic_storeptr_explicit(&srv_running, myvar, + MY_MEMORY_ORDER_RELAXED); /* wait until the server wakes the THD to abort and die */ while (!srv_running->abort) mysql_cond_wait(&thd_destructor_cond, &thd_destructor_mutex); @@ -4209,7 +4210,8 @@ innobase_init( mysql_thread_create(thd_destructor_thread_key, &thd_destructor_thread, NULL, thd_destructor_proxy, NULL); - while (!srv_running) + while (!my_atomic_loadptr_explicit(&srv_running, + MY_MEMORY_ORDER_RELAXED)) os_thread_sleep(20); } From 147ec14c5493a0b519322f0f4cd1a6b29eab6d52 Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Sun, 21 Jan 2018 18:11:14 +0300 Subject: [PATCH 2/3] fix InnoDB data race 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::exit() storage/innobase/include/ib0mutex.h:467:7 (mysqld+0x1a8d4cb) #2 PolicyMutex >::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::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::enter(unsigned int, unsigned int, char const*, unsigned int) storage/innobase/include/ib0mutex.h:516:6 (mysqld+0x1a8c206) #4 PolicyMutex >::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) --- storage/innobase/include/ib0mutex.h | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/storage/innobase/include/ib0mutex.h b/storage/innobase/include/ib0mutex.h index 76f02cc152115..afa8f295e1c8b 100644 --- a/storage/innobase/include/ib0mutex.h +++ b/storage/innobase/include/ib0mutex.h @@ -527,7 +527,8 @@ struct TTASEventMutex { int32 state() const UNIV_NOTHROW { - return(m_lock_word); + return(my_atomic_load32_explicit(&m_lock_word, + MY_MEMORY_ORDER_RELAXED)); } /** The event that the mutex will wait in sync0arr.cc From f18f71efcbb9c0989564ec78832db7d89f7d19a9 Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Sun, 21 Jan 2018 19:07:47 +0300 Subject: [PATCH 3/3] fix InnoDB data race srv_last_monitor_time: make all accesses relaxed atomical 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) Thread T15 (tid=29050, running) created by main thread at: #0 pthread_create /home/kevg/fun/cpp_projects/llvm_toolchain/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:992 (mysqld+0xb90016) #1 os_thread_create_func(void* (*)(void*), void*, unsigned long*) storage/innobase/os/os0thread.cc:137:12 (mysqld+0x1f50025) #2 innobase_start_or_create_for_mysql() storage/innobase/srv/srv0start.cc:2583:46 (mysqld+0x21b50b7) #3 innobase_init(void*) storage/innobase/handler/ha_innodb.cc:4193:8 (mysqld+0x1a5e3d7) #4 ha_initialize_handlerton(st_plugin_int*) sql/handler.cc:522:31 (mysqld+0xc74d33) #5 plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) sql/sql_plugin.cc:1447:9 (mysqld+0x1376d5d) #6 plugin_init(int*, char**, int) sql/sql_plugin.cc:1729:15 (mysqld+0x13761c0) #7 init_server_components() sql/mysqld.cc:5348:7 (mysqld+0xc0d0ff) #8 mysqld_main(int, char**) sql/mysqld.cc:5943:7 (mysqld+0xc06f9d) #9 main sql/main.cc:25:10 (mysqld+0xbff71b) --- storage/innobase/srv/srv0srv.cc | 19 ++++++++++++++----- 1 file changed, 14 insertions(+), 5 deletions(-) diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index af0ff2d31687d..608866aa8b8a5 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -1162,7 +1162,8 @@ srv_refresh_innodb_monitor_stats(void) { mutex_enter(&srv_innodb_monitor_mutex); - srv_last_monitor_time = time(NULL); + my_atomic_store32_explicit(&srv_last_monitor_time, time(NULL), + MY_MEMORY_ORDER_RELAXED); os_aio_refresh_stats(); @@ -1216,10 +1217,14 @@ srv_printf_innodb_monitor( by zero if two users happen to call SHOW ENGINE INNODB STATUS at the same time */ - time_elapsed = difftime(current_time, srv_last_monitor_time) + time_elapsed = + difftime(current_time, + my_atomic_load32_explicit(&srv_last_monitor_time, + MY_MEMORY_ORDER_RELAXED)) + 0.001; - srv_last_monitor_time = time(NULL); + my_atomic_store32_explicit(&srv_last_monitor_time, time(NULL), + MY_MEMORY_ORDER_RELAXED); fputs("\n=====================================\n", file); @@ -1696,7 +1701,8 @@ DECLARE_THREAD(srv_monitor_thread)(void*) pfs_register_thread(srv_monitor_thread_key); #endif /* UNIV_PFS_THREAD */ - srv_last_monitor_time = ut_time(); + my_atomic_store32_explicit(&srv_last_monitor_time, ut_time(), + MY_MEMORY_ORDER_RELAXED); last_monitor_time = ut_time(); mutex_skipped = 0; last_srv_print_monitor = srv_print_innodb_monitor; @@ -1829,7 +1835,10 @@ DECLARE_THREAD(srv_error_monitor_thread)(void*) old_lsn = new_lsn; } - if (difftime(time(NULL), srv_last_monitor_time) > 60) { + if (difftime(time(NULL), + my_atomic_load32_explicit(&srv_last_monitor_time, + MY_MEMORY_ORDER_RELAXED)) + > 60) { /* We referesh InnoDB Monitor values so that averages are printed from at most 60 last seconds */