[MDEV-8203] Assertion `!current_stmt_is_commit || !rgi->tables_to_lock' failed in Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32) Created: 2015-05-21  Updated: 2020-04-22  Resolved: 2019-04-22

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.1, 10.2
Fix Version/s: 10.3.0

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-19302 Assertion `!current_stmt_is_commit ||... Closed
relates to MDEV-22338 Assertion `!current_stmt_is_commit ||... Stalled

 Description   

Stack trace from 10.1 commit 536112dd

 
10.1/sql/log_event.cc:4103: int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32): Assertion `!current_stmt_is_commit || !rgi->tables_to_lock' failed.
 
150521 19:33:11 [ERROR] mysqld got signal 6 ;
 
 
 
#6  0x00007f411ca86311 in *__GI___assert_fail (assertion=0x7f411fe19f88 "!current_stmt_is_commit || !rgi->tables_to_lock", file=<optimized out>, line=4103, function=0x7f411fe1e240 "int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32)") at assert.c:81
 
#7  0x00007f411f6e3250 in Query_log_event::do_apply_event (this=0x7f410e8b0230, rgi=0x7f410e820800, query_arg=0x7f410e885579 "COMMIT", q_len_arg=6) at 10.1/sql/log_event.cc:4103
 
#8  0x00007f411f6e2f73 in Query_log_event::do_apply_event (this=0x7f410e8b0230, rgi=0x7f410e820800) at 10.1/sql/log_event.cc:4013
 
#9  0x00007f411f32a6c9 in Log_event::apply_event (this=0x7f410e8b0230, rgi=0x7f410e820800) at 10.1/sql/log_event.h:1347
 
#10 0x00007f411f32026f in apply_event_and_update_pos (ev=0x7f410e8b0230, thd=0x7f410e849070, rgi=0x7f410e820800, rpt=0x0) at 10.1/sql/slave.cc:3274
 
#11 0x00007f411f320a86 in exec_relay_log_event (thd=0x7f410e849070, rli=0x7f410fc0ac40, serial_rgi=0x7f410e820800) at 10.1/sql/slave.cc:3577
 
#12 0x00007f411f323d68 in handle_slave_sql (arg=0x7f410fc09000) at 10.1/sql/slave.cc:4677
 
#13 0x00007f411faa61a2 in pfs_spawn_thread (arg=0x7f411c01fc70) at 10.1/storage/perfschema/pfs.cc:1860
 
#14 0x00007f411eaa1b50 in start_thread (arg=<optimized out>) at pthread_create.c:304
 
#15 0x00007f411cb3695d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:112


--source include/master-slave.inc
 
--source include/have_innodb.inc
 
--source include/have_binlog_format_row.inc
 
 
 
CREATE TABLE t1 (i INT) ENGINE=InnoDB;
 
CREATE TABLE t2 (j INT) ENGINE=MyISAM;
 
 
 
--delimiter ||
 
CREATE TRIGGER tr AFTER INSERT ON t1 FOR EACH ROW 
BEGIN 
  SET @a = unknown_column_just_to_raise_an_error; 
  INSERT INTO t2 VALUES (NULL) ; 
END||
 
--delimiter ;
 
 
 
--error ER_BAD_FIELD_ERROR
 
INSERT INTO t1 VALUES (1);
 
 
 
--sync_slave_with_master



 Comments   
Comment by Elena Stepanova [ 2016-04-09 ]

Still happens on current 10.1 and 10.2.

Comment by Elena Stepanova [ 2017-03-23 ]

Still happens on 10.1 and 10.2

Comment by Michael Widenius [ 2017-04-06 ]

This happens because the master writes a table_map event to the binary log, but no row event.
The slave has a check that there should always be a row event if there was a table_map event, which
causes a crash.

I have fixed this for 10.3 by remembering all event types written to the log and not writing 'dummy' events to
the log. The fix is rather big so I propose the following for 10.1 and 10.2

int Query_log_event::do_apply_event(rpl_group_info *rgi,
const char *query_arg, uint32 q_len_arg)

Change
DBUG_ASSERT(!current_stmt_is_commit || !rgi->tables_to_lock);
to
#ifdef MYSQL_VERSION_ID >= 100300
DBUG_ASSERT(!current_stmt_is_commit || !rgi->tables_to_lock);
#endif

In 10.3 we have to also check that the master > 10.3.0

I have checked the code and this is ok to do.

Comment by Elena Stepanova [ 2019-04-22 ]

I assume it stayed open by mistake – there had been commits in main trees (and hence in change logs) fixing it, and indeed, it's not reproducible any longer with this particular scenario in 10.3+.

Comment by Alice Sherepa [ 2019-04-23 ]

I got something similar on 10.4, once:

2019-02-14 
mysqld: /git/10.4/sql/log_event.cc:5464: int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32): Assertion `!current_stmt_is_commit || !rgi->tables_to_lock' failed.
 
190214 18:34:41 [ERROR] mysqld got signal 6 ;
 
Server version: 10.4.3-MariaDB-debug-log
 
 
 
linux/raise.c:54(__GI_raise)[0x7ff4a563ebd7]
 
stdlib/abort.c:91(__GI_abort)[0x7ff4a563ec82]
 
/git/10.4/sql/mysqld(_ZN15Query_log_event14do_apply_eventEP14rpl_group_infoPKcj+0x9f0)[0x55b7f3c60d2a]
 
sql/log_event.cc:5465(Query_log_event::do_apply_event(rpl_group_info*, char const*, unsigned int))[0x55b7f3c6029f]
 
sql/log_event.cc:5359(Query_log_event::do_apply_event(rpl_group_info*))[0x55b7f300975d]
 
sql/log_event.h:1481(Log_event::apply_event(rpl_group_info*))[0x55b7f2ff0748]
 
sql/slave.cc:3950(apply_event_and_update_pos_apply(Log_event*, THD*, rpl_group_info*, int))[0x55b7f2ff115a]
 
sql/slave.cc:4105(apply_event_and_update_pos(Log_event*, THD*, rpl_group_info*))[0x55b7f2ff2651]
 
sql/slave.cc:4425(exec_relay_log_event(THD*, Relay_log_info*, rpl_group_info*))[0x55b7f2ff8a19]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x76ba)[0x7ff4a64876ba]
 
x86_64/clone.S:111(clone)[0x7ff4a571841d]

Comment by Elena Stepanova [ 2019-04-23 ]

alice,

I got something similar on 10.4, once

This is likely to be MDEV-19302.

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