[MDEV-10540] mysqld started by mysql_install_db will hang when having log-bin in config file Created: 2016-08-11  Updated: 2016-12-26  Resolved: 2016-12-26

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.2.1
Fix Version/s: 10.2.3

Type: Bug Priority: Major
Reporter: Hartmut Holzgraefe Assignee: Sergei Golubchik
Resolution: Fixed Votes: 2
Labels: None
Environment:

linux


Attachments: Text File gdb-all-bt-full.txt     Text File gdb-all-bt.txt     Text File gdb-bt-full.txt     Text File gdb-bt.txt    
Issue Links:
Duplicate
duplicates MDEV-11515 Assertion failure in mysql_install_db Closed

 Description   

I'm installing with a custom setup script and a my.cnf template that has "log-bin" in it from the very start.

This makes mysql_install_db, or actually the bootstrap mysqld process, hang.

The last line printed before hanging is

2016-08-11 12:13:04 140389765464832 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist

strace shows mysqld hanging on:

 futex(0x560b65c2db44, FUTEX_WAIT_PRIVATE, 1, NULL



 Comments   
Comment by Hartmut Holzgraefe [ 2016-08-11 ]

gdb backtrace of hanging mysqld bootstrap process:

(gdb) bt full
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
No locals.
#1  0x0000564a97d3105b in inline_mysql_cond_wait (src_file=0x564a98383b88 "/home/hartmut/projects/mariadb/releases/mariadb-10.2.1/sql/mysqld.cc", src_line=6324, 
    mutex=0x564a98b87240 <LOCK_thread_count>, that=0x564a98b86b40 <COND_thread_count>)
    at /home/hartmut/projects/mariadb/releases/mariadb-10.2.1/include/mysql/psi/mysql_thread.h:1149
        result = <optimized out>
#2  bootstrap (file=<optimized out>) at /home/hartmut/projects/mariadb/releases/mariadb-10.2.1/sql/mysqld.cc:6324
        thd = <optimized out>
        error = -512
#3  0x0000564a97d3ac37 in mysqld_main (argc=14, argv=0x7f5e87c7c4e8) at /home/hartmut/projects/mariadb/releases/mariadb-10.2.1/sql/mysqld.cc:5965
        ho_error = <optimized out>
        new_thread_stack_size = <optimized out>
#4  0x00007f5e88fac830 in __libc_start_main (main=0x564a97d1cc10 <main(int, char**)>, argc=11, argv=0x7fff6b209d38, init=<optimized out>, fini=<optimized out>, 
    rtld_fini=<optimized out>, stack_end=0x7fff6b209d28) at ../csu/libc-start.c:291
        result = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, -5463114453628400794, 94878374749760, 140734990687536, 0, 0, -1782026426318501018, -1871456903574500506}, 
              mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x7fff6b209d98, 0x7f5e8b619168}, data = {prev = 0x0, cleanup = 0x0, canceltype = 1797299608}}}
        not_first_call = <optimized out>
#5  0x0000564a97d2e669 in _start ()

Attaching "thread apply all bt full" as a file

Comment by Elena Stepanova [ 2016-08-15 ]

It seems the problem was introduced by this commit:

commit 562c1df7d97cb23145e09b3482fd18d49476752d
Author: Sergei Golubchik <serg@mariadb.org>
Date:   Sat May 14 13:22:47 2016 +0200
 
    cleanup: thread_count
    
    move thread_count handling into THD:
    * increment thread_count in THD constructor
    * decrement thread_count in THD destructor
    * never modify thread_count directly!

Assertion failure on the debug build:

Stack trace from 10.2 commit 69052ed022063d0770ad4562a1dd42572067547e

mysqld: /data/src/10.2/sql/sql_parse.cc:1086: void do_handle_bootstrap(THD*): Assertion `thread_count == 0' failed.
160816  2:25:38 [ERROR] mysqld got signal 6 ;
 
#6  0x00007f23bb5cf266 in __assert_fail_base (fmt=0x7f23bb708238 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x7f23be7353a2 "thread_count == 0", file=file@entry=0x7f23be735278 "/data/src/10.2/sql/sql_parse.cc", line=line@entry=1086, function=function@entry=0x7f23be736ed0 <do_handle_bootstrap(THD*)::__PRETTY_FUNCTION__> "void do_handle_bootstrap(THD*)") at assert.c:92
#7  0x00007f23bb5cf312 in __GI___assert_fail (assertion=0x7f23be7353a2 "thread_count == 0", file=0x7f23be735278 "/data/src/10.2/sql/sql_parse.cc", line=1086, function=0x7f23be736ed0 <do_handle_bootstrap(THD*)::__PRETTY_FUNCTION__> "void do_handle_bootstrap(THD*)") at assert.c:101
#8  0x00007f23bde073c9 in do_handle_bootstrap (thd=0x7f2397bbd070) at /data/src/10.2/sql/sql_parse.cc:1086
#9  0x00007f23bde072fd in handle_bootstrap (arg=0x7f2397bbd070) at /data/src/10.2/sql/sql_parse.cc:1062
#10 0x00007f23bd4d10a4 in start_thread (arg=0x7f23bed20300) at pthread_create.c:309
#11 0x00007f23bb68987d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Comment by Jaime Crespo [ 2016-11-06 ]

I can confirm still present on 10.2.2.

Comment by Elena Stepanova [ 2016-12-26 ]

The problem was fixed by this commit:

commit 1cae1af6f9286ca6695206ce20c63bb639c60310
Author: Sergei Golubchik <serg@mariadb.org>
Date:   Mon Nov 7 22:35:02 2016 +0100
 
    MDEV-5800 InnoDB support for indexed vcols
    
      * remove old 5.2+ InnoDB support for virtual columns
      * enable corresponding parts of the innodb-5.7 sources
      * copy corresponding test cases from 5.7
      * copy detailed Alter_inplace_info::HA_ALTER_FLAGS flags from 5.7
         - and more detailed detection of changes in fill_alter_inplace_info()
      * more "innodb compatibility hooks" in sql_class.cc to
         - create/destroy/reset a THD (used by background purge threads)
         - find a prelocked table by name
         - open a table (from a background purge thread)
    
      * different from 5.7:
        - new service thread "thd_destructor_proxy" to make sure all THDs are
          destroyed at the correct point in time during the server shutdown
        - proper opening/closing of tables for vcol evaluations in
           + FK checks (use already opened prelocked tables)
           + purge threads (open the table, MDLock it, add it to tdc, close
             when not needed)
        - cache open tables in vc_templ
        - avoid unnecessary allocations, reuse table->record[0] and table->s->default_values
        - not needed in 5.7, because it overcalculates:
          + tell the server to calculate vcols for an on-going inline ADD INDEX
          + calculate vcols for correct error messages
    
      * update other engines (mroonga/tokudb) accordingly

Particularly by this chunk:

diff --git a/sql/sql_parse.cc b/sql/sql_parse.cc
index d80706e..6dc9192 100644
--- a/sql/sql_parse.cc
+++ b/sql/sql_parse.cc
@@ -1085,20 +1085,11 @@ void do_handle_bootstrap(THD *thd)
 end:
   in_bootstrap= FALSE;
   delete thd;
-  if (!opt_bootstrap)
-  {
-    /*
-      We need to wake up main thread in case of read_init_file().
-      This is not done by THD::~THD() when there are other threads running
-      (binlog background thread, for example). So do it here again.
-    */
-    mysql_mutex_lock(&LOCK_thread_count);
-    mysql_cond_broadcast(&COND_thread_count);
-    mysql_mutex_unlock(&LOCK_thread_count);
-  }
+  mysql_mutex_lock(&LOCK_thread_count);
+  mysql_cond_broadcast(&COND_thread_count);
+  mysql_mutex_unlock(&LOCK_thread_count);
 
 #ifndef EMBEDDED_LIBRARY
-  DBUG_ASSERT(!opt_bootstrap || thread_count == 0);
   my_thread_end();
   pthread_exit(0);
 #endif

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