Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-19616

Galera test failure on galera_sr.galera_sr_cc_master wrong mutex usage

    XMLWordPrintable

    Details

      Description

      galera_sr.galera_sr_cc_master 'innodb'   w3 [ fail ]
              Test ended at 2019-05-28 11:40:30
       
      CURRENT_TEST: galera_sr.galera_sr_cc_master
      mysqltest: At line 44: query 'SET GLOBAL wsrep_cluster_address = ''' failed: 2013: Lost connection to MySQL server during query
       
      The result from queries just before the failure was:
      < snip >
      SET AUTOCOMMIT=OFF;
      START TRANSACTION;
      INSERT INTO t1 VALUES (1);
      INSERT INTO t1 VALUES (2);
      INSERT INTO t1 VALUES (3);
      INSERT INTO t1 VALUES (4);
      INSERT INTO t1 VALUES (5);
      SELECT COUNT(*) FROM mysql.wsrep_streaming_log;
      COUNT(*)
      5
      connection node_1;
      SELECT COUNT(*) FROM mysql.wsrep_streaming_log;
      COUNT(*)
      5
      connect node_2a, 127.0.0.1, root, , test, $NODE_MYPORT_2;
      connection node_2a;
      SET SESSION wsrep_sync_wait=0;
      SET GLOBAL wsrep_cluster_address = '';
       
      More results from queries before failure can be found in /home/jan/mysql/10.4/mysql-test/var/3/log/galera_sr_cc_master.log
       
       
      Server [mysqld.2 - pid: 18224, winpid: 18224, exit: 256] failed during test run
      Server log from this test:
      ----------SERVER LOG START-----------
      2019-05-28 11:40:25 322 [Note] WSREP: Stop replication by 322
      safe_mutex: Found wrong usage of mutex 'LOCK_wsrep_cluster_config' and 'LOCK_wsrep_server_state'
      Mutex currently locked (in reverse order):
      LOCK_wsrep_server_state           /home/jan/mysql/10.4/sql/wsrep_mutex.h  line 34
      LOCK_wsrep_cluster_config         /home/jan/mysql/10.4/sql/sys_vars_shared.h  line 56
      mysqld: /home/jan/mysql/10.4/mysys/thr_mutex.c:836: print_deadlock_warning: Assertion `my_assert_on_error == 0' failed.
      190528 11:40:25 [ERROR] mysqld got signal 6 ;
      This could be because you hit a bug. It is also possible that this binary
      or one of the libraries it was linked against is corrupt, improperly built,
      or misconfigured. This error can also be caused by malfunctioning hardware.
       
      To report this bug, see https://mariadb.com/kb/en/reporting-bugs
       
      We will try our best to scrape up some info that will hopefully help
      diagnose the problem, but since we have already crashed, 
      something is definitely wrong and this may fail.
       
      Server version: 10.4.6-MariaDB-debug-log
      key_buffer_size=1048576
      read_buffer_size=131072
      max_used_connections=2
      max_threads=153
      thread_count=11
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63612 K  bytes of memory
      Hope that's ok; if not, decrease some variables in the equation.
       
      Thread pointer: 0x7f6260002190
      Attempting backtrace. You can use the following information to find out
      where mysqld died. If you see no messages after this, something went
      terribly wrong...
      stack_bottom = 0x7f62780aee50 thread_stack 0x49000
      /home/jan/mysql/10.4/sql/mysqld(my_print_stacktrace+0x40)[0x55ad0fbd53fc]
      /home/jan/mysql/10.4/sql/mysqld(handle_fatal_signal+0x3ae)[0x55ad0f422ed9]
      /lib/x86_64-linux-gnu/libpthread.so.0(+0x13f40)[0x7f628e2f1f40]
      /lib/x86_64-linux-gnu/libc.so.6(gsignal+0xc7)[0x7f628dde5ed7]
      /lib/x86_64-linux-gnu/libc.so.6(abort+0x121)[0x7f628ddc7535]
      /lib/x86_64-linux-gnu/libc.so.6(+0x2540f)[0x7f628ddc740f]
      /lib/x86_64-linux-gnu/libc.so.6(+0x35012)[0x7f628ddd7012]
      /home/jan/mysql/10.4/sql/mysqld(+0x12c7a3b)[0x55ad0fbdba3b]
      /home/jan/mysql/10.4/sql/mysqld(safe_mutex_lock+0x41e)[0x55ad0fbda58b]
      mysys/thr_mutex.c:837(print_deadlock_warning)[0x55ad0f07d3d3]
      mysys/thr_mutex.c:362(safe_mutex_lock)[0x55ad0f093492]
      psi/mysql_thread.h:710(inline_mysql_mutex_lock)[0x55ad0efd0710]
      sql/wsrep_mutex.h:35(Wsrep_mutex::lock())[0x55ad0efcf56e]
      /home/jan/mysql/10.4/sql/mysqld(_Z22wsrep_stop_replicationP3THD+0x9f)[0x55ad0f337f77]
      /home/jan/mysql/10.4/sql/mysqld(_Z28wsrep_cluster_address_updateP7sys_varP3THD13enum_var_type+0x136)[0x55ad0f349275]
      wsrep/lock.hpp:38(wsrep::unique_lock<wsrep::mutex>::unique_lock(wsrep::mutex&))[0x55ad0efe771a]
      wsrep/server_state.hpp:525(wsrep::server_state::state() const)[0x55ad0efe93e4]
      sql/wsrep_mysqld.cc:914(wsrep_stop_replication(THD*))[0x55ad0efe9070]
      sql/wsrep_var.cc:485(wsrep_cluster_address_update(sys_var*, THD*, enum_var_type))[0x55ad0f0f97e3]
      sql/set_var.cc:209(sys_var::update(THD*, set_var*))[0x55ad0f1039fd]
      sql/set_var.cc:837(set_var::update(THD*))[0x55ad0f103079]
      sql/set_var.cc:740(sql_set_variables(THD*, List<set_var_base>*, bool))[0x55ad0f0ef0a7]
      sql/sql_parse.cc:5199(mysql_execute_command(THD*))[0x55ad0f0ed9c7]
      sql/sql_parse.cc:8157(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55ad0f263472]
      sql/sql_parse.cc:7980(wsrep_mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x55ad0f2631d6]
      sql/sql_parse.cc:1813(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x55ad0fb6d264]
      nptl/pthread_create.c:487(start_thread)[0x7f628e2e7182]
      /lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f628debfb1f]
       
      Trying to get some variables.
      Some pointers may be invalid and cause the dump to abort.
      Query (0x7f6260031938): SET GLOBAL wsrep_cluster_address = ''
      Connection ID (thread ID): 322
      Status: NOT_KILLED
       
      Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
       
      The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
      information that should help you find out what is causing the crash.
      Writing a core file...
      Working directory at /home/jan/mysql/10.4/mysql-test/var/3/mysqld.2/data
      Resource Limits:
      Limit                     Soft Limit           Hard Limit           Units     
      Max cpu time              unlimited            unlimited            seconds   
      Max file size             unlimited            unlimited            bytes     
      Max data size             unlimited            unlimited            bytes     
      Max stack size            8388608              unlimited            bytes     
      Max core file size        unlimited            unlimited            bytes     
      Max resident set          unlimited            unlimited            bytes     
      Max processes             127853               127853               processes 
      Max open files            1024                 1024                 files     
      Max locked memory         67108864             67108864             bytes     
      Max address space         unlimited            unlimited            bytes     
      Max file locks            unlimited            unlimited            locks     
      Max pending signals       127853               127853               signals   
      Max msgqueue size         819200               819200               bytes     
      Max nice priority         0                    0                    
      Max realtime priority     0                    0                    
      Max realtime timeout      unlimited            unlimited            us        
      Core pattern: |/usr/share/apport/apport %p %s %c %d %P
       
      ----------SERVER LOG END-------------
       
       
       - found 'core' (0/5)
       
      Trying 'dbx' to get a backtrace
       
      Trying 'gdb' to get a backtrace from coredump /home/jan/mysql/10.4/mysql-test/var/3/log/galera_sr.galera_sr_cc_master-innodb/mysqld.2/data/core
      Core generated by '/home/jan/mysql/10.4/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 20138]
      [New LWP 19242]
      [New LWP 18718]
      [New LWP 19212]
      [New LWP 18229]
      [New LWP 19213]
      [New LWP 19247]
      [New LWP 19207]
      [New LWP 19244]
      [New LWP 19215]
      [New LWP 19250]
      [New LWP 19241]
      [New LWP 19255]
      [New LWP 19243]
      [New LWP 19246]
      [New LWP 19251]
      [New LWP 18228]
      [New LWP 18717]
      [New LWP 19248]
      [New LWP 18226]
      [New LWP 18230]
      [New LWP 19217]
      [New LWP 19218]
      [New LWP 19239]
      [New LWP 19240]
      [New LWP 19252]
      [New LWP 19253]
      [New LWP 19254]
      [New LWP 19258]
      [New LWP 19245]
      [New LWP 19216]
      [New LWP 19214]
      [New LWP 18716]
      [New LWP 18715]
      [Thread debugging using libthread_db enabled]
      Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
      Core was generated by `/home/jan/mysql/10.4/sql/mysqld --defaults-group-suffix=.2 --defaults-file=/hom'.
      Program terminated with signal SIGABRT, Aborted.
      #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      56	../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
      [Current thread is 1 (Thread 0x7f62780af700 (LWP 20138))]
      #0  __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:56
      #1  0x000055ad0fbd54ee in my_write_core (sig=6) at /home/jan/mysql/10.4/mysys/stacktrace.c:481
      #2  0x000055ad0f423262 in handle_fatal_signal (sig=6) at /home/jan/mysql/10.4/sql/signal_handler.cc:343
      #3  <signal handler called>
      #4  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
      #5  0x00007f628ddc7535 in __GI_abort () at abort.c:79
      #6  0x00007f628ddc740f in __assert_fail_base (fmt=0x7f628df55588 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55ad10080d80 "my_assert_on_error == 0", file=0x55ad10080570 "/home/jan/mysql/10.4/mysys/thr_mutex.c", line=836, function=<optimized out>) at assert.c:92
      #7  0x00007f628ddd7012 in __GI___assert_fail (assertion=0x55ad10080d80 "my_assert_on_error == 0", file=0x55ad10080570 "/home/jan/mysql/10.4/mysys/thr_mutex.c", line=836, function=0x55ad10080e10 <__PRETTY_FUNCTION__.14642> "print_deadlock_warning") at assert.c:101
      #8  0x000055ad0fbdba3b in print_deadlock_warning (new_mutex=0x55ad107819a0 <LOCK_wsrep_server_state>, parent_mutex=0x55ad10777200 <LOCK_wsrep_cluster_config>) at /home/jan/mysql/10.4/mysys/thr_mutex.c:836
      #9  0x000055ad0fbda58b in safe_mutex_lock (mp=0x55ad107819a0 <LOCK_wsrep_server_state>, my_flags=0, file=0x55ad0fcd1cf8 "/home/jan/mysql/10.4/sql/wsrep_mutex.h", line=34) at /home/jan/mysql/10.4/mysys/thr_mutex.c:360
      #10 0x000055ad0f07d3d3 in inline_mysql_mutex_lock (that=0x55ad107819a0 <LOCK_wsrep_server_state>, src_file=0x55ad0fcd1cf8 "/home/jan/mysql/10.4/sql/wsrep_mutex.h", src_line=34) at /home/jan/mysql/10.4/include/mysql/psi/mysql_thread.h:710
      #11 0x000055ad0f093492 in Wsrep_mutex::lock (this=0x55ad12eab1d0) at /home/jan/mysql/10.4/sql/wsrep_mutex.h:34
      #12 0x000055ad0efd0710 in wsrep::unique_lock<wsrep::mutex>::unique_lock (this=0x7f62780ac750, mutex=...) at /home/jan/mysql/10.4/wsrep-lib/include/wsrep/lock.hpp:37
      #13 0x000055ad0efcf56e in wsrep::server_state::state (this=0x55ad12eaaf20) at /home/jan/mysql/10.4/wsrep-lib/include/wsrep/server_state.hpp:524
      #14 0x000055ad0f337f77 in wsrep_stop_replication (thd=0x7f6260002190) at /home/jan/mysql/10.4/sql/wsrep_mysqld.cc:914
      #15 0x000055ad0f349275 in wsrep_cluster_address_update (self=0x55ad1076f900 <Sys_wsrep_cluster_address>, thd=0x7f6260002190, type=SHOW_OPT_GLOBAL) at /home/jan/mysql/10.4/sql/wsrep_var.cc:483
      #16 0x000055ad0efe771a in sys_var::update (this=0x55ad1076f900 <Sys_wsrep_cluster_address>, thd=0x7f6260002190, var=0x7f6260031aa0) at /home/jan/mysql/10.4/sql/set_var.cc:209
      #17 0x000055ad0efe93e4 in set_var::update (this=0x7f6260031aa0, thd=0x7f6260002190) at /home/jan/mysql/10.4/sql/set_var.cc:837
      #18 0x000055ad0efe9070 in sql_set_variables (thd=0x7f6260002190, var_list=0x7f6260006fb0, free=true) at /home/jan/mysql/10.4/sql/set_var.cc:740
      #19 0x000055ad0f0f97e3 in mysql_execute_command (thd=0x7f6260002190) at /home/jan/mysql/10.4/sql/sql_parse.cc:5199
      #20 0x000055ad0f1039fd in mysql_parse (thd=0x7f6260002190, rawbuf=0x7f6260031938 "SET GLOBAL wsrep_cluster_address = ''", length=37, parser_state=0x7f62780ae160, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4/sql/sql_parse.cc:8157
      #21 0x000055ad0f103079 in wsrep_mysql_parse (thd=0x7f6260002190, rawbuf=0x7f6260031938 "SET GLOBAL wsrep_cluster_address = ''", length=37, parser_state=0x7f62780ae160, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4/sql/sql_parse.cc:7969
      #22 0x000055ad0f0ef0a7 in dispatch_command (command=COM_QUERY, thd=0x7f6260002190, packet=0x7f6260026151 "SET GLOBAL wsrep_cluster_address = ''", packet_length=37, is_com_multi=false, is_next_command=false) at /home/jan/mysql/10.4/sql/sql_parse.cc:1813
      #23 0x000055ad0f0ed9c7 in do_command (thd=0x7f6260002190) at /home/jan/mysql/10.4/sql/sql_parse.cc:1361
      #24 0x000055ad0f263472 in do_handle_one_connection (connect=0x55ad1338df50) at /home/jan/mysql/10.4/sql/sql_connect.cc:1403
      #25 0x000055ad0f2631d6 in handle_one_connection (arg=0x55ad1338df50) at /home/jan/mysql/10.4/sql/sql_connect.cc:1306
      #26 0x000055ad0fb6d264 in pfs_spawn_thread (arg=0x55ad13393ba0) at /home/jan/mysql/10.4/storage/perfschema/pfs.cc:1862
      #27 0x00007f628e2e7182 in start_thread (arg=<optimized out>) at pthread_create.c:486
      #28 0x00007f628debfb1f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              jplindst Jan Lindström
              Reporter:
              jplindst Jan Lindström
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: