[MDEV-15688] MariaDB Galera Cluster hangs with Error 1062 HA_ERR_FOUND_DUPP_KEY Created: 2018-03-27  Updated: 2019-12-12  Resolved: 2019-12-12

Status: Closed
Project: MariaDB Server
Component/s: Galera, Replication
Affects Version/s: 10.2.13
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Mattia Martinello Assignee: Jan Lindström (Inactive)
Resolution: Incomplete Votes: 0
Labels: galera, innodb, replication
Environment:

Server db3 v. 10.0.17 with master/slave replication to server mysql1.
Severs mysql1, mysql2 and mysql3 in a MariaDB Galera Cluster on Debian Wheezy 64bit nodes.


 Description   

Hi.
Our db3 server is running MariaDB 10.0.17 and it's configured as master in a master-slave replication to server mysql1 which is running MariaDB 10.2.13.
Servers mysql2 and mysql3 are running MariaDB 10.2.13 and they are configured in a MariaDB Galera Cluster with mysql1.
SST is done without problems and wsrep_cluster_size for mysql1, mysql2 and mysql3 is 3.

Yesterday we disabled the replication between db3 and mysql1, stopped db3 and we began reading and writing on mysql1. No operations were running on mysql2 and mysql3.

Suddenly the MariaDB Galera Cluster terminates with the HA_ERR_FOUND_DUPP_KEY error:

logs from mysql1:

Mar 26 22:21:48 mysql1 mysqld: 2018-03-26 22:21:48 140447914133248 [Note] Slave: received end packet from server, apparent master shutdown: 
Mar 26 22:21:48 mysql1 mysqld: 2018-03-26 22:21:48 140447914133248 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mariadb-bin.006068' at position 18917675
 
Mar 26 22:21:50 mysql1 mysqld: 2018-03-26 22:21:50 140447914133248 [ERROR] Slave I/O: error reconnecting to master 'replicator@192.168.70.23:3306' - retry-time: 60  maximum-retries: 86400  message: Lo
 
st connection to MySQL server at 'reading initial communication packet', system error: 104 "Connection reset by peer", Internal MariaDB error code: 2013
 
Mar 26 22:22:50 mysql1 mysqld: 2018-03-26 22:22:50 140447914133248 [ERROR] Slave I/O: error reconnecting to master 'replicator@192.168.70.23:3306' - retry-time: 60  maximum-retries: 86400  message: Ca
 
n't connect to MySQL server on '192.168.70.23' (111 "Connection refused"), Internal MariaDB error code: 2003
 
Mar 26 22:23:02 mysql1 mysqld: 2018-03-26 22:23:02 140447189485312 [Note] Error reading relay log event: slave SQL thread was killed
 
Mar 26 22:23:02 mysql1 mysqld: 2018-03-26 22:23:02 140447189485312 [Note] Slave SQL thread exiting, replication stopped in log 'mariadb-bin.006068' at position 18917675
 
Mar 26 22:23:02 mysql1 mysqld: 2018-03-26 22:23:02 140447914133248 [Note] Slave I/O thread killed during or after a reconnect done to recover from failed read
 
Mar 26 22:23:02 mysql1 mysqld: 2018-03-26 22:23:02 140447914133248 [Note] Slave I/O thread exiting, read up to log 'mariadb-bin.006068', position 18917675
 
Mar 26 22:23:18 mysql1 mysqld: 2018-03-26 22:23:18 140447914436352 [Note] Deleted Master_info file '/var/lib/mysql/master.info'.
 
Mar 26 22:23:18 mysql1 mysqld: 2018-03-26 22:23:18 140447914436352 [Note] Deleted Master_info file '/var/lib/mysql/relay-log.info'.
 
Mar 26 22:24:27 mysql1 mysqld: 2018-03-26 22:24:27 140447673902848 [Note] WSREP: declaring cf806572 at tcp://192.168.70.28:4567 stable
 
Mar 26 22:24:27 mysql1 mysqld: 2018-03-26 22:24:27 140447673902848 [Note] WSREP: forgetting 5e70bb5b (tcp://192.168.70.27:4567)
 
Mar 26 22:24:27 mysql1 mysqld: 2018-03-26 22:24:27 140447673902848 [Note] WSREP: Node 6d8a01d7 state prim
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447673902848 [Note] WSREP: view(view_id(NON_PRIM,6d8a01d7,49) memb {
 
Mar 26 22:24:28 mysql1 mysqld: #0116d8a01d7,0
 
Mar 26 22:24:28 mysql1 mysqld: } joined {
 
Mar 26 22:24:28 mysql1 mysqld: } left {
 
Mar 26 22:24:28 mysql1 mysqld: } partitioned {
 
Mar 26 22:24:28 mysql1 mysqld: #0115e70bb5b,0
 
Mar 26 22:24:28 mysql1 mysqld: #011cf806572,0
 
Mar 26 22:24:28 mysql1 mysqld: })
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447673902848 [Note] WSREP: Trans install leads to non-prim
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447673902848 [Note] WSREP: view(view_id(NON_PRIM,6d8a01d7,49) memb {
 
Mar 26 22:24:28 mysql1 mysqld: #0116d8a01d7,0
 
Mar 26 22:24:28 mysql1 mysqld: } joined {
 
Mar 26 22:24:28 mysql1 mysqld: } left {
 
Mar 26 22:24:28 mysql1 mysqld: } partitioned {
 
Mar 26 22:24:28 mysql1 mysqld: #0115e70bb5b,0
 
Mar 26 22:24:28 mysql1 mysqld: #011cf806572,0
 
Mar 26 22:24:28 mysql1 mysqld: })
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447673902848 [Note] WSREP: forgetting cf806572 (tcp://192.168.70.28:4567)
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Flow-control interval: [16, 16]
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Received NON-PRIMARY.
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 523)
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447673902848 [Note] WSREP: Nodes cf806572 are still in unknown state, unable to rebootstrap new prim
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447673902848 [Note] WSREP: view(view_id(NON_PRIM,6d8a01d7,50) memb {
 
Mar 26 22:24:28 mysql1 mysqld: #0116d8a01d7,0
 
Mar 26 22:24:28 mysql1 mysqld: } joined {
 
Mar 26 22:24:28 mysql1 mysqld: } left {
 
Mar 26 22:24:28 mysql1 mysqld: } partitioned {
 
Mar 26 22:24:28 mysql1 mysqld: #0115e70bb5b,0
 
Mar 26 22:24:28 mysql1 mysqld: #011cf806572,0
 
Mar 26 22:24:28 mysql1 mysqld: })
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Flow-control interval: [16, 16]
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Received NON-PRIMARY.
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447967565568 [Note] WSREP: New cluster view: global state: 7c945187-2cda-11e8-8aa3-471af66f50fc:523, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447967565568 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Flow-control interval: [16, 16]
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447665510144 [Note] WSREP: Received NON-PRIMARY.
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447967565568 [Note] WSREP: New cluster view: global state: 7c945187-2cda-11e8-8aa3-471af66f50fc:523, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447967565568 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447967565568 [Note] WSREP: New cluster view: global state: 7c945187-2cda-11e8-8aa3-471af66f50fc:523, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3
 
Mar 26 22:24:28 mysql1 mysqld: 2018-03-26 22:24:28 140447967565568 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Mar 26 22:24:32 mysql1 mysqld: 2018-03-26 22:24:32 140447673902848 [Note] WSREP: (6d8a01d7, 'tcp://0.0.0.0:4567') connection established to cf806572 tcp://192.168.70.28:4567
 
Mar 26 22:24:32 mysql1 mysqld: 2018-03-26 22:24:32 140447673902848 [Warning] WSREP: discarding established (time wait) cf806572 (tcp://192.168.70.28:4567) 
Mar 26 22:24:32 mysql1 mysqld: 2018-03-26 22:24:32 140447673902848 [Note] WSREP:  cleaning up 5e70bb5b (tcp://192.168.70.27:4567)
 
Mar 26 22:24:33 mysql1 mysqld: 2018-03-26 22:24:33 140447673902848 [Note] WSREP:  cleaning up cf806572 (tcp://192.168.70.28:4567)

logs from mysql2:

Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articol
 
i' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: Failed to apply app buffer: seqno: 522, status: 1
 
Mar 26 22:24:27 mysql2 mysqld: #011 at galera/src/trx_handle.cpp:apply():351
 
Mar 26 22:24:27 mysql2 mysqld: Retrying 2th time
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articoli' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: Failed to apply app buffer: seqno: 522, status: 1
 
Mar 26 22:24:27 mysql2 mysqld: #011 at galera/src/trx_handle.cpp:apply():351
 
Mar 26 22:24:27 mysql2 mysqld: Retrying 3th time
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articoli' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: Failed to apply app buffer: seqno: 522, status: 1
 
Mar 26 22:24:27 mysql2 mysqld: #011 at galera/src/trx_handle.cpp:apply():351
 
Mar 26 22:24:27 mysql2 mysqld: Retrying 4th time
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articoli' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] WSREP: Failed to apply trx: source: 6d8a01d7-2ceb-11e8-97e2-179f72a8ecd0 version: 3 local: 0 state: APPLYING flags: 1 conn_id: 269 trx_id: 4988128110 seqnos (l: 548, g: 522, s: 521, d: 511, ts: 533603427694991)
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] WSREP: Failed to apply trx 522 4 times
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [ERROR] WSREP: Node consistency compromised, aborting...
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: Closing send monitor...
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: Closed send monitor.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: gcomm: terminating thread
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: gcomm: joining thread
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: gcomm: closing backend
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: view(view_id(NON_PRIM,5e70bb5b,48) memb {
 
Mar 26 22:24:27 mysql2 mysqld: #0115e70bb5b,0
 
Mar 26 22:24:27 mysql2 mysqld: } joined {
 
Mar 26 22:24:27 mysql2 mysqld: } left {
 
Mar 26 22:24:27 mysql2 mysqld: } partitioned {
 
Mar 26 22:24:27 mysql2 mysqld: #0116d8a01d7,0
 
Mar 26 22:24:27 mysql2 mysqld: #011cf806572,0
 
Mar 26 22:24:27 mysql2 mysqld: })
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: view((empty))
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: gcomm: closed
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Flow-control interval: [16, 16]
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Received NON-PRIMARY.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 523)
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Received self-leave message.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Flow-control interval: [0, 0]
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Received SELF-LEAVE. Closing connection.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 523)
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639967041280 [Note] WSREP: RECV thread exiting 0: Success
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: recv_thread() joined.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: Closing replication queue.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: Closing slave action queue.
 
Mar 26 22:24:27 mysql2 mysqld: 2018-03-26 22:24:27 139639924012800 [Note] WSREP: /usr/sbin/mysqld: Terminated.
 
Mar 26 22:24:27 mysql2 mysqld_safe: Number of processes running now: 0
 
Mar 26 22:24:27 mysql2 mysqld_safe: WSREP: not restarting wsrep node automatically
 
Mar 26 22:24:27 mysql2 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended

logs from mysql3:

Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articol
 
i' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: Failed to apply app buffer: seqno: 522, status: 1
 
Mar 26 22:24:27 mysql3 mysqld: #011 at galera/src/trx_handle.cpp:apply():351
 
Mar 26 22:24:27 mysql3 mysqld: Retrying 2th time
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articol
 
i' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: Failed to apply app buffer: seqno: 522, status: 1
 
Mar 26 22:24:27 mysql3 mysqld: #011 at galera/src/trx_handle.cpp:apply():351
 
Mar 26 22:24:27 mysql3 mysqld: Retrying 3th time
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articol
 
i' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: Failed to apply app buffer: seqno: 522, status: 1
 
Mar 26 22:24:27 mysql3 mysqld: #011 at galera/src/trx_handle.cpp:apply():351
 
Mar 26 22:24:27 mysql3 mysqld: Retrying 4th time
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table phpmyadmin.pma__table_uiprefs; Duplicate entry 'root-presse-articol
 
i' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 353, Internal MariaDB error code: 1062
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Warning] WSREP: RBR event 3 Write_rows_v1 apply warning: 121, 522
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140156115678976 [Note] WSREP: (cf806572, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://192.168.70.27:4567 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140156115678976 [Note] WSREP: declaring 6d8a01d7 at tcp://192.168.70.26:4567 stable
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140156115678976 [Note] WSREP: forgetting 5e70bb5b (tcp://192.168.70.27:4567)
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] WSREP: Failed to apply trx: source: 6d8a01d7-2ceb-11e8-97e2-179f72a8ecd0 version: 3 local: 0 state: APPLYING flags: 1 conn_id: 269 trx_id: 4988128110 seqnos (l: 543, g: 522, s: 521, d: 511, ts: 533603427694991)
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140156115678976 [Note] WSREP: (cf806572, 'tcp://0.0.0.0:4567') turning message relay requesting off
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] WSREP: Failed to apply trx 522 4 times
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [ERROR] WSREP: Node consistency compromised, aborting...
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Note] WSREP: Closing send monitor...
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Note] WSREP: Closed send monitor.
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Note] WSREP: gcomm: terminating thread
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Note] WSREP: gcomm: joining thread
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Note] WSREP: gcomm: closing backend
 
Mar 26 22:24:27 mysql3 mysqld: 2018-03-26 22:24:27 140155926796032 [Note] WSREP: Node 6d8a01d7 state prim
 
Mar 26 22:24:30 mysql3 mysqld: 2018-03-26 22:24:30 140155926796032 [Note] WSREP: (cf806572, 'tcp://0.0.0.0:4567') connection to peer 6d8a01d7 with addr tcp://192.168.70.26:4567 timed out, no messages seen in PT3S
 
Mar 26 22:24:30 mysql3 mysqld: 2018-03-26 22:24:30 140155926796032 [Note] WSREP: (cf806572, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://192.168.70.26:4567 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: (cf806572, 'tcp://0.0.0.0:4567') reconnecting to 6d8a01d7 (tcp://192.168.70.26:4567), attempt 0
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP:  cleaning up 5e70bb5b (tcp://192.168.70.27:4567)
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: evs::proto(cf806572, LEAVING, view_id(REG,6d8a01d7,49)) suspecting node: 6d8a01d7
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: evs::proto(cf806572, LEAVING, view_id(REG,6d8a01d7,49)) suspected node without join message, declaring inactive
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: view(view_id(NON_PRIM,6d8a01d7,49) memb {
 
Mar 26 22:24:32 mysql3 mysqld: #011cf806572,0
 
Mar 26 22:24:32 mysql3 mysqld: } joined {
 
Mar 26 22:24:32 mysql3 mysqld: } left {
 
Mar 26 22:24:32 mysql3 mysqld: } partitioned {
 
Mar 26 22:24:32 mysql3 mysqld: #0115e70bb5b,0
 
Mar 26 22:24:32 mysql3 mysqld: #0116d8a01d7,0
 
Mar 26 22:24:32 mysql3 mysqld: })
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: Trans install leads to non-prim
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: view(view_id(NON_PRIM,6d8a01d7,49) memb {
 
Mar 26 22:24:32 mysql3 mysqld: #011cf806572,0
 
Mar 26 22:24:32 mysql3 mysqld: } joined {
 
Mar 26 22:24:32 mysql3 mysqld: } left {
 
Mar 26 22:24:32 mysql3 mysqld: } partitioned {
 
Mar 26 22:24:32 mysql3 mysqld: #0115e70bb5b,0
 
Mar 26 22:24:32 mysql3 mysqld: #0116d8a01d7,0
 
Mar 26 22:24:32 mysql3 mysqld: })
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: view((empty))
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: gcomm: closed
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Flow-control interval: [16, 16]
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Received NON-PRIMARY.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 523)
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Flow-control interval: [16, 16]
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Received NON-PRIMARY.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Received self-leave message.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Flow-control interval: [0, 0]
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Trying to continue unpaused monitor
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Received SELF-LEAVE. Closing connection.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 523)
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140156107286272 [Note] WSREP: RECV thread exiting 0: Success
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: recv_thread() joined.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: Closing replication queue.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: Closing slave action queue.
 
Mar 26 22:24:32 mysql3 mysqld: 2018-03-26 22:24:32 140155926796032 [Note] WSREP: /usr/sbin/mysqld: Terminated.
 
Mar 26 22:24:32 mysql3 mysqld_safe: Number of processes running now: 0
 
Mar 26 22:24:32 mysql3 mysqld_safe: WSREP: not restarting wsrep node automatically
 
Mar 26 22:24:32 mysql3 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended



 Comments   
Comment by Sachin Setiya (Inactive) [ 2018-04-02 ]

Hi decibel83,

Can you provide the query because of which this error happened ?
Or you upload on mariadb private ftp.

Comment by Jan Lindström (Inactive) [ 2018-06-15 ]

Hi, based on provided logs at least two of the galera nodes did shutdown (i.e. were not hang state). I would need my.cnf from all nodes and error logs from all nodes to say for sure what happened. If you have general log that would also help to identify the actual query that caused the duplicate key, did you check was the value actually a duplicate ?

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

No feedback provided.

Generated at Thu Feb 08 08:23:16 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.