Dang it… Pacemaker wigged out during pacemaker03:s Btrfs snapshots run. Well, it was probably the cleanup job that clears out old snapshots that did it. Yeah, I know. “Don’t run OLTP workloads on CoW-filesystems”
But I’m running like 30 transactions per second with short bursts of a few hundred per second. CoW works fine. But Pacemaker wigged out for some reason and seems to have fiddled with the GTID:
ov 29 04:01:05.616 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=pacemaker03.svealiden.se/crmd/49, version=0.173.120) Nov 29 04:01:05.619 pacemaker03.svealiden.se pacemaker-controld [1206] (process_lrm_event) info: Result of monitor operation for mariadb_server on pacemaker03.svealiden.se: Cancelled | call=41 key=mariadb_server_monitor_20000 confirmed=true Nov 29 04:01:10.624 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_ping) info: Reporting our current digest to pacemaker01.svealiden.se: bfbe319be87955b6424bb9b041600d5e for 0.173.120 (0x5646a9a5eac0 0) Nov 29 04:01:27.325 pacemaker03.svealiden.se pacemaker-controld [1206] (throttle_check_thresholds) notice: High CPU load detected: 4.050000 Nov 29 04:01:27.325 pacemaker03.svealiden.se pacemaker-controld [1206] (throttle_send_command) info: New throttle mode: high load (was medium) Nov 29 04:01:57.327 pacemaker03.svealiden.se pacemaker-controld [1206] (throttle_check_thresholds) notice: High CPU load detected: 4.060000 Nov 29 04:02:03 mariadb(mariadb_server)[1456545]: INFO: MySQL stopped Nov 29 04:02:03.343 pacemaker03.svealiden.se pacemaker-execd [1203] (log_finished) info: mariadb_server stop (call 44, PID 1456545) exited with status 0 (execution time 57728ms, queue time 0ms) Nov 29 04:02:03.346 pacemaker03.svealiden.se pacemaker-controld [1206] (process_lrm_event) notice: Result of stop operation for mariadb_server on pacemaker03.svealiden.se: ok | rc=0 call=44 key=mariadb_server_stop_0 confirmed=true cib-update=50 Nov 29 04:02:03.346 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/50) Nov 29 04:02:03.351 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: Diff: --- 0.173.120 2 Nov 29 04:02:03.351 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: Diff: +++ 0.173.121 (null) Nov 29 04:02:03.351 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: + /cib: @num_updates=121 Nov 29 04:02:03.351 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: + /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='mariadb_server']/lrm_rsc_op[@id='mariadb_server_last_0']: @transition-magic=0:0;5:3308:0:7c487611-27b4-49ce-b931-c548d64ecc98, @call-id=44, @rc-code=0, @op-status=0, @exec-time=57728 Nov 29 04:02:03.352 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=pacemaker03.svealiden.se/crmd/50, version=0.173.121) Nov 29 04:02:03.890 pacemaker03.svealiden.se pacemaker-controld [1206] (do_lrm_rsc_op) notice: Requesting local execution of start operation for mariadb_server on pacemaker03.svealiden.se | transition_key=16:3308:0:7c487611-27b4-49ce-b931-c548d64ecc98 op_key=mariadb_server_start_0 Nov 29 04:02:03.891 pacemaker03.svealiden.se pacemaker-execd [1203] (log_execute) info: executing - rsc:mariadb_server action:start call_id:45 Nov 29 04:02:03.891 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_request) info: Forwarding cib_modify operation for section status to all (origin=local/crmd/51) Nov 29 04:02:03.893 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: Diff: --- 0.173.121 2 Nov 29 04:02:03.894 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: Diff: +++ 0.173.122 (null) Nov 29 04:02:03.894 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: + /cib: @num_updates=122 Nov 29 04:02:03.894 pacemaker03.svealiden.se pacemaker-based [1201] (cib_perform_op) info: + /cib/status/node_state[@id='3']/lrm[@id='3']/lrm_resources/lrm_resource[@id='mariadb_server']/lrm_rsc_op[@id='mariadb_server_last_0']: @operation_key=mariadb_server_start_0, @operation=start, @transition-key=16:3308:0:7c487611-27b4-49ce-b931-c548d64ecc98, @transition-magic=-1:193;16:3308:0:7c487611-27b4-49ce-b931-c548d64ecc98, @call-id=-1, @rc-code=193, @op-status=-1, @last-rc-change=1638154923, @exec-time=0 Nov 29 04:02:03.894 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_request) info: Completed cib_modify operation for section status: OK (rc=0, origin=pacemaker03.svealiden.se/crmd/51, version=0.173.122) Nov 29 04:02:04 mariadb(mariadb_server)[1456733]: INFO: MySQL is not running Nov 29 04:02:05 mariadb(mariadb_server)[1456733]: INFO: MySQL is not running Nov 29 04:02:08.906 pacemaker03.svealiden.se pacemaker-based [1201] (cib_process_ping) info: Reporting our current digest to pacemaker01.svealiden.se: 506f4f6824d1cd4857592724a902db4b for 0.173.122 (0x5646a9a5eac0 0) Nov 29 04:02:09 mariadb(mariadb_server)[1456733]: INFO: Changing MariaDB configuration to replicate from pacemaker02.svealiden.se. Nov 29 04:02:10 mariadb(mariadb_server)[1456733]: ERROR: MariaDB slave io has failed (1236): Got fatal error 1236 from master when reading data from binary log: 'Error: connecting slave requested to start from GTID 1-3-30418952, which is not in the master's binlog. Since the master's binlog contains GTIDs with higher sequence numbers, it probably means that the slave has diverged due to executing extra erroneous transactions' Nov 29 04:02:10.888 pacemaker03.svealiden.se pacemaker-execd [1203] (log_op_output) notice: mariadb_server_start_0[1456733] error output [ ocf-exit-reason:MariaDB slave io has failed (1236): Got fatal error 1236 from master when reading data from binary log: 'Error: connecting slave requested to start from GTID 1-3-30418952, which is not in the master's binlog. Since the master's binlog contains GTIDs with higher sequence numbers, it probably means that the slave has diverged due to executing extra erroneous transactions' ]
So it seems Pacemaker stopped MariaDB and then started it in a wonky state. Haven’t seen that before. But it’s not the first thing to make me go “Is this setup really solid?”
’cause I ran Galera without a hitch for like a year and half at least. Sure, when quorum is lost you’re in a world of hurt but there are recovery methods that work in artifically generated scenarios worst case scenarios at least: https://deref.se/2019/10/29/percona-xtradb-cluster-again/
I’m thinking of writing my own master-slave runner. It sounds almost as bad as writing your own encryption algorithm but I see benefits in creating something that is written with the sole purpose of dealing with MariaDB master-slave setups. Also something that I can debug. That’s a big plus. Now I’m not quite crazy enough to try to implement my own consistency protocol. Obviously corosync or etcd will have to serve as a coordinator for any code I write. I’ll dive into that part right now so I know if this is even halfway workable.
Addendum:
Okey, so that seemed less than ideal. I think I’m going to go with keepalived. It’s not super-safe but if the slave doesn’t get a heartbeat from the master than it can fence the master and start in master mode. If the master won’t fence the slave(why would I give it that ability? If we’re concerned about the slave assuming the master role while the master is still running, the slave fencing the master “solves” that) then we can avoid mutual killing in case of a glitch. The worst case scenario should be that the slave kills the master unnecessarily.