[MDEV-33211] Galera SST on maria-backup causes donor node to be unresponsive Created: 2024-01-10  Updated: 2024-01-26

Status: In Progress
Project: MariaDB Server
Component/s: mariabackup
Affects Version/s: 10.11.6
Fix Version/s: 10.11

Type: Bug Priority: Critical
Reporter: Michael Widenius Assignee: Jan Lindström
Resolution: Unresolved Votes: 0
Labels: None

Attachments: File galera_backup_stage.test     File mariabackup.diff     File node1.cnf     File node2.cnf     File node3.cnf     File prep.sh     File run.ods     File run.sh    
Issue Links:
Blocks
is blocked by MDEV-33278 Assertion failure in thd_get_thread_i... In Review

 Description   

Scenario:

  • MariaDB Galera cluster with 3 nodes.
  • Take down 2 of the nodes
  • Use SST to create a new node (using mariadb-backup)

At some point during the SST, the node stops responding to DML queries for long times.
As the new mariadb-backup in 10.11 is using BACKUP LOCK's this should not happen.



 Comments   
Comment by Jan Lindström [ 2024-01-11 ]

branch : maria-10.11-backup
commit : 7d1b395550da

Fix for mariabackup :

diff --git a/extra/mariabackup/backup_mysql.cc b/extra/mariabackup/backup_mysql.cc
index 51107f2ff1a..cf4ad09b5c5 100644
--- a/extra/mariabackup/backup_mysql.cc
+++ b/extra/mariabackup/backup_mysql.cc
@@ -1392,7 +1392,7 @@ saves it in a file. It also prints it to stdout. */
 bool
 write_galera_info(ds_ctxt *datasink, MYSQL *connection)
 {
-  return 0;
+  return true; // success
 }
 

Comment by Jan Lindström [ 2024-01-11 ]

Update from local testing with Galera library 26.4.17

Debug:

Failing test(s): galera.galera_log_bin_ext_mariabackup galera_3nodes.GCF-354 galera_3nodes.MDEV-29171 galera_3nodes.galera_gtid_consistency

Release:

Failing test(s): galera.galera_log_bin_ext_mariabackup galera_3nodes.galera_gtid_consistency galera_3nodes.MDEV-29171

  • From these galera_gtid_consistency and MDEV-29171 are clear regressions related on GTID (domain_id).
  • galera_log_bin_ext_mariabackup failure not clear

CURRENT_TEST: galera.galera_log_bin_ext_mariabackup
--- /home/jan/work/mariadb/upstream/mysql-test/suite/galera/r/galera_log_bin_ext_mariabackup.result	2023-09-26 07:17:42.000000000 +0200
+++ /home/jan/work/mariadb/upstream/mysql-test/suite/galera/r/galera_log_bin_ext_mariabackup.reject	2024-01-11 11:39:50.461945836 +0200
@@ -58,8 +58,6 @@
 COUNT(*) = 2
 1
 include/show_binlog_events.inc
-Log_name	Pos	Event_type	Server_id	End_log_pos	Info
-hostname1-bin.000002	#	Binlog_checkpoint	#	#	hostname1-bin.000002
 DROP TABLE t1;
 DROP TABLE t2;
 #cleanup

Comment by Jan Lindström [ 2024-01-14 ]

Update: With attached mariabackup.diff regressions except galera_log_bin_ext_mariabackup are fixed.

  • Test: 2-node cluster with sysbench db (prep.sh) with table-size=20000000
  • All queries and updates are done to node_1 (node_2 is just a slave)
  • 3rd will join cluster after 100s warm-up using SST method mariabackup
  • Results on attached sheet. (Please note that I was using my laptop so actual performance numbers are meaningless)
  • Executive summary: When actual SST starts performance drops to 0
  • Reason: wsrep_sst.cc still uses FLUSH TABLE WITH READ LOCK and all internal writes on InnoDB are disabled.
Comment by Jan Lindström [ 2024-01-16 ]

Update:

  • sysbench oltp or oltp_read_write tests after FLUSH TABLES WITH READ LOCK performance is 0
  • sysbench oltp_read_only works fine.
  • Percona TPCC-C also performance drops to 0
  • Reason is that threads doing writes will block until MDL lock timeout expires
Comment by Michael Widenius [ 2024-01-19 ]

wsrep_sst.cc is only using FUSH TABLE WITH READ LOCK if one uses rsync. This is ok and expected.
How to solve the galera_log_bin_ext_mariabackup failure?

Comment by Jan Lindström [ 2024-01-22 ]

Update: With attached test case I tried to find out at what backup stage DML is blocked. Based on my testing it is already on BACKUP STAGE BLOCK_DDL;

Comment by Michael Widenius [ 2024-01-26 ]

Here is a test case in the terminal that inserts are not blocked by BLOCK_DDL:

Terminal 1

MariaDB [test]> create table t1 (a int primary key, b int) engine innodb;
MariaDB [test]> insert into t1 values (1,1);

Terminal 2
MariaDB [test]> backup stage start; backup stage block_ddl;

Terminal 1

MariaDB [test]> insert into t1 values (2,2);
MariaDB [test]> select * from t1;
-------+

a b

-------+

1 1
2 2

Terminal 2;

MariaDB [test]> backup stage end;

Terminal 1
MariaDB [test]> begin;
MariaDB [test]> insert into t1 values (3,3);

Terminal 2
MariaDB [test]> backup stage start; backup stage block_ddl;

Terminal 1
MariaDB [test]> insert into t1 values (4,4);
MariaDB [test]> commit;

Comment by Michael Widenius [ 2024-01-26 ]

The lock is in galera, not in the MDL's used by BACKUP STAGE BLOCK_DDL

0 0x00007ffff786b70c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00007fffef856a3b in gu_cond_wait_SYS (mutex=0x284d058, cond=0x7fff74019d50) at /home/buildbot/buildbot/build/galerautils/src/gu_threads.h:251
#2 gu::Lock::wait (this=<synthetic pointer>, cond=...) at /home/buildbot/buildbot/build/galerautils/src/gu_lock.hpp:46
#3 galera::Monitor<galera::ReplicatorSMM::LocalOrder>::enter (this=this@entry=0x284d058, obj=...) at /home/buildbot/buildbot/build/galera/src/monitor.hpp:194
#4 0x00007fffef845f87 in galera::ReplicatorSMM::enter_local_monitor_for_cert (this=this@entry=0x284bea0, trx=trx@entry=0x7fffa00160e0, ts=...) at /home/buildbot/buildbot/build/galera/src/replicator_smm.cpp:3232
#5 0x00007fffef84d86a in galera::ReplicatorSMM::cert (ts=..., trx=0x7fffa00160e0, this=0x284bea0) at /home/buildbot/buildbot/build/galera/src/replicator_smm.cpp:3392
#6 galera::ReplicatorSMM::cert_and_catch (this=this@entry=0x284bea0, trx=trx@entry=0x7fffa00160e0, ts=...) at /home/buildbot/buildbot/build/galera/src/replicator_smm.cpp:3411
#7 0x00007fffef84da43 in galera::ReplicatorSMM::certify (this=0x284bea0, trx=..., meta=0x7fffd45ecbc8) at /home/buildbot/buildbot/build/galera/src/replicator_smm.cpp:989
#8 0x00007fffef825d70 in galera_certify (gh=<optimized out>, conn_id=<optimized out>, trx_handle=<optimized out>, flags=<optimized out>, meta=0x7fffd45ecbc8) at /home/buildbot/buildbot/build/galera/src/wsrep_provider.cpp:669
#9 0x00000000013a653d in wsrep::wsrep_provider_v26::certify (this=<optimized out>, client_id=..., ws_handle=..., flags=<optimized out>, ws_meta=...) at /my/maria-10.6/wsrep-lib/src/wsrep_provider_v26.cpp:921
#10 0x000000000139967e in wsrep::transaction::certify_commit (this=this@entry=0x7fff74007658, lock=...) at /my/maria-10.6/wsrep-lib/src/transaction.cpp:1816
#11 0x00000000013a1086 in wsrep::transaction::before_prepare (this=this@entry=0x7fff74007658, lock=...) at /my/maria-10.6/wsrep-lib/src/transaction.cpp:346
#12 0x00000000013a1346 in wsrep::transaction::before_commit (this=this@entry=0x7fff74007658) at /my/maria-10.6/wsrep-lib/src/transaction.cpp:462
#13 0x00000000013733e8 in wsrep::client_state::before_commit (this=this@entry=0x7fff740075f0) at /my/maria-10.6/wsrep-lib/src/client_state.cpp:389
#14 0x0000000000a52118 in wsrep_before_commit (thd=thd@entry=0x7fff74000d48, all=all@entry=false) at /my/maria-10.6/sql/wsrep_trans_observer.h:315
#15 0x0000000000a55c87 in ha_commit_trans (thd=thd@entry=0x7fff74000d48, all=all@entry=false) at /my/maria-10.6/sql/handler.cc:1843
#16 0x00000000008f087c in trans_commit_stmt (thd=thd@entry=0x7fff74000d48) at /my/maria-10.6/sql/transaction.cc:472
#17 0x000000000076aa5c in mysql_execute_command (thd=thd@entry=0x7fff74000d48, is_called_from_prepared_stmt=is_called_from_prepared_stmt@entry=false) at /my/maria-10.6/sql/sql_parse.cc:6151
#18 0x0000000000771be7 in mysql_parse (thd=thd@entry=0x7fff74000d48, rawbuf=rawbuf@entry=0x7fff7401a250 "INSERT INTO t1(b) values (1)", l

Generated at Thu Feb 08 10:37:12 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.