Skip to:

  1. Skip to Jira Navigation
  2. Skip to Side Navigation
  3. Skip to Main Content

Updating a row with a variable-length unique key (that conflicts) causes the entire cluster to go down

Description

An aborted transaction is replayed causing a duplicate entry error for a unique index only if the UPDATE query is appending an empty string/value.

t1: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '2828'

t2: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '9418'

t1: is first to replicate

t2: tries to execute but fails on cert conflict with n1, applier thread wins and local thread is aborted

t2: aborts but will be replayed

when t2 replays it will fail with duplicate entry error. two nodes will end up failing with duplicate entry error and the remaining node will become non-primary. Here t1 and t2 executed in separate nodes.

node1:

2019-10-10T13:10:11.758239Z 26 [Note] WSREP: wsrep: initiating pre-commit for write set (10003) 2019-10-10T13:10:11.758281Z 26 [Note] WSREP: wsrep: pre-commit/certification passed (10003) 2019-10-10T13:10:11.758397Z 26 [Note] WSREP: cleanup transaction for LOCAL_STATE: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '2828'

node2:

2019-10-10T13:10:11.758300Z 2 [Note] WSREP: wsrep: applying write-set (10003) 2019-10-10T13:10:11.758808Z 2 [Note] WSREP: wsrep: updating row for write-set (10003) 2019-10-10T13:10:11.758823Z 19 [Note] WSREP: wsrep: replicating commit (-1) 2019-10-10T13:10:11.758954Z 19 [Note] WSREP: wsrep: initiating replication for write set (-1) *** Priority TRANSACTION: TRANSACTION 84003, ACTIVE 0 sec updating or deleting mysql tables in use 1, locked 1 , undo log entries 1 MySQL thread id 2, OS thread handle 140460718245632, query id 20005 wsrep: updating row for write-set (10003) *** Victim TRANSACTION: TRANSACTION 84002, ACTIVE 0 sec mysql tables in use 1, locked 1 , undo log entries 1 MySQL thread id 19, OS thread handle 140460665276160, query id 20003 jericho-rivera-267941-pxc-1.lxd 172.16.0.77 root wsrep: initiating replication for write set (-1) UPDATE `tblname` SET `col2` = '' WHERE `col1` = '9418' *** WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 23 page no 8 n bits 544 index path of table `test`.`tblname` trx id 84002 lock_mode X locks rec but not gap 2019-10-10T13:10:11.759713Z 2 [Note] WSREP: --------- CONFLICT DETECTED -------- 2019-10-10T13:10:11.759747Z 2 [Note] WSREP: cluster conflict due to high priority abort for threads: 2019-10-10T13:10:11.759774Z 2 [Note] WSREP: Winning thread: THD: 2, mode: applier, state: executing, conflict: no conflict, seqno: 10003 SQL: (null) 2019-10-10T13:10:11.759798Z 2 [Note] WSREP: Victim thread: THD: 19, mode: local, state: committing, conflict: no conflict, seqno: -1 SQL: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '9418' 2019-10-10T13:10:11.759820Z 2 [Note] WSREP: BF thread 2 (with write-set: 10003) aborting Victim thread 19 with transaction (84002) 2019-10-10T13:10:11.759841Z 2 [Note] WSREP: Aborting query: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '9418' 2019-10-10T13:10:11.759863Z 2 [Note] WSREP: Killing Transaction (84002) in QUERY_COMMITTING state 2019-10-10T13:10:11.759916Z 2 [Note] WSREP: Abort transaction in pre-commit state bearing trx-id: 20003, next-trx-id: 20003 query-id: 20003 (seqno: -1) 2019-10-10T13:10:11.759991Z 19 [Note] WSREP: THD: 19, seqno 10004 was BF aborted by provider, will replay 2019-10-10T13:10:11.760042Z 19 [Note] WSREP: replaying increased: 1, thd: 19 2019-10-10T13:10:11.760067Z 19 [Note] WSREP: commit action failed for reason: WSREP_BF_ABORT THD: 19 Query: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '9418' 2019-10-10T13:10:11.760087Z 19 [Note] WSREP: conflict state: MUST_REPLAY 2019-10-10T13:10:11.760464Z 2 [Note] WSREP: wsrep: applied write set (10003) 2019-10-10T13:10:11.760520Z 2 [Note] WSREP: wsrep: committing write set (10003) 2019-10-10T13:10:11.760721Z 2 [Note] WSREP: wsrep: committed write set (10003) 2019-10-10T13:10:11.760721Z 19 [Note] WSREP: wsrep: replaying write set (10004) 2019-10-10T13:10:11.760849Z 19 [Note] WSREP: Replaying transaction for SQL query: UPDATE `tblname` SET `col2` = '' WHERE `col1` = '9418' with write-set: 10004 2019-10-10T13:10:11.760987Z 19 [Note] WSREP: wsrep: applying write-set (10004) 2019-10-10T13:10:11.761271Z 19 [Note] WSREP: wsrep: updating row for write-set (10004) 2019-10-10T13:10:11.761753Z 19 [ERROR] Slave SQL: Could not execute Update_rows event on table test.tblname; Duplicate entry '' for key 'col2', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 216, Error_code: 1062
CREATE TABLE `tblname` ( `col1` bigint(20) unsigned NOT NULL AUTO_INCREMENT, `col2` varchar(500) NOT NULL, `col3` int(10) unsigned NOT NULL, `col4` int(10) unsigned NOT NULL, PRIMARY KEY (`col1`), UNIQUE KEY `path` (`col2`) ) ENGINE=InnoDB

This only happens if appending an empty string/value in path column, otherwise if you append a non-empty string eg UPDATE tblname SET col2='aaa' WHERE col1=<someRandomId>; t2 will not be replayed and will be aborted.

Environment

wsrep_debug=1

wsrep_log_conflicts=1

wsrep_provider_options="cert.log_conflicts=1"

wsrep_slave_threads=16

AFFECTED CS IDs

267941

Smart Checklist

Activity

Show:
Done

Details

Assignee

Reporter

Fix versions

Affects versions

Priority

Smart Checklist

Created November 6, 2019 at 1:28 PM
Updated March 6, 2024 at 10:02 PM
Resolved November 6, 2019 at 1:29 PM

Flag notifications