From 52fd74b8d3d9cc4d3079cc8ba064738193a90b8e Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Wed, 31 Jan 2018 20:30:46 +0300 Subject: [PATCH 1/5] fix data races 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::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) 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) --- storage/innobase/handler/ha_innodb.cc | 6 ++++-- storage/innobase/include/ib0mutex.h | 3 ++- storage/innobase/srv/srv0srv.cc | 19 ++++++++++++++----- 3 files changed, 20 insertions(+), 8 deletions(-) diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index b8e72f398f188..361c6110c1ab3 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -332,7 +332,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); @@ -4333,7 +4334,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); } 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 diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index 90196516651ce..fc8db3c992884 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -1170,7 +1170,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(); @@ -1224,10 +1225,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); @@ -1730,7 +1735,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; @@ -1863,7 +1869,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 */ From 5cb0f4f7c7c8889ddcb1a369e32556b20f598a9e Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Wed, 14 Mar 2018 14:00:34 +0300 Subject: [PATCH 2/5] move code to a proper place --- storage/innobase/srv/srv0srv.cc | 17 +++++++---------- 1 file changed, 7 insertions(+), 10 deletions(-) diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index fc8db3c992884..975f008c66355 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -1798,6 +1798,13 @@ DECLARE_THREAD(srv_monitor_thread)(void*) } } + if (difftime(current_time, srv_last_monitor_time) > 60) { + /* We referesh InnoDB Monitor values so that averages are + printed from at most 60 last seconds */ + + srv_refresh_innodb_monitor_stats(); + } + if (srv_shutdown_state != SRV_SHUTDOWN_NONE) { goto exit_func; } @@ -1869,16 +1876,6 @@ DECLARE_THREAD(srv_error_monitor_thread)(void*) old_lsn = new_lsn; } - 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 */ - - srv_refresh_innodb_monitor_stats(); - } - /* Update the statistics collected for deciding LRU eviction policy. */ buf_LRU_stat_update(); From e8696e5942845618c02c1b98fdb2a32fdd9325e9 Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Mon, 19 Mar 2018 10:59:02 +0300 Subject: [PATCH 3/5] make srv_running accesses atomical, remove unneeded atomic accesses for srv_last_monitor_time --- storage/innobase/handler/ha_innodb.cc | 21 ++++++++++++++------- storage/innobase/include/srv0srv.h | 2 +- storage/innobase/srv/srv0srv.cc | 17 ++++++----------- storage/innobase/srv/srv0start.cc | 3 ++- 4 files changed, 23 insertions(+), 20 deletions(-) diff --git a/storage/innobase/handler/ha_innodb.cc b/storage/innobase/handler/ha_innodb.cc index 361c6110c1ab3..869c25b46d375 100644 --- a/storage/innobase/handler/ha_innodb.cc +++ b/storage/innobase/handler/ha_innodb.cc @@ -305,7 +305,7 @@ is_partition( /** Signal to shut down InnoDB (NULL if shutdown was signaled, or if running in innodb_read_only mode, srv_read_only_mode) */ -volatile st_my_thread_var *srv_running; +st_my_thread_var *srv_running; /** Service thread that waits for the server shutdown and stops purge threads. Purge workers have THDs that are needed to calculate virtual columns. This THDs must be destroyed rather early in the server shutdown sequence. @@ -335,10 +335,13 @@ thd_destructor_proxy(void *) 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) + while (!my_atomic_loadptr_explicit(&srv_running, + MY_MEMORY_ORDER_RELAXED) + ->abort) mysql_cond_wait(&thd_destructor_cond, &thd_destructor_mutex); mysql_mutex_unlock(&thd_destructor_mutex); - srv_running = NULL; + my_atomic_storeptr_explicit(&srv_running, NULL, + MY_MEMORY_ORDER_RELAXED); while (srv_fast_shutdown == 0 && (trx_sys_any_active_transactions() || @@ -4429,10 +4432,12 @@ innobase_end(handlerton*, ha_panic_function) hash_table_free(innobase_open_tables); innobase_open_tables = NULL; - if (!abort_loop && srv_running) { + st_my_thread_var* running = my_atomic_loadptr_explicit( + &srv_running, MY_MEMORY_ORDER_RELAXED); + if (!abort_loop && running) { // may be UNINSTALL PLUGIN statement - srv_running->abort = 1; - mysql_cond_broadcast(srv_running->current_cond); + running->abort = 1; + mysql_cond_broadcast(running->current_cond); } if (!srv_read_only_mode) { @@ -17766,7 +17771,9 @@ fast_shutdown_validate( uint new_val = *reinterpret_cast(save); - if (srv_fast_shutdown && !new_val && !srv_running) { + if (srv_fast_shutdown && !new_val + && !my_atomic_loadptr_explicit(&srv_running, + MY_MEMORY_ORDER_RELAXED)) { return(1); } diff --git a/storage/innobase/include/srv0srv.h b/storage/innobase/include/srv0srv.h index e24aa89f046e0..9ba65d8097ea8 100644 --- a/storage/innobase/include/srv0srv.h +++ b/storage/innobase/include/srv0srv.h @@ -476,7 +476,7 @@ extern uint srv_fast_shutdown; /*!< If this is 1, do not do a /** Signal to shut down InnoDB (NULL if shutdown was signaled, or if running in innodb_read_only mode, srv_read_only_mode) */ -extern volatile st_my_thread_var *srv_running; +extern st_my_thread_var *srv_running; extern ibool srv_innodb_status; diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index 975f008c66355..1979dd57e8410 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -1170,8 +1170,7 @@ srv_refresh_innodb_monitor_stats(void) { mutex_enter(&srv_innodb_monitor_mutex); - my_atomic_store32_explicit(&srv_last_monitor_time, time(NULL), - MY_MEMORY_ORDER_RELAXED); + srv_last_monitor_time = time(NULL); os_aio_refresh_stats(); @@ -1225,14 +1224,10 @@ 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, - my_atomic_load32_explicit(&srv_last_monitor_time, - MY_MEMORY_ORDER_RELAXED)) + time_elapsed = difftime(current_time, srv_last_monitor_time) + 0.001; - my_atomic_store32_explicit(&srv_last_monitor_time, time(NULL), - MY_MEMORY_ORDER_RELAXED); + srv_last_monitor_time = time(NULL); fputs("\n=====================================\n", file); @@ -1735,8 +1730,7 @@ DECLARE_THREAD(srv_monitor_thread)(void*) pfs_register_thread(srv_monitor_thread_key); #endif /* UNIV_PFS_THREAD */ - my_atomic_store32_explicit(&srv_last_monitor_time, ut_time(), - MY_MEMORY_ORDER_RELAXED); + srv_last_monitor_time = ut_time(); last_monitor_time = ut_time(); mutex_skipped = 0; last_srv_print_monitor = srv_print_innodb_monitor; @@ -2944,7 +2938,8 @@ srv_purge_wakeup() srv_release_threads(SRV_WORKER, n_workers); } - } while (!srv_running + } while (!my_atomic_loadptr_explicit(&srv_running, + MY_MEMORY_ORDER_RELAXED) && (srv_sys.n_threads_active[SRV_WORKER] || srv_sys.n_threads_active[SRV_PURGE])); } diff --git a/storage/innobase/srv/srv0start.cc b/storage/innobase/srv/srv0start.cc index 8c2d0dc8871b0..424b45e8def9a 100644 --- a/storage/innobase/srv/srv0start.cc +++ b/storage/innobase/srv/srv0start.cc @@ -2840,7 +2840,8 @@ srv_shutdown_bg_undo_sources() void innodb_shutdown() { - ut_ad(!srv_running); + ut_ad(!my_atomic_loadptr_explicit(&srv_running, + MY_MEMORY_ORDER_RELAXED)); ut_ad(!srv_undo_sources); switch (srv_operation) { From bd4fadaf299d8a5a289d8e44905e01cb74cbe639 Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Mon, 19 Mar 2018 14:46:33 +0300 Subject: [PATCH 4/5] move code to mutex protected place --- storage/innobase/srv/srv0srv.cc | 17 ++++++++++------- 1 file changed, 10 insertions(+), 7 deletions(-) diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index 1979dd57e8410..a18b57e819446 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -1170,7 +1170,15 @@ srv_refresh_innodb_monitor_stats(void) { mutex_enter(&srv_innodb_monitor_mutex); - srv_last_monitor_time = time(NULL); + time_t current_time = time(NULL); + + if (difftime(current_time, srv_last_monitor_time) > 60) { + /* We referesh InnoDB Monitor values so that averages are + printed from at most 60 last seconds */ + return; + } + + srv_last_monitor_time = current_time; os_aio_refresh_stats(); @@ -1792,12 +1800,7 @@ DECLARE_THREAD(srv_monitor_thread)(void*) } } - if (difftime(current_time, srv_last_monitor_time) > 60) { - /* We referesh InnoDB Monitor values so that averages are - printed from at most 60 last seconds */ - - srv_refresh_innodb_monitor_stats(); - } + srv_refresh_innodb_monitor_stats(); if (srv_shutdown_state != SRV_SHUTDOWN_NONE) { goto exit_func; From 86b4a7b3d3e523eaa21978fa7280f20381681117 Mon Sep 17 00:00:00 2001 From: Eugene Kosov Date: Mon, 19 Mar 2018 16:06:30 +0300 Subject: [PATCH 5/5] unlock mutex --- storage/innobase/srv/srv0srv.cc | 1 + 1 file changed, 1 insertion(+) diff --git a/storage/innobase/srv/srv0srv.cc b/storage/innobase/srv/srv0srv.cc index a18b57e819446..9050061d56c30 100644 --- a/storage/innobase/srv/srv0srv.cc +++ b/storage/innobase/srv/srv0srv.cc @@ -1175,6 +1175,7 @@ srv_refresh_innodb_monitor_stats(void) if (difftime(current_time, srv_last_monitor_time) > 60) { /* We referesh InnoDB Monitor values so that averages are printed from at most 60 last seconds */ + mutex_exit(&srv_innodb_monitor_mutex); return; }