[MXS-4918] Readconnroute router allows starting a transaction which stops replication on slave due to 'Lock wait timeout exceeded; try restarting transaction' error Created: 2024-01-04  Updated: 2024-01-05  Resolved: 2024-01-05

Status: Closed
Project: MariaDB MaxScale
Component/s: N/A
Affects Version/s: 6.4.13, 23.08.4
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Susmeet Khaire Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: CS0692282

Issue Links:
Duplicate
duplicates MXS-4820 Add option for preventing writes with... Open

 Description   

Readconnroute router allows starting a transaction which can cause replication issues on slave due to 'Lock wait timeout exceeded; try restarting transaction' error
Please see below demo.

-- Running two services in maxscale
-- ReadWriteSplitService listening on port 3306
-- Read-Service listening on port 3307
[root@LAPTOP-15531O7Q ~]# maxctrl list services
┌───────────────────────┬────────────────┬─────────────┬───────────────────┬─────────────────────┐
│ Service               │ Router         │ Connections │ Total Connections │ Targets             │
├───────────────────────┼────────────────┼─────────────┼───────────────────┼─────────────────────┤
│ ReadWriteSplitService │ readwritesplit │ 00                 │ node1, node2, node3 │
├───────────────────────┼────────────────┼─────────────┼───────────────────┼─────────────────────┤
│ Read-Service          │ readconnroute  │ 00                 │ node2, node3        │
└───────────────────────┴────────────────┴─────────────┴───────────────────┴─────────────────────┘
 
 
 
-- Running SELECT... LOCK IN SHARE MODE in a transaction and not committing it via 3307 Read-only port
[root@localhost ~]# mysql -h192.168.20.26 -usbtest -pTest@123 -P3307
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 1
Server version: 10.6.12-8-MariaDB-enterprise-log MariaDB Enterprise Server
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [(none)]> BEGIN;
Query OK, 0 rows affected (0.004 sec)
MariaDB [(none)]> use test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A
 
Database changed
MariaDB [test]> SELECT * FROM job_locks WHERE name = 'AUDIT_LOG' LOCK IN SHARE MODE;
+-----------+---------------------+
| name      | timestamp           |
+-----------+---------------------+
| AUDIT_LOG | 2024-01-02 17:51:54 |
+-----------+---------------------+
1 row in set (0.002 sec)
 
MariaDB [test]> SELECT @@hostname;
+---------------+
| @@hostname    |
+---------------+
| mariadb-slave |
+---------------+
1 row in set (0.005 sec)
 
 
 
 
-- Running an UPDATE query on 3306 port READWRITE port
[root@localhost ~]# mysql -h192.168.20.26 -usbtest -pTest@123 -A test
Welcome to the MariaDB monitor.  Commands end with ; or \g.
Your MariaDB connection id is 2
Server version: 10.6.12-8-MariaDB-enterprise-log MariaDB Enterprise Server
 
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
 
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
 
MariaDB [test]> UPDATE job_locks SET timestamp = '2024-01-02 19:00:00'  WHERE name = 'AUDIT_LOG' ;
Query OK, 1 row affected (0.013 sec)
Rows matched: 1  Changed: 1  Warnings: 0
 
 
 
 
 
-- Slave status on the slave
MariaDB [(none)]> SHOW SLAVE STATUS\G
*************************** 1. row ***************************
                Slave_IO_State: Waiting for master to send event
                   Master_Host: 192.168.20.19
                   Master_User: repl
                   Master_Port: 3306
                 Connect_Retry: 60
               Master_Log_File: mariadb-master-bin.000002
           Read_Master_Log_Pos: 571
                Relay_Log_File: mariadb-slave-relay-bin.000006
                 Relay_Log_Pos: 659
         Relay_Master_Log_File: mariadb-master-bin.000002
              Slave_IO_Running: Yes
             Slave_SQL_Running: No
               Replicate_Do_DB:
           Replicate_Ignore_DB:
            Replicate_Do_Table:
        Replicate_Ignore_Table:
       Replicate_Wild_Do_Table:
   Replicate_Wild_Ignore_Table:
                    Last_Errno: 1205
                    Last_Error: Lock wait timeout exceeded; try restarting transaction
                  Skip_Counter: 0
           Exec_Master_Log_Pos: 351
               Relay_Log_Space: 1504
               Until_Condition: None
                Until_Log_File:
                 Until_Log_Pos: 0
            Master_SSL_Allowed: No
            Master_SSL_CA_File:
            Master_SSL_CA_Path:
               Master_SSL_Cert:
             Master_SSL_Cipher:
                Master_SSL_Key:
         Seconds_Behind_Master: NULL
 Master_SSL_Verify_Server_Cert: No
                 Last_IO_Errno: 0
                 Last_IO_Error:
                Last_SQL_Errno: 1205
                Last_SQL_Error: Lock wait timeout exceeded; try restarting transaction
   Replicate_Ignore_Server_Ids:
              Master_Server_Id: 100
                Master_SSL_Crl:
            Master_SSL_Crlpath:
                    Using_Gtid: No
                   Gtid_IO_Pos:
       Replicate_Do_Domain_Ids:
   Replicate_Ignore_Domain_Ids:
                 Parallel_Mode: optimistic
                     SQL_Delay: 0
           SQL_Remaining_Delay: NULL
       Slave_SQL_Running_State:
              Slave_DDL_Groups: 0
Slave_Non_Transactional_Groups: 0
    Slave_Transactional_Groups: 11
1 row in set (0.000 sec)
 
 
 
MariaDB [(none)]> SELECT straight_join w.trx_mysql_thread_id waiting_thread, w.trx_id waiting_trx_id, w.trx_query waiting_query, b.trx_mysql_thread_id blocking_thread, b.trx_id blocking_trx_id, b.trx_query blocking_query, bl.lock_id blocking_lock_id, bl.lock_mode blocking_lock_mode, bl.lock_type blocking_lock_type, bl.lock_table blocking_lock_table, bl.lock_index blocking_lock_index, wl.lock_id waiting_lock_id, wl.lock_mode waiting_lock_mode, wl.lock_type waiting_lock_type, wl.lock_table waiting_lock_table, wl.lock_index waiting_lock_index FROM information_schema.INNODB_LOCK_WAITS ilw , information_schema.INNODB_TRX b , information_schema.INNODB_TRX w , information_schema.INNODB_LOCKS bl , information_schema.INNODB_LOCKS wl WHERE b.trx_id = ilw.blocking_trx_id AND w.trx_id = ilw.requesting_trx_id AND bl.lock_id = ilw.blocking_lock_id AND wl.lock_id = ilw.requested_lock_id\G
*************************** 1. row ***************************
     waiting_thread: 6
     waiting_trx_id: 136
      waiting_query: UPDATE job_locks SET timestamp = '2024-01-02 19:00:00'  WHERE name = 'AUDIT_LOG'
    blocking_thread: 14
    blocking_trx_id: 0
     blocking_query: NULL
   blocking_lock_id: 0:11:3:2
 blocking_lock_mode: S
 blocking_lock_type: RECORD
blocking_lock_table: `test`.`job_locks`
blocking_lock_index: PRIMARY
    waiting_lock_id: 136:11:3:2
  waiting_lock_mode: X
  waiting_lock_type: RECORD
 waiting_lock_table: `test`.`job_locks`
 waiting_lock_index: PRIMARY
1 row in set (0.000 sec)

I think Readconnroute should NOT allow starting transactions as it is supposed to be a read-only service.



 Comments   
Comment by markus makela [ 2024-01-05 ]

This is by design and it's also documented over here: https://mariadb.com/kb/en/mariadb-maxscale-2308-readconnroute/#overview

However, a separate mode where this is prevented does make sense and there's an open feature request for it (MXS-4820). Since this is expected and documented behavior, I'll close this as a duplicate of MXS-4820.

Generated at Thu Feb 08 04:32:05 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.