Description
Data inconsistency is observed when two golang program are concurrently writing to the same DB tables through different MariaDB instances. The MariaDB instances are clustered using Galera.
The test database looks like as follows:
CREATE TABLE `Inc` (
`Id` int(11) NOT NULL,
`Cnt` int(11) NOT NULL DEFAULT 0,
PRIMARY KEY (`Id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
CREATE TABLE `Role` (
`Name` varchar(64) COLLATE utf8_unicode_ci DEFAULT NULL
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;
INSERT INTO `Inc` (`Id`, `Cnt`) VALUES ('1', 0);
The golang program is running 10 goroutines, each does the following DB operations:
SET TRANSACTION ISOLATION LEVEL SERIALIZABLE;
START TRANSACTION;
SELECT `Cnt` FROM `Inc` WHERE `Id`=1 FOR UPDATE;
INSERT INTO `Role` (`Name`) VALUES(<some string unique to this transaction>);
UPDATE `Inc` SET `Cnt`=<previous select result + 1> WHERE `Id`=1 and `Cnt`=<previous select result>;
COMMIT;
Simply put, the golang program reads Inc.Cnt, inserts a unique row to Role, and then increases Inc.Cnt by one. When the program completes, Inc.Cnt should be identical to the number of rows in Role:
mysql> START TRANSACTION; SELECT `Cnt` FROM `Inc`; SELECT COUNT(*) FROM `Role`; COMMIT;
Query OK, 0 rows affected (0.27 sec)
+------+
| Cnt |
+------+
| 30 |
+------+
1 row in set (0.27 sec)
+----------+
| count(*) |
+----------+
| 30 |
+----------+
1 row in set (0.27 sec)
Query OK, 0 rows affected (0.27 sec)
But if two programs concurrently run against two different MariaDB instances, Inc.Cnt becomes snaller than the number of rows in Role. Stranger still, sometimes the update statement returns no changed row, as if the current transaction is not isolated from other transaction. Furthermore, even if I make the program rollback when the 0 changed row is returned, the row inserted in the same transaction still remains.
I first suspected that this is because multi-master Galera does not support SERIALIZABLE isolation level. It does supports SNAPSHOT transaction isolation level, which checks transaction conflict at commit time. With this optimistic approach, it's understandable that the concurrent writes lead to many deadlock. But I still think data consistency should not break even at SNAPSHOT isolation level.
Is this an expected behaviour of Galera cluster or some mistake in Galera configuration? Or a miss in using go-sql-driver/mysql or any known limitation/bug? I didn't see the above anomaly when the number of goroutines is one.
Any suggestion will be appreciated.
Environment
- Golang version: go1.13.5 linux/amd64
- MySQl library:
go-sql-driver/mysqlv1.5.0 - MariaDB docker image: mariadb:10.4.13
- Num of goroutines per program: 10 (when set to 1, no inconsistency happens)
MariaDB configuration
[mysqld]
user = mysql
server_id = 11 # unique to this node in the Galera cluster
port = 13306
collation-server = utf8_unicode_ci
character-set-server = utf8
skip-character-set-client-handshake
skip_name_resolve = ON
default_storage_engine = InnoDB
binlog_format = ROW
log_bin = /var/log/mysql/mysql-bin.log
relay_log = /var/log/mysql/mysql-relay-bin.log
log_slave_updates = on
innodb_flush_log_at_trx_commit = 0
innodb_flush_method = O_DIRECT
innodb_file_per_table = 1
innodb_autoinc_lock_mode = 2
innodb_lock_schedule_algorithm = FCFS # MariaDB >10.1.19 and >10.2.3 only
innodb_rollback_on_timeout = 1
innodb_print_all_deadlocks = ON
bind-address = 0.0.0.0
wsrep_on = ON
wsrep_provider = /usr/lib/libgalera_smm.so
wsrep_sst_method = mariabackup
wsrep_gtid_mode = ON
wsrep_gtid_domain_id = 9999
wsrep_cluster_name = mycluster
wsrep_cluster_address = gcomm://172.24.50.27:14567,172.24.52.27:14567,172.24.54.27:14567 # all three MariaDB instances that constitute this Galera cluster
wsrep_sst_auth = repl:secret
wsrep_node_address = 172.24.50.27:14567
wsrep_provider_options = "ist.recv_addr=172.24.50.27:14568;socket.ssl_cert=/etc/mysql/certificates/maria-server-cert.pem;socket.ssl_key=/etc/mysql/certificates/maria-server-key.pem;socket.ssl_ca=/etc/mysql/certificates/maria-ca.pem"
wsrep_sst_receive_address = 172.24.50.27:14444
wsrep_log_conflicts = ON
gtid_domain_id = 9011 # unique to this node in the Galera cluster
ssl_cert = /etc/mysql/certificates/maria-server-cert.pem
ssl_key = /etc/mysql/certificates/maria-server-key.pem
ssl_ca = /etc/mysql/certificates/maria-ca.pem
# File Key Management
plugin_load_add = file_key_management
file_key_management_filename = /etc/mysql/encryption/keyfile.enc
file_key_management_filekey = FILE:/etc/mysql/encryption/keyfile.key
file_key_management_encryption_algorithm = AES_CTR
# Enables table encryption, but allows unencrypted tables to be created
innodb_encrypt_tables = OFF
# Encrypt the Redo Log
innodb_encrypt_log = ON
# Binary Log Encryption
encrypt_binlog=ON
Golang writer
package main
import (
"context"
"database/sql"
"fmt"
"github.com/go-sql-driver/mysql"
_ "github.com/go-sql-driver/mysql"
"os"
"strconv"
"sync"
)
func task(ctx context.Context, prefix string, num int, c *sql.Conn) error {
_, err := c.ExecContext(ctx, "SET SESSION wsrep_sync_wait=15")
if err != nil {
return err
}
tx, err := c.BeginTx(ctx, &sql.TxOptions{Isolation: sql.LevelSerializable})
if err != nil {
return err
}
var count int
incRes, err := tx.Query("SELECT Cnt FROM Inc WHERE Id=? FOR UPDATE", 1)
if err != nil {
tx.Rollback()
return err
}
defer incRes.Close()
for incRes.Next() {
err := incRes.Scan(&count)
if err != nil {
tx.Rollback()
return err
}
}
res, err := tx.ExecContext(ctx, "INSERT INTO Role (Name) VALUES (?)", fmt.Sprintf("%s-%03d", prefix, num))
if err != nil {
tx.Rollback()
return err
}
affected, err := res.RowsAffected()
if err != nil {
tx.Rollback()
return err
}
if affected != 1 {
tx.Rollback()
return fmt.Errorf("inconsistency: inserted row is %d", affected)
}
res, err = tx.ExecContext(ctx, "UPDATE Inc SET Cnt = ? WHERE Id=? AND Cnt=?", count+1, 1, count)
if err != nil {
tx.Rollback()
return err
}
affected, err = res.RowsAffected()
if err != nil {
tx.Rollback()
return err
}
if affected != 1 {
tx.Rollback()
return fmt.Errorf("inconsistency: inserted row is %d", affected)
}
err = tx.Commit()
if err != nil {
tx.Rollback()
return err
}
return nil
}
func main() {
if len(os.Args) != 5 {
fmt.Println("Usage: %s <db host> <db port> <count>")
return
}
host := os.Args[1]
port, err := strconv.Atoi(os.Args[2])
if err != nil {
panic(err)
}
count, err := strconv.Atoi(os.Args[3])
if err != nil {
panic(err)
}
prefix := os.Args[4]
db := "test"
user := "root"
pwd := "secret"
parallelism := 10
driver := "mysql"
connstr := fmt.Sprintf("%s:%s@tcp(%s:%d)/%s", user, pwd, host, port, db)
dbconn, err := sql.Open(driver, connstr)
if err != nil {
panic(err)
}
defer dbconn.Close()
wg := sync.WaitGroup{}
for thread := 0; thread <parallelism ; thread++ {
wg.Add(1)
go func(thread int) {
ctx := context.Background()
defer wg.Done()
for i := 0; i<count; i++ {
conn, err := dbconn.Conn(ctx)
if err != nil {
fmt.Println(err)
}
err = task(ctx, fmt.Sprintf("%s-%d", prefix, thread), i, conn)
if err != nil {
fmt.Printf("error for %s-%d-%d: %s\n",prefix, thread, i, err)
_, ok := err.(*mysql.MySQLError)
if !ok {
break
}
}
conn.Close()
}
}(thread)
}
wg.Wait()
}
Run the program
$ go build
$ ./native 172.24.54.27 13306 50 first
EDITED
As suggested, I added session configuration of SET SESSION wsrep_sync_wait=15 before starting transaction. SQL statements are sent as expected when I checked it using wireshark. But that doesn't change the test results.
EDITED 2
After adding option interpolateParams=true from go-sql-driver, now we do not see data inconsistency. That option is necessary to avoid using prepared statement, making each statemet fully specified. We suspect that query interruption of prepared statements is not handled as expected in Galera multi-master situation. The changed code is as follows:
driver := "mysql"
connstr := fmt.Sprintf("%s:%s@tcp(%s:%d)/%s?interpolateParams=true", user, pwd, host, port, db)
It seems that avoiding prepared statement is a work-around. We'd like to know whether it's a limitation of Galera cluster or our misconfiguration/misuse. So this question is not answered yet.
