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

safe_mutex: Trying to lock mutex at <somewhere> , when the mutex was already locked at sql_parse.cc

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open (View Workflow)
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 10.4, 10.5
    • Fix Version/s: 10.4, 10.5
    • Component/s: Admin statements, wsrep
    • Labels:
      None
    • Environment:
      Galera 26.4.4(r4599)

      Description

      Test case 1: <somewhere> == sql_parse.cc, line ~9017

      --source include/galera_cluster.inc
       
      --connect(con1,localhost,root,,)
      --let $conid= `SELECT CONNECTION_ID()`
       
      --connection default
       
      --error ER_TARGET_NOT_EXPLAINABLE
      eval SHOW EXPLAIN FOR $conid;
      --error ER_TARGET_NOT_EXPLAINABLE
      eval SHOW EXPLAIN FOR $conid;
       
      # Cleanup
      --disconnect con1
      

      10.4 aa7f2578

      safe_mutex: Trying to lock mutex at /data/src/10.4/sql/sql_parse.cc, line 9017, when the mutex was already locked at /data/src/10.4/sql/sql_parse.cc, line 9017 in thread T@20
      200406  1:02:30 [ERROR] mysqld got signal 6 ;
       
      #5  0x00007f8d1cba5535 in __GI_abort () at abort.c:79
      #6  0x000055dbb0ba542f in safe_mutex_lock (mp=0x62b000120e10, my_flags=0, file=0x55dbb0e896c0 "/data/src/10.4/sql/sql_parse.cc", line=9017) at /data/src/10.4/mysys/thr_mutex.c:265
      #7  0x000055dbaf05510a in inline_mysql_mutex_lock (that=0x62b000120e10, src_file=0x55dbb0e896c0 "/data/src/10.4/sql/sql_parse.cc", src_line=9017) at /data/src/10.4/include/mysql/psi/mysql_thread.h:702
      #8  0x000055dbaf094578 in find_thread_callback (thd=0x62b00011f270, arg=0x7f8d02dde680) at /data/src/10.4/sql/sql_parse.cc:9017
      #9  0x000055dbaf09f9b5 in THD_list::iterate<find_thread_callback_arg> (this=0x55dbb2612be0 <server_threads>, action=0x55dbaf09435b <find_thread_callback(THD*, find_thread_callback_arg*)>, arg=0x7f8d02dde680) at /data/src/10.4/sql/sql_class.h:7023
      #10 0x000055dbaf09469f in find_thread_by_id (id=18, query_id=false) at /data/src/10.4/sql/sql_parse.cc:9029
      #11 0x000055dbaf21ee92 in fill_show_explain (thd=0x62b0000cb270, table=0x62b0000d30f0, cond=0x0) at /data/src/10.4/sql/sql_show.cc:3157
      #12 0x000055dbaf260c23 in get_schema_tables_result (join=0x62b0000d4680, executed_place=PROCESSED_BY_JOIN_EXEC) at /data/src/10.4/sql/sql_show.cc:8913
      #13 0x000055dbaf13b98e in JOIN::exec_inner (this=0x62b0000d4680) at /data/src/10.4/sql/sql_select.cc:4416
      #14 0x000055dbaf13989a in JOIN::exec (this=0x62b0000d4680) at /data/src/10.4/sql/sql_select.cc:4241
      #15 0x000055dbaf13d780 in mysql_select (thd=0x62b0000cb270, tables=0x62b0000d30f0, wild_num=0, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x62b0000d4650, unit=0x62b0000cf198, select_lex=0x62b0000cf990) at /data/src/10.4/sql/sql_select.cc:4673
      #16 0x000055dbaf10f9b8 in handle_select (thd=0x62b0000cb270, lex=0x62b0000cf0d8, result=0x62b0000d4650, setup_tables_done_option=0) at /data/src/10.4/sql/sql_select.cc:410
      #17 0x000055dbaf083f3b in execute_sqlcom_select (thd=0x62b0000cb270, all_tables=0x62b0000d30f0) at /data/src/10.4/sql/sql_parse.cc:6359
      #18 0x000055dbaf06fcc7 in mysql_execute_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:3898
      #19 0x000055dbaf08d47a in mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW EXPLAIN FOR 18", length=19, parser_state=0x7f8d02de45d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7900
      #20 0x000055dbaf08beca in wsrep_mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW EXPLAIN FOR 18", length=19, parser_state=0x7f8d02de45d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7704
      #21 0x000055dbaf0620c0 in dispatch_command (command=COM_QUERY, thd=0x62b0000cb270, packet=0x6290002df271 "SHOW EXPLAIN FOR 18", packet_length=19, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1827
      #22 0x000055dbaf05ea98 in do_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:1359
      #23 0x000055dbaf436dd4 in do_handle_one_connection (connect=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1412
      #24 0x000055dbaf436676 in handle_one_connection (arg=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1316
      #25 0x000055dbb0a7466d in pfs_spawn_thread (arg=0x61600007daf0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
      #26 0x00007f8d1d42dfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
      #27 0x00007f8d1cc7c4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Test case 2: <somewhere> == repl_failsafe.cc, line ~177

      --source include/galera_cluster.inc
       
      --connect(con1,localhost,root,,)
      --let $conid= `SELECT CONNECTION_ID()`
       
      --connection default
       
      --error ER_TARGET_NOT_EXPLAINABLE
      eval SHOW EXPLAIN FOR $conid;
      SHOW SLAVE HOSTS;
       
      # Cleanup
      --disconnect con1
      

      safe_mutex: Trying to lock mutex at /data/src/10.4/sql/repl_failsafe.cc, line 177, when the mutex was already locked at /data/src/10.4/sql/sql_parse.cc, line 9017 in thread T@20
      200406  1:04:09 [ERROR] mysqld got signal 6 ;
       
      #6  0x00005589cfe7e42f in safe_mutex_lock (mp=0x62b000120e10, my_flags=0, file=0x5589d00d7560 "/data/src/10.4/sql/repl_failsafe.cc", line=177) at /data/src/10.4/mysys/thr_mutex.c:265
      #7  0x00005589ce0a058e in inline_mysql_mutex_lock (that=0x62b000120e10, src_file=0x5589d00d7560 "/data/src/10.4/sql/repl_failsafe.cc", src_line=177) at /data/src/10.4/include/mysql/psi/mysql_thread.h:702
      #8  0x00005589ce0a0f77 in show_slave_hosts_callback (thd=0x62b00011f270, protocol=0x62b0000cb838) at /data/src/10.4/sql/repl_failsafe.cc:177
      #9  0x00005589ce0a9d5b in THD_list::iterate<Protocol> (this=0x5589d18ebbe0 <server_threads>, action=0x5589ce0a0f45 <show_slave_hosts_callback(THD*, Protocol*)>, arg=0x62b0000cb838) at /data/src/10.4/sql/sql_class.h:7023
      #10 0x00005589ce0a17c6 in show_slave_hosts (thd=0x62b0000cb270) at /data/src/10.4/sql/repl_failsafe.cc:238
      #11 0x00005589ce3492bb in mysql_execute_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:4000
      #12 0x00005589ce36647a in mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW SLAVE HOSTS", length=16, parser_state=0x7fe096f615d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7900
      #13 0x00005589ce364eca in wsrep_mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW SLAVE HOSTS", length=16, parser_state=0x7fe096f615d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7704
      #14 0x00005589ce33b0c0 in dispatch_command (command=COM_QUERY, thd=0x62b0000cb270, packet=0x6290002df271 "", packet_length=16, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1827
      #15 0x00005589ce337a98 in do_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:1359
      #16 0x00005589ce70fdd4 in do_handle_one_connection (connect=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1412
      #17 0x00005589ce70f676 in handle_one_connection (arg=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1316
      #18 0x00005589cfd4d66d in pfs_spawn_thread (arg=0x61600007daf0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
      #19 0x00007fe0b15befa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
      #20 0x00007fe0b0e0d4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Test case 3: <somewhere> == sql_show.cc, line ~157

      --source include/galera_cluster.inc
       
      --connect(con1,localhost,root,,)
      --let $conid= `SELECT CONNECTION_ID()`
       
      --connection default
       
      --error ER_TARGET_NOT_EXPLAINABLE
      eval SHOW EXPLAIN FOR $conid;
      SHOW PROCESSLIST;
       
      # Cleanup
      --disconnect con1
      

      safe_mutex: Trying to lock mutex at /data/src/10.4/sql/sql_show.cc, line 157, when the mutex was already locked at /data/src/10.4/sql/sql_parse.cc, line 9017 in thread T@20
      200406  1:06:09 [ERROR] mysqld got signal 6 ;
       
      #5  0x00007faae3273535 in __GI_abort () at abort.c:79
      #6  0x000055d43fa4e42f in safe_mutex_lock (mp=0x62b000120e10, my_flags=1, file=0x55d43fd71340 "/data/src/10.4/sql/sql_show.cc", line=157) at /data/src/10.4/mysys/thr_mutex.c:265
      #7  0x000055d43e0af2ea in inline_mysql_mutex_trylock (that=0x62b000120e10, src_file=0x55d43fd71340 "/data/src/10.4/sql/sql_show.cc", src_line=157) at /data/src/10.4/include/mysql/psi/mysql_thread.h:745
      #8  0x000055d43e0b0c00 in trylock_short (mutex=0x62b000120e10) at /data/src/10.4/sql/sql_show.cc:157
      #9  0x000055d43e0c4a68 in list_callback (tmp=0x62b00011f270, arg=0x7faac949e340) at /data/src/10.4/sql/sql_show.cc:2847
      #10 0x000055d43e112291 in THD_list::iterate<list_callback_arg> (this=0x55d4414bbbe0 <server_threads>, action=0x55d43e0c4154 <list_callback(THD*, list_callback_arg*)>, arg=0x7faac949e340) at /data/src/10.4/sql/sql_class.h:7023
      #11 0x000055d43e0c5cb2 in mysqld_list_processes (thd=0x62b0000cb270, user=0x0, verbose=false) at /data/src/10.4/sql/sql_show.cc:2961
      #12 0x000055d43df2066a in mysql_execute_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:4882
      #13 0x000055d43df3647a in mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW PROCESSLIST", length=16, parser_state=0x7faac94a35d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7900
      #14 0x000055d43df34eca in wsrep_mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW PROCESSLIST", length=16, parser_state=0x7faac94a35d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7704
      #15 0x000055d43df0b0c0 in dispatch_command (command=COM_QUERY, thd=0x62b0000cb270, packet=0x6290002df271 "", packet_length=16, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1827
      #16 0x000055d43df07a98 in do_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:1359
      #17 0x000055d43e2dfdd4 in do_handle_one_connection (connect=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1412
      #18 0x000055d43e2df676 in handle_one_connection (arg=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1316
      #19 0x000055d43f91d66d in pfs_spawn_thread (arg=0x61600007daf0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
      #20 0x00007faae3afbfa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
      #21 0x00007faae334a4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      Test case 4: <somewhere> == wsrep_mutex.h, line ~34

      --source include/galera_cluster.inc
       
      --connection default
      --let $conid= `SELECT CONNECTION_ID()`
       
      --error ER_TARGET_NOT_EXPLAINABLE
      eval SHOW EXPLAIN FOR $conid;
      

      safe_mutex: Trying to lock mutex at /data/src/10.4/sql/wsrep_mutex.h, line 34, when the mutex was already locked at /data/src/10.4/sql/sql_parse.cc, line 9017 in thread T@20
      200406  1:13:37 [ERROR] mysqld got signal 6 ;
       
      #5  0x00007f57a1257535 in __GI_abort () at abort.c:79
      #6  0x0000557c436ee42f in safe_mutex_lock (mp=0x62b0000cce10, my_flags=0, file=0x557c43993260 "/data/src/10.4/sql/wsrep_mutex.h", line=34) at /data/src/10.4/mysys/thr_mutex.c:265
      #7  0x0000557c41a8b316 in inline_mysql_mutex_lock (that=0x62b0000cce10, src_file=0x557c43993260 "/data/src/10.4/sql/wsrep_mutex.h", src_line=34) at /data/src/10.4/include/mysql/psi/mysql_thread.h:702
      #8  0x0000557c41ac541f in Wsrep_mutex::lock (this=0x62b0000d13d0) at /data/src/10.4/sql/wsrep_mutex.h:34
      #9  0x0000557c418ecf62 in wsrep::unique_lock<wsrep::mutex>::unique_lock (this=0x7f578747c990, mutex=...) at /data/src/10.4/wsrep-lib/include/wsrep/lock.hpp:37
      #10 0x0000557c438e8e57 in wsrep::transaction::before_rollback (this=0x62b0000d1470) at /data/src/10.4/wsrep-lib/src/transaction.cpp:623
      #11 0x0000557c41a5b3f3 in wsrep::client_state::before_rollback (this=0x62b0000d1408) at /data/src/10.4/wsrep-lib/include/wsrep/client_state.hpp:496
      #12 0x0000557c41ba13ca in wsrep_before_rollback (thd=0x62b0000cb270, all=true) at /data/src/10.4/sql/wsrep_trans_observer.h:364
      #13 0x0000557c41ba23aa in wsrep_commit_empty (thd=0x62b0000cb270, all=true) at /data/src/10.4/sql/wsrep_trans_observer.h:513
      #14 0x0000557c41bcb84b in mysql_execute_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:6256
      #15 0x0000557c41bd647a in mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW EXPLAIN FOR 15", length=19, parser_state=0x7f57874825d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7900
      #16 0x0000557c41bd4eca in wsrep_mysql_parse (thd=0x62b0000cb270, rawbuf=0x62b0000d2290 "SHOW EXPLAIN FOR 15", length=19, parser_state=0x7f57874825d0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7704
      #17 0x0000557c41bab0c0 in dispatch_command (command=COM_QUERY, thd=0x62b0000cb270, packet=0x6290002d5271 "SHOW EXPLAIN FOR 15", packet_length=19, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1827
      #18 0x0000557c41ba7a98 in do_command (thd=0x62b0000cb270) at /data/src/10.4/sql/sql_parse.cc:1359
      #19 0x0000557c41f7fdd4 in do_handle_one_connection (connect=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1412
      #20 0x0000557c41f7f676 in handle_one_connection (arg=0x61100006de30) at /data/src/10.4/sql/sql_connect.cc:1316
      #21 0x0000557c435bd66d in pfs_spawn_thread (arg=0x61600007daf0) at /data/src/10.4/storage/perfschema/pfs.cc:1869
      #22 0x00007f57a1adffa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
      #23 0x00007f57a132e4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
      

      I suppose there are other conflicts.

      Reproducible on 10.4, 10.5.
      Not reproducible on 10.3.
      Not reproducible without wsrep_on=ON.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              jplindst Jan Lindström
              Reporter:
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Dates

                Created:
                Updated: