INSERT undone by ROLLBACK TO SAVEPOINT is still replicated when log_bin is OFF on the originating node

Steps to reproduce

Two-node cluster. node1 has binary logging OFF, node2 has it ON. Every block below was run as a separate client connection (one mariadb -e call each); this matters, see "Conditions".

On node1:

CREATE DATABASE repro;

CREATE TABLE repro.user_tasks (id INT UNSIGNED AUTO_INCREMENT PRIMARY KEY, user_id INT NOT NULL, task_id INT NOT NULL, UNIQUE KEY uq (user_id, task_id)) ENGINE=InnoDB;

On node1, new connection:

START TRANSACTION;

SELECT COUNT(*) FROM repro.user_tasks WHERE user_id=10;

SAVEPOINT trans2;

INSERT INTO repro.user_tasks (user_id, task_id) VALUES (10, 10);

ROLLBACK TO SAVEPOINT trans2;

COMMIT;

On node1, new connection: the same, with 11 instead of 10.

All statements succeed; the SELECT returns 0 both times.

Then:

-- node1

SELECT @@version, GROUP_CONCAT(user_id ORDER BY user_id) AS node1_rows FROM repro.user_tasks;

-- node2

SELECT @@version, GROUP_CONCAT(user_id ORDER BY user_id) AS node2_rows FROM repro.user_tasks;

Actual result

@@version	node1_rows

10.6.23-MariaDB-0ubuntu0.22.04.1	NULL

@@version	node2_rows

10.6.23-MariaDB-0ubuntu0.22.04.1-log	10,11

The rows that node1 rolled back with ROLLBACK TO SAVEPOINT were replicated and committed on node2. The cluster is now inconsistent. No error is returned to the client.

Expected result

No row on either node.

Control

The same two transactions (values 20 and 21, separate connections) run on node2, which has log_bin ON, behave correctly: rows 20 and 21 exist on neither node (node2 still shows only 10,11).

Conditions

The leak happened only when all of these were true:

• log_bin is OFF on the node that runs the transaction (log_bin ON: no leak, see Control);
• it is the first transaction on a new connection (a second, identical transaction on the same connection did not leak);
• a SELECT runs inside the transaction before the SAVEPOINT (same sequence without the SELECT, on new connections: no leak);
• nothing is written before the SAVEPOINT. With an INSERT before the SAVEPOINT (and no SELECT) only the first INSERT was replicated, which is correct. SELECT + write + SAVEPOINT was not tested.

The results were deterministic: every run on every version listed in Affects Version/s gave the same result. Both Galera 26.4.9 and 26.4.22 are affected, and toggling log_bin changes the outcome with the same Galera library, so the problem looks server-side (the trx cache / binlog emulation used when log_bin is OFF), not in the Galera library.

Not tested: 11.8, 12.x. First affected version: unknown.

Configuration

Both nodes:

[mysqld]

binlog_format            = ROW

default_storage_engine   = InnoDB

innodb_autoinc_lock_mode = 2

wsrep_on                 = ON

wsrep_provider           = /usr/lib/galera/libgalera_smm.so

wsrep_cluster_name       = repro

wsrep_cluster_address    = gcomm://node1,node2

wsrep_sst_method         = rsync

wsrep_slave_threads      = 4

wsrep_ignore_apply_errors = 7

node1 (log_bin OFF):

[mysqld]

wsrep_node_name = node1

server_id       = 1001

node2 (log_bin ON):

[mysqld]

wsrep_node_name   = node2

server_id         = 1000

log_bin           = mysql-bin

log_slave_updates = ON

Docker Compose for the official image (node1 bootstrapped with --wsrep-new-cluster, node2 joins via SST):

services:

  node1:

    image: mariadb:10.6.28

    hostname: node1

    environment:

      MARIADB_ROOT_PASSWORD: root

    command: ["--wsrep-new-cluster"]

    ports:

      - "127.0.0.1:33061:3306"

    volumes:

      - ./common.cnf:/etc/mysql/conf.d/10-common.cnf:ro

      - ./node1.cnf:/etc/mysql/conf.d/20-node.cnf:ro

    healthcheck:

      test: ["CMD", "mariadb", "-uroot", "-proot", "-e", "SHOW STATUS LIKE 'wsrep_ready'"]

      interval: 3s

      retries: 40

  node2:

    image: mariadb:10.6.28

    hostname: node2

    environment:

      MARIADB_ROOT_PASSWORD: root

    ports:

      - "127.0.0.1:33062:3306"

    depends_on:

      node1:

        condition: service_healthy

    volumes:

      - ./common.cnf:/etc/mysql/conf.d/10-common.cnf:ro

      - ./node2.cnf:/etc/mysql/conf.d/20-node.cnf:ro

How we hit it in production

Laravel's Model::updateOrCreate() runs a SELECT and, when the row is missing, does the INSERT inside a savepoint because the caller had already opened a transaction. A model observer then threw an exception after the INSERT, Laravel issued ROLLBACK TO SAVEPOINT, the application caught the exception and the outer transaction committed. PHP uses a new connection per request, so the first-transaction condition always holds.

The writer node (log_bin OFF) did not have the rows; the other nodes (log_bin ON) did. When the application later inserted the same unique key again, the other nodes failed with error 1062 and inconsistency voting removed a healthy node from the cluster.

Workaround: enable log_bin on the originating node. We confirmed on production that the sequence above no longer leaks after doing so.

Related

MDEV-22021 and MDEV-32549 are both savepoint rollbacks that made a Galera cluster inconsistent, and both are fixed (MDEV-32549 needs a storage engine without savepoint support; this case is plain InnoDB). I searched MDEV (component Galera, text "savepoint") and found no open issue that matches.