Skip to content

Conversation

@kevgs
Copy link
Contributor

@kevgs kevgs commented Jan 11, 2018

==================
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
==================

I'm contributing this new code of the whole pull request, including one or several files that are either new files or modified ones, under the BSD-new license.

kevgs added 3 commits January 21, 2018 17:52
==================
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
==================
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)
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)
@svoj
Copy link
Contributor

svoj commented Jan 29, 2018

I'd argue the whole thd_destructor_proxy() idea and the way srv_last_monitor_time used by different threads. But I leave it up to @dr-m to decide.

@svoj svoj added this to the 10.3 milestone Jan 29, 2018
@svoj
Copy link
Contributor

svoj commented Jan 29, 2018

@kevgs good title for this task would be "Fix simple data races around srv_running and srv_last_monitor_time" so that it gives an idea how is it different from your other fixes.

@svoj svoj changed the title fix simple InnoDB data race MDEV-15111 - fix simple InnoDB data race Jan 29, 2018
@svoj
Copy link
Contributor

svoj commented Jan 29, 2018

Thanks for you contribution! This task was added to our 10.3 queue.

@dr-m
Copy link
Contributor

dr-m commented Jan 29, 2018

The thd_destructor_proxy was added by @vuvova to fix a shutdown problem that was introduced by MDEV-5800.
The changes look reasonable to me, but I think that we should apply the fix to 10.2 already.

@codership-jenkins
Copy link

Can one of the admins verify this patch?

@kevgs
Copy link
Contributor Author

kevgs commented Mar 6, 2018

Replaced by #582

@kevgs kevgs closed this Mar 6, 2018
@kevgs kevgs deleted the kevgs/data_race branch September 28, 2018 16:00
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Development

Successfully merging this pull request may close these issues.

4 participants