MDEV-21613 Failed to open table mysql.wsrep_streaming_log for writingbb-10.4-MDEV-21613

Fix sporadic failure for MTR test galera_sr.GCF-1018B. The test
sometimes fails due to an error that is logged to the error log
unnecessarily.
A deterministic test case (included in this patch) shows that the
error is loggen when a transaction is BF aborted right before  it
opens the streaming log table to perform fragment removal. When that
happens, the attempt to open the table fails and consequently an error
is logged. There is no need to log this error, as an ER_LOCK_DEADLOCK
error is returned to the client.

Reviewed-by: Jan Lindström <jan.lindstrom@mariadb.com>

5 files changed, 73 insertions, 8 deletions

diff --git a/mysql-test/suite/galera_sr/r/MDEV-21613.result b/mysql-test/suite/galera_sr/r/MDEV-21613.result
new file mode 100644
index 00000000000..67af2d49331
--- /dev/null
+++ b/mysql-test/suite/galera_sr/r/MDEV-21613.result
@@ -0,0 +1,20 @@
+connection node_2;
+connection node_1;
+CREATE TABLE t1 (f1 INTEGER PRIMARY KEY);
+connection node_1;
+SET SESSION wsrep_trx_fragment_size = 1;
+SET DEBUG_SYNC = "wsrep_before_fragment_removal SIGNAL fragment_removal_reached WAIT_FOR fragment_removal_continue";
+START TRANSACTION;
+INSERT INTO t1 VALUES(1), (2);
+COMMIT;
+connect node_ctrl, 127.0.0.1, root, , test, $NODE_MYPORT_1;
+connection node_ctrl;
+SET DEBUG_SYNC = "now WAIT_FOR fragment_removal_reached";
+connect node_1a, 127.0.0.1, root, , test, $NODE_MYPORT_1;
+connection node_1a;
+TRUNCATE TABLE t1;
+connection node_1;
+ERROR 40001: Deadlock found when trying to get lock; try restarting transaction
+connection node_ctrl;
+SET DEBUG_SYNC = 'RESET';
+DROP TABLE t1;
diff --git a/mysql-test/suite/galera_sr/t/MDEV-21613.cnf b/mysql-test/suite/galera_sr/t/MDEV-21613.cnf
new file mode 100644
index 00000000000..d8e3488f044
--- /dev/null
+++ b/mysql-test/suite/galera_sr/t/MDEV-21613.cnf
@@ -0,0 +1,7 @@
+# Set thread-handling as a workaround to avoid MDEV-26528.
+# The file can be removed once fixed.
+
+!include ../galera_2nodes.cnf
+
+[mysqld.1]
+thread-handling=pool-of-threads
diff --git a/mysql-test/suite/galera_sr/t/MDEV-21613.test b/mysql-test/suite/galera_sr/t/MDEV-21613.test
new file mode 100644
index 00000000000..8a1fea1b7f5
--- /dev/null
+++ b/mysql-test/suite/galera_sr/t/MDEV-21613.test
@@ -0,0 +1,36 @@
+#
+# MDEV-21613 - galera_sr.GCF-1018B MTR failed:
+# Failed to open table mysql.wsrep_streaming_log for writing
+#
+# A BF abort right before fragment removal caused this error to
+# be logged to the error log.
+#
+--source include/galera_cluster.inc
+--source include/have_debug_sync.inc
+
+CREATE TABLE t1 (f1 INTEGER PRIMARY KEY);
+
+--connection node_1
+SET SESSION wsrep_trx_fragment_size = 1;
+SET DEBUG_SYNC = "wsrep_before_fragment_removal SIGNAL fragment_removal_reached WAIT_FOR fragment_removal_continue";
+START TRANSACTION;
+INSERT INTO t1 VALUES(1), (2);
+--send COMMIT
+
+--connect node_ctrl, 127.0.0.1, root, , test, $NODE_MYPORT_1
+--connection node_ctrl
+SET DEBUG_SYNC = "now WAIT_FOR fragment_removal_reached";
+
+
+--connect node_1a, 127.0.0.1, root, , test, $NODE_MYPORT_1
+--connection node_1a
+TRUNCATE TABLE t1;
+
+
+--connection node_1
+--error ER_LOCK_DEADLOCK
+--reap
+
+--connection node_ctrl
+SET DEBUG_SYNC = 'RESET';
+DROP TABLE t1;
diff --git a/sql/wsrep_client_service.cc b/sql/wsrep_client_service.cc
index f045e5d271a..dd993097135 100644
--- a/sql/wsrep_client_service.cc
+++ b/sql/wsrep_client_service.cc
@@ -193,6 +193,7 @@ cleanup:
 int Wsrep_client_service::remove_fragments()
 {
   DBUG_ENTER("Wsrep_client_service::remove_fragments");
+  DEBUG_SYNC(m_thd, "wsrep_before_fragment_removal");
   if (wsrep_schema->remove_fragments(m_thd,
                                      Wsrep_server_state::instance().id(),
                                      m_thd->wsrep_trx().id(),
diff --git a/sql/wsrep_schema.cc b/sql/wsrep_schema.cc
index 5ee6468e9c1..06f0f7840ab 100644
--- a/sql/wsrep_schema.cc
+++ b/sql/wsrep_schema.cc
@@ -251,13 +251,7 @@ static int open_table(THD* thd,
   thd->lex->query_tables_own_last= 0;
 
   if (!open_n_lock_single_table(thd, &tables, tables.lock_type, flags)) {
-    if (thd->is_error()) {
-      WSREP_WARN("Can't lock table %s.%s : %d (%s)",
-                 schema_name->str, table_name->str,
-                 thd->get_stmt_da()->sql_errno(), thd->get_stmt_da()->message());
-    }
     close_thread_tables(thd);
-    my_error(ER_NO_SUCH_TABLE, MYF(0), schema_name->str, table_name->str);
     DBUG_RETURN(1);
   }
 
@@ -273,8 +267,15 @@ static int open_for_write(THD* thd, const char* table_name, TABLE** table) {
   LEX_CSTRING table_str= { table_name, strlen(table_name) };
   if (Wsrep_schema_impl::open_table(thd, &schema_str, &table_str, TL_WRITE,
                                     table)) {
-    WSREP_ERROR("Failed to open table %s.%s for writing",
-                schema_str.str, table_name);
+    // No need to log an error if the query was bf aborted,
+    // thd client will get ER_LOCK_DEADLOCK in the end.
+    const bool interrupted= thd->killed ||
+      (thd->is_error() &&
+       (thd->get_stmt_da()->sql_errno() == ER_QUERY_INTERRUPTED));
+    if (!interrupted) {
+      WSREP_ERROR("Failed to open table %s.%s for writing",
+                  schema_str.str, table_name);
+    }
     return 1;
   }
   empty_record(*table);