[MDEV-9609] wsrep_debug only logs DDL information on originating node Created: 2016-02-22  Updated: 2021-06-01  Resolved: 2021-05-15

Status: Closed
Project: MariaDB Server
Component/s: Galera, wsrep
Fix Version/s: 10.6.1

Type: Task Priority: Major
Reporter: Geoff Montee (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: galera, wsrep

Sub-Tasks:
Key
 Summary
 Type
 Status
 Assignee
MDEV-25722 Document the change to wsrep_debug - ... Technical task Closed Ian Gilfillan  

 Description   

When wsrep_debug is enabled, Galera Cluster logs more verbose information to the error log.

For example, when DDL is executed on a particular node, the node logs some information like this:

160222 15:30:44 [Note] WSREP: TO BEGIN: -1, 0 : ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: TO BEGIN: 1100033, 2
 
160222 15:30:44 [Note] WSREP: TO END: 1100033, 2 : ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: Set WSREPXid for InnoDB:  fbeb045d-b94f-11e5-8504-4ae80b892690:1100033
 
160222 15:30:44 [Note] WSREP: TO END: 1100033, update seqno
 
160222 15:30:44 [Note] WSREP: TO END: 1100033

However, when wsrep_OSU_method is set to TOI and the DDL command is replicated to the other nodes in the cluster, those other nodes do not log anything about the DDL to their error logs, even if wsrep_debug is enabled on those other nodes.

It would be useful to see some kind of information in the error logs about replicated DDL when wsrep_debug is ON. The main use case is when trying to track exactly what DDL is being replicated to other nodes.

 Comments   
Comment by Nirbhay Choubey (Inactive) [ 2016-02-23 ]

GeoffMontee Even though DDLs, replicated under TOI, show up in the error log, they
are received on the other nodes just like any other update. So, IIUC, there is no trivial way
to distinguish them from other updates. Said that, they are always logged in general log
(if enabled). Wouldn't that be sufficient for your use case?

Comment by Geoff Montee (Inactive) [ 2016-02-23 ]

Hi nirbhay_c,

I was hoping the logs would have some Galera-specific information that the general log doesn't contain, such as the server that sent the DDL.

The problem that I am debugging is that a user's cluster seems to be executing DDL statements twice. I can see the duplicate DDL statements in SHOW ENGINE INNODB STATUS and SHOW FULL PROCESSLIST, so the general log would only confirm what I already know: that the statements are being executed twice.

What I was actually hoping for was a way to determine where the duplicate DDL statements are coming from. For example, maybe log entries like this:

For DDL executed locally:

160222 15:30:44 [Note] WSREP: DDL executed locally: ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: TO BEGIN: -1, 0 : ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: TO BEGIN: 1100033, 2
 
160222 15:30:44 [Note] WSREP: TO END: 1100033, 2 : ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: Set WSREPXid for InnoDB:  fbeb045d-b94f-11e5-8504-4ae80b892690:1100033
 
160222 15:30:44 [Note] WSREP: TO END: 1100033, update seqno
 
160222 15:30:44 [Note] WSREP: TO END: 1100033

For DDL received from another node:

 
160222 15:30:44 [Note] WSREP: DDL received from node1: ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: TO BEGIN: -1, 0 : ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: TO BEGIN: 1100033, 2
 
160222 15:30:44 [Note] WSREP: TO END: 1100033, 2 : ALTER ONLINE TABLE test_table DROP KEY str
 
160222 15:30:44 [Note] WSREP: Set WSREPXid for InnoDB:  fbeb045d-b94f-11e5-8504-4ae80b892690:1100033
 
160222 15:30:44 [Note] WSREP: TO END: 1100033, update seqno
 
160222 15:30:44 [Note] WSREP: TO END: 1100033

Maybe I can find the information that I need in the binary log instead.

Comment by Jan Lindström (Inactive) [ 2021-05-11 ]

Example of output:

2021-05-11  7:43:49 2 [Note] WSREP: Apply TOI Begin: DROP TABLE child
 
2021-05-11  7:43:49 2 [Note] WSREP: Apply TO END: 20: DROP TABLE child

Comment by Jan Lindström (Inactive) [ 2021-05-19 ]

ralf.gebhardt@mariadb.com Only wsrep_debug=1

Comment by Jan Lindström (Inactive) [ 2021-05-19 ]

1 == SERVER

Generated at Thu Feb 08 07:35:58 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.