Details
-
Bug
-
Status: Stalled (View Workflow)
-
Critical
-
Resolution: Unresolved
-
12.2, 10.6.23, 10.11.14, 11.8.3
-
Q4/2025 Server Maintenance
Description
This was discovered as part of adding query sequence number feature to server_audit plugin as specified in MDEV-37004.
Problem: If a multi-insert statement such as INSERT INTO ... VALUES (A), (B) fires off a trigger, the query id for the trigger statements fired by A-insert is different from trigger statements fired by B-insert. This results in trigger statements fired by A to be unlinked from the source INSERT that caused them.
Example:
20250812 23:05:51,HOSTNAME,root,localhost,4,38,QUERY,test,'set global server_audit_logging=on',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,39,QUERY,test,'CREATE DATABASE IF NOT EXISTS test',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,40,QUERY,test,'SHOW WARNINGS',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,41,QUERY,test,'USE test',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,42,QUERY,test,'CREATE TABLE source (\nid bigint(20) NOT NULL AUTO_INCREMENT,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_uca1400_ai_ci',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,43,QUERY,test,'CREATE TABLE dest (\nid bigint(20) NOT NULL,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_uca1400_ai_ci',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,44,QUERY,test,'CREATE TABLE dest_2 (\nid bigint(20) NOT NULL,\nPRIMARY KEY (id)\n) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_uca1400_ai_ci',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,45,QUERY,test,'CREATE TRIGGER test_trigger \nAFTER INSERT ON source \nFOR EACH ROW \nINSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,46,QUERY,test,'CREATE TRIGGER test_trigger_2\nAFTER INSERT ON dest \nFOR EACH ROW \nINSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,48,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,48,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,48,QUERY,test,'INSERT INTO source VALUES (NULL)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,51,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,51,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,51,QUERY,test,'INSERT INTO source VALUES (NULL)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,54,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,54,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,56,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,56,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,56,QUERY,test,'INSERT INTO source VALUES (NULL), (NULL)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,58,QUERY,test,'SET TRANSACTION ISOLATION LEVEL REPEATABLE READ',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,59,QUERY,test,'BEGIN',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO source VALUES (NULL), (NULL)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,65,QUERY,test,'COMMIT',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,66,QUERY,test,'DROP TABLE source, dest',0
|
20250812 23:05:52,HOSTNAME,root,localhost,4,67,QUERY,test,'DROP DATABASE test',0
|
20250812 23:05:53,HOSTNAME,root,localhost,4,68,QUERY,test,'set global server_audit_logging=off',0
|
Observe that the first two INSERTs are query_id 61, while the triggering and second set of INSERTs are query_id 63.
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO source VALUES (NULL), (NULL)',0
|
This is incorrect. Either all query IDs should be 61, or the triggering multi-valued insert statement should be split into separate inserts and logged as such appearing as:
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,61,QUERY,test,'INSERT INTO source VALUES (NULL)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO dest_2 (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO dest (id) VALUES(NEW.id)',0
|
20250812 23:05:51,HOSTNAME,root,localhost,4,63,QUERY,test,'INSERT INTO source VALUES (NULL)',0
|
It has to be either or, otherwise important audit information is lost.
Reproducible test case is available at: https://github.com/arcivanov/mariadb-server/blob/MDEV-37434/mysql-test/suite/plugins/t/server_audit_query_seqnum.test