[MDEV-30303] run optimize table got [Note] WSREP: MDL BF-BF conflict and [ERROR] Aborting Created: 2022-12-25  Updated: 2023-03-31  Resolved: 2023-03-31

Status: Closed
Project: MariaDB Server
Component/s: Galera
Affects Version/s: 10.6.10
Fix Version/s: 11.1.0, 10.11.3, 10.6.13, 10.8.8, 10.9.6, 10.10.4

Type: Bug Priority: Major
Reporter: William Wong Assignee: Jan Lindström
Resolution: Fixed Votes: 1
Labels: None
Environment:

redhat on VMware

Attachments: Text File 20230323-create-table.txt    
Issue Links:
Relates
relates to MDEV-30413 run sequence nextval got [Note] WSREP... Closed

 Description   

one of our Galera DB cluster got one DB node status wsrep_ready changed to OFF when application running "optimize table". We need to restart the DB node in order to resume the cluster.

Below is from debug log. Kindly help to advise how to avoid the node down.

2022-12-26 1:00:00 1 [Note] WSREP: wsrep_commit_empty(1)
2022-12-26 1:00:00 1 [Note] WSREP: assigned new next trx id: 9201958
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_before_prepare: 1
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_after_prepare: 1
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_before_commit: 1, 22083004
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_ordered_commit: 1
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_after_commit: 1, 1, 22083004, 0
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_after_apply 1
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_commit_empty(7)
2022-12-26 1:00:00 7 [Note] WSREP: assigned new next trx id: 9201959
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_before_prepare: 1
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_after_prepare: 1
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_before_commit: 1, 22083005
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_ordered_commit: 1
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_after_commit: 1, 1, 22083005, 0
2022-12-26 1:00:00 7 [Note] WSREP: wsrep_after_apply 7
2022-12-26 1:00:00 6 [Note] WSREP: Wsrep_high_priority_service::apply_toi: 22083006
2022-12-26 1:00:00 6 [Note] WSREP: assigned new next query and trx id: 9201960
2022-12-26 1:00:00 6 [Note] WSREP: Apply TOI Begin: ANALYZE TABLE oss_sup_doc
2022-12-26 1:00:00 6 [Note] WSREP: Apply TO END: 22083006: ANALYZE TABLE oss_sup_doc
2022-12-26 1:00:00 6 [Note] WSREP: Set WSREPXid for InnoDB: 92b3ac91-e636-11ec-ae4a-2348379544ba:22083006
2022-12-26 1:00:00 8 [Note] WSREP: Wsrep_high_priority_service::apply_toi: 22083007
2022-12-26 1:00:00 8 [Note] WSREP: assigned new next query and trx id: 9201961
2022-12-26 1:00:00 8 [Note] WSREP: Apply TOI Begin: OPTIMIZE TABLE oss_sup_doc
2022-12-26 1:00:00 8 [Note] InnoDB: Online DDL : Start reading clustered index of the table and create temporary files
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_commit_empty(1)
2022-12-26 1:00:00 1 [Note] WSREP: assigned new next trx id: 9201962
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_before_prepare: 1
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_after_prepare: 1
2022-12-26 1:00:00 1 [Note] WSREP: wsrep_before_commit: 1, 22083008
2022-12-26 1:00:00 8 [Note] InnoDB: Online DDL : End of reading clustered index of the table and create temporary files
2022-12-26 1:00:00 8 [Note] WSREP: MDL conflict
schema: swdcisdb
request: (8 seqno 22083007 wsrep (toi, exec, committed) cmd 0 45 OPTIMIZE TABLE oss_sup_doc)
granted: (1 seqno 22083008 wsrep (high priority, exec, committing) cmd 0 161 (null))
2022-12-26 1:00:00 8 [Note] WSREP: MDL ticket: type: MDL_SHARED_READ space: TABLE db: swdcisdb name: oss_sup_doc (Waiting for table metadata lock)
2022-12-26 1:00:00 8 [Note] WSREP: MDL BF-BF conflict
schema: swdcisdb
request: (8 seqno 22083007 wsrep (toi, exec, committed) cmd 0 45 OPTIMIZE TABLE oss_sup_doc)
granted: (1 seqno 22083008 wsrep (high priority, exec, committing) cmd 0 161 (null))
2022-12-26 1:00:00 8 [Note] WSREP: MDL ticket: type: MDL_SHARED_READ space: TABLE db: swdcisdb name: oss_sup_doc (Waiting for table metadata lock)
2022-12-26 1:00:00 8 [ERROR] Aborting

 Comments   
Comment by Jan Lindström [ 2023-03-15 ]

frelist I would need more information. Can you provide show create table swdcisdb.oss_sup_doc; Do you have any errors on other node error logs?

Comment by William Wong [ 2023-03-23 ]

20230323-create-table.txt

Create table of swdcisdb.oss_sup_doc is uploaded as file "20230323-create-table.txt"

Time already 2 months. Not sure whether application team modified the schema or not.

Below are error messages at the other node:

2022-12-26 1:00:00 2819439 [Note] WSREP: MDL conflict
schema: swdcisdb
request: (2819439 seqno 22083007 wsrep (toi, exec, aborted) cmd 3 45 OPTIMIZE TABLE oss_sup_doc)
granted: (2819290 seqno -1 wsrep (local, exec, certifying) cmd 3 7 DELETE FROM oss_sub WHERE sub_id = 3348)
2022-12-26 1:00:00 2819439 [Note] WSREP: MDL ticket: type: MDL_SHARED_READ space: TABLE db: swdcisdb name: oss_sup_doc (Waiting for table metadata lock)
2022-12-26 1:00:00 2819439 [Note] WSREP: MDL conflict-> BF abort
schema: swdcisdb
request: (2819439 seqno 22083007 wsrep (toi, exec, aborted) cmd 3 45 OPTIMIZE TABLE oss_sup_doc)
granted: (2819290 seqno -1 wsrep (local, exec, certifying) cmd 3 7 DELETE FROM oss_sub WHERE sub_id = 3348)
2022-12-26 1:00:00 2819439 [Note] WSREP: MDL ticket: type: MDL_SHARED_READ space: TABLE db: swdcisdb name: oss_sup_doc (Waiting for table metadata lock)
2022-12-26 1:00:00 2819439 [Note] WSREP: wsrep_abort_thd, by: 140199981389568, victim: 140199979853568
2022-12-26 1:00:00 2819439 [Note] WSREP: abort transaction: BF: OPTIMIZE TABLE oss_sup_doc victim: DELETE FROM oss_sub WHERE sub_id = 3348 victim conf: certifying
2022-12-26 1:00:00 2819439 [Note] WSREP: wsrep_thd_set_wsrep_aborter called
2022-12-26 1:00:00 2819439 [Note] WSREP: wsrep_bf_abort BF aborter before
thd: 2819439 thd_ptr: 0x7f816c02a8c8 client_mode: toi client_state: exec trx_state: aborted
next_trx_id: 13677147 trx_id: -1 seqno: 22083007
is_streaming: 0 fragments: 0
sql_errno: 0 message:
command: 45 query: OPTIMIZE TABLE oss_sup_doc
2022-12-26 1:00:00 2819439 [Note] WSREP: wsrep_bf_abort victim before
thd: 2819290 thd_ptr: 0x7f8150390bd8 client_mode: local client_state: exec trx_state: certifying
next_trx_id: 13677146 trx_id: 13677146 seqno: -1
is_streaming: 0 fragments: 0
sql_errno: 0 message:
command: 7 query: DELETE FROM oss_sub WHERE sub_id = 3348
2022-12-26 1:00:00 2819439 [Note] WSREP: MDL conflict db=swdcisdb table=oss_sup_doc ticket=3 solved by abort

Comment by Ramesh Sivaraman [ 2023-03-31 ]

Could not reproduce issue with OPTIMIZE table + SEQUENCE NEXTVAL test case on bug fix branch MDEV-30413

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