Bug #114892 Test XComControlTest.SuspectMemberFailedRemovalDueToMajorityLoss fails

Submitted: 6 May 2024 7:30 Modified: 10 Jun 12:57
Reporter: Laurynas Biveinis (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:Tests: Group Replication Severity:S7 (Test Cases)
Version:8.0.46, 8.4.4 OS:MacOS (14.4.1)
Assigned to: CPU Architecture:ARM

[6 May 2024 7:30] Laurynas Biveinis 
Description:
I only saw this in Release configuration:
$ runtime_output_directory/gcs_xcom_control_interface-t
...
[ RUN      ] XComControlTest.SuspectMemberFailedRemovalDueToMajorityLoss
[MYSQL_GCS_DEBUG] [GCS] Gcs_xcom_engine::initialize invoked!

GMOCK WARNING:
Uninteresting mock function call - taking default action specified at:
/Users/laurynas/vilniusdb/mysql-8.0.37/unittest/gunit/libmysqlgcs/xcom/gcs_xcom_control_interface-t.cc:467:
    Function call: configure_active_provider(@0x16b766820 104-byte object <39-30 76-6B 01-00 00-00 38-37 85-04 01-00 00-00 90-43 E0-15 01-00 00-00 00-15 BB-04 01-00 00-00 A0-14 BB-04 01-00 00-00 BD-97 B8-04 01-00 00-00 70-00 23-03 00-60 00-00 90-00 23-03 00-60 00-00 80-68 76-6B 01-00 00-00 8C-2C 7B-04 01-80 62-97 70-00 23-03 00-60 00-00 30-00 23-03 00-60 00-00 C0-68 76-6B 01-00 00-00>)
          Returns: false
NOTE: You can safely ignore the above warning unless this call should not happen.  Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call.  See https://github.com/google/googletest/blob/master/docs/gmock_cook_book.md#knowing-when-to-e... for details.
[MYSQL_GCS_INFO] [GCS] Booting a group: 17149803781773500:12345
[MYSQL_GCS_DEBUG] [GCS] ::join():: I am the boot node. 12345 - 17149803781773500. Calling xcom_client_boot.
[MYSQL_GCS_DEBUG] [GCS] Node[0]=(address=127.0.0.1:12345), (uuid=17149803781773500)
[MYSQL_GCS_DEBUG] [GCS] Prepared 1 nodes at 0x60000003c600
[MYSQL_GCS_DEBUG] [GCS] Booting up 1 nodes at 0x60000003c600
[MYSQL_GCS_DEBUG] [GCS] Unprepared 1 nodes at 0x60000003c600
[MYSQL_GCS_INFO] [GCS] The member has joined the group. Local port: 12345
[MYSQL_GCS_DEBUG] [GCS] Started the suspicions processing thread...
[MYSQL_GCS_DEBUG] [GCS] Set suspicions processing period to 15 seconds.
[MYSQL_GCS_DEBUG] [GCS] Set non-member expel timeout to 60 seconds (60000000000  ns).
[MYSQL_GCS_DEBUG] [GCS] Set member expel timeout to 0 seconds (0  ns).
[MYSQL_GCS_DEBUG] [GCS] forget_expels_that_have_taken_effect: config_id_where_members_left={0 0} members_that_left=( )
[MYSQL_GCS_DEBUG] [GCS] forget_expels_that_have_taken_effect: expels_in_progress=[ ]
[MYSQL_GCS_DEBUG] [GCS] process_view: total_number_nodes=3 total_number_suspect_nodes=2 m_has_majority=0
[MYSQL_GCS_DEBUG] [GCS] add_suspicions: Adding member expel suspicion for 127.0.0.1:12346
[MYSQL_GCS_DEBUG] [GCS] add_suspicions: Adding member expel suspicion for 127.0.0.1:12347
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12346 hasn't timed out.
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12347 hasn't timed out.
/Users/laurynas/vilniusdb/mysql-8.0.37/unittest/gunit/libmysqlgcs/xcom/gcs_xcom_control_interface-t.cc:1581: Failure
Expected equality of these values:
  0ul
    Which is: 0
  number_suspects
    Which is: 2
[MYSQL_GCS_DEBUG] [GCS] Gcs_xcom_engine::finalize invoked!
[MYSQL_GCS_DEBUG] [GCS] xcom_id 0 Started executing during regular phase: 0x600000e305e0
[MYSQL_GCS_DEBUG] [GCS] Node[0]=(address=127.0.0.1:12345), (uuid=17149803781773500)
[MYSQL_GCS_DEBUG] [GCS] Prepared 1 nodes at 0x600000024030
[MYSQL_GCS_DEBUG] [GCS] Removing 1 nodes at 0x600000024030
[MYSQL_GCS_DEBUG] [GCS] Unprepared 1 nodes at 0x600000024030
[MYSQL_GCS_DEBUG] [GCS] wake_suspicions_processing_thread: Locked mutex!
[MYSQL_GCS_DEBUG] [GCS] wake_suspicions_processing_thread: Signaled cond! Return= 0
[MYSQL_GCS_DEBUG] [GCS] wake_suspicions_processing_thread: Unlocked mutex!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspicions manager thread was awaken to process new suspicions!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12346 has timed out!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12347 has timed out!
[MYSQL_GCS_DEBUG] [GCS] The suspicions processing thread has joined.
[MYSQL_GCS_DEBUG] [GCS] The member left the group.
[MYSQL_GCS_DEBUG] [GCS] Will install leave view: requested 1, delivered 0
[MYSQL_GCS_DEBUG] [GCS] Installing leave view.
[MYSQL_GCS_DEBUG] [GCS] ::install_view():: No exchanged data
[MYSQL_GCS_DEBUG] [GCS] Installed leave view: requested 1, delivered 1
[MYSQL_GCS_DEBUG] [GCS] xcom_id 0 Finish executing during regular phase: 0x600000e305e0
/Users/laurynas/vilniusdb/mysql-8.0.37/unittest/gunit/libmysqlgcs/xcom/gcs_xcom_control_interface-t.cc:1543: Failure
Actual function call count doesn't match EXPECT_CALL(proxy, xcom_client_remove_node(_, _))...
         Expected: to be called twice
           Actual: called once - unsatisfied and active
/Users/laurynas/vilniusdb/mysql-8.0.37/unittest/gunit/libmysqlgcs/xcom/gcs_xcom_control_interface-t.cc:1544: Failure
Actual function call count doesn't match EXPECT_CALL(proxy, delete_node_address(_, _))...
         Expected: to be called 3 times
           Actual: called twice - unsatisfied and active
[  FAILED  ] XComControlTest.SuspectMemberFailedRemovalDueToMajorityLoss (0 ms)

How to repeat:
See above. CMake options used for the build: -DCMAKE_EXPORT_COMPILE_COMMANDS=ON -DBUILD_CONFIG=mysql_release -DCMAKE_BUILD_TYPE=Release -DMYSQL_MAINTAINER_MODE=ON -DWITH_SYSTEM_LIBS=ON -DFORCE_COLORED_OUTPUT=ON -DDOWNLOAD_BOOST=ON -DWITH_BOOST=~/vilniusdb/mysql-boost/
[7 May 2024 12:33] MySQL Verification Team 
Hello Laurynas,

Thank you for the report and feedback!

regards,
Umesh
[2 Jul 2024 13:46] Laurynas Biveinis 
Did not reproduce on 8.0.38
Same test failing on 8.4.1
[17 Oct 2024 13:24] Laurynas Biveinis 
Did not see any instances so far under 8.0.40 / 8.4.3 / 9.1.0
[27 Jan 2025 11:28] Laurynas Biveinis 
Repeatable with 8.4.4
[27 Oct 2025 16:51] Laurynas Biveinis 
Something on the same test seen on 8.0.44, but cannot confirm being the same issue
[21 Jan 11:37] Laurynas Biveinis 
8.0.45:

[ RUN      ] XComControlTest.SuspectMembersRemoval
[MYSQL_GCS_DEBUG] [GCS] Gcs_xcom_engine::initialize invoked!

GMOCK WARNING:
Uninteresting mock function call - taking default action specified at:
/Users/laurynas/vilniusdb/mysql-8.0.45/unittest/gunit/libmysqlgcs/xcom/gcs_xcom_control_interface-t.cc:467:
    Function call: configure_active_provider(@0x16b86e258 104-byte object <39-30 00-00 00-00 00-00 06-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 E8-E1 86-6B 01-00 00-00 28-64 FD-F7 01-00 00-00 00-00 00-00 00-00 00-00 90-00 C6-18 0A-00 00-00 80-00 C6-18 0A-00 00-00 70-00 C6-18 0A-00 00-00 90-00 C6-18 0A-00 00-00 70-00 C6-18 0A-00 00-00 00-00 C6-18 0A-00 00-00>)
          Returns: false
NOTE: You can safely ignore the above warning unless this call should not happen.  Do not suppress it by blindly adding an EXPECT_CALL() if you don't mean to enforce the call.  See https://github.com/google/googletest/blob/main/docs/gmock_cook_book.md#knowing-when-to-exp... for details.
[MYSQL_GCS_INFO] [GCS] Booting a group: 17689951966402540:12345
[MYSQL_GCS_DEBUG] [GCS] ::join():: I am the boot node. 12345 - 17689951966402540. Calling xcom_client_boot.
[MYSQL_GCS_DEBUG] [GCS] Node[0]=(address=127.0.0.1:12345), (uuid=17689951966402540)
[MYSQL_GCS_DEBUG] [GCS] Prepared 1 nodes at 0xa18c28270
[MYSQL_GCS_DEBUG] [GCS] Booting up 1 nodes at 0xa18c28270
[MYSQL_GCS_DEBUG] [GCS] Unprepared 1 nodes at 0xa18c28270
[MYSQL_GCS_INFO] [GCS] The member has joined the group. Local port: 12345
[MYSQL_GCS_DEBUG] [GCS] Started the suspicions processing thread...
/Users/laurynas/vilniusdb/mysql-8.0.45/unittest/gunit/libmysqlgcs/xcom/gcs_xcom_control_interface-t.cc:1521: Failure
Expected equality of these values:
  0ul
    Which is: 0
  number_suspects
    Which is: 2

[MYSQL_GCS_DEBUG] [GCS] Set suspicions processing period to 15 seconds.
[MYSQL_GCS_DEBUG] [GCS] Set non-member expel timeout to 60 seconds (60000000000  ns).
[MYSQL_GCS_DEBUG] [GCS] Set member expel timeout to 0 seconds (0  ns).
[MYSQL_GCS_DEBUG] [GCS] forget_expels_that_have_taken_effect: config_id_where_members_under_effect={0 0} members_under_effect=( )
[MYSQL_GCS_DEBUG] [GCS] forget_expels_that_have_taken_effect: expels_in_progress=[ ]
[MYSQL_GCS_DEBUG] [GCS] process_view: total_number_nodes=5 total_number_suspect_nodes=2 m_has_majority=1
[MYSQL_GCS_DEBUG] [GCS] add_suspicions: Adding member expel suspicion for 127.0.0.1:12346
[MYSQL_GCS_DEBUG] [GCS] add_suspicions: Adding member expel suspicion for 127.0.0.1:12347
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12346 hasn't timed out.
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12347 hasn't timed out.
[MYSQL_GCS_DEBUG] [GCS] Gcs_xcom_engine::finalize invoked!
[MYSQL_GCS_DEBUG] [GCS] xcom_id 0 Started executing during regular phase: 0xa190009c0
[MYSQL_GCS_DEBUG] [GCS] Node[0]=(address=127.0.0.1:12345), (uuid=17689951966402540)
[MYSQL_GCS_DEBUG] [GCS] Prepared 1 nodes at 0xa18c28270
[MYSQL_GCS_DEBUG] [GCS] Removing 1 nodes at 0xa18c28270
[MYSQL_GCS_DEBUG] [GCS] Unprepared 1 nodes at 0xa18c28270
[MYSQL_GCS_DEBUG] [GCS] wake_suspicions_processing_thread: Locked mutex!
[MYSQL_GCS_DEBUG] [GCS] wake_suspicions_processing_thread: Signaled cond! Return= 0
[MYSQL_GCS_DEBUG] [GCS] wake_suspicions_processing_thread: Unlocked mutex!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspicions manager thread was awaken to process new suspicions!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12346 has timed out!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Suspect 127.0.0.1:12347 has timed out!
[MYSQL_GCS_DEBUG] [GCS] process_suspicions: Expelling suspects that timed out!
[MYSQL_GCS_DEBUG] [GCS] Node[0]=(address=127.0.0.1:12346), (uuid=17689951966402810)
[MYSQL_GCS_DEBUG] [GCS] Node[1]=(address=127.0.0.1:12347), (uuid=17689951966402810)
[MYSQL_GCS_DEBUG] [GCS] Prepared 2 nodes at 0xa18c1c000
[MYSQL_GCS_DEBUG] [GCS] Removing 2 nodes at 0xa18c1c000
[MYSQL_GCS_DEBUG] [GCS] Unprepared 2 nodes at 0xa18c1c000
[MYSQL_GCS_DEBUG] [GCS] The suspicions processing thread has joined.
[MYSQL_GCS_DEBUG] [GCS] The member left the group.
[MYSQL_GCS_DEBUG] [GCS] Will install leave view: requested 1, delivered 0
[MYSQL_GCS_DEBUG] [GCS] Installing leave view.
[MYSQL_GCS_DEBUG] [GCS] ::install_view():: No exchanged data
[MYSQL_GCS_DEBUG] [GCS] Installed leave view: requested 1, delivered 1
[MYSQL_GCS_DEBUG] [GCS] xcom_id 0 Finish executing during regular phase: 0xa190009c0
[  FAILED  ] XComControlTest.SuspectMembersRemoval (0 ms)
[10 Jun 12:57] Laurynas Biveinis 
Same on 8.0.46

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.062 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.