Clean up and speed up interfaces for binary row logging (MDEV-21605)

[MDEV-21617] Assertion `binlog_table_maps == 0' failed in THD::reset_for_next_command Created: 2020-01-31  Updated: 2020-04-13  Resolved: 2020-02-08

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: N/A
Fix Version/s: N/A

Type: Technical task Priority: Major
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: logger

Issue Links:
Relates
relates to MDEV-22048 Assertion `binlog_table_maps == 0 || ... Closed

 Description   

--source include/have_innodb.inc
--source include/have_binlog_format_row.inc
 
CREATE TABLE t1 (
    id INT,
    k INT,
    c CHAR(8),
    KEY (k),
    PRIMARY KEY (id),
    FOREIGN KEY (id) REFERENCES t1 (k)
) ENGINE=InnoDB;
LOCK TABLES t1 WRITE;
SET SESSION FOREIGN_KEY_CHECKS= OFF;
SET AUTOCOMMIT=OFF;
INSERT INTO t1 VALUES (1,1,'foo');
DROP TABLE t1;

bb-10.5-monty cd129db8

mysqld: /data/src/bb-10.5-monty/sql/sql_parse.cc:7481: void THD::reset_for_next_command(bool): Assertion `binlog_table_maps == 0' failed.
200131 15:11:30 [ERROR] mysqld got signal 6 ;
 
#7  0x00007fbfedc62f12 in __GI___assert_fail (assertion=0x55c1bc00c8cd "binlog_table_maps == 0", file=0x55c1bc00b200 "/data/src/bb-10.5-monty/sql/sql_parse.cc", line=7481, function=0x55c1bc00e660 <THD::reset_for_next_command(bool)::__PRETTY_FUNCTION__> "void THD::reset_for_next_command(bool)") at assert.c:101
#8  0x000055c1bb2b9e8c in THD::reset_for_next_command (this=0x7fbfb0000b00, do_clear_error=true) at /data/src/bb-10.5-monty/sql/sql_parse.cc:7481
#9  0x000055c1bb2bb36d in mysql_parse (thd=0x7fbfb0000b00, rawbuf=0x7fbfb00135c8 "DROP TABLE t1", length=13, parser_state=0x7fbfe2f67570, is_com_multi=false, is_next_command=false) at /data/src/bb-10.5-monty/sql/sql_parse.cc:7931
#10 0x000055c1bb2a65a9 in dispatch_command (command=COM_QUERY, thd=0x7fbfb0000b00, packet=0x7fbfb01380a1 "DROP TABLE t1", packet_length=13, is_com_multi=false, is_next_command=false) at /data/src/bb-10.5-monty/sql/sql_parse.cc:1846
#11 0x000055c1bb2a4d03 in do_command (thd=0x7fbfb0000b00) at /data/src/bb-10.5-monty/sql/sql_parse.cc:1364
#12 0x000055c1bb446b85 in do_handle_one_connection (connect=0x55c1bf743810, put_in_cache=true) at /data/src/bb-10.5-monty/sql/sql_connect.cc:1422
#13 0x000055c1bb4468b4 in handle_one_connection (arg=0x55c1bf743810) at /data/src/bb-10.5-monty/sql/sql_connect.cc:1319
#14 0x000055c1bb9a312b in pfs_spawn_thread (arg=0x55c1bf666d30) at /data/src/bb-10.5-monty/storage/perfschema/pfs.cc:1869
#15 0x00007fbfefbeb4a4 in start_thread (arg=0x7fbfe2f68700) at pthread_create.c:456
#16 0x00007fbfedd1fd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Not reproducible on 10.5 main tree 74f76206.



 Comments   
Comment by Elena Stepanova [ 2020-01-31 ]

Also observed in THD::binlog_query:

bb-10.5-monty b834d1fc

mysqld: /home/elenst/src/bb-10.5-monty/sql/sql_class.cc:7295: int THD::binlog_query(THD::enum_binlog_query_type, const char*, ulong, bool, bool, bool, int): Assertion 
`binlog_table_maps == 0' failed.
200131 16:21:52 [ERROR] mysqld got signal 6 ;
 
#7  0x00007f54042f80d2 in __assert_fail () from /lib64/libc.so.6
#8  0x000055d742f084af in THD::binlog_query (this=0x7f5370000b00, qtype=THD::ROW_QUERY_TYPE, query_arg=0x7f5370012188 "REPLACE INTO ts9 (`from`,`to`) VALUES ( '2015-04-04', '2016-08-05') /* QNO 7463 CON_ID 12 */", query_len=92, is_trans=true, direct=false, suppress_use=false, errcode=0) at /home/elenst/src/bb-10.5-monty/sql/sql_class.cc:7295
#9  0x000055d742f26745 in mysql_insert (thd=0x7f5370000b00, table_list=0x7f53700122f0, fields=..., values_list=..., update_fields=..., update_values=..., duplic=DUP_REPLACE, ignore=false, result=0x0) at /home/elenst/src/bb-10.5-monty/sql/sql_insert.cc:1222
#10 0x000055d742f76bda in mysql_execute_command (thd=0x7f5370000b00) at /home/elenst/src/bb-10.5-monty/sql/sql_parse.cc:4507
#11 0x000055d742f8345a in mysql_parse (thd=0x7f5370000b00, rawbuf=0x7f5370012188 "REPLACE INTO ts9 (`from`,`to`) VALUES ( '2015-04-04', '2016-08-05') /* QNO 7463 CON_ID 12 */", length=92, parser_state=0x7f5400177480, is_com_multi=false, is_next_command=false) at /home/elenst/src/bb-10.5-monty/sql/sql_parse.cc:7990
#12 0x000055d742f6e5e8 in dispatch_command (command=COM_QUERY, thd=0x7f5370000b00, packet=0x7f53700086c1 "REPLACE INTO ts9 (`from`,`to`) VALUES ( '2015-04-04', '2016-08-05') /* QNO 7463 CON_ID 12 */ ", packet_length=93, is_com_multi=false, is_next_command=false) at /home/elenst/src/bb-10.5-monty/sql/sql_parse.cc:1846
#13 0x000055d742f6cc86 in do_command (thd=0x7f5370000b00) at /home/elenst/src/bb-10.5-monty/sql/sql_parse.cc:1364
#14 0x000055d743110ddf in do_handle_one_connection (connect=0x55d747f562e0, put_in_cache=true) at /home/elenst/src/bb-10.5-monty/sql/sql_connect.cc:1422
#15 0x000055d743110aee in handle_one_connection (arg=0x55d747f562e0) at /home/elenst/src/bb-10.5-monty/sql/sql_connect.cc:1319
#16 0x00007f540620fdd5 in start_thread () from /lib64/libpthread.so.0
#17 0x00007f54043c6ead in clone () from /lib64/libc.so.6

Comment by Michael Widenius [ 2020-02-08 ]

The problem was not exact enough asserts. Would have worked in non debug builds.
Have fixed one of the asserts and replaced other with a code comment

Comment by Michael Widenius [ 2020-02-08 ]

Fix pushed to bb-10.5-monty

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