[MDEV-21189] Dropping partition with 'wsrep_OSU_method=RSU' and 'SESSION sql_log_bin = 0' cases the galera node to hang Created: 2019-12-02  Updated: 2019-12-23  Resolved: 2019-12-23

Status: Closed
Project: MariaDB Server
Component/s: Galera
Affects Version/s: 10.2.27
Fix Version/s: 10.2.31, 10.3.22, 10.4.12

Type: Bug Priority: Blocker
Reporter: Tomas Mozes Assignee: Seppo Jaakola
Resolution: Fixed Votes: 0
Labels: None

Attachments: File galera_partition.cnf     File galera_partition.test     File mysqld.err     Text File stack.txt     File table.sql    

 Description   

Suppose there is a 3 node mariadb galera cluster and an async replicated node connected to it. The galera cluster has a partitioned table that you wish to keep only for a few weeks, while the slave has several months of data in it. Once in a while you have to drop the partitions in the galera cluster without affecting the async slave.

On the load-balancer (haproxy): disable traffic to galera1 node.

galera1 node)
SET GLOBAL wsrep_OSU_method='RSU';
SET SESSION sql_log_bin = 0;

ALTER TABLE db.table DROP PARTITION 201909;
ALTER TABLE db.table DROP PARTITION 201910;
ALTER TABLE db.table DROP PARTITION 201911;

And so on for all galera nodes. This way the galera nodes will have the 201909-201911 partitions dropped, while the slave will have the table as before.

In some cases the DROP PARTITION statement causes the mariadb process to hang, the operation doesn't end and a new connection cannot be made to the server. Server version 10.2.27. There is nothing in the error log.

Galera nodes have the following configuration:
ignore_db_dirs = lost+found
innodb_buffer_pool_size = 120G
innodb_flush_log_at_trx_commit = 1
max_allowed_packet = 60M
table_open_cache = 800

wsrep_on=ON
binlog_format=ROW
default_storage_engine=innodb
innodb_autoinc_lock_mode=2
query_cache_size=0
wsrep_provider=/usr/lib64/galera/libgalera_smm.so
wsrep_provider_options="gcache.size=20G; gcache.page_size=20G; gcs.fc_limit=256; gcs.fc_factor=0.99; gcs.fc_master_slave=YES"
wsrep-node-name=node1
wsrep_node_address=1.1.1.1
wsrep_cluster_name=cluster
wsrep_cluster_address="gcomm://1.1.1.1,1.1.1.2,1.1.1.3"
wsrep_sst_method=mariabackup
wsrep_sst_auth=user:pass
wsrep_slave_threads=24

binlog_checksum = CRC32
innodb_checksum_algorithm = crc32
innodb_strict_mode = 0
log_slave_updates = 1
master_verify_checksum = 1
max_connect_errors = 500
max_connections = 1500
max_heap_table_size = 1G
slave_parallel_threads = 20
slave_sql_verify_checksum = 1
sql_mode = "NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"
sync_binlog = 1
tmp_table_size = 1G

This also happened in version 10.1, but it does not happen all the time. If it happens, only sending kill -9 to mariadb works to stop it.

 Comments   
Comment by Jan Lindström (Inactive) [ 2019-12-03 ]

Can you share output for show create table for the problematic table and error log for at least one node?

Comment by Tomas Mozes [ 2019-12-03 ]

Please find attached the table definition and the log from db3b (donor for the broken node db3a)

2019-12-02 9:53:34: tried dropping partitions from db3a (with GLOBAL wsrep_OSU_method='RSU' and SESSION sql_log_bin = 0)
2019-12-02 9:56:04: killed db3a, restarted, then the log of db3a was full of corruption
2019-12-02 10:00:16: tried setting innodb_force_recovery = 1 on db3a, but it resulted in sst from db3b
2019-12-02 10:02:18: set innodb_force_recovery to default and restarted sst
2019-12-02 12:48:18: node db3a rebuilt from db3b and the cluster is running

Comment by Tomas Mozes [ 2019-12-03 ]

Seems like a long running process was still running against this database and was writing to the mentioned table.

Comment by Tomas Mozes [ 2019-12-03 ]

Steps to reproduce in testing environment (mariadb 10.2.29 with galera 25.3.28):

  • create 3 node galera cluster
  • create partitioned table
  • start inserting values into the partitioned table on all 3 nodes
  • on one node: 

    mysql -e "SET GLOBAL wsrep_OSU_method='RSU';"
    		 
     
    		 
    mysql << EOF
    		 
    SET SESSION sql_log_bin = 0;
    		 
    ALTER TABLE ... DROP PARTITION p1;
    		 
    ALTER TABLE ... DROP PARTITION p2;
    		 
    ...
    		 
    EOF

The node is blocked, cannot connect to it. The log contains:

Version: '10.2.29-MariaDB-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Source distribution
 
2019-12-03 11:17:14 140493673453312 [Note] WSREP: Member 2.0 (db1) desyncs itself from group
 
2019-12-03 11:17:14 140493673453312 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 24399)

After doing $(pkill -f mysqld) the process doesn't terminate:

2019-12-03 11:18:45 140491805148928 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: Stop replication
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: Closing send monitor...
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: Closed send monitor.
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: gcomm: terminating thread
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: gcomm: joining thread
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: gcomm: closing backend
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: view(view_id(NON_PRIM,c273650c,34) memb {
 
        e7d203f4,0
 
} joined {
 
} left {
 
} partitioned {
 
        c273650c,0
 
        c6e12b07,0
 
})
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: view((empty))
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: gcomm: closed
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Flow-control interval: [253, 256]
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Trying to continue unpaused monitor
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Received NON-PRIMARY.
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Shifting DONOR/DESYNCED -> OPEN (TO: 27057)
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Received self-leave message.
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Flow-control interval: [253, 256]
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Trying to continue unpaused monitor
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Received SELF-LEAVE. Closing connection.
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 27057)
 
2019-12-03 11:18:45 140493673453312 [Note] WSREP: RECV thread exiting 0: Success
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: recv_thread() joined.
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: Closing replication queue.
 
2019-12-03 11:18:45 140491805148928 [Note] WSREP: Closing slave action queue.
 
2019-12-03 11:18:45 140493214394112 [Note] WSREP: New cluster view: global state: 4e1e2015-159b-11ea-b35e-db1f5efdc259:27057, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3
 
2019-12-03 11:18:45 140493214394112 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
2019-12-03 11:18:45 140493214394112 [Note] WSREP: New cluster view: global state: 4e1e2015-159b-11ea-b35e-db1f5efdc259:27057, view# -1: non-Primary, number of nodes: 0, my index: -1, protocol version 3
 
2019-12-03 11:18:45 140493214394112 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
2019-12-03 11:18:45 140493214394112 [Note] WSREP: applier thread exiting (code:0)
 
2019-12-03 11:18:45 140493215930112 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493214701312 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493216237312 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493214086912 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140491807299328 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140491807606528 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493213165312 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493217466112 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493215622912 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493216851712 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493212550912 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140491807913728 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493213779712 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493215008512 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493215315712 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493216544512 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140491808220928 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493217773312 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493665060608 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493217158912 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493212858112 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493615163136 [Note] WSREP: applier thread exiting (code:6)
 
2019-12-03 11:18:45 140493213472512 [Note] WSREP: applier thread exiting (code:6)

Sending signal 9 means the tables are corrupted and mariadb cannot start and a full sst is probably needed.

Comment by Tomas Mozes [ 2019-12-03 ]

Just tested with mariadb 10.4.10 and galera 26.4.3. The ALTER is blocked, but at least a new session can be opened and the query terminated. This is in the processlist:

| 120 | root        | localhost | NULL | Query   |   64 | Waiting for table metadata lock | ALTER TABLE db.tbl DROP PARTITION p1                        |    0.000 |
 
| 121 | root        | localhost | NULL | Query  |   64 | Commit                          | INSERT INTO db.tbl VALUES (55205965,'d9c790ed-a1fa-475b-9755-fe7b02961c1f |    0.000 |

The ALTER won't run and the mysqld process cannot be stopped normally. The error log after trying to shutdown the server:

2019-12-03 12:11:31 0 [Note] /usr/sbin/mysqld (initiated by: unknown): Normal shutdown
 
2019-12-03 12:11:31 0 [Note] WSREP: Shutdown replication
 
2019-12-03 12:11:31 0 [Note] WSREP: Server status change synced -> disconnecting
 
2019-12-03 12:11:31 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
2019-12-03 12:11:31 0 [Note] WSREP: Closing send monitor...
 
2019-12-03 12:11:31 0 [Note] WSREP: Closed send monitor.
 
2019-12-03 12:11:31 0 [Note] WSREP: gcomm: terminating thread
 
2019-12-03 12:11:31 0 [Note] WSREP: gcomm: joining thread
 
2019-12-03 12:11:31 204 [ERROR] WSREP: Node desync failed.: 77 (File descriptor in bad state)
 
         at galera/src/replicator_smm.cpp:desync():2986
 
2019-12-03 12:11:31 204 [Warning] WSREP: Failed to desync server
 
2019-12-03 12:11:31 204 [Warning] WSREP: RSU begin failed
 
2019-12-03 12:11:31 0 [Note] WSREP: gcomm: closing backend
 
2019-12-03 12:11:31 0 [Note] WSREP: view(view_id(NON_PRIM,1655e047,5) memb {
 
        1655e047,0
 
} joined {
 
} left {
 
} partitioned {
 
        3fa269cc,0
 
        4db6c1fa,0
 
})
 
2019-12-03 12:11:31 0 [Note] WSREP: PC protocol downgrade 1 -> 0
 
2019-12-03 12:11:31 0 [Note] WSREP: view((empty))
 
2019-12-03 12:11:31 0 [Note] WSREP: gcomm: closed
 
2019-12-03 12:11:31 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
2019-12-03 12:11:31 0 [Note] WSREP: Flow-control interval: [253, 256]
 
2019-12-03 12:11:31 0 [Note] WSREP: Received NON-PRIMARY.
 
2019-12-03 12:11:31 0 [Note] WSREP: Shifting JOINED -> OPEN (TO: 3024)
 
2019-12-03 12:11:31 0 [Note] WSREP: New SELF-LEAVE.
 
2019-12-03 12:11:31 0 [Note] WSREP: Flow-control interval: [253, 256]
 
2019-12-03 12:11:31 0 [Note] WSREP: Received SELF-LEAVE. Closing connection.
 
2019-12-03 12:11:31 0 [Note] WSREP: Shifting OPEN -> CLOSED (TO: -1)
 
2019-12-03 12:11:31 0 [Note] WSREP: RECV thread exiting 0: Success
 
2019-12-03 12:11:31 0 [Note] WSREP: recv_thread() joined.
 
2019-12-03 12:11:31 0 [Note] WSREP: Closing replication queue.
 
2019-12-03 12:11:31 0 [Note] WSREP: Closing slave action queue.

Comment by Jan Lindström (Inactive) [ 2019-12-03 ]

I can't immediately repeat your problem, one thing I noticed that SET GLOBAL wsrep_OSU_method='RSU'; is not effective it does use TOI instead, I must use SET SESSION wsrep_OSU_method='RSU'; to do it on RSU (see my attached test case). Did you check you really used RSU ?

Comment by Tomas Mozes [ 2019-12-04 ]

If I understand the test scenario correctly, it creates the table on node1, populates the data and then drops the partitions, while the second node only drops the partitions. This scenario is different from what causes the issue.

How to trigger the hang on node1:
1) init galera cluster
2) create table on node1 (actually it doesn't matter where it's created)
3) keep inserting data to the table on node1 and node2 (both simultaneously)
4) while still inserting data on both nodes, switch the wsrep_OSU_method and sql_log_bin and DROP partitions on node1

It's important that the node on which I'm dropping the partitions and one other node is inserting data into the table in parallel while dropping the partitions.

As seen below it's really RSU because it's called in other session before setting the session variable sql_log_bin with dropping the partitions:

+ mysql -e 'show variables like '\''wsrep_OSU_method'\'';'
 
+------------------+-------+
 
| Variable_name    | Value |
 
+------------------+-------+
 
| wsrep_osu_method | TOI   |
 
+------------------+-------+
 
+ mysql -e 'SET GLOBAL wsrep_OSU_method='\''RSU'\'';'
 
+ mysql -e 'show variables like '\''wsrep_OSU_method'\'';'
 
+------------------+-------+
 
| Variable_name    | Value |
 
+------------------+-------+
 
| wsrep_osu_method | RSU   |
 
+------------------+-------+
 
+ mysql -e 'show processlist'
 
+-----+-------------+-----------+------+---------+------+--------------------------+------------------------------------------------------------------------------------------------------+----------+
 
| Id  | User        | Host      | db   | Command | Time | State                    | Info                                                                                                 | Progress |
 
+-----+-------------+-----------+------+---------+------+--------------------------+------------------------------------------------------------------------------------------------------+----------+
 
|   1 | system user |           | NULL | Sleep   |  311 | wsrep aborter idle       | NULL                                                                                                 |    0.000 |
 
|   2 | system user |           | NULL | Sleep   |    0 | committed 1048           | NULL                                                                                                 |    0.000 |
 
|   3 | system user |           | NULL | Daemon  | NULL | InnoDB purge worker      | NULL                                                                                                 |    0.000 |
 
|   5 | system user |           | NULL | Daemon  | NULL | InnoDB purge worker      | NULL                                                                                                 |    0.000 |
 
|   4 | system user |           | NULL | Daemon  | NULL | InnoDB purge coordinator | NULL                                                                                                 |    0.000 |
 
|   6 | system user |           | NULL | Daemon  | NULL | InnoDB purge worker      | NULL                                                                                                 |    0.000 |
 
|   7 | system user |           | NULL | Daemon  | NULL | InnoDB shutdown handler  | NULL                                                                                                 |    0.000 |
 
|  10 | system user |           | NULL | Sleep   |    1 | committed 1041           | NULL                                                                                                 |    0.000 |
 
|  12 | system user |           | NULL | Sleep   |    0 | committed 1049           | NULL                                                                                                 |    0.000 |
 
|  15 | system user |           | NULL | Sleep   |    0 | committed 1044           | NULL                                                                                                 |    0.000 |
 
|  13 | system user |           | NULL | Sleep   |    1 | committed 1029           | NULL                                                                                                 |    0.000 |
 
|   9 | system user |           | NULL | Sleep   |    0 | committing 1051          | NULL                                                                                                 |    0.000 |
 
|  11 | system user |           | NULL | Sleep   |    0 | applied write set 1055   | NULL                                                                                                 |    0.000 |
 
|  18 | system user |           | NULL | Sleep   |    0 | committed 1043           | NULL                                                                                                 |    0.000 |
 
|  28 | system user |           | NULL | Sleep   |    1 | committed 1031           | NULL                                                                                                 |    0.000 |
 
|  17 | system user |           | NULL | Sleep   |    0 | committed 1045           | NULL                                                                                                 |    0.000 |
 
|  30 | system user |           | NULL | Sleep   |    0 | applied write set 1053   | NULL                                                                                                 |    0.000 |
 
|  31 | system user |           | NULL | Sleep   |    1 | committed 1033           | NULL                                                                                                 |    0.000 |
 
|  22 | system user |           | NULL | Sleep   |    1 | committed 1037           | NULL                                                                                                 |    0.000 |
 
|  23 | system user |           | NULL | Sleep   |    0 | committed 1046           | NULL                                                                                                 |    0.000 |
 
|  19 | system user |           | NULL | Sleep   |    1 | committed 1042           | NULL                                                                                                 |    0.000 |
 
|  25 | system user |           | NULL | Sleep   |    1 | committed 1035           | NULL                                                                                                 |    0.000 |
 
|  16 | system user |           | NULL | Sleep   |    1 | committed 1027           | NULL                                                                                                 |    0.000 |
 
|  14 | system user |           | NULL | Sleep   |    0 | applied write set 1057   | NULL                                                                                                 |    0.000 |
 
|  27 | system user |           | NULL | Sleep   |    3 | committed 984            | NULL                                                                                                 |    0.000 |
 
|  24 | system user |           | NULL | Sleep   |    3 | committed 982            | NULL                                                                                                 |    0.000 |
 
|  20 | system user |           | NULL | Sleep   |    0 | applied write set 1052   | NULL                                                                                                 |    0.000 |
 
|  21 | system user |           | NULL | Sleep   |    1 | committed 1039           | NULL                                                                                                 |    0.000 |
 
|  26 | system user |           | NULL | Sleep   |    0 | applied write set 1054   | NULL                                                                                                 |    0.000 |
 
|  29 | system user |           | NULL | Sleep   |    0 | committed 1050           | NULL                                                                                                 |    0.000 |
 
| 565 | root        | localhost | NULL | Query   |    0 | query end                | INSERT INTO db.table VALUES (12867503,'d9c790ed-a1fa-475b-9755-fe7b02961c1f                          |    0.000 |
 
| 569 | root        | localhost | NULL | Query   |    0 | init                     | show processlist                                                                                     |    0.000 |
 
+-----+-------------+-----------+------+---------+------+--------------------------+------------------------------------------------------------------------------------------------------+----------+
 
+ mysql
 
SET SESSION sql_log_bin = 0;
 
show variables like 'sql_log_bin';
 
Variable_name   Value
 
sql_log_bin     OFF
 
DROP PARTITION ...
 
<HANG>

If you set a global variable and check it, it will show the old value as seen below (you then close the session and open a new one and it's changed):

# mysql
 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
 
Your MariaDB connection id is 842
 
Server version: 10.2.29-MariaDB-log Source distribution
 
 
 
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)]> show variables like '%OSU%';
 
+------------------+-------+
 
| Variable_name    | Value |
 
+------------------+-------+
 
| wsrep_osu_method | TOI   |
 
+------------------+-------+
 
1 row in set (0.00 sec)
 
 
 
MariaDB [(none)]> SET GLOBAL wsrep_OSU_method='RSU';
 
Query OK, 0 rows affected (0.00 sec)
 
 
 
MariaDB [(none)]> show variables like '%OSU%';
 
+------------------+-------+
 
| Variable_name    | Value |
 
+------------------+-------+
 
| wsrep_osu_method | TOI   |
 
+------------------+-------+
 
1 row in set (0.00 sec)
 
 
 
MariaDB [(none)]> ^CCtrl-C -- exit!
 
Aborted
 
 
 
# mysql
 
Welcome to the MariaDB monitor.  Commands end with ; or \g.
 
Your MariaDB connection id is 843
 
Server version: 10.2.29-MariaDB-log Source distribution
 
 
 
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)]> show variables like '%OSU%';
 
+------------------+-------+
 
| Variable_name    | Value |
 
+------------------+-------+
 
| wsrep_osu_method | RSU   |
 
+------------------+-------+
 
1 row in set (0.00 sec)

Comment by Tomas Mozes [ 2019-12-04 ]

https://mariadb.com/kb/en/library/set/

A global variable change affects all new sessions. It does *not* affect any currently open sessions, including the one that made the change.

Comment by Jan Lindström (Inactive) [ 2019-12-04 ]

Is the new data you insert inserted to partitions that are not being dropped ?

Comment by Tomas Mozes [ 2019-12-04 ]

Yes, the data are written to the December partition and I'm dropping the August partitions.

Comment by Jan Lindström (Inactive) [ 2019-12-04 ]

I retry with 4 node cluster, where nodes 2-4 will execute procedure inserting data to partitions not being dropped and node 1 executes alters, then node by node I execute alters on other nodes (see updated attachments). I still can't repeat the hang. If you have a repeatable test case I could try it would help a lot.

Comment by Tomas Mozes [ 2019-12-04 ]

You need to keep inserting data on node1 in the moment you are dropping the partitions (in 2 separate sessions on node1). Can you execute commands in parallel with this testing suite?

I'm running it on 3 separate virtual machines and with 100% success rate in simulating this issue.

Comment by Jan Lindström (Inactive) [ 2019-12-04 ]

In node_2 I do send call p1(1000); and similarly nodes 3 and 4, it should then concurrently run those drop partition -clauses in node_1, but there is not much control on that test case so I can only hope that those inserts and alter really run concurrently.

Comment by Jan Lindström (Inactive) [ 2019-12-04 ]

Can you provide output of show processlist when it starts to hang and show engine innodb status.

Comment by Tomas Mozes [ 2019-12-04 ]

In mariadb 10.2 you cannot open a new session after the hanging alter so I cannot check the processlist nor the innodb engine status In mariadb 10.4 you can check the processlist and even kill the alter (see https://jira.mariadb.org/browse/MDEV-21189?focusedCommentId=139128&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-139128), but you need to kill the mysqld process with signal 9 (meaning corrupted state and new sst needed).

Comment by Tomas Mozes [ 2019-12-04 ]

I see the tests are inserting on nodes2-4, but you need to also insert on node1 and call the alter simultaneously.

Comment by Jan Lindström (Inactive) [ 2019-12-05 ]

After adding inserting on node_1 from second connection I got assertion (note this is debug build) see attachment.

Comment by Tomas Mozes [ 2019-12-05 ]

Cool, I'm glad it's simulated on your side too

Comment by Jan Lindström (Inactive) [ 2019-12-05 ]

I think I found a fix for your issue. However, there is one thing you should remember on Galera 3 ALTER will take metadata lock (MDL) for whole table, this will effectively restrict inserts from other connections and nodes it does not matter if insert are done to other partitions. If ALTER does not get change to continue (i.e. there can't be other active transactions doing something on same table) it will return a error and same could happen to insert transactions.

Comment by Tomas Mozes [ 2019-12-06 ]

What is then the recommended solution for this scenario?

Since I wasn't sure what triggered the error I did the following in a rolling fashion on all 3 nodes (to be sure the DROP will pass and the node won't be crippled):

  • disable traffic to node
  • disable wsrep_on and wsrep_provider
  • restart mariadb (starting standalone)
  • SET SESSION sql_log_bin = 0
  • DROP PARTITION ...
  • enable wsrep_on and wsrep_provider
  • restart mariadb (starting with galara again and doing IST)
  • enable traffic to node

This way the change wasn't propagated to the other nodes and it wasn't written to the binary log either (that's what I wanted).

Comment by Tomas Mozes [ 2019-12-09 ]

Thanks Jan, just tried applying the patch from https://github.com/MariaDB/server/commit/59e14b96847e458909ca7fcf95b144fd6ccdb708.patch to 10.2.29 and it works great.

Comment by Marko Mäkelä [ 2019-12-13 ]

The test reliably times out on 10.4. Here is one of many examples.
http://buildbot.askmonty.org/buildbot/builders/kvm-deb-stretch-amd64/builds/11359/steps/mtr-galera/logs/stdio
I disabled the test on my merge to 10.4. Please fix it.

Comment by Marko Mäkelä [ 2019-12-20 ]

I am raising the priority, because the fix is present in 10.2 and 10.3 branches but not yet in the 10.4 (or 10.5) branch. I think that we should try to include the fix in the next set of releases for all versions.

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