handle_fatal_signal (sig=11) in free/pthread_create originating from spawn_thread_v1

[Roel Van de Paar]

(gdb) t 40
+t 40
(gdb) bt
+bt
#0 0x0000000005072771 in pthread_kill () from /lib64/libpthread.so.0
#1 0x0000000000ad3e5e in my_write_core (sig=11) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/my
sys/stacktrace.c:422
#2 0x000000000073156f in handle_fatal_signal (sig=11) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-server-5.6.20-6
8.0/sql/signal_handler.cc:236
#3 <signal handler called>
#4 0x0000000004e3652c in free () from /usr/lib64/libjemalloc.so.1
#5 0x000000000506e2ea in pthread_create@@GLIBC_2.2.5 () from /lib64/libpthread.so.0
#6 0x0000000000e198c6 in spawn_thread_v1 (key=22, thread=0x82bffd70, attr=0x18de480 <connection_attrib>, start_routine=0x8cfb1c <worker_main(void*)>, arg=0x190
4600 <all_groups+2560>) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/storage/perfschema/pfs.cc:1
910
#7 0x00000000008cd982 in inline_mysql_thread_create (key=22, thread=0x82bffd70, attr=0x18de480 <connection_attrib>, start_routine=0x8cfb1c <worker_main(void*)>
, arg=0x1904600 <all_groups+2560>) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/include/mysql/ps
i/mysql_thread.h:1252
#8 0x00000000008ce737 in create_worker (thread_group=0x1904600 <all_groups+2560>) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos
6-64/percona-server-5.6.20-68.0/sql/threadpool_unix.cc:881
#9 0x00000000008ce969 in wake_or_create_thread (thread_group=0x1904600 <all_groups+2560>) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_ex
p/centos6-64/percona-server-5.6.20-68.0/sql/threadpool_unix.cc:971
#10 0x00000000008ce24f in check_stall (thread_group=0x1904600 <all_groups+2560>) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-
64/percona-server-5.6.20-68.0/sql/threadpool_unix.cc:660
#11 0x00000000008ce0e9 in timer_thread (param=0x1913c20 <pool_timer>) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-
server-5.6.20-68.0/sql/threadpool_unix.cc:580
#12 0x0000000000e19760 in pfs_spawn_thread (arg=0x217a0560) at /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-server-5.6
.20-68.0/storage/perfschema/pfs.cc:1860
#13 0x000000000506ddf3 in start_thread () from /lib64/libpthread.so.0
#14 0x00000000063dc3dd in clone () from /lib64/libc.so.6

Could this be the issue?

Code (/bzr/5.6/storage/perfschema/pfs.cc :1910)
   int result= pthread_create(thread, attr, pfs_spawn_thread, psi_arg);

(gdb) list
+list
16 /mnt/workspace/percona-server-5.6-binaries-valgrind-yassl/label_exp/centos6-64/percona-server-5.6.20-68.0/sql/main.cc: No such file or directory.
(gdb) p pfs_spawn_thread
+p pfs_spawn_thread
$1 = {void *(void *)} 0xe19607 <pfs_spawn_thread(void*)> <------------------ ?
(gdb) p thread
+p thread
$2 = 608175872

[Roel Van de Paar (roel11)]

There are several Valgrind warnings in the log that may help. See bundles. An example:

==8625== Invalid read of size 8
==8625== at 0x4E363CD: free (in /usr/lib64/libjemalloc.so.1)
==8625== by 0x506E2E9: pthread_create@@GLIBC_2.2.5 (in /usr/lib64/libpthread-2.17.so)
==8625== by 0xE198C5: spawn_thread_v1 (pfs.cc:1910)
==8625== by 0x8CD981: inline_mysql_thread_create (mysql_thread.h:1252)
==8625== by 0x8CE736: create_worker(thread_group_t*) (threadpool_unix.cc:881)
==8625== by 0x8CE968: wake_or_create_thread(thread_group_t*) (threadpool_unix.cc:971)
==8625== by 0x8CE24E: check_stall(thread_group_t*) (threadpool_unix.cc:660)
==8625== by 0x8CE0E8: timer_thread(void*) (threadpool_unix.cc:580)
==8625== by 0xE1975F: pfs_spawn_thread (pfs.cc:1860)
==8625== by 0x506DDF2: start_thread (in /usr/lib64/libpthread-2.17.so)
==8625== by 0x63DC3DC: clone (in /usr/lib64/libc-2.17.so)
==8625== Address 0x74047f8 is 3,384 bytes inside a block of size 8,288 free'd
==8625== at 0x4C29991: operator delete(void*) (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==8625== by 0x631871: __gnu_cxx::new_allocator<my_option>::deallocate(my_option*, unsigned long) (new_allocator.h:110)
==8625== by 0x6306AD: std::_Vector_base<my_option, std::allocator<my_option> >::_M_deallocate(my_option*, unsigned long) (stl_vector.h:174)
==8625== by 0x62FCF6: std::vector<my_option, std::allocator<my_option> >::_M_insert_aux(__gnu_cxx::__normal_iterator<my_option*, std::vector<my_option, std::allocator<my_option> > >, my_option const&) (vector.tcc:386)
==8625== by 0x62F043: std::vector<my_option, std::allocator<my_option> >::push_back(my_option const&) (stl_vector.h:913)
==8625== by 0x730803: sys_var::register_option(std::vector<my_option, std::allocator<my_option> >*, int) (set_var.h:155)
==8625== by 0x72E9E2: sys_var_add_options(std::vector<my_option, std::allocator<my_option> >*, int) (set_var.cc:86)
==8625== by 0x62BA11: get_options(int*, char***) (mysqld.cc:9077)
==8625== by 0x6235A6: init_common_variables() (mysqld.cc:3950)
==8625== by 0x626822: mysqld_main(int, char**) (mysqld.cc:5515)
==8625== by 0x61BAEF: main (main.cc:25)
==8625==
==8625== Invalid write of size 8
==8625== at 0x4E3652C: free (in /usr/lib64/libjemalloc.so.1)
==8625== by 0x506E2E9: pthread_create@@GLIBC_2.2.5 (in /usr/lib64/libpthread-2.17.so)
==8625== by 0xE198C5: spawn_thread_v1 (pfs.cc:1910)
==8625== by 0x8CD981: inline_mysql_thread_create (mysql_thread.h:1252)
==8625== by 0x8CE736: create_worker(thread_group_t*) (threadpool_unix.cc:881)
==8625== by 0x8CE968: wake_or_create_thread(thread_group_t*) (threadpool_unix.cc:971)
==8625== by 0x8CE24E: check_stall(thread_group_t*) (threadpool_unix.cc:660)
==8625== by 0x8CE0E8: timer_thread(void*) (threadpool_unix.cc:580)
==8625== by 0xE1975F: pfs_spawn_thread (pfs.cc:1860)
==8625== by 0x506DDF2: start_thread (in /usr/lib64/libpthread-2.17.so)
==8625== by 0x63DC3DC: clone (in /usr/lib64/libc-2.17.so)
==8625== Address 0x0 is not stack'd, malloc'd or (recently) free'd

[Roel Van de Paar (roel11)]

Adding another very interesting occurence - check error log re: Valgrinds.

[Roel Van de Paar (roel11)]

Another very interesting occurence. Check the stack trace, and this interesting Valgrind just before crash

==16747== Thread 83:
==16747== Invalid read of size 4
==16747== at 0x506FC10: pthread_mutex_lock (in /usr/lib64/libpthread-2.17.so)
==16747== by 0x4E4017E: ??? (in /usr/lib64/libjemalloc.so.1)
==16747== by 0x506E2E9: pthread_create@@GLIBC_2.2.5 (in /usr/lib64/libpthread-2.17.so)
==16747== by 0xE198C5: spawn_thread_v1 (pfs.cc:1910)
==16747== by 0x8CD981: inline_mysql_thread_create (mysql_thread.h:1252)
==16747== by 0x8CE736: create_worker(thread_group_t*) (threadpool_unix.cc:881)
==16747== by 0x8CE8F9: wake_or_create_thread(thread_group_t*) (threadpool_unix.cc:960)
==16747== by 0x8CF1D5: wait_begin(thread_group_t*) (threadpool_unix.cc:1268)
==16747== by 0x8CF65F: tp_wait_begin(THD*, int) (threadpool_unix.cc:1402)
==16747== by 0x7A29DA: thd_wait_begin (sql_class.cc:4561)
==16747== by 0x71C2A5: MDL_wait::timed_wait(MDL_context_owner*, timespec*, bool, PSI_stage_info_v1 const* (mdl.cc:1422)
==16747== by 0x71D66F: MDL_context::acquire_lock(MDL_request*, unsigned long) (mdl.cc:2365)
==16747== by 0x71DB31: MDL_context::acquire_locks(I_P_List<MDL_request, I_P_List_adapter<MDL_request, &MDL_request::next_in_list, &MDL_request::prev_in_list>, I_P_List_counter, I_P_List_no_push_back<MDL_request> >*, unsigned long) (mdl.cc:2485)
==16747== by 0x964211: lock_schema_name(THD*, char const*) (lock.cc:805)
==16747== by 0x7ADEE6: mysql_rm_db(THD*, char*, bool, bool) (sql_db.cc:787)
==16747== by 0x7EC109: mysql_execute_command(THD*) (sql_parse.cc:4293)
==16747== Address 0x3ffff8 is not stack'd, malloc'd or (recently) free'd

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-817