Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.4(EOL)
-
None
Description
Note: There was a bug report with a similar assertion failure, MDEV-8203. But even thought it's not closed in JIRA, there had been commits for MDEV-8203 in main trees (and hence in change logs) fixing it, and indeed, it's not reproducible any longer with that particular scenario in 10.3+.
--source include/have_innodb.inc
|
--source include/have_binlog_format_mixed_or_row.inc
|
--source include/master-slave.inc
|
|
|
CREATE TABLE t1 (a INT) ENGINE=MyISAM; |
CREATE TABLE t2 (b INT); |
CREATE TABLE t3 (c INT) ENGINE=InnoDB; |
--delimiter $
|
CREATE TRIGGER d AFTER UPDATE ON t1 FOR EACH ROW |
BEGIN
|
UPDATE t2 SET b = 0 LIMIT 0; |
INSERT INTO t3 VALUES (NULL); |
CALL x();
|
END $ |
--delimiter ;
|
INSERT INTO t1 VALUES (1); |
--error ER_SP_DOES_NOT_EXIST
|
UPDATE t1 SET a = 0; |
|
|
--sync_slave_with_master
|
|
|
# Cleanup
|
--connection master
|
DROP TABLE t1, t2, t3; |
--source include/rpl_end.inc |
|
10.4 a65d3b2c |
mysqld: /data/src/10.4/sql/log_event.cc:5479: int Query_log_event::do_apply_event(rpl_group_info*, const char*, uint32): Assertion `!current_stmt_is_commit || !rgi->tables_to_lock' failed.
|
190422 16:00:39 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007fae1d785ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x0000562a574cc884 in Query_log_event::do_apply_event (this=0x7fadb0031040, rgi=0x7fadb0000a90, query_arg=0x7fadb00a4b4b "COMMIT", q_len_arg=6) at /data/src/10.4/sql/log_event.cc:5479
|
#9 0x0000562a574cc4a3 in Query_log_event::do_apply_event (this=0x7fadb0031040, rgi=0x7fadb0000a90) at /data/src/10.4/sql/log_event.cc:5373
|
#10 0x0000562a56f64013 in Log_event::apply_event (this=0x7fadb0031040, rgi=0x7fadb0000a90) at /data/src/10.4/sql/log_event.h:1482
|
#11 0x0000562a56f57620 in apply_event_and_update_pos_apply (ev=0x7fadb0031040, thd=0x7fadb0001560, rgi=0x7fadb0000a90, reason=0) at /data/src/10.4/sql/slave.cc:3953
|
#12 0x0000562a56f57c52 in apply_event_and_update_pos (ev=0x7fadb0031040, thd=0x7fadb0001560, rgi=0x7fadb0000a90) at /data/src/10.4/sql/slave.cc:4107
|
#13 0x0000562a56f5868c in exec_relay_log_event (thd=0x7fadb0001560, rli=0x562a5a2920d8, serial_rgi=0x7fadb0000a90) at /data/src/10.4/sql/slave.cc:4428
|
#14 0x0000562a56f5be6f in handle_slave_sql (arg=0x562a5a290410) at /data/src/10.4/sql/slave.cc:5592
|
#15 0x0000562a575ea2f5 in pfs_spawn_thread (arg=0x7fadc4049160) at /data/src/10.4/storage/perfschema/pfs.cc:1862
|
#16 0x00007fae1f87a494 in start_thread (arg=0x7fae129b3700) at pthread_create.c:333
|
#17 0x00007fae1d84293f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
Not reproducible on 10.3.
No obvious problems on a non-debug build.
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Stalled
-
This issue is already fixed as part of MDEV:18300's fix.
Analysis: During the execution of stored procedure the table map event gets
written twice in the binlog as shown below. Observe that table map event is
written for INSERT statement as shown below. Because of this additional
table_map event slave reports an assert.
### UPDATE `test`.`t1`### WHERE### @1=1### SET### @1=0# Number of rows: 1# at 1461# at 1512#190610 13:40:01 server id 1 end_log_pos 1512 CRC32 0x047a074c Annotate_rows:#Q> INSERT INTO t3 VALUES (NULL)#190610 13:40:01 server id 1 end_log_pos 1557 CRC32 0x5213bc91 Table_map: `test`.`t1` mapped to number 33 (has triggers)# at 1557#190610 13:40:01 server id 1 end_log_pos 1602 CRC32 0x42051901 Table_map: `test`.`t2` mapped to number 35# at 1602#190610 13:40:01 server id 1 end_log_pos 1675 CRC32 0x79539423 Query thread_id=14 exec_time=0 error_code=0SET TIMESTAMP=1560154201/*!*/;COMMIT/*!*/;# at 1675#190610 13:40:01 server id 1 end_log_pos 1717 CRC32 0x4d9da44c GTID 0-1-7 trans/*!100001 SET @@session.gtid_seq_no=7*//*!*/;BEGIN/*!*/;# at 1717#190610 13:40:01 server id 1 end_log_pos 1762 CRC32 0x72308344 Table_map: `test`.`t3` mapped to number 34# at 1762#190610 13:40:01 server id 1 end_log_pos 1807 CRC32 0x974f13e4 Table_map: `test`.`t3` mapped to number 34# at 1807#190610 13:40:01 server id 1 end_log_pos 1841 CRC32 0x9c5e0f41 Write_rows: table id 34 flags: STMT_END_FAt the time of execution of INSERT statement on the master, code tries to read
the statistics of the table. Since the statistics are not available, system
tables are opened for reading stats and then they are closed. During this
process the pending events get written into binlog and they also clear
existing table_maps that were prepared during update statement. Hence when
code reaches a place where it has to write insert into the binary log it finds
no table maps and re-writes them once again. This leads to an assert on slave.
As part of
MDEV-18300patch 'read_statistics_for_tables_if_needed' is addedwithin "mysql_update" code. Since stats are already calculated during 'update'
statement execution the following 'insert' doesn't have to recalculate stats
and table_maps get retained so no additional table_map event is written.
Binlog is clear.
Hence closing this issue as fixed.