Datadir from master and slave attached.
The assertion is reproducible on 10.5 30c9833751529d4039 (I haven't checked versions before 10.5 yet). To reproduce I started slave with (default cnf+ --slave-skip-errors=all) and then pointed it in binlog from master, where the problem occurred :
change master to master_host='localhost', master_port=3306, master_user='root', MASTER_LOG_FILE='mysql-bin.000001', MASTER_LOG_POS=1728186; start slave;
Attachments
Issue Links
relates to
MDEV-8203Assertion `!current_stmt_is_commit || !rgi->tables_to_lock' failed in Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32)
Closed
MDEV-19302Assertion `!current_stmt_is_commit || !rgi->tables_to_lock' failed in Query_log_event::do_apply_event
#8 0x000055f79a58ea63 in Query_log_event::do_apply_event (this=0x7faeb8474070, rgi=0x7faeb8404000, query_arg=0x7faeb842897b "COMMIT", q_len_arg=6) at /10.1/sql/log_event.cc:4332
#9 0x000055f79a58e691 in Query_log_event::do_apply_event (this=0x7faeb8474070, rgi=0x7faeb8404000) at /10.1/sql/log_event.cc:4226
#10 0x000055f79a1b6a01 in Log_event::apply_event (this=0x7faeb8474070, rgi=0x7faeb8404000) at /10.1/sql/log_event.h:1343
#11 0x000055f79a1ac44a in apply_event_and_update_pos_apply (ev=0x7faeb8474070, thd=0x7faeb8418130, rgi=0x7faeb8404000, reason=0) at /10.1/sql/slave.cc:3482
#12 0x000055f79a1ac820 in apply_event_and_update_pos (ev=0x7faeb8474070, thd=0x7faeb8418130, rgi=0x7faeb8404000) at /10.1/sql/slave.cc:3603
#13 0x000055f79a1ace7d in exec_relay_log_event (thd=0x7faeb8418130, rli=0x7faec9c3ead0, serial_rgi=0x7faeb8404000) at /10.1/sql/slave.cc:3884
#14 0x000055f79a1b0013 in handle_slave_sql (arg=0x7faec9c3ce00) at /10.1/sql/slave.cc:4987
#15 0x000055f79a7ae252 in pfs_spawn_thread (arg=0x7faeb9214070) at /10.1/storage/perfschema/pfs.cc:1868
#16 0x00007faed13cafa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#17 0x00007faed0a8f4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Alice Sherepa
added a comment -
--source include/have_innodb.inc
--source include/have_binlog_format_mixed_or_row.inc
--source include/master-slave.inc
CREATE TABLE t1 (id int ) engine=innodb;
CREATE TABLE t2 (id int ) engine=myisam;
CREATE TRIGGER t2 BEFORE INSERT ON t2 FOR EACH ROW DELETE FROM t1 LIMIT 1;
INSERT INTO t2 VALUES (1);
--sync_slave_with_master
# Cleanup
--connection master
DROP TABLE t1,t2;
--source include/rpl_end.inc
10.1 29851b677ebbd954278d5530
#3 <signal handler called>
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#5 0x00007faed09b8535 in __GI_abort () at abort.c:79
#6 0x00007faed09b840f in __assert_fail_base (fmt=0x7faed0b1aee0 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=0x55f79acc1fc8 "!current_stmt_is_commit || !rgi->tables_to_lock", file=0x55f79acbfff0 "/10.1/sql/log_event.cc", line=4332, function=<optimized out>) at assert.c:92
#7 0x00007faed09c6102 in __GI___assert_fail (assertion=0x55f79acc1fc8 "!current_stmt_is_commit || !rgi->tables_to_lock", file=0x55f79acbfff0 "/10.1/sql/log_event.cc", line=4332, function=0x55f79acc51e0 <Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int)::__PRETTY_FUNCTION__> "int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32)") at assert.c:101
#8 0x000055f79a58ea63 in Query_log_event::do_apply_event (this=0x7faeb8474070, rgi=0x7faeb8404000, query_arg=0x7faeb842897b "COMMIT", q_len_arg=6) at /10.1/sql/log_event.cc:4332
#9 0x000055f79a58e691 in Query_log_event::do_apply_event (this=0x7faeb8474070, rgi=0x7faeb8404000) at /10.1/sql/log_event.cc:4226
#10 0x000055f79a1b6a01 in Log_event::apply_event (this=0x7faeb8474070, rgi=0x7faeb8404000) at /10.1/sql/log_event.h:1343
#11 0x000055f79a1ac44a in apply_event_and_update_pos_apply (ev=0x7faeb8474070, thd=0x7faeb8418130, rgi=0x7faeb8404000, reason=0) at /10.1/sql/slave.cc:3482
#12 0x000055f79a1ac820 in apply_event_and_update_pos (ev=0x7faeb8474070, thd=0x7faeb8418130, rgi=0x7faeb8404000) at /10.1/sql/slave.cc:3603
#13 0x000055f79a1ace7d in exec_relay_log_event (thd=0x7faeb8418130, rli=0x7faec9c3ead0, serial_rgi=0x7faeb8404000) at /10.1/sql/slave.cc:3884
#14 0x000055f79a1b0013 in handle_slave_sql (arg=0x7faec9c3ce00) at /10.1/sql/slave.cc:4987
#15 0x000055f79a7ae252 in pfs_spawn_thread (arg=0x7faeb9214070) at /10.1/storage/perfschema/pfs.cc:1868
#16 0x00007faed13cafa3 in start_thread (arg=<optimized out>) at pthread_create.c:486
#17 0x00007faed0a8f4cf in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
#8 0x00005600fa476335 in Query_log_event::do_apply_event (this=0x7fc00802c4d8, rgi=0x7fc008000cf0, query_arg=0x7fc0089772c3 "COMMIT", q_len_arg=6) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event_server.cc:1667
#9 0x00005600fa475f11 in Query_log_event::do_apply_event (this=0x7fc00802c4d8, rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event_server.cc:1561
#10 0x00005600f9ebe845 in Log_event::apply_event (this=0x7fc00802c4d8, rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event.h:1496
#11 0x00005600f9eb13a0 in apply_event_and_update_pos_apply (ev=0x7fc00802c4d8, thd=0x7fc008001a48, rgi=0x7fc008000cf0, reason=0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:4003
#12 0x00005600f9eb1975 in apply_event_and_update_pos (ev=0x7fc00802c4d8, thd=0x7fc008001a48, rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:4165
#13 0x00005600f9eb2316 in exec_relay_log_event (thd=0x7fc008001a48, rli=0x5600fe73f328, serial_rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:4486
#14 0x00005600f9eb5c58 in handle_slave_sql (arg=0x5600fe73d660) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:5659
#15 0x00005600fa693cb9 in pfs_spawn_thread (arg=0x7fc01c195e98) at /home/sujatha/bug_repo/MDEV-22338-10.5/storage/perfschema/pfs.cc:2201
#16 0x00007fc050f5d6db in start_thread (arg=0x7fc04822e700) at pthread_create.c:463
#17 0x00007fc0500f8a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
Sujatha Sivakumar (Inactive)
added a comment - Test case to reproduce the issue on 10.5:
--source include/have_innodb.inc
--source include/have_binlog_format_mixed.inc
--source include/master-slave.inc
CREATE TABLE t1(f INT) ENGINE=innodb;
CREATE VIEW v_t1 AS SELECT * FROM t1;
CREATE TABLE tm(f INT) ENGINE=MYISAM;
CREATE TABLE t2(id INT AUTO_INCREMENT, i INT, PRIMARY KEY (id)) ENGINE=INNODB;
CREATE TABLE t3(f INT) ENGINE=MYISAM;
CREATE TRIGGER trig1 BEFORE INSERT ON tm FOR EACH ROW INSERT INTO t2(i) SELECT * FROM t3 LIMIT 0;
BEGIN;
DELETE FROM v_t1 WHERE f=0;
INSERT INTO tm VALUES (2);
COMMIT;
--sync_slave_with_master
--connection master
DROP TABLE t1,t2,t3,tm;
--source incude/rpl_end.inc
Problematic Binlog Output:
======================
#200806 15:12:46 server id 1 end_log_pos 2107 CRC32 0x8191997a GTID 0-1-9 trans
/*!100001 SET @@session.gtid_seq_no=9*//*!*/;
BEGIN
/*!*/;
# at 2107
#200806 15:12:46 server id 1 end_log_pos 2200 CRC32 0x07386b19 Query thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1596706966/*!*/;
DELETE FROM v_t1 WHERE f=0
/*!*/;
# at 2200
#200806 15:12:46 server id 1 end_log_pos 2246 CRC32 0x95b8e22b Table_map: `test`.`t2` mapped to number 38
# at 2246
#200806 15:12:46 server id 1 end_log_pos 2319 CRC32 0x1c05f94d Query thread_id=9 exec_time=0 error_code=0
SET TIMESTAMP=1596706966/*!*/;
COMMIT
/*!*/;
DELIMITER ;
Issue:
=====
Table map event is not followed by a row event. ( MDEV-8203 ).
Assert stack:
==========
Thread 1 (Thread 0x7fc04822e700 (LWP 10333)):
#0 __pthread_kill (threadid=<optimized out>, signo=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1 0x00005600fac6aa79 in my_write_core (sig=6) at /home/sujatha/bug_repo/MDEV-22338-10.5/mysys/stacktrace.c:518
#2 0x00005600fa31082e in handle_fatal_signal (sig=6) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/signal_handler.cc:330
#3 <signal handler called>
#4 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#5 0x00007fc0500178b1 in __GI_abort () at abort.c:79
#6 0x00007fc05000742a in __assert_fail_base (fmt=0x7fc05018ea38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x5600fb05ba10 "!current_stmt_is_commit || !rgi->tables_to_lock", file=file@entry=0x5600fb05aaf8 "/home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event_server.cc", line=line@entry=1667, function=function@entry=0x5600fb05ebc0 <Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int)::__PRETTY_FUNCTION__> "int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32)") at assert.c:92
#7 0x00007fc0500074a2 in __GI___assert_fail (assertion=0x5600fb05ba10 "!current_stmt_is_commit || !rgi->tables_to_lock", file=0x5600fb05aaf8 "/home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event_server.cc", line=1667, function=0x5600fb05ebc0 <Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int)::__PRETTY_FUNCTION__> "int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32)") at assert.c:101
#8 0x00005600fa476335 in Query_log_event::do_apply_event (this=0x7fc00802c4d8, rgi=0x7fc008000cf0, query_arg=0x7fc0089772c3 "COMMIT", q_len_arg=6) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event_server.cc:1667
#9 0x00005600fa475f11 in Query_log_event::do_apply_event (this=0x7fc00802c4d8, rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event_server.cc:1561
#10 0x00005600f9ebe845 in Log_event::apply_event (this=0x7fc00802c4d8, rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/log_event.h:1496
#11 0x00005600f9eb13a0 in apply_event_and_update_pos_apply (ev=0x7fc00802c4d8, thd=0x7fc008001a48, rgi=0x7fc008000cf0, reason=0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:4003
#12 0x00005600f9eb1975 in apply_event_and_update_pos (ev=0x7fc00802c4d8, thd=0x7fc008001a48, rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:4165
#13 0x00005600f9eb2316 in exec_relay_log_event (thd=0x7fc008001a48, rli=0x5600fe73f328, serial_rgi=0x7fc008000cf0) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:4486
#14 0x00005600f9eb5c58 in handle_slave_sql (arg=0x5600fe73d660) at /home/sujatha/bug_repo/MDEV-22338-10.5/sql/slave.cc:5659
#15 0x00005600fa693cb9 in pfs_spawn_thread (arg=0x7fc01c195e98) at /home/sujatha/bug_repo/MDEV-22338-10.5/storage/perfschema/pfs.cc:2201
#16 0x00007fc050f5d6db in start_thread (arg=0x7fc04822e700) at pthread_create.c:463
#17 0x00007fc0500f8a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
This issue is a duplicate of MDEV-8203 and the fix was pushed into 10.3+
version. The assert still exists in 10.3+ version in case of mixed mode
replication. The main idea of MDEV-8203 patch is to remember the set of events
written into the cache and ignore/reset the cache content if it has only
Table_Map event. This fix works for row based replication mode but it fails
with mixed based replication as the cache contains a combination of
Query_log_events and Table_Map event. Hence reverted the patch. Following fix
is implemented.
Fix:
====
Replace the assert with if-else check. In a case where TABLE_MAP event is not
followed by rows event invoke 'rows_event_stmt_cleanup' to initiate
appropriate cleanup.
Sujatha Sivakumar (Inactive)
added a comment - Hello Andrei,
Can you please review the fix for MDEV-22338 .
10.1 Patch :
https://github.com/MariaDB/server/commit/0664e1e766d303187b381ace1c53547d1821e35c
Test results : http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha
10.3 Patch :
https://github.com/MariaDB/server/commit/f3b3b2fb542327ce4e799c546acb00f1a35a8df7
Test results : http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.3-sujatha
This issue is a duplicate of MDEV-8203 and the fix was pushed into 10.3+
version. The assert still exists in 10.3+ version in case of mixed mode
replication. The main idea of MDEV-8203 patch is to remember the set of events
written into the cache and ignore/reset the cache content if it has only
Table_Map event. This fix works for row based replication mode but it fails
with mixed based replication as the cache contains a combination of
Query_log_events and Table_Map event. Hence reverted the patch. Following fix
is implemented.
Fix:
====
Replace the assert with if-else check. In a case where TABLE_MAP event is not
followed by rows event invoke 'rows_event_stmt_cleanup' to initiate
appropriate cleanup.
Hello alice,
Please assign this issue back to me along with simplified set of queries.
Thank you.