[MDEV-27170] TSAN: data race in mysqld_main when disabling InnoDB, setting Aria as the default SE Created: 2021-12-05  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - Aria
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Michael Widenius
Resolution: Unresolved Votes: 0
Labels: not-10.2, regression-10.3


 Description    

# mysqld options required for replay:  --disable-innodb --default-storage-engine=aria

Leads to:

10.8.0 5566cbadb03856aba9c236b131f544490cd2bee4 (Debug, TSAN)

 
WARNING: ThreadSanitizer: data race (pid=869668)
 
  Read of size 8 at 0x5631c2f35c58 by main thread:
 
    #0 mysqld_main(int, char**) /test/10.8_dbg_san/sql/mysqld.cc:5855 (mariadbd+0x6800e7)
 
    #1 main /test/10.8_dbg_san/sql/main.cc:34 (mariadbd+0x668dcb)
 
 
 
  Previous atomic write of size 8 at 0x5631c2f35c58 by thread T1 (mutexes: write M1459):
 
    #0 __tsan_atomic64_fetch_add ../../../../src/libsanitizer/tsan/tsan_interface_atomic.cpp:620 (libtsan.so.0+0x7f2e9)
 
    #1 update_global_memory_status /test/10.8_dbg_san/sql/sql_class.h:1053 (mariadbd+0x66ee5e)
 
    #2 my_malloc_size_cb_func /test/10.8_dbg_san/sql/mysqld.cc:3687 (mariadbd+0x66ee5e)
 
    #3 my_malloc /test/10.8_dbg_san/mysys/my_malloc.c:108 (mariadbd+0x1b0763b)
 
    #4 init_dynamic_array2 /test/10.8_dbg_san/mysys/array.c:72 (mariadbd+0x1ad0732)
 
    #5 my_hash_init2 /test/10.8_dbg_san/mysys/hash.c:98 (mariadbd+0x1ad77b6)
 
    #6 safe_mutex_lazy_init_deadlock_detection /test/10.8_dbg_san/mysys/thr_mutex.c:175 (mariadbd+0x1b16eaa)
 
    #7 safe_mutex_lock /test/10.8_dbg_san/mysys/thr_mutex.c:316 (mariadbd+0x1b16eaa)
 
    #8 inline_mysql_mutex_lock /test/10.8_dbg_san/include/mysql/psi/mysql_thread.h:750 (mariadbd+0x1b18896)
 
    #9 timer_handler /test/10.8_dbg_san/mysys/thr_timer.c:302 (mariadbd+0x1b18896)
 
 
 
  Location is global 'global_status_var' of size 2080 at 0x5631c2f35440 (mariadbd+0x00000277bc58)
 
 
 
  Mutex M1459 (0x5631c3810288) created at:
 
    #0 pthread_mutex_init ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:1220 (libtsan.so.0+0x4a616)
 
    #1 safe_mutex_init /test/10.8_dbg_san/mysys/thr_mutex.c:189 (mariadbd+0x1b167ae)
 
    #2 inline_mysql_mutex_init /test/10.8_dbg_san/include/mysql/psi/mysql_thread.h:703 (mariadbd+0x1b18d7d)
 
    #3 init_thr_timer /test/10.8_dbg_san/mysys/thr_timer.c:76 (mariadbd+0x1b18d7d)
 
    #4 init_server_components /test/10.8_dbg_san/sql/mysqld.cc:4786 (mariadbd+0x6728fa)
 
    #5 mysqld_main(int, char**) /test/10.8_dbg_san/sql/mysqld.cc:5695 (mariadbd+0x67d962)
 
    #6 main /test/10.8_dbg_san/sql/main.cc:34 (mariadbd+0x668dcb)
 
 
 
  Thread T1 (tid=870145, running) created by main thread at:
 
    #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:962 (libtsan.so.0+0x5ea79)
 
    #1 spawn_thread_noop /test/10.8_dbg_san/mysys/psi_noop.c:188 (mariadbd+0x1b366bb)
 
    #2 inline_mysql_thread_create /test/10.8_dbg_san/include/mysql/psi/mysql_thread.h:1139 (mariadbd+0x1b18eef)
 
    #3 init_thr_timer /test/10.8_dbg_san/mysys/thr_timer.c:90 (mariadbd+0x1b18eef)
 
    #4 init_server_components /test/10.8_dbg_san/sql/mysqld.cc:4786 (mariadbd+0x6728fa)
 
    #5 mysqld_main(int, char**) /test/10.8_dbg_san/sql/mysqld.cc:5695 (mariadbd+0x67d962)
 
    #6 main /test/10.8_dbg_san/sql/main.cc:34 (mariadbd+0x668dcb)
 
 
 
SUMMARY: ThreadSanitizer: data race /test/10.8_dbg_san/sql/mysqld.cc:5855 in mysqld_main(int, char**)

10.8.0 5566cbadb03856aba9c236b131f544490cd2bee4 (Optimized, TSAN)

 
WARNING: ThreadSanitizer: data race (pid=1960)
 
  Read of size 8 at 0x55e77e941cd8 by main thread:
 
    #0 mysqld_main(int, char**) /test/10.8_opt_san/sql/mysqld.cc:5855 (mariadbd+0x761b99)
 
    #1 main /test/10.8_opt_san/sql/main.cc:34 (mariadbd+0x6f5135)
 
 
 
  Previous atomic write of size 8 at 0x55e77e941cd8 by thread T4:
 
    #0 __tsan_atomic64_fetch_add ../../../../src/libsanitizer/tsan/tsan_interface_atomic.cpp:620 (libtsan.so.0+0x7f2e9)
 
    #1 update_global_memory_status /test/10.8_opt_san/sql/sql_class.h:1053 (mariadbd+0x7527e8)
 
    #2 my_malloc_size_cb_func /test/10.8_opt_san/sql/mysqld.cc:3687 (mariadbd+0x7527e8)
 
    #3 my_free /test/10.8_opt_san/mysys/my_malloc.c:202 (mariadbd+0x17e963e)
 
    #4 delete_dynamic /test/10.8_opt_san/mysys/array.c:309 (mariadbd+0x17ba09c)
 
    #5 Dynamic_array<Opt_trace_stmt*>::~Dynamic_array() /test/10.8_opt_san/sql/sql_array.h:274 (mariadbd+0xcd69f9)
 
    #6 Opt_trace_context::~Opt_trace_context() /test/10.8_opt_san/sql/opt_trace.cc:427 (mariadbd+0xcd69f9)
 
    #7 THD::~THD() /test/10.8_opt_san/sql/sql_class.cc:1660 (mariadbd+0x89cfbe)
 
    #8 THD::~THD() /test/10.8_opt_san/sql/sql_class.cc:1751 (mariadbd+0x89d3f1)
 
    #9 bg_rpl_load_gtid_slave_state /test/10.8_opt_san/sql/slave.cc:503 (mariadbd+0x7d8819)
 
    #10 handle_manager /test/10.8_opt_san/sql/sql_manager.cc:113 (mariadbd+0x938f4c)
 
    #11 pfs_spawn_thread /test/10.8_opt_san/storage/perfschema/pfs.cc:2201 (mariadbd+0x1283cc0)
 
 
 
  Location is global 'global_status_var' of size 2080 at 0x55e77e9414c0 (mariadbd+0x000002360cd8)
 
 
 
  Thread T4 (tid=3820, running) created by main thread at:
 
    #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:962 (libtsan.so.0+0x5ea79)
 
    #1 my_thread_create /test/10.8_opt_san/storage/perfschema/my_thread.h:48 (mariadbd+0x1283efe)
 
    #2 pfs_spawn_thread_v1 /test/10.8_opt_san/storage/perfschema/pfs.cc:2252 (mariadbd+0x1283efe)
 
    #3 inline_mysql_thread_create /test/10.8_opt_san/include/mysql/psi/mysql_thread.h:1139 (mariadbd+0x93945c)
 
    #4 start_handle_manager() /test/10.8_opt_san/sql/sql_manager.cc:140 (mariadbd+0x93945c)
 
    #5 mysqld_main(int, char**) /test/10.8_opt_san/sql/mysqld.cc:5792 (mariadbd+0x76195c)
 
    #6 main /test/10.8_opt_san/sql/main.cc:34 (mariadbd+0x6f5135)
 
 
 
SUMMARY: ThreadSanitizer: data race /test/10.8_opt_san/sql/mysqld.cc:5855 in mysqld_main(int, char**)

Setup:

Compiled with GCC >=7.5.0 (I use GCC 9.3.0) and:
 
    -DWITH_TSAN=ON -DWSREP_LIB_WITH_TSAN=ON -DMUTEXTYPE=sys
 
Set before execution:
 
    export TSAN_OPTIONS=suppress_equal_stacks=1:suppress_equal_addresses=1:history_size=7:verbosity=1:exitcode=0

Bug confirmed present in:
MariaDB: 10.3.33 (dbg), 10.3.33 (opt), 10.4.23 (dbg), 10.4.23 (opt), 10.5.14 (dbg), 10.5.14 (opt), 10.6.6 (dbg), 10.6.6 (opt), 10.7.2 (dbg), 10.7.2 (opt), 10.8.0 (dbg), 10.8.0 (opt)

Bug (or feature/syntax) confirmed not present in:
MariaDB: 10.2.42 (dbg), 10.2.42 (opt)

 Comments   
Comment by Marko Mäkelä [ 2021-12-05 ]

If I understood correctly, the reported problem is that some code is accessing global_status_var.global_memory_used without an atomic memory operation. Example:

static inline void update_global_memory_status(int64 size)
 
{
 
  DBUG_PRINT("info", ("global memory_used: %lld  size: %lld",
 
                      (longlong) global_status_var.global_memory_used,
 
                      size));
 
  // workaround for gcc 4.2.4-1ubuntu4 -fPIE (from DEB_BUILD_HARDENING=1)
 
  int64 volatile * volatile ptr= &global_status_var.global_memory_used;
 
  my_atomic_add64_explicit(ptr, size, MY_MEMORY_ORDER_RELAXED);
 
}

Side note: Do we still need a workaround for such an old compiler? The minimum requirement of 10.4 or later is GCC 4.8.5, to have enough support of C++11.

In the above code, the DBUG_PRINT macro is reading the variable without using a proper atomic operation. That too should be flagged as a data race. The proper way would be to invoke the equivalent of std::atomic::fetch_add(std::memory_order_relaxed only once, and pass the return value to the DBUG_PRINT macro. On IA-32 and AMD64, the fetch_add() and fetch_sub() will translate into the 80486 instruction LOCK XADD.

Likewise, in other accesses of global_status_var.global_memory_order, the equivalent of std::atomic::load(std::memory_order_relaxed) should be used. In processors with a strong memory model, atomic loads and stores do not differ at all from regular loads and stores. See https://www.cl.cam.ac.uk/~pes20/cpp/cpp0xmappings.html for some examples.

It could be simplest to declare global_status_var.global_memory_order as Atomic_relaxed<int64>. In that way, all accesses are guaranteed to be atomic.

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