Bug #44091 libmysqld gets stuck waiting on mutex on initialization
Submitted: 4 Apr 2009 23:17 Modified: 15 May 2009 2:12
Reporter: Andrew Hutchings Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Embedded Library ( libmysqld ) Severity:S2 (Serious)
Version:5.1.33 OS:Linux (Fedora 10 x86_64)
Assigned to: Davi Arnaut CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[4 Apr 2009 23:17] Andrew Hutchings
Description:
Whilst running a test (test2.c) in bug #43706 I found it just hangs on the first mysql_library_init() whereas in 5.1.32 it does get past this (but will crash later in this test due to bug #43706).

This is after a ctrl-c whilst running through GDB with mysql-advanced-gpl-5.1.33-linux-x86_64-glibc23:

Program received signal SIGINT, Interrupt.
__lll_lock_wait_private ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:91
91	2:	movl	%edx, %eax
Current language:  auto; currently asm
(gdb) bt
#0  __lll_lock_wait_private ()
    at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:91
#1  0x000000354e60b096 in _L_lock_20 () from /lib64/libpthread.so.0
#2  0x000000354e60aed9 in __pthread_cond_destroy (cond=0xd8a380)
    at pthread_cond_destroy.c:33
#3  0x000000000054b7c3 in my_thread_global_end () at my_thr_init.c:219
#4  0x0000000000549c4d in my_end (infoflag=0) at my_init.c:220
#5  0x000000000050c487 in mysql_server_end () at libmysql.c:210
#6  0x000000000055ee9d in init_embedded_server (argc=4, argv=0xd19080, 
    groups=0x7fffffffe2f0) at lib_sql.cc:563
#7  0x0000000000503b8f in main (argc=1, argv=0x7fffffffe468) at test.c:28

When running with a custom build of 5.1.33 we get a SIGABRT:

safe_mutex: Trying to lock unitialized mutex at my_thr_init.c, line 176

Program received signal SIGABRT, Aborted.
0x000000354da32f05 in raise (sig=<value optimized out>)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
64	  return INLINE_SYSCALL (tgkill, 3, pid, selftid, sig);
(gdb) bt
#0  0x000000354da32f05 in raise (sig=<value optimized out>)
    at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#1  0x000000354da34a73 in abort () at abort.c:88
#2  0x00000000004fc964 in safe_mutex_lock (mp=0xb16ca0, try_lock=0 '\0', 
    file=0x75496c "my_thr_init.c", line=176) at thr_mutex.c:103
#3  0x00000000004f9859 in my_thread_global_end () at my_thr_init.c:176
#4  0x00000000004f6b25 in my_end (infoflag=0) at my_init.c:220
#5  0x00000000004d1d97 in mysql_server_end () at libmysql.c:210
#6  0x00000000004d6bfd in init_embedded_server (argc=4, argv=0xab29a0, 
    groups=0x7fffffffe2a0) at lib_sql.cc:522
#7  0x00000000004d1ecb in mysql_server_init (argc=4, argv=0xab29a0, groups=0x0)
    at libmysql.c:173
#8  0x00000000004c375f in main (argc=1, argv=0x7fffffffe468) at test.c:28

How to repeat:
test2.c in bug #43706

Built using:

gcc test2.c -otest -g -lz `mysql-advanced-gpl-5.1.33-linux-x86_64-glibc23/bin/mysql_config --libmysqld-libs --include`
[7 Apr 2009 17:50] Andrew Hutchings
A slightly more simplified test case

Attachment: test3.c (text/plain), 1.11 KiB.

[9 Apr 2009 0:50] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/71707

2857 Davi Arnaut	2009-04-08
      Bug#43706: libmysqld segfaults when re-intialised
      Bug#44091: libmysqld gets stuck waiting on mutex on initialization
      
      The problem was that libmysqld wasn't enforcing a certain
      initialization and deinitialization order for the mysys
      library. Another problem was that the global object used
      for management of log event handlers (aka LOGGER) wasn't
      being prepared for a possible reutilization.
      
      The solution is enforce a order on the initialization and
      deinitialization of the mysys library within the libmysqld
      library and to ensure that the global LOGGER object reset
      it's internal state during cleanup.
      
      No test case is provided as the infrastructure for testing
      the C client API with the embedded server is disabled.
     @ mysys/my_init.c
        Deinitialize only if initialized already.
     @ sql/log.cc
        Reset state.
[9 Apr 2009 15:10] Georgi Kodinov
OK to push. Please move setting to null of table_log_handler/file_log_handler to be right after their deletion ( seems more natural to me) and add a note describing the exact case in which the problem occurs (and that it's not the general case when mysql_server_init succeeds).
[9 Apr 2009 15:22] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/71793

2867 Davi Arnaut	2009-04-09
      Bug#43706: libmysqld segfaults when re-intialised
      Bug#44091: libmysqld gets stuck waiting on mutex on initialization
      
      The problem was that libmysqld wasn't enforcing a certain
      initialization and deinitialization order for the mysys
      library. Another problem was that the global object used
      for management of log event handlers (aka LOGGER) wasn't
      being prepared for a possible reutilization.
      
      What leads to the hang/crash reported is that a failure
      to load the language file triggers a double call of the
      cleanup functions, causing a already destroyed mutex to
      be used.
      
      The solution is enforce a order on the initialization and
      deinitialization of the mysys library within the libmysqld
      library and to ensure that the global LOGGER object reset
      it's internal state during cleanup.
     @ mysys/my_init.c
        Deinitialize only if initialized already.
     @ sql/log.cc
        Reset state.
[9 Apr 2009 15:25] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/71794

2867 Davi Arnaut	2009-04-09
      Bug#43706: libmysqld segfaults when re-intialised
      Bug#44091: libmysqld gets stuck waiting on mutex on initialization
      
      The problem was that libmysqld wasn't enforcing a certain
      initialization and deinitialization order for the mysys
      library. Another problem was that the global object used
      for management of log event handlers (aka LOGGER) wasn't
      being prepared for a possible reutilization.
      
      What leads to the hang/crash reported is that a failure
      to load the language file triggers a double call of the
      cleanup functions, causing an already destroyed mutex to
      be used.
      
      The solution is enforce a order on the initialization and
      deinitialization of the mysys library within the libmysqld
      library and to ensure that the global LOGGER object reset
      it's internal state during cleanup.
     @ mysys/my_init.c
        Deinitialize only if initialized already.
     @ sql/log.cc
        Reset state.
[9 Apr 2009 15:32] Davi Arnaut
Queued to 5.1-bugteam
[5 May 2009 19:41] Bugs System
Pushed into 5.1.35 (revid:davi.arnaut@sun.com-20090505190206-9xmh7dlc6kom8exp) (version source revid:davi.arnaut@sun.com-20090505190206-9xmh7dlc6kom8exp) (merge vers: 5.1.35) (pib:6)
[6 May 2009 14:10] Bugs System
Pushed into 6.0.12-alpha (revid:svoj@sun.com-20090506125450-yokcmvqf2g7jhujq) (version source revid:davi.arnaut@sun.com-20090409152928-1v9z9bnf7zefopul) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 2:12] Paul Dubois
Noted in 5.1.35, 6.0.12 changelogs.

libmysqld crashed when it was reinitialized.
[15 Jun 2009 8:28] Bugs System
Pushed into 5.1.35-ndb-6.3.26 (revid:jonas@mysql.com-20090615074202-0r5r2jmi83tww6sf) (version source revid:jonas@mysql.com-20090615070837-9pccutgc7repvb4d) (merge vers: 5.1.35-ndb-6.3.26) (pib:6)
[15 Jun 2009 9:07] Bugs System
Pushed into 5.1.35-ndb-7.0.7 (revid:jonas@mysql.com-20090615074335-9hcltksp5cu5fucn) (version source revid:jonas@mysql.com-20090615072714-rmfkvrbbipd9r32c) (merge vers: 5.1.35-ndb-7.0.7) (pib:6)
[15 Jun 2009 9:48] Bugs System
Pushed into 5.1.35-ndb-6.2.19 (revid:jonas@mysql.com-20090615061520-sq7ds4yw299ggugm) (version source revid:jonas@mysql.com-20090615054654-ebgpz7elwu1xj36j) (merge vers: 5.1.35-ndb-6.2.19) (pib:6)
[10 Jul 2009 23:19] Bugs System
Pushed into 5.1.37 (revid:build@mysql.com-20090710231213-9guqdu0avc0uwdkp) (version source revid:build@mysql.com-20090710231213-9guqdu0avc0uwdkp) (merge vers: 5.1.37) (pib:11)
[23 Jul 2009 10:24] Bugs System
Pushed into 5.4.4-alpha (revid:alik@sun.com-20090723102221-ps4uaphwbxzj8p0q) (version source revid:joerg@mysql.com-20090721145751-rqqnhv0kage18wfi) (merge vers: 5.4.4-alpha) (pib:11)
[26 Aug 2009 13:46] Bugs System
Pushed into 5.1.37-ndb-7.0.8 (revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (version source revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)
[26 Aug 2009 13:46] Bugs System
Pushed into 5.1.37-ndb-6.3.27 (revid:jonas@mysql.com-20090826105955-bkj027t47gfbamnc) (version source revid:jonas@mysql.com-20090826105955-bkj027t47gfbamnc) (merge vers: 5.1.37-ndb-6.3.27) (pib:11)
[26 Aug 2009 13:48] Bugs System
Pushed into 5.1.37-ndb-6.2.19 (revid:jonas@mysql.com-20090825194404-37rtosk049t9koc4) (version source revid:jonas@mysql.com-20090825194404-37rtosk049t9koc4) (merge vers: 5.1.37-ndb-6.2.19) (pib:11)
[27 Aug 2009 16:33] Bugs System
Pushed into 5.1.35-ndb-7.1.0 (revid:magnus.blaudd@sun.com-20090827163030-6o3kk6r2oua159hr) (version source revid:jonas@mysql.com-20090826132541-yablppc59e3yb54l) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)