-
Type:
Problem report
-
Resolution: Commercial support required
-
Priority:
Critical
-
None
-
Affects Version/s: 4.0.4
-
Component/s: Server (S)
-
None
-
Environment:Zabbix 4.0.1, MariaDB 10.1.31 and Galera 25.3.18
I´m getting the error message below on the MaraiDB log:
======================
[ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table zabbix.problem; Can't find record in 'problem', Error_code: 1032; ha
ndler error HA_ERR_KEY_NOT_FOUND; the event's master log FIRST, end_log_pos 504698, Internal MariaDB error code: 1032
=====================
This started to happen afew days ago and after that the DB nodes stop.
I have 3 nodes. One is the master and the other 2 nodes are slaves. Only the master receives SQL operations (insert, update, delete, select ...) from Zabbix Server.
The size of the database is about 1.2 TB.
Recently this problem started to happen. The 2 slave nodes try to execute "Delete_rows_v1" operation in the zabbix.problem table and as, they didn´t manage, they goes down. The master becomes no-primary and Zabbix stops.
Very serious problem.
Does someone have this problem? Any help?
Delete on zabbix.problem table is made by the housekeeper process?
I have partitiong for the histories and trends tables, but not for the events table.
Some more informations:
1) The events table is very big. More than 36 millions of registers.
2) We were having performance problems with the cluster and it was only solved when we disabled totally the swap memory on the servers.
This is the log from one slave node. The other slave node have the same messages at the same time:
======
2019-02-14 16:27:01 139992771357440 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table zabbix.problem; Can't find record in 'problem', Error_code: 1032; ha
ndler error HA_ERR_KEY_NOT_FOUND; the event's master log FIRST, end_log_pos 504698, Internal MariaDB error code: 1032
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: RBR event 63 Delete_rows_v1 apply warning: 120, 1859890715
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: Failed to apply app buffer: seqno: 1859890715, status: 1
2019-02-14 16:27:01 139992771357440 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table zabbix.problem; Can't find record in 'problem', Error_code: 1032; ha
ndler error HA_ERR_KEY_NOT_FOUND; the event's master log FIRST, end_log_pos 504698, Internal MariaDB error code: 1032
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: RBR event 63 Delete_rows_v1 apply warning: 120, 1859890715
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: Failed to apply app buffer: seqno: 1859890715, status: 1
2019-02-14 16:27:01 139992771357440 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table zabbix.problem; Can't find record in 'problem', Error_code: 1032; ha
ndler error HA_ERR_KEY_NOT_FOUND; the event's master log FIRST, end_log_pos 504698, Internal MariaDB error code: 1032
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: RBR event 63 Delete_rows_v1 apply warning: 120, 1859890715
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: Failed to apply app buffer: seqno: 1859890715, status: 1
2019-02-14 16:27:01 139939014506240 [Note] WSREP: declaring b46992ff at tcp://10.30.138.98:4567 stable
2019-02-14 16:27:01 139939014506240 [Note] WSREP: declaring dc780cbe at tcp://10.152.27.200:4567 stable
2019-02-14 16:27:01 139939014506240 [Note] WSREP: forgetting 88813637 (tcp://10.152.28.140:4567)
2019-02-14 16:27:01 139992771357440 [ERROR] Slave SQL: Could not execute Delete_rows_v1 event on table zabbix.problem; Can't find record in 'problem', Error_code: 1032; ha
ndler error HA_ERR_KEY_NOT_FOUND; the event's master log FIRST, end_log_pos 504698, Internal MariaDB error code: 1032
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: RBR event 63 Delete_rows_v1 apply warning: 120, 1859890715
2019-02-14 16:27:01 139992771357440 [ERROR] WSREP: Failed to apply trx: source: b46992ff-dc31-11e8-a16a-fb4e0972de17 version: 3 local: 0 state: APPLYING flags: 1 conn_id:
55934263 trx_id: 11905597584 seqnos (l: 5290198, g: 1859890715, s: 1859890713, d: 1859890695, ts: 9309730685227667)
2019-02-14 16:27:01 139992771357440 [ERROR] WSREP: Failed to apply trx 1859890715 4 times
2019-02-14 16:27:01 139992771357440 [ERROR] WSREP: Node consistency compromised, aborting...
2019-02-14 16:27:01 139992771357440 [Note] WSREP: Closing send monitor...
2019-02-14 16:27:01 139992771357440 [Note] WSREP: Closed send monitor.
2019-02-14 16:27:01 139992771357440 [Note] WSREP: gcomm: terminating thread
2019-02-14 16:27:01 139992771357440 [Note] WSREP: gcomm: joining thread
2019-02-14 16:27:01 139992771357440 [Note] WSREP: gcomm: closing backend
2019-02-14 16:27:01 139992771357440 [Note] WSREP: Node a4d90112 state prim
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: user message in state LEAVING
2019-02-14 16:27:01 139992771357440 [Warning] WSREP: a4d90112 sending install message failed: Transport endpoint is not connected
2019-02-14 16:27:01 139992771357440 [Note] WSREP: view(view_id(NON_PRIM,a4d90112,144) memb {
2019-02-14 16:27:01 139992771357440 [Note] WSREP: view((empty))
2019-02-14 16:27:01 139992771357440 [Note] WSREP: gcomm: closed
2019-02-14 16:27:01 139939006113536 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Flow-control interval: [1000000000, 1000000000]
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Trying to continue unpaused monitor
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Received NON-PRIMARY.
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 1859890747)
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Received self-leave message.
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Flow-control interval: [1000000000, 1000000000]
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Trying to continue unpaused monitor
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Received SELF-LEAVE. Closing connection.
2019-02-14 16:27:01 139939006113536 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 1859890747)
2019-02-14 16:27:01 139939006113536 [Note] WSREP: RECV thread exiting 0: Success
2019-02-14 16:27:01 139992771357440 [Note] WSREP: recv_thread() joined.
2019-02-14 16:27:01 139992771357440 [Note] WSREP: Closing replication queue.
2019-02-14 16:27:01 139992771357440 [Note] WSREP: Closing slave action queue.
2019-02-14 16:27:01 139992771357440 [Note] WSREP: /usr/sbin/mysqld: Terminated.
======
This is the master log at this time:
=====================
2019-02-14 16:27:01 140512887568128 [Note] WSREP: (b46992ff, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://10.152.28.140:4567
2019-02-14 16:27:01 140512887568128 [Note] WSREP: declaring a4d90112 at tcp://10.30.139.247:4567 stable
2019-02-14 16:27:01 140512887568128 [Note] WSREP: declaring dc780cbe at tcp://10.152.27.200:4567 stable
2019-02-14 16:27:01 140512887568128 [Note] WSREP: forgetting 88813637 (tcp://10.152.28.140:4567)
2019-02-14 16:27:01 140512887568128 [Note] WSREP: (b46992ff, 'tcp://0.0.0.0:4567') turning message relay requesting off
2019-02-14 16:27:01 140512887568128 [Note] WSREP: Node a4d90112 state prim
2019-02-14 16:27:01 140512887568128 [Note] WSREP: declaring dc780cbe at tcp://10.152.27.200:4567 stable
2019-02-14 16:27:01 140512887568128 [Note] WSREP: forgetting a4d90112 (tcp://10.30.139.247:4567)
2019-02-14 16:27:01 140512887568128 [Note] WSREP: Node b46992ff state prim
2019-02-14 16:27:01 140512887568128 [Note] WSREP: view(view_id(PRIM,b46992ff,145) memb {
2019-02-14 16:27:01 140512887568128 [Note] WSREP: save pc into disk
2019-02-14 16:27:01 140512887568128 [Note] WSREP: forgetting 88813637 (tcp://10.152.28.140:4567)
2019-02-14 16:27:01 140512887568128 [Note] WSREP: forgetting a4d90112 (tcp://10.30.139.247:4567)
2019-02-14 16:27:01 140512879175424 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2019-02-14 16:27:01 140512879175424 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 1f240ef5-3086-11e9-a861-d7fde14a40b6
2019-02-14 16:27:01 140512879175424 [Note] WSREP: STATE EXCHANGE: sent state msg: 1f240ef5-3086-11e9-a861-d7fde14a40b6
2019-02-14 16:27:01 140512879175424 [Note] WSREP: STATE EXCHANGE: got state msg: 1f240ef5-3086-11e9-a861-d7fde14a40b6 from 0 (s6006as2400)
2019-02-14 16:27:01 140512879175424 [Note] WSREP: STATE EXCHANGE: got state msg: 1f240ef5-3086-11e9-a861-d7fde14a40b6 from 1 (s602das490)
2019-02-14 16:27:01 140512879175424 [Note] WSREP: Quorum results:
2019-02-14 16:27:01 140512879175424 [Note] WSREP: Flow-control interval: [1000000000, 1000000000]
2019-02-14 16:27:01 140512879175424 [Note] WSREP: Trying to continue unpaused monitor
2019-02-14 16:27:01 140512943704832 [Note] WSREP: New cluster view: global state: 84d4d8c6-7c93-11e7-9bed-3e4a4b9dd52a:1859890747, view# 19: Primary, number of nodes: 2, m
y index: 0, protocol version 3
2019-02-14 16:27:01 140512943704832 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2019-02-14 16:27:01 140512943704832 [Note] WSREP: REPL Protocols: 7 (3, 2)
2019-02-14 16:27:01 140512943704832 [Note] WSREP: Assign initial position for certification: 1859890747, protocol version: 3
2019-02-14 16:27:01 140512937899776 [Note] WSREP: Service thread queue flushed.
2019-02-14 16:27:03 140512887568128 [Note] WSREP: (b46992ff, 'tcp://0.0.0.0:4567') reconnecting to dc780cbe (tcp://10.152.27.200:4567), attempt 0
2019-02-14 16:27:06 140512887568128 [Note] WSREP: cleaning up 88813637 (tcp://10.152.28.140:4567)
2019-02-14 16:27:06 140512887568128 [Note] WSREP: cleaning up a4d90112 (tcp://10.30.139.247:4567)
2019-02-14 16:27:07 140512887568128 [Note] WSREP: evs::proto(b46992ff, OPERATIONAL, view_id(REG,b46992ff,145)) suspecting node: dc780cbe
2019-02-14 16:27:07 140512887568128 [Note] WSREP: evs::proto(b46992ff, OPERATIONAL, view_id(REG,b46992ff,145)) suspected node without join message, declaring inactive
2019-02-14 16:27:08 140512887568128 [Note] WSREP: view(view_id(NON_PRIM,b46992ff,145) memb {
2019-02-14 16:27:08 140512887568128 [Note] WSREP: view(view_id(NON_PRIM,b46992ff,146) memb {
2019-02-14 16:27:08 140512879175424 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2019-02-14 16:27:08 140512879175424 [Note] WSREP: Flow-control interval: [1000000000, 1000000000]
2019-02-14 16:27:08 140512879175424 [Note] WSREP: Trying to continue unpaused monitor
2019-02-14 16:27:08 140512879175424 [Note] WSREP: Received NON-PRIMARY.
2019-02-14 16:27:08 140512879175424 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 1859890747)
2019-02-14 16:27:08 140512943704832 [Note] WSREP: New cluster view: global state: 84d4d8c6-7c93-11e7-9bed-3e4a4b9dd52a:1859890747, view# -1: non-Primary, number of nodes:
1, my index: 0, protocol version 3
2019-02-14 16:27:08 140512943704832 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2019-02-14 16:27:08 140474743606016 [Note] WSREP: cluster conflict due to certification failure for threads:
2019-02-14 16:27:08 140474742696704 [Note] WSREP: cluster conflict due to certification failure for threads:
2019-02-14 16:27:08 140473480563456 [Note] WSREP: cluster conflict due to certification failure for threads:
2019-02-14 16:27:08 140473752890112 [Note] WSREP: cluster conflict due to certification failure for threads:
2019-02-14 16:27:08 140473752890112 [Note] WSREP: Victim thread:
2019-02-14 16:27:08 140474743606016 [Note] WSREP: Victim thread:
2019-02-14 16:27:08 140474742696704 [Note] WSREP: Victim thread:
2019-02-14 16:27:08 140462563953408 [Note] WSREP: cluster conflict due to certification failure for threads:
===============
Thanks in advance.