Sometimes IST/event queue starts with lower seqno than previously SST was finished

2024-08-14 12:30:01 2 [Note] WSREP: Installed new state from SST: f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708184

2024-08-14 12:30:01 3 [Note] WSREP: SST succeeded for position f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708249

2024-08-14 12:30:01 6 [Note] WSREP: Starting applier thread 6

2024-08-14 12:30:01 2 [Note] WSREP: Installed new state from SST: f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708184

2024-08-14 12:30:01 3 [Note] WSREP: SST succeeded for position f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708249

2024-08-14 12:30:01 9 [Note] WSREP: Starting applier thread 9

2024-08-14 12:30:01 12 [Note] WSREP: Starting applier thread 12

2024-08-14 12:30:01 8 [Note] WSREP: Starting applier thread 8

2024-08-14 12:30:01 0 [Note] WSREP: Joiner monitor thread ended with total time 160 sec

2024-08-14 12:30:01 14 [Note] WSREP: Starting applier thread 14

2024-08-14 12:30:01 0 [Note] /usr/sbin/mariadbd: ready for connections.

Version: '10.6.16-11-MariaDB-enterprise-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MariaDB Enterprise Server

2024-08-14 12:30:01 2 [Note] WSREP: Cert. index preload up to 11708184

2024-08-14 12:30:01 0 [Note] WSREP: ####### IST applying starts with 11708185

2024-08-14 12:30:01 0 [Note] WSREP: ####### IST current seqno initialized to 11691649

2024-08-14 12:30:01 0 [Note] WSREP: Receiving IST...  0.0% (    0/16506 events) complete.

2024-08-14 12:30:01 0 [Note] WSREP: IST preload starting at 11691649

2024-08-14 12:30:01 0 [Note] WSREP: Service thread queue flushed.

2024-08-14 12:30:01 0 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:11691648, protocol version: 5

2024-08-14 12:30:01 16 [Warning] Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)

2024-08-14 12:30:01 17 [Warning] Access denied for user 'debian-sys-maint'@'localhost' (using password: YES)

2024-08-14 12:30:01 0 [Note] WSREP: REPL Protocols: 10 (5)

2024-08-14 12:30:01 0 [Note] WSREP: ####### Adjusting cert position: 11708153 -> 11708154

2024-08-14 12:30:01 0 [Note] WSREP: Service thread queue flushed.

2024-08-14 12:30:01 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 11691649

2024-08-14 12:30:01 0 [Note] WSREP: Min available from gcache for CC from preload: 11691649

2024-08-14 12:30:01 0 [Note] WSREP: Receiving IST...100.0% (16506/16506 events) complete.

2024-08-14 12:30:01 2 [Note] WSREP: Cert. index preloaded up to 11708154

2024-08-14 12:30:01 2 [Note] WSREP: Lowest cert index boundary for CC from sst: 11691649

2024-08-14 12:30:01 2 [Note] WSREP: Min available from gcache for CC from sst: 11691649

2024-08-14 12:30:01 0 [Note] WSREP: 2.0 (xxx001  ): State transfer from 0.0 (xxx003  ) complete.

2024-08-14 12:30:01 0 [Note] WSREP: Shifting JOINER -> JOINED (TO: 11708397)

2024-08-14 12:30:01 0 [Note] WSREP: Processing event queue:...  0.0% (  0/239 events) complete.

2024-08-14 12:30:01 10 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table database_32.bacc; Duplicate entry '73400' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 359, Internal MariaDB error code: 1062

2024-08-14 12:30:01 10 [Warning] WSREP: Event 2 Write_rows_v1 apply failed: 121, seqno 11708189

2024-08-14 12:28:57 0 [Note] WSREP: Member 0.0 (xxx003  ) synced with group.

2024-08-14 12:29:22 19297643 [Warning] Aborted connection 19297643 to db: 'unconnected' user: 'unauthenticated' host: 'x.x.x.5' (This connection closed normally without authentication)

2024-08-14 12:29:38 19297661 [Warning] Aborted connection 19297661 to db: 'unconnected' user: 'unauthenticated' host: 'x.x.x.4' (This connection closed normally without authentication)

2024-08-14 12:30:01 0 [Note] WSREP: 2.0 (xxx001  ): State transfer from 0.0 (xxx003  ) complete.

2024-08-14 12:30:01 0 [Note] WSREP: Member 2(xxx001  ) initiates vote on f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185,ade0306a58969dbc:  Duplicate entry '1033043' for key 'PRIMARY', Error_code: 1062;

2024-08-14 12:30:01 8 [Note] WSREP: Got vote request for seqno f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185

2024-08-14 12:30:01 0 [Note] WSREP: Member 0(xxx003  ) responds to vote on f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185,0000000000000000: Success

2024-08-14 12:30:01 0 [Warning] WSREP: Received bogus VOTE message: 11708185.0, from node 1312e9d5-dba7-11ee-8116-cfbb1d00a289, expected > 11708310. Ignoring.

2024-08-14 12:30:01 0 [Note] WSREP: Member 1(xxx002  ) responds to vote on f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185,0000000000000000: Success

2024-08-14 12:30:01 0 [Warning] WSREP: Received bogus VOTE message: 11708185.0, from node 222fa4ed-dba7-11ee-b6da-867b6a8d88f0, expected > 11708309. Ignoring.

2024-08-14 12:30:22 19297730 [Warning] Aborted connection 19297730 to db: 'unconnected' user: 'unauthenticated' host: 'x.x.x.5' (This connection closed normally without authentication)

2024-08-14 12:28:57 0 [Note] WSREP: Donor monitor thread ended with total time 95 sec

2024-08-14 12:30:01 0 [Note] WSREP: async IST sender served

2024-08-14 12:30:01 0 [Note] WSREP: 2.0 (xxx001  ): State transfer from 0.0 (xxx003  ) complete.

2024-08-14 12:30:01 0 [Note] WSREP: Member 2(xxx001  ) initiates vote on f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185,ade0306a58969dbc:  Duplicate entry '1033043' for key 'PRIMARY', Error_code: 1062;

2024-08-14 12:30:01 9 [Note] WSREP: Got vote request for seqno f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185

2024-08-14 12:30:01 0 [Note] WSREP: Member 0(xxx003  ) responds to vote on f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185,0000000000000000: Success

2024-08-14 12:30:01 0 [Warning] WSREP: Received bogus VOTE message: 11708185.0, from node 1312e9d5-dba7-11ee-8116-cfbb1d00a289, expected > 11708310. Ignoring.

2024-08-14 12:30:01 0 [Note] WSREP: Member 1(xxx002 ) responds to vote on f7d36ee0-cb0c-11ee-88f9-f3dcd4a9bcfc:11708185,0000000000000000: Success

2024-08-14 12:30:01 0 [Warning] WSREP: Received bogus VOTE message: 11708185.0, from node 222fa4ed-dba7-11ee-b6da-867b6a8d88f0, expected > 11708309. Ignoring.

2024-08-14 12:41:04 0 [Note] WSREP: declaring 222fa4ed-b6da at ssl://x.x.x.x.41:4567 stable

2024-08-27  1:14:37 0 [Note] WSREP: 2.0 ( galera103 ): State transfer to 0.0 ( galera104 ) complete.

2024-08-27  1:14:37 0 [Note] WSREP: Member 2.0 ( galera103) synced with group.

2024-08-27  1:18:19 0 [Note] WSREP: 0.0 ( galera104): State transfer from 2.0 ( galera103 ) complete.

2024-08-27  1:21:48 0 [Note] WSREP: Member 0( galera104) initiates vote on 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503,d8c6e58f6f68441e:  Duplicate entry '2703907675-35' for key 'PRIMARY', Error_code: 1062;

2024-08-27  1:21:48 10 [Note] WSREP: Got vote request for seqno 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503

2024-08-27  1:21:48 0 [Note] WSREP: Member 2( galera103) responds to vote on 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503,0000000000000000: Success

2024-08-27  1:21:48 0 [Warning] WSREP: Received bogus VOTE message: 311239503.0, from node dd0d0532-607a-11ef-ab69-7fa270c233a4, expected > 311559638. Ignoring.

2024-08-27  1:21:48 0 [Note] WSREP: Member 1( galera102 ) responds to vote on 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503,0000000000000000: Success

2024-08-27  1:21:48 0 [Warning] WSREP: Received bogus VOTE message: 311239503.0, from node 6cd056bd-606d-11ef-89d7-eacb19e1cda7, expected > 311559556. Ignoring.

2024-08-27  1:14:37 0 [Note] WSREP: Donor monitor thread ended with total time 16231 sec

2024-08-27  1:18:19 0 [Note] WSREP: async IST sender served

2024-08-27  1:18:19 0 [Note] WSREP: 0.0 ( galera104 ): State transfer from 2.0 ( galera103 ) complete.

2024-08-27  1:21:48 0 [Note] WSREP: Member 0( galera104 ) initiates vote on 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503,d8c6e58f6f68441e:  Duplicate entry '2703907675-35' for key 'PRIMARY', Error_code: 1062;

2024-08-27  1:21:48 8 [Note] WSREP: Got vote request for seqno 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503

2024-08-27  1:21:48 0 [Note] WSREP: Member 2( galera103 ) responds to vote on 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503,0000000000000000: Success

2024-08-27  1:21:48 0 [Warning] WSREP: Received bogus VOTE message: 311239503.0, from node dd0d0532-607a-11ef-ab69-7fa270c233a4, expected > 311559638. Ignoring.

2024-08-27  1:21:48 0 [Note] WSREP: Member 1( galera102 ) responds to vote on 6cd167d4-606d-11ef-a548-83a024a42e9e:311239503,0000000000000000: Success

2024-08-27  1:21:48 0 [Warning] WSREP: Received bogus VOTE message: 311239503.0, from node 6cd056bd-606d-11ef-89d7-eacb19e1cda7, expected > 311559556. Ignoring.

2024-08-27  8:18:25 0 [Note] WSREP: declaring 6cd056bd-89d7 at ssl://x.x.x.33:4567 stable

2024-08-27  8:18:25 0 [Note] WSREP: forgetting 356452ce-a0d8 (ssl://x.x.x.35:4567)

2024-08-27  8:18:25 0 [Note] WSREP: Node 6cd056bd-89d7 state prim

2024-08-27  8:18:25 0 [Note] WSREP: view(view_id(PRIM,6cd056bd-89d7,6) memb {

	6cd056bd-89d7,0

	dd0d0532-ab69,0

} joined {

} left {

} partitioned {

	356452ce-a0d8,0

})

2024-08-27  8:18:25 0 [Note] WSREP: save pc into disk

2024-08-27  8:18:25 0 [Note] WSREP: forgetting 356452ce-a0d8 (ssl://x.x.x.35:4567)

2024-08-27  8:18:25 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2

2024-08-27  8:18:25 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.

2024-08-27  8:18:25 0 [Note] WSREP: STATE EXCHANGE: sent state msg: d4d82000-641e-11ef-8c68-0a36ad7f3272

2024-08-27  8:18:25 0 [Note] WSREP: STATE EXCHANGE: got state msg: d4d82000-641e-11ef-8c68-0a36ad7f3272 from 0 ( galera102 )

2024-08-27  8:18:25 0 [Note] WSREP: STATE EXCHANGE: got state msg: d4d82000-641e-11ef-8c68-0a36ad7f3272 from 1 ( galera103 )

2024-08-27  8:18:25 0 [Note] WSREP: Quorum results:

	version    = 6,

	component  = PRIMARY,

	conf_id    = 5,

	members    = 2/2 (joined/total),

	act_id     = 311559682,

	last_appl. = 311559556,

	protocols  = 2/10/4 (gcs/repl/appl),

	vote policy= 0,

	group UUID = 6cd167d4-606d-11ef-a548-83a024a42e9e

2024-08-27  8:18:25 0 [Note] WSREP: Flow-control interval: [145, 181]

2024-08-27  8:18:30 0 [Note] WSREP:  cleaning up 356452ce-a0d8 (ssl://x.x.x.35:4567)

2024-08-27  1:18:19 10 [Note] WSREP: Starting applier thread 10

2024-08-27  1:18:19 0 [Note] /usr/sbin/mariadbd: ready for connections.

Version: '10.6.16-11-MariaDB-enterprise-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MariaDB Enterprise Server

2024-08-27  1:18:19 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.

2024-08-27  1:18:19 15 [Note] WSREP: Recovered cluster id 6cd167d4-606d-11ef-a548-83a024a42e9e

2024-08-27  1:18:19 3 [Note] WSREP: SST received: 6cd167d4-606d-11ef-a548-83a024a42e9e:311239500

2024-08-27  1:18:19 3 [Note] WSREP: SST succeeded for position 6cd167d4-606d-11ef-a548-83a024a42e9e:311239530

2024-08-27  1:18:19 2 [Note] WSREP: Installed new state from SST: 6cd167d4-606d-11ef-a548-83a024a42e9e:311239500

2024-08-27  1:18:19 0 [Note] WSREP: Joiner monitor thread ended with total time 16454 sec

2024-08-27  1:18:19 2 [Note] WSREP: Cert. index preload up to 311239500

2024-08-27  1:18:19 0 [Note] WSREP: ####### IST applying starts with 311239501

2024-08-27  1:18:19 0 [Note] WSREP: ####### IST current seqno initialized to 303363076

2024-08-27  1:18:19 0 [Note] WSREP: Receiving IST...  0.0% (  0/112 events) complete.

2024-08-27  1:18:19 0 [Note] WSREP: IST preload starting at 303363076

2024-08-27  1:18:19 0 [Note] WSREP: Service thread queue flushed.

2024-08-27  1:18:19 0 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:303363075, protocol version: 5

2024-08-27  1:18:19 0 [Note] WSREP: REPL Protocols: 10 (5)

2024-08-27  1:18:19 0 [Note] WSREP: ####### Adjusting cert position: 303363186 -> 303363187

2024-08-27  1:18:19 0 [Note] WSREP: Service thread queue flushed.

2024-08-27  1:18:19 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 303363076

2024-08-27  1:18:19 0 [Note] WSREP: Min available from gcache for CC from preload: 303363076

2024-08-27  1:18:19 0 [Note] WSREP: Receiving IST...100.0% (112/112 events) complete.

2024-08-27  1:18:19 2 [Note] WSREP: Cert. index preloaded up to 303363187

2024-08-27  1:18:19 2 [Note] WSREP: Lowest cert index boundary for CC from sst: 303363076

2024-08-27  1:18:19 2 [Note] WSREP: Min available from gcache for CC from sst: 303363076

2024-08-27  1:18:19 0 [Note] WSREP: 0.0 ( galerax104 ): State transfer from 2.0 ( galerax103. ) complete.

2024-08-27  1:18:19 0 [Note] WSREP: Shifting JOINER -> JOINED (TO: 311405864)

2024-08-27  1:18:19 0 [Note] WSREP: Processing event queue:...  0.0% (      0/8045248 events) complete.

[..]

2024-08-27  1:21:39 8 [Note] WSREP: Processing event queue:... 91.2% (7473344/8193701 events) complete.

2024-08-27  1:21:48 2 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table database03.logs; Duplicate entry '2703907675-35' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 281, Internal MariaDB error code: 1062

2024-08-27  1:21:48 9 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table database32.logs; Duplicate entry '3401829649-35' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 281, Internal MariaDB error code: 1062

2024-08-27  1:21:48 2 [Warning] WSREP: Event 2 Write_rows_v1 apply failed: 121, seqno 311239503

2024-08-27  1:21:48 9 [Warning] WSREP: Event 2 Write_rows_v1 apply failed: 121, seqno 311239508

2024-08-27  1:21:48 11 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table database09..logs; Duplicate entry '2704005055-35' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 281, Internal MariaDB error code: 1062

2024-08-27  1:21:48 11 [Warning] WSREP: Event 2 Write_rows_v1 apply failed: 121, seqno 311239510