(8.4)PS-11216: Timestamps needed in the GCS_DEBUG_TRACE file

mysql-test/suite/group_replication/r/gr_gcs_debug_trace_timestamps.result

@@ -0,0 +1,28 @@
+include/group_replication.inc
+Warnings:
+Note	####	Sending passwords in plain text without SSL/TLS is extremely insecure.
+Note	####	Storing MySQL user name or password information in the connection metadata repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START REPLICA; see the 'START REPLICA Syntax' in the MySQL Manual for more information.
+[connection server1]
+
+# Step 1: Start Group Replication — GCS_DEBUG_TRACE must be created.
+include/start_and_bootstrap_group_replication.inc
+
+# Step 2: Enable GCS_DEBUG_BASIC tracing
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_BASIC";
+include/assert.inc [Debug option is GCS_DEBUG_BASIC]
+
+# Step 3: verify ISO 8601 UTC timestamps(microsecond) in GCS_DEBUG_TRACE
+include/wait_for_pattern_in_file.inc [\[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{6}Z\] \[MYSQL_GCS_DEBUG\] \[GCS\]]
+
+# Step 4: disable then re-enable tracing; timestamps must persist
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_NONE";
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_ALL";
+include/assert_grep.inc [Timestamps persist after tracing re-enable]
+
+# Step 5: Verify Group Replication is still ONLINE.
+include/assert.inc [Member is ONLINE after timestamp test]
+
+# Step 6: Cleanup.
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_NONE";
+include/stop_group_replication.inc
+include/group_replication_end.inc

mysql-test/suite/group_replication/t/gr_gcs_debug_trace_timestamps.test

@@ -0,0 +1,95 @@
+################################################################################
+# PS-11216: Timestamps needed in the GCS_DEBUG_TRACE file
+#
+# This test case veritfy that every log written to GCS_DEBUG_TRACE carries a
+# ISO 8601 UTC timestamp with microsecond precision, leading the line:
+#   [YYYY-MM-DDTHH:MM:SS.uuuuuuZ] [MYSQL_GCS_DEBUG] [GCS] <message>
+#
+# Test steps:
+#   1. Start Group Replication — GCS_DEBUG_TRACE must be created.
+#   2. Enable tracing; let the consumer write a few lines.
+#   3. Verify ISO 8601 UTC timestamps with microsecond precision.
+#   4. Disable then re-enable; verify timestamps continue in new entries.
+#   5. Verify Group Replication is still ONLINE.
+#   6. Cleanup.
+################################################################################
+
+--source include/have_group_replication_plugin.inc
+--let $rpl_skip_group_replication_start = 1
+--source include/group_replication.inc
+
+##############################################################################
+# Step 1: Start Group Replication — GCS_DEBUG_TRACE is created.
+##############################################################################
+
+--echo
+--echo # Step 1: Start Group Replication — GCS_DEBUG_TRACE must be created.
+--source include/start_and_bootstrap_group_replication.inc
+--file_exists $MYSQLTEST_VARDIR/mysqld.1/data/GCS_DEBUG_TRACE
+
+##############################################################################
+# Step 2: Enable tracing; let the consumer write a few lines.
+##############################################################################
+--echo
+--echo # Step 2: Enable GCS_DEBUG_BASIC tracing
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_BASIC";
+
+--let $assert_text = Debug option is GCS_DEBUG_BASIC
+--let $assert_cond = "[SELECT @@GLOBAL.group_replication_communication_debug_options]" = "GCS_DEBUG_BASIC"
+--source include/assert.inc
+
+##############################################################################
+# Step 3: Verify ISO 8601 UTC timestamps with microsecond precision.
+##############################################################################
+--echo
+--echo # Step 3: verify ISO 8601 UTC timestamps(microsecond) in GCS_DEBUG_TRACE
+
+# Wait until at least one timestamped line appears in the trace file.
+--let $grep_pattern = \[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{6}Z\] \[MYSQL_GCS_DEBUG\] \[GCS\]
+--let $grep_file = $MYSQLTEST_VARDIR/mysqld.1/data/GCS_DEBUG_TRACE
+--source include/wait_for_pattern_in_file.inc
+
+##############################################################################
+# Step 4: Disable then re-enable; verify timestamps continue in new entries.
+##############################################################################
+--echo
+--echo # Step 4: disable then re-enable tracing; timestamps must persist
+
+# Record file size before the cycle so we can prove new entries were appended.
+--let $size_before = `SELECT LENGTH(LOAD_FILE(CONCAT(@@datadir, 'GCS_DEBUG_TRACE')))`
+
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_NONE";
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_ALL";
+
+# Wait until the file grows beyond the size recorded before the cycle.
+--let $wait_condition = SELECT LENGTH(LOAD_FILE(CONCAT(@@datadir, 'GCS_DEBUG_TRACE'))) > $size_before
+--source include/wait_condition.inc
+
+--let $assert_text = Timestamps persist after tracing re-enable
+--let $assert_file = $MYSQLTEST_VARDIR/mysqld.1/data/GCS_DEBUG_TRACE
+--let $assert_select = \[\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{6}Z\] \[MYSQL_GCS_DEBUG\] \[GCS\]
+--let $assert_count_condition = >= 1
+--source include/assert_grep.inc
+
+##############################################################################
+# Step 5: Verify Group Replication is still ONLINE.
+##############################################################################
+--echo
+--echo # Step 5: Verify Group Replication is still ONLINE.
+
+--let $assert_text = Member is ONLINE after timestamp test
+--let $assert_cond = COUNT(*) = 1 FROM performance_schema.replication_group_members WHERE MEMBER_STATE = "ONLINE"
+--source include/assert.inc
+
+##############################################################################
+# Step 6: Cleanup.
+##############################################################################
+--echo
+--echo # Step 6: Cleanup.
+
+SET GLOBAL group_replication_communication_debug_options = "GCS_DEBUG_NONE";
+--source include/stop_group_replication.inc
+
+--remove_file $MYSQLTEST_VARDIR/mysqld.1/data/GCS_DEBUG_TRACE
+
+--source include/group_replication_end.inc

plugin/group_replication/libmysqlgcs/include/mysql/gcs/gcs_logging_system.h

@@ -659,19 +659,15 @@ class Gcs_default_debugger {
 
   /**
     Add extra information as a message prefix.
+    [YYYY-MM-DDTHH:MM:SS.uuuuuuZ] [MYSQL_GCS_DEBUG] [GCS] <message>
 
     We assume that there is room to accommodate it. Before changing this
     method, make sure the maximum buffer size will always have room to
     accommodate any new information.
 
     @return Return the size of appended information
   */
-  inline size_t append_prefix(char *buffer) {
-    strcpy(buffer, GCS_DEBUG_PREFIX);
-    strcpy(buffer + GCS_DEBUG_PREFIX_SIZE, GCS_PREFIX);
-
-    return GCS_DEBUG_PREFIX_SIZE + GCS_PREFIX_SIZE;
-  }
+  size_t append_prefix(char *buffer);
 
   /**
     Append information into a message such as end of line.

plugin/group_replication/libmysqlgcs/src/interface/gcs_logging_system.cc

@@ -37,6 +37,7 @@
 #include "my_dir.h"
 #include "my_io.h"
 #include "my_sys.h"
+#include "my_systime.h"
 #endif /* XCOM_STANDALONE */
 
 #include "plugin/group_replication/libmysqlgcs/include/mysql/gcs/gcs_logging_system.h"
@@ -337,6 +338,44 @@ enum_gcs_error Gcs_default_debugger::initialize() {
 
 enum_gcs_error Gcs_default_debugger::finalize() { return m_sink->finalize(); }
 
+/*
+  Returns 0 for XCOM_STANDALONE because XCOM_STANDALONE excludes the MySQL
+  portability headers (my_systime.h, my_sys.h) needed by my_micro_time().
+
+  XCOM_STANDALONE is defined when XCom is built as a standalone library
+  for unit-testing the consensus protocol in isolation.
+*/
+static size_t gcs_format_timestamp(char *buf [[maybe_unused]]) {
+#ifdef XCOM_STANDALONE
+  return 0;
+#else
+  const unsigned long long us = my_micro_time();
+  const time_t sec = static_cast<time_t>(us / 1000000);
+  const long usec = static_cast<long>(us % 1000000);
+  struct tm tm_info;
+  if (gmtime_r(&sec, &tm_info) == nullptr) return 0;
+  int len = sprintf(buf, "[%04d-%02d-%02dT%02d:%02d:%02d.%06ldZ] ",
+                    tm_info.tm_year + 1900, tm_info.tm_mon + 1, tm_info.tm_mday,
+                    tm_info.tm_hour, tm_info.tm_min, tm_info.tm_sec, usec);
+  return (len > 0) ? static_cast<size_t>(len) : 0;
+#endif
+}
+
+size_t Gcs_default_debugger::append_prefix(char *buffer) {
+  size_t base = 0;
+
+  /* Timestamp leads the prefix so the final format is:
+     [YYYY-MM-DDTHH:MM:SS.uuuuuuZ] [MYSQL_GCS_DEBUG] [GCS] <message> */
+  size_t ts_len = gcs_format_timestamp(buffer);
+  base += ts_len;
+
+  strcpy(buffer + base, GCS_DEBUG_PREFIX);
+  strcpy(buffer + base + GCS_DEBUG_PREFIX_SIZE, GCS_PREFIX);
+  base += GCS_DEBUG_PREFIX_SIZE + GCS_PREFIX_SIZE;
+
+  return base;
+}
+
 /**
   Reference to the default debugger which is used internally by GCS and XCOM.
 */