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

galera.galera_bf_kill_debug MTR failed: A long semaphore wait

Details

    Description

      galera.galera_bf_kill_debug failed on BB 10.5 CS: "A long semaphore wait".
      It seems to be a sporadic issue.

      stdio.log:

      10.5.9, 39378e1366f78b38c05e45103b9fb9c829cc5f4f, kvm-rpm-centos74-amd64-debug

      galera.galera_bf_kill_debug 'innodb'     w2 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2020-12-21 19:46:40
      line
      2020-12-21 19:45:52 0 [Warning] InnoDB: A long semaphore wait:
      2020-12-21 19:46:07 0 [Warning] InnoDB: A long semaphore wait:
      2020-12-21 19:46:22 0 [Warning] InnoDB: A long semaphore wait:
      2020-12-21 19:46:37 0 [Warning] InnoDB: A long semaphore wait:
      ^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
      ok
       
       - skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
       
      Retrying test galera.galera_bf_kill_debug, attempt(2/3)...
       
      worker[2] > Restart  - not started
      worker[2] > Restart  - not started
      

      10.5 Server logs.

      But on BB 10.6 CS it failed with another output: "safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'".

      stdio.log:

      10.6.0, 30dc4287ec3d46bae7593f56383b9f3738e3c4e6, kvm-rpm-centos74-amd64-debug

      galera.galera_bf_kill_debug 'innodb'     w2 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2020-12-19 12:47:06
      line
      safe_mutex: Found wrong usage of mutex 'LOCK_thd_kill' and 'mutex'
      ^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
      ok
       
       - skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
       
      Retrying test galera.galera_bf_kill_debug, attempt(2/3)...
       
      worker[2] > Restart  - not started
      worker[2] > Restart  - not started
      galera.galera_bf_kill_debug 'innodb'     w2 [ retry-pass ]   2059
       
      Retrying test galera.galera_bf_kill_debug, attempt(3/3)...
       
      galera.galera_bf_kill_debug 'innodb'     w2 [ retry-fail ]  Found warnings/errors in server log file!
              Test ended at 2020-12-19 12:47:14
      line
      safe_mutex: Found wrong usage of mutex 'mutex' and 'LOCK_thd_data'
      ^ Found warnings in /dev/shm/var/2/log/mysqld.2.err
      ok
       
       - skipping '/dev/shm/var/2/log/galera.galera_bf_kill_debug-innodb/'
      worker[2] > Restart  - using different config file
      worker[2] > Restart  - using different config file
      

      10.6 Server logs.

      Attachments

        Issue Links

          Activity

            I will disable the test on 10.5 due to this local failure:

            CURRENT_TEST: galera.galera_bf_kill_debug
            mysqltest: At line 93: query 'drop table t1' failed: 2013: Lost connection to MySQL server during query
            …
            2021-03-19 12:28:31 0 [Note] WSREP: enqueuing trx abort for (11)
            2021-03-19 12:28:31 10 [Note] WSREP: wsrep_thd_binlog_reset
            mariadbd: /mariadb/10.5m/wsrep-lib/src/client_state.cpp:775: void wsrep::client_state::do_acquire_ownership(wsrep::unique_lock<wsrep::mutex> &): Assertion `state_ == s_idle || mode_ != m_local' failed.
            …
            #7  0x000055c0a15c828f in wsrep::client_state::do_acquire_ownership (this=0x7f93f4008308, lock=<optimized out>) at /mariadb/10.5m/wsrep-lib/src/client_state.cpp:775
            #8  0x000055c0a10dffa7 in wsrep::client_state::acquire_ownership (this=this@entry=0x7f93f4008308) at /mariadb/10.5m/wsrep-lib/include/wsrep/client_state.hpp:153
            #9  0x000055c0a10f6383 in wsrep_rollback_process (rollbacker=0x7f93fc000d48, arg=<optimized out>) at /mariadb/10.5m/sql/wsrep_thd.cc:253
            #10 0x000055c0a10ec4db in start_wsrep_THD (arg=arg@entry=0x55c0a3310c10) at /mariadb/10.5m/sql/wsrep_mysqld.cc:3050
            #11 0x000055c0a107aa2f in pfs_spawn_thread (arg=0x55c0a3335398) at /mariadb/10.5m/storage/perfschema/pfs.cc:2201
            #12 0x00007f9423fcdea7 in start_thread (arg=<optimized out>) at pthread_create.c:477
            #13 0x00007f94235fadef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
            

            marko Marko Mäkelä added a comment - I will disable the test on 10.5 due to this local failure: CURRENT_TEST: galera.galera_bf_kill_debug mysqltest: At line 93: query 'drop table t1' failed: 2013: Lost connection to MySQL server during query … 2021-03-19 12:28:31 0 [Note] WSREP: enqueuing trx abort for (11) 2021-03-19 12:28:31 10 [Note] WSREP: wsrep_thd_binlog_reset mariadbd: /mariadb/10.5m/wsrep-lib/src/client_state.cpp:775: void wsrep::client_state::do_acquire_ownership(wsrep::unique_lock<wsrep::mutex> &): Assertion `state_ == s_idle || mode_ != m_local' failed. … #7 0x000055c0a15c828f in wsrep::client_state::do_acquire_ownership (this=0x7f93f4008308, lock=<optimized out>) at /mariadb/10.5m/wsrep-lib/src/client_state.cpp:775 #8 0x000055c0a10dffa7 in wsrep::client_state::acquire_ownership (this=this@entry=0x7f93f4008308) at /mariadb/10.5m/wsrep-lib/include/wsrep/client_state.hpp:153 #9 0x000055c0a10f6383 in wsrep_rollback_process (rollbacker=0x7f93fc000d48, arg=<optimized out>) at /mariadb/10.5m/sql/wsrep_thd.cc:253 #10 0x000055c0a10ec4db in start_wsrep_THD (arg=arg@entry=0x55c0a3310c10) at /mariadb/10.5m/sql/wsrep_mysqld.cc:3050 #11 0x000055c0a107aa2f in pfs_spawn_thread (arg=0x55c0a3335398) at /mariadb/10.5m/storage/perfschema/pfs.cc:2201 #12 0x00007f9423fcdea7 in start_thread (arg=<optimized out>) at pthread_create.c:477 #13 0x00007f94235fadef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

            I can repeat the last assertion on wsrep-lib using --repeat=100

            jplindst Jan Lindström (Inactive) added a comment - I can repeat the last assertion on wsrep-lib using --repeat=100

            Automated message:
            ----------------------------
            Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

            julien.fritsch Julien Fritsch added a comment - Automated message: ---------------------------- Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.
            JIraAutomate JiraAutomate added a comment -

            Automated message:
            ----------------------------
            Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

            JIraAutomate JiraAutomate added a comment - Automated message: ---------------------------- Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

            10.6 Current failure:

            galera.galera_bf_kill_debug              w8 [ fail ]
            21:14:11         Test ended at 2024-10-24 19:14:11
            21:14:11 
            21:14:11 CURRENT_TEST: galera.galera_bf_kill_debug
            21:14:11 --- /tmp/workspace/mariadb-10.6-mtr/mysql-test/suite/galera/r/galera_bf_kill_debug.result	2024-10-24 18:51:05.000000000 +0000
            21:14:11 +++ /tmp/workspace/mariadb-10.6-mtr/mysql-test/suite/galera/r/galera_bf_kill_debug.reject	2024-10-24 19:14:01.140471419 +0000
            21:14:11 @@ -48,6 +48,8 @@
            21:14:11  SET DEBUG_SYNC = "now SIGNAL bwoc_continue";
            21:14:11  SET DEBUG_SYNC='RESET';
            21:14:11  connection node_2a;
            21:14:11 +Warnings:
            21:14:11 +Warning	1639	debug sync point wait timed out
            21:14:11  connection node_2;
            21:14:11  select * from t1;
            21:14:11  
            

            janlindstrom Jan Lindström added a comment - 10.6 Current failure: galera.galera_bf_kill_debug w8 [ fail ] 21:14:11 Test ended at 2024-10-24 19:14:11 21:14:11 21:14:11 CURRENT_TEST: galera.galera_bf_kill_debug 21:14:11 --- /tmp/workspace/mariadb-10.6-mtr/mysql-test/suite/galera/r/galera_bf_kill_debug.result 2024-10-24 18:51:05.000000000 +0000 21:14:11 +++ /tmp/workspace/mariadb-10.6-mtr/mysql-test/suite/galera/r/galera_bf_kill_debug.reject 2024-10-24 19:14:01.140471419 +0000 21:14:11 @@ -48,6 +48,8 @@ 21:14:11 SET DEBUG_SYNC = "now SIGNAL bwoc_continue"; 21:14:11 SET DEBUG_SYNC='RESET'; 21:14:11 connection node_2a; 21:14:11 +Warnings: 21:14:11 +Warning 1639 debug sync point wait timed out 21:14:11 connection node_2; 21:14:11 select * from t1; 21:14:11
            janlindstrom Jan Lindström added a comment - https://github.com/MariaDB/server/pull/3622
            sysprg Julius Goryavsky added a comment - - edited

            janlindstrom Thanks, the fix for test has been merged with the main branch: https://github.com/MariaDB/server/commit/1f93aece3d187e870bc5810107f393c42daa0cc9

            sysprg Julius Goryavsky added a comment - - edited janlindstrom Thanks, the fix for test has been merged with the main branch: https://github.com/MariaDB/server/commit/1f93aece3d187e870bc5810107f393c42daa0cc9

            People

              sysprg Julius Goryavsky
              stepan.patryshev Stepan Patryshev (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.