[MDEV-16837] Trigger can't find table Created: 2018-07-27  Updated: 2023-04-27

Status: Confirmed
Project: MariaDB Server
Component/s: Replication, Storage Engine - InnoDB, Triggers
Affects Version/s: 10.1, 10.1.34, 10.2.16, 10.3.8, 10.2, 10.3, 10.4
Fix Version/s: 10.4

Type: Bug Priority: Major
Reporter: Martin Dunsmore Assignee: Andrei Elkin
Resolution: Unresolved Votes: 0
Labels: cross-vendor-replication
Environment:

Debian


Attachments: Text File error.log     Text File gdb.log    
Issue Links:
Relates
relates to MDEV-16764 Crash on delete from sql-versioned ta... Closed

 Description   

We have a Percona server replicating to a MeriaDB server like follows:

Server A (Percona 5.6.32-78.1-log)

Table A – (trigger inserts record, after update) --> Table B

Server B (10.3.9-MariaDB-debug-log)

Table A (replication from server A OK)
Table B (replication from server A OK)

If a trigger is added on Table A - triggers work OK
If a trigger is added on Table B - assertion fails in sql_trigger.cc line 2192

For our particular use case we added a trigger (after insert) on Server B::Table B to insert a record into ServerB::Table C

Outside of a debug build replication breaks with the error message; can't find `Server B.Table C`

I have attached out error log and output from gdb.

Hope this is enough information, happy to provide more if needed.

Edit: Replication is ROW based with slave_run_triggers_for_rbr enabled

Thanks Martin



 Comments   
Comment by Elena Stepanova [ 2018-08-03 ]

Could you please just provide the relevant table and trigger definitions from both servers? You can obfuscate the names, logic and data, but we need to see what exists where, I appreciate the attempt to pseudo-code it, but it's just confusing.

"Table A – (trigger inserts record, after update) --> Table B" – trigger on which table, where does it insert a record after update on what?
"If a trigger is added on Table A - triggers work OK" – added where, on master or on slave? Which triggers work okay, and where, on master or on slave?
and so on.

Please also attach your cnf file(s) and the exact error which you are getting on a non-debug server.

Thanks.

Comment by Martin Dunsmore [ 2018-08-06 ]

Hi Elena,

Here is the extra information as requested.

Master my.cnf

[mysql]
 
port							= 3306
socket							= /var/run/mysqld/mysqld.sock
 
[mysqld]
 
user							= mysql
socket							= /var/run/mysqld/mysqld.sock
pid-file						= /var/run/mysqld/mysqld.pid
port							= 3306
bind-address					= 0.0.0.0
basedir							= /usr
lc-messages-dir					= /usr/share/mysql
server-id						= 1001
skip-name-resolve
 
# MariaDB only
# slave_run_triggers_for_rbr	= logging
 
character-set-server            = latin1
collation-server                = latin1_swedish_ci
skip-character-set-client-handshake
 
datadir							= /var/lib/mysql/
tmpdir							= /var/tmp/
slave-load-tmpdir				= /var/tmp/
 
log-bin							= /var/log/mysql/mysql-bin.log
expire-logs-days				= 1
binlog-format					= ROW
max-binlog-size					= 100M
 
log-output						= file
log-error						= /var/log/mysql/mysql-error.log
 
slow-query-log					= 1
slow-query-log-file				= /var/log/mysql/mysql-slow.log

Slave my.cnf

[mysql]
 
port				= 3306
socket				= /var/run/mysqld/mysqld.sock
 
[mysqld]
 
# For debugging
core-file
stack-trace
debug				= d:t:i:o,/tmp/mysqld.trace
 
user				= mysql
socket				= /var/run/mysqld/mysqld.sock
pid-file			= /var/run/mysqld/mysqld.pid
port				= 3306
bind-address			= 0.0.0.0
basedir				= /usr
lc-messages-dir			= /usr/share/mysql
server-id			= 1002
skip-name-resolve
 
slave_run_triggers_for_rbr	= logging
 
character-set-server            = latin1
collation-server                = latin1_swedish_ci
skip-character-set-client-handshake
 
datadir				= /var/lib/mysql/
tmpdir				= /var/tmp/
slave-load-tmpdir		= /var/tmp/
 
log-bin				= /var/log/mysql/mysql-bin.log
expire-logs-days		= 1
binlog-format			= ROW
max-binlog-size			= 100M
 
log-output			= file
log-error			= /var/log/mysql/mysql-error.log
 
relay-log			= /var/log/mysql/mysql-relay.log
 
slow-query-log			= 1
slow-query-log-file		= /var/log/mysql/mysql-slow.log

On master execute:

DROP DATABASE IF EXISTS testdb;
 
CREATE DATABASE IF NOT EXISTS testdb
CHARACTER SET utf8mb4
COLLATE utf8mb4_unicode_ci;
 
CREATE TABLE IF NOT EXISTS recording_parts (
  id int(11) NOT NULL AUTO_INCREMENT,
  call_id int(11) NOT NULL,
  h323_conf_id varchar(36) NOT NULL,
  i_customer int(11) NOT NULL,
  i_account int(11) NOT NULL,
  bill_time datetime NOT NULL,
  PRIMARY KEY (id)
)
ENGINE = INNODB,
CHARACTER SET utf8mb4,
COLLATE utf8mb4_unicode_ci;
 
CREATE TABLE IF NOT EXISTS calls (
  call_id int(11) NOT NULL,
  h323_conf_id varchar(36) NOT NULL,
  i_customer int(11) NOT NULL,
  i_account int(11) NOT NULL,
  bill_time datetime NOT NULL
)
ENGINE = INNODB,
CHARACTER SET utf8mb4,
COLLATE utf8mb4_unicode_ci;
 
DELIMITER $$
 
CREATE
DEFINER = 'root'@'localhost'
TRIGGER calls_after_update
AFTER UPDATE
ON calls
FOR EACH ROW
BEGIN
  INSERT INTO recording_parts (call_id, h323_conf_id, i_customer, i_account, bill_time)
    VALUES (NEW.call_id, NEW.h323_conf_id, NEW.i_customer, NEW.i_account, NEW.bill_time);
END
$$
 
DELIMITER ;

Trigger calls_after_update will replicate to the slave, this needs to be deleted on the slave.

On slave execute:

USE testdb;
 
CREATE TABLE IF NOT EXISTS rec_test (
  call_id int(11) NOT NULL,
  h323_conf_id varchar(36) NOT NULL,
  i_customer int(11) NOT NULL,
  i_account int(11) NOT NULL,
  bill_time datetime NOT NULL
)
ENGINE = INNODB,
CHARACTER SET utf8mb4,
COLLATE utf8mb4_unicode_ci;
 
DELIMITER $$
 
CREATE
DEFINER = 'root'@'localhost'
TRIGGER recording_parts_after_insert
AFTER INSERT
ON recording_parts
FOR EACH ROW
BEGIN
  INSERT INTO rec_test (call_id, h323_conf_id, i_customer, i_account, bill_time)
    VALUES (NEW.call_id, NEW.h323_conf_id, NEW.i_customer, NEW.i_account, NEW.bill_time);
END
$$
 
DELIMITER ;

Insert a record in to calls on the master and then update that record, that will cause the trigger and calls to fire. A record will be inserted in to recording_parts and will replicate over to the slave. The trigger on recording_parts will fire and insert a record in to rec_test, but it will only work once!

Then I get the following error when not using a debug build:
Could not execute Write_rows event on table testdb.recording_parts; Table 'testdb.rec_test' doesn't exist, Error_code: 1146; handler error HA_ERR_GENERIC; the event's master log mysql-bin.000003, end_log_pos 4132

Hope this helps, please let me know if you need any more information or if anything remains unclear.

Thanks Martin

Comment by Elena Stepanova [ 2018-09-04 ]

Thanks for the test case, now I can reproduce it. It fails even if both master and slave are running MariaDB of the same version.

Please note that with this setup, if master were running MariaDB, the trigger on the slave wouldn't be not supposed to be invoked. Since `calls` table already has triggers on master, the binlog would contain a corresponding flag, and triggers on the slave shouldn't even be executed. Of course, it shouldn't cause replication abort or debug assertion failures as it does now, so it's a bug from every perspective.

Test case (same as above, only wrapped up for MTR):

--source include/have_innodb.inc
--source include/have_binlog_format_row.inc
--source include/master-slave.inc
 
--connection slave
 
SET GLOBAL slave_run_triggers_for_rbr = 'LOGGING';
 
--connection master
 
CREATE TABLE IF NOT EXISTS recording_parts (
  id int(11) NOT NULL AUTO_INCREMENT,
  call_id int(11) NOT NULL,
  h323_conf_id varchar(36) NOT NULL,
  i_customer int(11) NOT NULL,
  i_account int(11) NOT NULL,
  bill_time datetime NOT NULL,
  PRIMARY KEY (id)
)
ENGINE = INNODB,
CHARACTER SET utf8mb4,
COLLATE utf8mb4_unicode_ci;
 
CREATE TABLE IF NOT EXISTS calls (
  call_id int(11) NOT NULL,
  h323_conf_id varchar(36) NOT NULL,
  i_customer int(11) NOT NULL,
  i_account int(11) NOT NULL,
  bill_time datetime NOT NULL
)
ENGINE = INNODB,
CHARACTER SET utf8mb4,
COLLATE utf8mb4_unicode_ci;
 
--delimiter $$
 
CREATE
DEFINER = 'root'@'localhost'
TRIGGER calls_after_update
AFTER UPDATE
ON calls
FOR EACH ROW
BEGIN
  INSERT INTO recording_parts (call_id, h323_conf_id, i_customer, i_account, bill_time)
    VALUES (NEW.call_id, NEW.h323_conf_id, NEW.i_customer, NEW.i_account, NEW.bill_time);
END
$$
 
--delimiter ;
 
--sync_slave_with_master
 
DROP TRIGGER calls_after_update;
 
CREATE TABLE IF NOT EXISTS rec_test (
  call_id int(11) NOT NULL,
  h323_conf_id varchar(36) NOT NULL,
  i_customer int(11) NOT NULL,
  i_account int(11) NOT NULL,
  bill_time datetime NOT NULL
)
ENGINE = INNODB,
CHARACTER SET utf8mb4,
COLLATE utf8mb4_unicode_ci;
 
--delimiter $$
 
CREATE
DEFINER = 'root'@'localhost'
TRIGGER recording_parts_after_insert
AFTER INSERT
ON recording_parts
FOR EACH ROW
BEGIN
  INSERT INTO rec_test (call_id, h323_conf_id, i_customer, i_account, bill_time)
    VALUES (NEW.call_id, NEW.h323_conf_id, NEW.i_customer, NEW.i_account, NEW.bill_time);
END
$$
 
--delimiter ;
 
--connection master
 
INSERT INTO calls VALUES (1,'foo1',1,1,NOW());
UPDATE calls SET h323_conf_id = 'bar1';
SELECT * FROM recording_parts;
 
--sync_slave_with_master
SELECT * FROM recording_parts;
 
# Cleanup
DROP TABLE rec_test;
--connection master
DROP TABLE recording_parts, calls;
--source include/rpl_end.inc

10.1 debug 288212f489

mysqld: /data/src/10.1/sql/sql_trigger.cc:2175: bool Table_triggers_list::process_triggers(THD*, trg_event_type, trg_action_time_type, bool): Assertion `trigger_table->pos_in_table_list->trg_event_map & static_cas
t<uint>(1 << static_cast<int>(event))' failed.
180904 18:16:30 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f9d83248ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x000056467df843bb in Table_triggers_list::process_triggers (this=0x7f9d6c044a88, thd=0x7f9d6c060070, event=TRG_EVENT_INSERT, time_type=TRG_ACTION_AFTER, old_row_is_record1=true) at /data/src/10.1/sql/sql_trigger.cc:2174
#9  0x000056467e1fb2b7 in Rows_log_event::process_triggers (this=0x7f9d6c0b0230, event=TRG_EVENT_INSERT, time_type=TRG_ACTION_AFTER, old_row_is_record1=true) at /data/src/10.1/sql/log_event.cc:11533
#10 0x000056467e1fc13d in Rows_log_event::write_row (this=0x7f9d6c0b0230, rgi=0x7f9d6c016800, overwrite=false) at /data/src/10.1/sql/log_event.cc:11840
#11 0x000056467e1fc29f in Write_rows_log_event::do_exec_row (this=0x7f9d6c0b0230, rgi=0x7f9d6c016800) at /data/src/10.1/sql/log_event.cc:11863
#12 0x000056467e1f7f24 in Rows_log_event::do_apply_event (this=0x7f9d6c0b0230, rgi=0x7f9d6c016800) at /data/src/10.1/sql/log_event.cc:10149
#13 0x000056467de193a9 in Log_event::apply_event (this=0x7f9d6c0b0230, rgi=0x7f9d6c016800) at /data/src/10.1/sql/log_event.h:1343
#14 0x000056467de0ec69 in apply_event_and_update_pos_apply (ev=0x7f9d6c0b0230, thd=0x7f9d6c060070, rgi=0x7f9d6c016800, reason=0) at /data/src/10.1/sql/slave.cc:3479
#15 0x000056467de0f104 in apply_event_and_update_pos (ev=0x7f9d6c0b0230, thd=0x7f9d6c060070, rgi=0x7f9d6c016800) at /data/src/10.1/sql/slave.cc:3600
#16 0x000056467de0f906 in exec_relay_log_event (thd=0x7f9d6c060070, rli=0x7f9d7bb08cd0, serial_rgi=0x7f9d6c016800) at /data/src/10.1/sql/slave.cc:3885
#17 0x000056467de12b32 in handle_slave_sql (arg=0x7f9d7bb07000) at /data/src/10.1/sql/slave.cc:4981
#18 0x000056467e3a3540 in pfs_spawn_thread (arg=0x7f9d6d5c20f0) at /data/src/10.1/storage/perfschema/pfs.cc:1861
#19 0x00007f9d84f4c494 in start_thread (arg=0x7f9d8321bb00) at pthread_create.c:333
#20 0x00007f9d8330593f in clone () from /lib/x86_64-linux-gnu/libc.so.6

10.1 non-debug 288212f489

2018-09-04 18:18:00 140595623271168 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table test.recording_parts; Table 'test.rec_test' doesn't exist, Error_code: 1146; handler error HA_ERR_GENERIC; the event's master log master-bin.000001, end_log_pos 1907, Gtid 0-1-5, Internal MariaDB error code: 1146
2018-09-04 18:18:00 140595623271168 [Warning] Slave: Table 'test.rec_test' doesn't exist Error_code: 1146
2018-09-04 18:18:00 140595623271168 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 1624

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