[MDEV-9472] 13 node Galera cluster blocks all writes until affected node restart Created: 2016-01-26  Updated: 2019-12-12  Resolved: 2019-12-12

Status: Closed
Project: MariaDB Server
Component/s: Galera, Locking
Affects Version/s: 10.1.10
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Bryan Seitz Assignee: Jan Lindström (Inactive)
Resolution: Incomplete Votes: 0
Labels: galera
Environment:

13 nodes running MariaDB 10.1.10 with Galera
This occurs with the shipping .9 version of the Galera library as well as the latest .14 version.

Layout:

DC1: 3 nodes
DC2: 3 nodes
DC3: 3 nodes
DC4: 3 nodes
DC5: 1 node

Each site minus DC5 has at least 4 async slaves hanging off a VIP, where only one of the 3 nodes at that site is active. (Priority LB method)

Attachments: File v-mysql-003-net.ams2.symcpe.net.err.bz2     File v-mysql-003-net.lhr1.symcpe.net.err.bz2    

 Description   

My 13 node cluster is used for DNS and therefor has a lot more reads than writes. The issue seems to stem from DNS slave nodes in each site which perform a lot of UPDATE statements on the same table. Each site has a VIP where only one of the 3 nodes at that site are active at one time. I will attach my error log and configuration file.

 Comments   
Comment by Bryan Seitz [ 2016-01-26 ]

Configuration File:

[mysqld]
 
server_id=1
 
datadir=/var/lib/mysql
 
user=mysql
 
default_storage_engine=InnoDB
 
skip-name-resolve
 
 
 
### WSRep
 
wsrep_on=ON
 
wsrep_provider=/usr/lib64/galera/libgalera_smm.so
 
wsrep_cluster_address=gcomm://100.65.3.71,100.65.3.72,100.65.3.73,100.65.11.71,100.65.11.72,100.65.11.73,10.51.22.253,100.65.19.201,100.65.19.202,100.65.19.203,100.65.27.201,100.65.27.202,100.65.27.203
 
wsrep_node_address=100.65.3.71
 
wsrep_node_name=v-mysql-001-net.ash2.symcpe.net
 
wsrep_slave_threads=8
 
wsrep_sst_method=rsync
 
wsrep_cluster_name=net_cluster_1
 
wsrep_provider_options="gcache.size=256M; evs.keepalive_period=PT3S; evs.suspect_timeout=PT30S; evs.inactive_timeout=PT1M; evs.install_timeout=PT1M; evs.send_window=4; evs.user_send_window=2; evs.inactive_check_period=PT2S; evs.join_retrans_period=PT0.5S; gmcast.segment=0"
 
wsrep_certify_nonPK=1
 
wsrep_max_ws_rows=131072
 
wsrep_max_ws_size=1073741824
 
wsrep_debug=0
 
wsrep_convert_LOCK_to_trx=1
 
wsrep_retry_autocommit=5
 
wsrep_auto_increment_control=1
 
wsrep_replicate_myisam=0
 
wsrep_causal_reads=0
 
gtid_strict_mode=1
 
gtid-domain-id=2
 
innodb-force-primary-key=1
 
enforce-storage-engine=innodb
 
 
 
# Command to call when node status or cluster membership changes.
 
# Will be passed all or some of the following options:
 
# --status - new status of this node
 
# --uuid - UUID of the cluster
 
# --primary - whether the component is primary or not ("yes"/"no")
 
# --members - comma-separated list of members
 
# --index - index of this node in the list
 
wsrep_notify_cmd=/usr/local/sbin/galera_notify.py
 
#wsrep_sst_auth="sstuser:N3+S3kr3t"
 
 
 
### Tuning
 
tmp_table_size=64M
 
max_allowed_packet=1073741824
 
key_buffer_size=24M
 
query_cache_type=0
 
query_cache_size=0
 
max_connections=500
 
thread_cache_size=512
 
open_files_limit=65534
 
table_definition_cache=1024
 
table_open_cache=2048
 
### Default is 1 year...
 
lock_wait_timeout=60
 
 
 
### InnoDB
 
innodb_flush_method=O_DIRECT
 
innodb_log_files_in_group=2
 
innodb-log-buffer-size=64M
 
innodb_log_file_size=256M
 
innodb_flush_log_at_trx_commit=0
 
innodb_file_per_table=1
 
innodb_buffer_pool_size=1G
 
innodb-doublewrite=1
 
innodb-stats-on-metadata=0
 
innodb_autoinc_lock_mode=2
 
innodb-thread-concurrency=0
 
innodb_print_all_deadlocks
 
 
 
 
 
### Binary logging
 
binlog_format=ROW
 
log_bin=/data/mysql-logs/mysql-bin
 
expire_logs_days=7
 
sync_binlog=1
 
binlog_checksum=1
 
max_binlog_size=1073741824
 
log_slave_updates=1
 
ignore_db_dirs=.ssh
 
ignore_db_dirs=lost+found
 
 
 
### SST
 
[sst]
 
progress=1
 
 
 
### EOF
 
 

Comment by Bryan Seitz [ 2016-01-26 ]

Attached error logs from two nodes that have been exhibiting the behavior.

Comment by Bryan Seitz [ 2016-01-26 ]

I determine which node is locked/hung by looking in the error log at the last few entries. It will be the node with INNODB status/dumps.

Comment by Bryan Seitz [ 2016-02-02 ]

I tried a few tweaks to see if they made any difference with no luck:

wsrep_sync_wait=2
 
wsrep_retry_autocommit=4
 
wsrep_convert_LOCK_to_trx=1

None of these seemed to have any effect and my cluster still deadlocks/hangs a few times a day. Sometimes it recovers on it's own which makes no sense. If there is some issue that works out on it's own why can't it be worked around and not cause a total write block.

Comment by Bryan Seitz [ 2016-02-03 ]

Sample transaction in the InnoDB status dumps:

BEGIN
 
/*!*/;
 
# at 204572441
 
#160203 20:50:41 server id 3  end_log_pos 204572527 CRC32 0x47c88e48    Table_map: `designate_powerdns_kilo`.`domains` mapped to number 18
 
# at 204572527
 
#160203 20:50:41 server id 3  end_log_pos 204572871 CRC32 0x5fcd52c2    Update_rows: table id 18 flags: STMT_END_F
 
### UPDATE `designate_powerdns_kilo`.`domains`
 
### WHERE
 
###   @1=13755 /* INT meta=0 nullable=0 is_null=0 */
 
###   @2='somedomain.com' /* VARSTRING(765) meta=765 nullable=0 is_null=0 */
 
###   @3='100.72.130.93:5354,100.72.138.58:5354' /* VARSTRING(765) meta=765 nullable=1 is_null=0 */
 
###   @4=1454529017 /* INT meta=0 nullable=1 is_null=0 */
 
###   @5='SLAVE' /* VARSTRING(18) meta=18 nullable=0 is_null=0 */
 
###   @6=NULL /* INT meta=0 nullable=1 is_null=1 */
 
###   @7='aea5fd15750f4cbe8cfc3d399f45949d' /* VARSTRING(120) meta=120 nullable=1 is_null=0 */
 
###   @8='977d8b079d6c4fc59aa83f7443750634' /* STRING(96) meta=65120 nullable=1 is_null=0 */
 
### SET
 
###   @1=13755 /* INT meta=0 nullable=0 is_null=0 */
 
###   @2='somedomain.com' /* VARSTRING(765) meta=765 nullable=0 is_null=0 */
 
###   @3='100.72.130.93:5354,100.72.138.58:5354' /* VARSTRING(765) meta=765 nullable=1 is_null=0 */
 
###   @4=1454532641 /* INT meta=0 nullable=1 is_null=0 */
 
###   @5='SLAVE' /* VARSTRING(18) meta=18 nullable=0 is_null=0 */
 
###   @6=NULL /* INT meta=0 nullable=1 is_null=1 */
 
###   @7='aea5fd15750f4cbe8cfc3d399f45949d' /* VARSTRING(120) meta=120 nullable=1 is_null=0 */
 
###   @8='977d8b079d6c4fc59aa83f7443750634' /* STRING(96) meta=65120 nullable=1 is_null=0 */
 
# at 204572871
 
#160203 20:50:41 server id 3  end_log_pos 204572902 CRC32 0xa3cee6b7    Xid = 1626558
 
COMMIT/*!*/;

Comment by Bryan Seitz [ 2016-02-04 ]

Another data point. I've seen it hang on writes for about 2500 seconds and then recover without intervention.

Comment by Nirbhay Choubey (Inactive) [ 2016-02-27 ]

bryan_seitz Do you, by any chance, have long running transactions? Its worth monitoring
the values of flow control status variables on all the nodes to be sure if this hang-up is not due
to flow-control.

SHOW STATUS LIKE 'wsrep_flow_control_%';

Comment by Bryan Seitz [ 2016-02-27 ]

These TX are all very fast as it houses a DNS database. I did seem to eliminate the blocking by reducing the number of writers (DNS Slaves) possibly writing the same data at the same time. I do however question why this confuses MariaDB/Galera. Shouldn't it sort that out ?

Generated at Thu Feb 08 07:34:56 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.