[MDEV-10542] innodb.innodb_bug59641 failed in buildbot (race condition in unlink_thd) Created: 2016-08-11  Updated: 2016-12-20  Resolved: 2016-12-20

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 5.5
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Sergey Vojtovich Assignee: Vladislav Vaintroub
Resolution: Won't Fix Votes: 0
Labels: foundation

Sprint: 5.5.54

 Description   

Rather a subtle race condition detected by buildbot: http://buildbot.askmonty.org/buildbot/builders/p8-rhel6-bintar-debug/builds/97/steps/test/logs/stdio

innodb.innodb_bug59641 'innodb_plugin'   w1 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2016-08-10 13:07:03
line
Attempting backtrace. You can use the following information to find out
^ Found warnings in /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/log/mysqld.1.err
ok
 
 - saving '/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/log/innodb.innodb_bug59641-innodb_plugin/' to '/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/log/innodb.innodb_bug59641-innodb_plugin/'
 - found 'core.29529' (0/5)
 
Trying 'dbx' to get a backtrace
 
Trying 'gdb' to get a backtrace
Core generated by '/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/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 Thread 29592]
[New Thread 29529]
[New Thread 29600]
[New Thread 29532]
[New Thread 29534]
[New Thread 29533]
[New Thread 29535]
[New Thread 29536]
[New Thread 29537]
[New Thread 29583]
[New Thread 29584]
[New Thread 29585]
[New Thread 29586]
[New Thread 29591]
 
warning: Ignoring non-absolute filename: <linux-vdso64.so.1>
Missing separate debuginfo for linux-vdso64.so.1
Try: yum --enablerepo='*-debug*' install /usr/lib/debug/.build-id/a3/6ae73fe9bbc7822a25c079e500ae9d226661a4
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
To enable execution of this file add
	add-auto-load-safe-path /opt/at7.0/lib64/libthread_db-1.0.so
line to your configuration file "/home/buildbot/.gdbinit".
To completely disable this security protection add
	set auto-load safe-path /
line to your configuration file "/home/buildbot/.gdbinit".
For more information about this security protection see the
"Auto-loading safe path" section in the GDB manual.  E.g., run from the shell:
	info "(gdb)Auto-loading safe path"
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
 
warning: File "/opt/at7.0/lib64/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "/usr/share/gdb/auto-load:/usr/lib/debug:/usr/bin/mono-gdb.py".
 
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
Core was generated by `/home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld --defaults-gr'.
Program terminated with signal 6, Aborted.
#0  0x00000fff7daa3a40 in .pthread_kill () from /opt/at7.0/lib64/power7/libpthread.so.0
#0  0x00000fff7daa3a40 in .pthread_kill () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b4d608 in .my_write_core ()
#2  0x00000000104747e0 in .handle_fatal_signal () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/signal_handler.cc:262
#3  <signal handler called>
#4  0x00000fff7d4ff2f0 in .raise () from /opt/at7.0/lib64/power7/libc.so.6
#5  0x00000fff7d5012f4 in .abort () from /opt/at7.0/lib64/power7/libc.so.6
#6  0x00000fff7772fb3c in .trx_free_for_mysql () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#7  0x00000fff77655e48 in ._ZL12innobase_endP10handlerton17ha_panic_function () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:2665
#8  0x00000000104769fc in ._Z22ha_finalize_handlertonP13st_plugin_int () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:415
#9  0x00000000102562ac in ._ZL19plugin_deinitializeP13st_plugin_intb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1165
#10 0x0000000010256854 in ._ZL12reap_pluginsv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1242
#11 0x0000000010256ca0 in ._Z13plugin_unlockP3THDPP13st_plugin_int () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1314
#12 0x00000000101ee14c in .thd_set_ha_data () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_class.cc:640
#13 0x0000000010477704 in ._ZL19closecon_handlertonP3THDPP13st_plugin_intPv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:680
#14 0x000000001025a5d8 in ._Z24plugin_foreach_with_maskP3THDPFcS0_PP13st_plugin_intPvEijS4_ () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:2344
#15 0x0000000010477764 in ._Z19ha_close_connectionP3THD () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:691
#16 0x00000000101f0e54 in ._ZN3THDD2Ev () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_class.cc:1472
#17 0x00000000101f118c in ._ZN3THDD0Ev () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_class.cc:1502
#18 0x0000000010157070 in ._Z10unlink_thdP3THD () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:2495
#19 0x0000000010157524 in ._Z29one_thread_per_connection_endP3THDb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:2600
#20 0x0000000010387f20 in ._Z24do_handle_one_connectionP3THD () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_connect.cc:1281
#21 0x0000000010387ab4 in .handle_one_connection () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_connect.cc:1186
#22 0x0000000010af0310 in .pfs_spawn_thread () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/perfschema/pfs.cc:1015
#23 0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#24 0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 14 (Thread 29591):
#0  0x00000fff7daa7f18 in .__libc_sigwait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x00000000101581a8 in .signal_hand () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:3056
#2  0x0000000010af0310 in .pfs_spawn_thread () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/perfschema/pfs.cc:1015
#3  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#4  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 13 (Thread 29586):
#0  0x00000fff7daa2130 in .pthread_cond_wait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b5817c in .safe_cond_wait ()
#2  0x00000fff77619978 in .os_cond_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761a574 in .os_event_wait_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff77700f1c in .sync_array_wait_event () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff777057b4 in .mutex_spin_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff775db420 in .mutex_enter_func () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#7  0x00000fff775db564 in .pfs_mutex_enter_func () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#8  0x00000fff775e8dbc in .lock_update_delete () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#9  0x00000fff7750c898 in .btr_cur_optimistic_delete () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#10 0x00000fff776bb3f0 in .row_purge_remove_clust_if_poss_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#11 0x00000fff776bb520 in .row_purge_remove_clust_if_poss () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#12 0x00000fff776bbd84 in .row_purge_del_mark () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#13 0x00000fff776bc6d8 in .row_purge () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#14 0x00000fff776bc84c in .row_purge_step () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#15 0x00000fff7764e0e0 in .que_thr_step () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#16 0x00000fff7764e3b0 in .que_run_threads_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#17 0x00000fff7764e55c in .que_run_threads () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#18 0x00000fff77712b04 in .trx_purge () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#19 0x00000fff776f8788 in .srv_master_do_purge () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#20 0x00000fff776f91dc in .srv_master_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#21 0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#22 0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 12 (Thread 29585):
#0  0x00000fff7daa25a4 in .pthread_cond_timedwait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b584c4 in .safe_cond_timedwait ()
#2  0x00000fff776197f8 in .os_cond_wait_timed () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761a7b8 in .os_event_wait_time_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff776f75b0 in .srv_monitor_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#6  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 11 (Thread 29584):
#0  0x00000fff7daa25a4 in .pthread_cond_timedwait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b584c4 in .safe_cond_timedwait ()
#2  0x00000fff776197f8 in .os_cond_wait_timed () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761a7b8 in .os_event_wait_time_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff776f8014 in .srv_error_monitor_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#6  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 10 (Thread 29583):
#0  0x00000fff7daa25a4 in .pthread_cond_timedwait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b584c4 in .safe_cond_timedwait ()
#2  0x00000fff776197f8 in .os_cond_wait_timed () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761a7b8 in .os_event_wait_time_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff776f7ae4 in .srv_lock_timeout_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#6  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 9 (Thread 29537):
#0  0x00000fff7da50958 in ?? () from /lib64/libaio.so.1
#1  0x00000fff7da509bc in .io_getevents () from /lib64/libaio.so.1
#2  0x00000fff77616de4 in .os_aio_linux_collect () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761730c in .os_aio_linux_handle () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff7759bcdc in .fil_aio_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff776fbe78 in .io_handler_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#7  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 8 (Thread 29536):
#0  0x00000fff7da50958 in ?? () from /lib64/libaio.so.1
#1  0x00000fff7da509bc in .io_getevents () from /lib64/libaio.so.1
#2  0x00000fff77616de4 in .os_aio_linux_collect () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761730c in .os_aio_linux_handle () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff7759bcdc in .fil_aio_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff776fbe78 in .io_handler_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#7  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 7 (Thread 29535):
#0  0x00000fff7da50958 in ?? () from /lib64/libaio.so.1
#1  0x00000fff7da509bc in .io_getevents () from /lib64/libaio.so.1
#2  0x00000fff77616de4 in .os_aio_linux_collect () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761730c in .os_aio_linux_handle () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff7759bcdc in .fil_aio_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff776fbe78 in .io_handler_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#7  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 6 (Thread 29533):
#0  0x00000fff7da50958 in ?? () from /lib64/libaio.so.1
#1  0x00000fff7da509bc in .io_getevents () from /lib64/libaio.so.1
#2  0x00000fff77616de4 in .os_aio_linux_collect () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761730c in .os_aio_linux_handle () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff7759bcdc in .fil_aio_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff776fbe78 in .io_handler_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#7  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 5 (Thread 29534):
#0  0x00000fff7da50958 in ?? () from /lib64/libaio.so.1
#1  0x00000fff7da509bc in .io_getevents () from /lib64/libaio.so.1
#2  0x00000fff77616de4 in .os_aio_linux_collect () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761730c in .os_aio_linux_handle () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff7759bcdc in .fil_aio_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff776fbe78 in .io_handler_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#7  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 4 (Thread 29532):
#0  0x00000fff7da50958 in ?? () from /lib64/libaio.so.1
#1  0x00000fff7da509bc in .io_getevents () from /lib64/libaio.so.1
#2  0x00000fff77616de4 in .os_aio_linux_collect () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761730c in .os_aio_linux_handle () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff7759bcdc in .fil_aio_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff776fbe78 in .io_handler_thread () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#7  0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 3 (Thread 29600):
#0  0x00000fff7daa2130 in .pthread_cond_wait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b5817c in .safe_cond_wait ()
#2  0x00000fff77619978 in .os_cond_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#3  0x00000fff7761a574 in .os_event_wait_low () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#4  0x00000fff77700f1c in .sync_array_wait_event () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#5  0x00000fff777057b4 in .mutex_spin_wait () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#6  0x00000fff775f0a48 in .mutex_enter_func () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#7  0x00000fff775f0b8c in .pfs_mutex_enter_func () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#8  0x00000fff775f7624 in .logs_empty_and_mark_files_at_shutdown () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#9  0x00000fff776ff684 in .innobase_shutdown_for_mysql () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#10 0x00000fff77655ea0 in ._ZL12innobase_endP10handlerton17ha_panic_function () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:2673
#11 0x00000000104769fc in ._Z22ha_finalize_handlertonP13st_plugin_int () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:415
#12 0x00000000102562ac in ._ZL19plugin_deinitializeP13st_plugin_intb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1165
#13 0x0000000010258eac in ._Z15plugin_shutdownv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1949
#14 0x0000000010155060 in ._ZL8clean_upb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:1816
#15 0x0000000010154d4c in ._Z10unireg_endv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:1734
#16 0x0000000010154b7c in ._ZL11kill_serverPv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:1662
#17 0x0000000010154bcc in .kill_server_thread () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:1685
#18 0x0000000010af0310 in .pfs_spawn_thread () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/perfschema/pfs.cc:1015
#19 0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#20 0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104
 
Thread 2 (Thread 29529):
#0  0x00000fff7daa2130 in .pthread_cond_wait () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b5817c in .safe_cond_wait ()
#2  0x0000000010152054 in .inline_mysql_cond_wait () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/include/mysql/psi/mysql_thread.h:984
#3  0x000000001015ca34 in ._Z11mysqld_mainiPPc () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:5096
#4  0x0000000010151588 in .main ()
 
Thread 1 (Thread 29592):
#0  0x00000fff7daa3a40 in .pthread_kill () from /opt/at7.0/lib64/power7/libpthread.so.0
#1  0x0000000010b4d608 in .my_write_core ()
#2  0x00000000104747e0 in .handle_fatal_signal () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/signal_handler.cc:262
#3  <signal handler called>
#4  0x00000fff7d4ff2f0 in .raise () from /opt/at7.0/lib64/power7/libc.so.6
#5  0x00000fff7d5012f4 in .abort () from /opt/at7.0/lib64/power7/libc.so.6
#6  0x00000fff7772fb3c in .trx_free_for_mysql () from /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/mysql-test/var/1/plugins/ha_innodb.so
#7  0x00000fff77655e48 in ._ZL12innobase_endP10handlerton17ha_panic_function () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/innobase/handler/ha_innodb.cc:2665
#8  0x00000000104769fc in ._Z22ha_finalize_handlertonP13st_plugin_int () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:415
#9  0x00000000102562ac in ._ZL19plugin_deinitializeP13st_plugin_intb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1165
#10 0x0000000010256854 in ._ZL12reap_pluginsv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1242
#11 0x0000000010256ca0 in ._Z13plugin_unlockP3THDPP13st_plugin_int () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:1314
#12 0x00000000101ee14c in .thd_set_ha_data () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_class.cc:640
#13 0x0000000010477704 in ._ZL19closecon_handlertonP3THDPP13st_plugin_intPv () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:680
#14 0x000000001025a5d8 in ._Z24plugin_foreach_with_maskP3THDPFcS0_PP13st_plugin_intPvEijS4_ () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_plugin.cc:2344
#15 0x0000000010477764 in ._Z19ha_close_connectionP3THD () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/handler.cc:691
#16 0x00000000101f0e54 in ._ZN3THDD2Ev () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_class.cc:1472
#17 0x00000000101f118c in ._ZN3THDD0Ev () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_class.cc:1502
#18 0x0000000010157070 in ._Z10unlink_thdP3THD () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:2495
#19 0x0000000010157524 in ._Z29one_thread_per_connection_endP3THDb () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/mysqld.cc:2600
#20 0x0000000010387f20 in ._Z24do_handle_one_connectionP3THD () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_connect.cc:1281
#21 0x0000000010387ab4 in .handle_one_connection () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/sql/sql_connect.cc:1186
#22 0x0000000010af0310 in .pfs_spawn_thread () at /home/buildbot/maria-slave/p8-rhel6-bintar-debug/build/storage/perfschema/pfs.cc:1015
#23 0x00000fff7da9c548 in .start_thread () from /opt/at7.0/lib64/power7/libpthread.so.0
#24 0x00000fff7d5d8454 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:104

Note 2 threads deinitialize InnoDB concurrently. I couldn't reproduce exactly the same assertion failure, but very similar issue can reliably reproduced with the following test on a patched server:

source include/have_innodb.inc;
 
CREATE TABLE t1(a INT);
 
connect(con1,localhost,root);
INSERT INTO t1 VALUES(1);
disconnect con1;
 
connection default;
DROP TABLE t1;

Patch:

diff --git a/sql/mysqld.cc b/sql/mysqld.cc
index 9b8f964..aa6f3bf 100644
--- a/sql/mysqld.cc
+++ b/sql/mysqld.cc
@@ -2492,6 +2492,9 @@ void unlink_thd(THD *thd)
   thread_count--;
   mysql_mutex_unlock(&LOCK_thread_count);
 
+  if (thd)
+    sleep(5);
+
   delete thd;
   DBUG_VOID_RETURN;
 }

Result:

main.AAA 'innodb_plugin'                 [ pass ]      7
***Warnings generated in error logs during shutdown after running tests: main.AAA
 
safe_mutex: Trying to lock unitialized mutex at /home/svoj/devel/maria/mariadb/sql/sql_class.cc, line 3421
Attempting backtrace. You can use the following information to find out
safe_mutex: Trying to lock unitialized mutex at /home/svoj/devel/maria/mariadb/sql/sql_class.cc, line 3421



 Comments   
Comment by Sergey Vojtovich [ 2016-08-11 ]

ATTN wlad

Comment by Sergey Vojtovich [ 2016-08-11 ]

10.0 and up seem to be unaffected: thread_count is decremented after THD deletion.

Comment by Vladislav Vaintroub [ 2016-12-15 ]

Hmm , I do not really know.
So far my alternatives for fixing this are
1. Not fixing it - the race is very subtle, and only happens at shutdown , and 5.5 is almost EOL

2. Decrement thread_count thread at the end of the function

   mysql_mutex_lock(&LOCK_thread_count);
   thread_count--;
   mysql_mutex_unlock(&LOCK_thread_count);

Safe, slightly ugly , because the same lock acquired by the same thread twice within short time.

3. move "delete thd" inside the mutex lock.

Seems far too expensive (some system calls, free(), shutdown/close for socket), don't like that.

What do you think is appropriate? I tend to either 1) or 2). We can't fix it like in 10.x, with atomics, that would be too big of a change

Comment by Sergey Vojtovich [ 2016-12-15 ]

If we won't ever have to touch 5.5 after April 2017, I wouldn't bother fixing this.
elenst, what's your thinking?

Comment by Elena Stepanova [ 2016-12-15 ]

svoj, I expect we will touch 5.5 after April 2017 – as long as MySQL keeps releasing 5.5, we probably will too, plus security fixes.

That said, I don't insist on fixing it if it only affects 5.5.

Comment by Vladislav Vaintroub [ 2016-12-20 ]

Closing as "Won't fix" ,since nobody objected issue is very subtle, the worst effect that probably never pops up is "just" a crash at shutdown.

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