[MDEV-12445] Rocksdb does not shutdown worker threads and aborts in memleak check on server shutdown Created: 2017-04-05  Updated: 2021-05-10

Status: Open
Project: MariaDB Server
Component/s: Storage Engine - RocksDB
Affects Version/s: 10.2
Fix Version/s: 10.2

Type: Bug Priority: Major
Reporter: Sergei Petrunia Assignee: Sergei Petrunia
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Duplicate
is duplicated by MDEV-20322 rocksdb doesn't free memory on shutdown Open
is duplicated by MDEV-23906 Failed tests (Valgrind warings) - mar... Closed
PartOf
is part of MDEV-9658 Make MyRocks in MariaDB stable Closed
Relates
relates to MDEV-11208 galera_sst_xtrabackup-v2: assertion f... Closed

 Description   

rocksdb.validate_datadic fails on Windows in buildbot:
http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/3295/steps/test/logs/stdio

The issue is not easily reproducible.

Based on the above, it fails an assertion here:

mysqld!my_sigabrt_handler [d:\winx64-debug\build\src\mysys\my_thr_init.c @ 488]
 
mysqld!raise [d:\th\minkernel\crts\ucrt\src\appcrt\misc\signal.cpp @ 516]
 
mysqld!abort [d:\th\minkernel\crts\ucrt\src\appcrt\startup\abort.cpp @ 71]
 
mysqld!common_assert_to_stderr<wchar_t> [d:\th\minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 149]
 
  wchar_t * expression = 0x00007ff7`1def0900 "global_status_var.global_memory_used == 0"
 
  wchar_t * file_name = 0x00007ff7`1def08b0 "D:\winx64-debug\build\src\sql\mysqld.cc"
 
  unsigned int line_number = 0x86a
 
(Inline Function) --------`-------- mysqld!common_assert [d:\th\minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 383]
 
mysqld!_wassert [d:\th\minkernel\crts\ucrt\src\appcrt\startup\assert.cpp @ 404]
 
mysqld!mysqld_exit [d:\winx64-debug\build\src\sql\mysqld.cc @ 2154]
 
mysqld!win_main [d:\winx64-debug\build\src\sql\mysqld.cc @ 6064]
 
mysqld!mysql_service [d:\winx64-debug\build\src\sql\mysqld.cc @ 6086]
 
mysqld!mysqld_main [d:\winx64-debug\build\src\sql\mysqld.cc @ 6279]
 
mysqld!main [d:\winx64-debug\build\src\sql\main.cc @ 26]
 
(Inline Function) --------`-------- mysqld!invoke_main [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 64]
 
mysqld!__scrt_common_main_seh [f:\dd\vctools\crt\vcstartup\src\startup\exe_common.inl @ 253]

This is in mysqld_exit() here:

  if (!opt_debugging)
 
  {
 
=>   DBUG_ASSERT(global_status_var.global_memory_used == 0);
 
  }
 
  cleanup_tls();
 
  DBUG_LEAVE;
 
  if (opt_endinfo && global_status_var.global_memory_used)
 
    fprintf(stderr, "Warning: Memory not freed: %ld\n",
 
            (long) global_status_var.global_memory_used);
 
  sd_notify(0, "STATUS=MariaDB server is down");
 
  exit(exit_code); /* purecov: inspected */
 
}

An observation by wlad: below, we also see that one other thread is still running, it's here:

(Inline Function) --------`-------- ha_rocksdb!Concurrency::details::stl_condition_variable_win7::wait_for [f:\dd\vctools\crt\crtw32\stdcpp\thr\primitives.h @ 216]
 
ha_rocksdb!Concurrency::details::stl_condition_variable_win7::wait(class Concurrency::details::stl_critical_section_interface * lock = <Value unavailable error>) [f:\dd\vctools\crt\crtw32\stdcpp\thr\primitives.h @ 210]
 
ha_rocksdb!do_wait(struct _Cnd_internal_imp_t * cond = 0x00000036`aa929788, struct _Mtx_internal_imp_t * mtx = 0x00000036`aa929738, struct xtime * target = 0x00000000`00000000) [f:\dd\vctools\crt\crtw32\stdcpp\thr\cond.c @ 77]
 
ha_rocksdb!std::_Cnd_waitX(struct _Cnd_internal_imp_t * _Cnd = 0x00000036`aa929788, struct _Mtx_internal_imp_t * _Mtx = 0x00000036`aa929738) [c:\program files (x86)\microsoft visual studio 14.0\vc\include\thr\xthread @ 95]
 
ha_rocksdb!std::condition_variable::wait(class std::unique_lock<std::mutex> * _Lck = 0x00000036`ad97f6f8) [c:\program files (x86)\microsoft visual studio 14.0\vc\include\mutex @ 566]
 
ha_rocksdb!rocksdb::ThreadPoolImpl::Impl::BGThread(unsigned int64 thread_id = 0) [d:\winx64-debug\build\src\storage\rocksdb\rocksdb\util\threadpool_imp.cc @ 180]
 
ha_rocksdb!rocksdb::ThreadPoolImpl::Impl::BGThreadWrapper(void * arg = 0x00000036`aab6bec0) [d:\winx64-debug\build\src\storage\rocksdb\rocksdb\util\threadpool_imp.cc @ 262]
 
ha_rocksdb!std::_Invoker_functor::_Call<void * __ptr64 (<function> ** _Obj = 0x00000036`aab06388, struct rocksdb::BGThreadMetadata ** <_Args_0> = 0x00000036`aab06390) [c:\program files (x86)\microsoft visual studio 14.0\vc\include\type_traits @ 1377]

this does not look normal. One would expect that at this point the plugin is unloaded and its threads stopped.

  • Could it be that that other thread has allocated (and is keeping allocated) something and this is why we see the assert to fire?

 Comments   
Comment by Alexander Barkov [ 2017-04-05 ]

Also sporadically fails on Fedora 23:

Linux home 4.3.4-300.fc23.x86_64 #1 SMP Mon Jan 25 13:39:23 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux

rocksdb.validate_datadic                 w1 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2017-04-06 08:01:12
 
line
 
mysqld: /home/bar/maria-git/server.10.3/sql/mysqld.cc:2146: void mysqld_exit(int): Assertion `global_status_var.global_memory_used == 0' failed.
 
Attempting backtrace. You can use the following information to find out
 
^ Found warnings in /home/bar/maria-git/server.10.3/mysql-test/var/1/log/mysqld.1.err
 
ok
 
 
 
 - saving '/home/bar/maria-git/server.10.3/mysql-test/var/1/log/rocksdb.validate_datadic/' to '/home/bar/maria-git/server.10.3/mysql-test/var/log/rocksdb.validate_datadic/'
 
 - found 'core.7335' (0/5)
 
 
 
Trying 'dbx' to get a backtrace
 
 
 
Trying 'gdb' to get a backtrace from coredump /home/bar/maria-git/server.10.3/mysql-test/var/log/rocksdb.validate_datadic/mysqld.1/data/core.7335
 
Core generated by '/home/bar/maria-git/server.10.3/sql/mysqld'
 
Output from gdb follows. The first stack trace is from the failing thread.
 
The following stack traces are from all threads (so the failing one is
 
duplicated).
 
--------------------------
 
[New LWP 7335]
 
[New LWP 7442]
 
[New LWP 7435]
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libpthread-2.22.so.debug" does not match "/lib64/libpthread.so.0" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/libpthread-2.22.so.debug" does not match "/lib64/libpthread.so.0" (CRC mismatch).
 
 
 
[Thread debugging using libthread_db enabled]
 
Using host libthread_db library "/lib64/libthread_db.so.1".
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libcrypt-2.22.so.debug" does not match "/lib64/libcrypt.so.1" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/libcrypt-2.22.so.debug" does not match "/lib64/libcrypt.so.1" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libdl-2.22.so.debug" does not match "/lib64/libdl.so.2" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/libdl-2.22.so.debug" does not match "/lib64/libdl.so.2" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libm-2.22.so.debug" does not match "/lib64/libm.so.6" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/libm-2.22.so.debug" does not match "/lib64/libm.so.6" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libc-2.22.so.debug" does not match "/lib64/libc.so.6" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/libc-2.22.so.debug" does not match "/lib64/libc.so.6" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/ld-2.22.so.debug" does not match "/lib64/ld-linux-x86-64.so.2" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/ld-2.22.so.debug" does not match "/lib64/ld-linux-x86-64.so.2" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libfreebl3.so.debug" does not match "/lib64/libfreebl3.so" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//lib64/libresolv-2.22.so.debug" does not match "/lib64/libresolv.so.2" (CRC mismatch).
 
 
 
 
 
warning: the debug information found in "/usr/lib/debug//usr/lib64/libresolv-2.22.so.debug" does not match "/lib64/libresolv.so.2" (CRC mismatch).
 
 
 
Core was generated by `/home/bar/maria-git/server.10.3/sql/mysqld --defaults-group-suffix=.1 --default'.
 
Program terminated with signal SIGABRT, Aborted.
 
#0  0x00007f9e719f4bff in pthread_kill () from /lib64/libpthread.so.0
 
[Current thread is 1 (Thread 0x7f9e71df3840 (LWP 7335))]
 
#0  0x00007f9e719f4bff in pthread_kill () from /lib64/libpthread.so.0
 
#1  0x000056299500b786 in my_write_core (sig=6) at /home/bar/maria-git/server.10.3/mysys/stacktrace.c:477
 
#2  0x000056299485929f in handle_fatal_signal (sig=6) at /home/bar/maria-git/server.10.3/sql/signal_handler.cc:299
 
#3  <signal handler called>
 
#4  0x00007f9e6fc03a28 in raise () from /lib64/libc.so.6
 
#5  0x00007f9e6fc0562a in abort () from /lib64/libc.so.6
 
#6  0x00007f9e6fbfc227 in __assert_fail_base () from /lib64/libc.so.6
 
#7  0x00007f9e6fbfc2d2 in __assert_fail () from /lib64/libc.so.6
 
#8  0x00005629944bfc05 in mysqld_exit (exit_code=0) at /home/bar/maria-git/server.10.3/sql/mysqld.cc:2146
 
#9  0x00005629944c7a57 in mysqld_main (argc=150, argv=0x562996f0e268) at /home/bar/maria-git/server.10.3/sql/mysqld.cc:6063
 
#10 0x00005629944bbe90 in main (argc=22, argv=0x7ffd75ec9918) at /home/bar/maria-git/server.10.3/sql/main.cc:25
 
 
 
Thread 3 (Thread 0x7f9e4ffff700 (LWP 7435)):
 
#0  0x00007f9e719f3b20 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
 
#1  0x00007f9e7055cacc in std::condition_variable::wait(std::unique_lock<std::mutex>&) () from /lib64/libstdc++.so.6
 
#2  0x00007f9e6995199f in rocksdb::ThreadPoolImpl::Impl::BGThread (this=0x562997063150, thread_id=0) at /home/bar/maria-git/server.10.3/storage/rocksdb/rocksdb/util/threadpool_imp.cc:179
 
#3  0x00007f9e69951c14 in rocksdb::ThreadPoolImpl::Impl::BGThreadWrapper (arg=0x7f9e58000cc0) at /home/bar/maria-git/server.10.3/storage/rocksdb/rocksdb/util/threadpool_imp.cc:260
 
#4  0x00007f9e69958632 in std::_Bind_simple<void* (*(rocksdb::BGThreadMetadata*))(void*)>::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x7f9e58000d08) at /usr/include/c++/5.3.1/functional:1531
 
#5  0x00007f9e6995854f in std::_Bind_simple<void* (*(rocksdb::BGThreadMetadata*))(void*)>::operator()() (this=0x7f9e58000d08) at /usr/include/c++/5.3.1/functional:1520
 
#6  0x00007f9e699584ee in std::thread::_Impl<std::_Bind_simple<void* (*(rocksdb::BGThreadMetadata*))(void*)> >::_M_run() (this=0x7f9e58000cf0) at /usr/include/c++/5.3.1/thread:115
 
#7  0x00007f9e70561f20 in ?? () from /lib64/libstdc++.so.6
 
#8  0x00007f9e719ee61a in start_thread () from /lib64/libpthread.so.0
 
#9  0x00007f9e6fcd15fd in clone () from /lib64/libc.so.6
 
 
 
Thread 2 (Thread 0x7f9e68d91700 (LWP 7442)):
 
#0  0x00007f9e719f3b20 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
 
#1  0x00007f9e7055cacc in std::condition_variable::wait(std::unique_lock<std::mutex>&) () from /lib64/libstdc++.so.6
 
#2  0x00007f9e6995199f in rocksdb::ThreadPoolImpl::Impl::BGThread (this=0x562997063440, thread_id=0) at /home/bar/maria-git/server.10.3/storage/rocksdb/rocksdb/util/threadpool_imp.cc:179
 
#3  0x00007f9e69951c14 in rocksdb::ThreadPoolImpl::Impl::BGThreadWrapper (arg=0x7f9e58001620) at /home/bar/maria-git/server.10.3/storage/rocksdb/rocksdb/util/threadpool_imp.cc:260
 
#4  0x00007f9e69958632 in std::_Bind_simple<void* (*(rocksdb::BGThreadMetadata*))(void*)>::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x7f9e58001e68) at /usr/include/c++/5.3.1/functional:1531
 
#5  0x00007f9e6995854f in std::_Bind_simple<void* (*(rocksdb::BGThreadMetadata*))(void*)>::operator()() (this=0x7f9e58001e68) at /usr/include/c++/5.3.1/functional:1520
 
#6  0x00007f9e699584ee in std::thread::_Impl<std::_Bind_simple<void* (*(rocksdb::BGThreadMetadata*))(void*)> >::_M_run() (this=0x7f9e58001e50) at /usr/include/c++/5.3.1/thread:115
 
#7  0x00007f9e70561f20 in ?? () from /lib64/libstdc++.so.6
 
#8  0x00007f9e719ee61a in start_thread () from /lib64/libpthread.so.0
 
#9  0x00007f9e6fcd15fd in clone () from /lib64/libc.so.6
 
 
 
Thread 1 (Thread 0x7f9e71df3840 (LWP 7335)):
 
#0  0x00007f9e719f4bff in pthread_kill () from /lib64/libpthread.so.0
 
#1  0x000056299500b786 in my_write_core (sig=6) at /home/bar/maria-git/server.10.3/mysys/stacktrace.c:477
 
#2  0x000056299485929f in handle_fatal_signal (sig=6) at /home/bar/maria-git/server.10.3/sql/signal_handler.cc:299
 
#3  <signal handler called>
 
#4  0x00007f9e6fc03a28 in raise () from /lib64/libc.so.6
 
#5  0x00007f9e6fc0562a in abort () from /lib64/libc.so.6
 
#6  0x00007f9e6fbfc227 in __assert_fail_base () from /lib64/libc.so.6
 
#7  0x00007f9e6fbfc2d2 in __assert_fail () from /lib64/libc.so.6
 
#8  0x00005629944bfc05 in mysqld_exit (exit_code=0) at /home/bar/maria-git/server.10.3/sql/mysqld.cc:2146
 
#9  0x00005629944c7a57 in mysqld_main (argc=150, argv=0x562996f0e268) at /home/bar/maria-git/server.10.3/sql/mysqld.cc:6063
 
#10 0x00005629944bbe90 in main (argc=22, argv=0x7ffd75ec9918) at /home/bar/maria-git/server.10.3/sql/main.cc:25
 
 
 
Compressed file /home/bar/maria-git/server.10.3/mysql-test/var/log/rocksdb.validate_datadic/mysqld.1/data/core.7335

Comment by Vladislav Vaintroub [ 2017-04-19 ]

Same assertion in debug build on trusty : http://buildbot.askmonty.org/buildbot/builders/p8-trusty-bintar-debug/builds/717/steps/test/logs/stdio. Continues to happen on Windows after validate_datadic was disabled (but without nice callstacks anymore)

Comment by Marko Mäkelä [ 2017-08-18 ]

For the record, there are some pre-existing memory leaks in 10.2; see MDEV-11208 and the MDEV-13471 comments about failed innodb.log_file_size shutdown.

Generated at Thu Feb 08 07:57:46 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.