[MDEV-22757] Assertion `!binlog || exist_hton_without_prepare' failed in MYSQL_BIN_LOG::unlog_xa_prepare - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 10.5
Fix Version/s: 10.5.10
Component/s: Replication, XA
Labels:
- regression

Description

--source include/have_innodb.inc

--source include/have_log_bin.inc

CREATE TABLE t1 (a INT) ENGINE=MyISAM;

INSERT INTO t1 VALUES (1),(2);

CREATE TABLE t2 (id INT PRIMARY KEY) ENGINE=InnoDB;

INSERT INTO t2 VALUES (1),(2);

XA BEGIN 'x';

REPLACE INTO t1 SELECT * FROM t1;

REPLACE INTO t2 SELECT * FROM t2;

XA END 'x';

XA PREPARE 'x';

# Cleanup

XA COMMIT 'x';

DROP TABLE t1, t2;

10.5 043828bd
mariadbd: /data/src/10.5/sql/log.cc:10149: virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool): Assertion `!binlog \|\| exist_hton_without_prepare' failed.
200530 22:26:14 [ERROR] mysqld got signal 6 ;

#7 0x00007f2f370dff12 in __GI___assert_fail (assertion=0x556040115270 "!binlog \|\| exist_hton_without_prepare", file=0x556040111394 "/data/src/10.5/sql/log.cc", line=10149, function=0x556040117aa0 <MYSQL_BIN_LOG::unlog_xa_prepare(THD, bool)::__PRETTY_FUNCTION__> "virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD, bool)") at assert.c:101
#8 0x000055603f5f2974 in MYSQL_BIN_LOG::unlog_xa_prepare (this=0x556040d00120 <mysql_bin_log>, thd=0x7f2f00000b18, all=true) at /data/src/10.5/sql/log.cc:10149
#9 0x000055603f4af35b in ha_prepare (thd=0x7f2f00000b18) at /data/src/10.5/sql/handler.cc:1361
#10 0x000055603f3e4886 in trans_xa_prepare (thd=0x7f2f00000b18) at /data/src/10.5/sql/xa.cc:531
#11 0x000055603f1603f0 in mysql_execute_command (thd=0x7f2f00000b18) at /data/src/10.5/sql/sql_parse.cc:5802
#12 0x000055603f166fb9 in mysql_parse (thd=0x7f2f00000b18, rawbuf=0x7f2f00013a70 "XA PREPARE 'x'", length=14, parser_state=0x7f2f3061b520, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:7991
#13 0x000055603f153365 in dispatch_command (command=COM_QUERY, thd=0x7f2f00000b18, packet=0x7f2f000087c9 "XA PREPARE 'x'", packet_length=14, is_com_multi=false, is_next_command=false) at /data/src/10.5/sql/sql_parse.cc:1875
#14 0x000055603f151a9d in do_command (thd=0x7f2f00000b18) at /data/src/10.5/sql/sql_parse.cc:1356
#15 0x000055603f2f55fb in do_handle_one_connection (connect=0x556043972d58, put_in_cache=true) at /data/src/10.5/sql/sql_connect.cc:1411
#16 0x000055603f2f5363 in handle_one_connection (arg=0x556043972d58) at /data/src/10.5/sql/sql_connect.cc:1313
#17 0x000055603f82c2de in pfs_spawn_thread (arg=0x556043912ed8) at /data/src/10.5/storage/perfschema/pfs.cc:2201
#18 0x00007f2f390684a4 in start_thread (arg=0x7f2f3061c700) at pthread_create.c:456
#19 0x00007f2f3719cd0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97

Not reproducible on 10.4.
No obvious effect on a non-debug build.

Attachments

Issue Links

relates to

MDEV-22430 Assertion `ha_info->ht() != binlog_hton' failed in MYSQL_BIN_LOG::unlog_xa_prepare

Closed

Activity

Ascending order - Click to sort in descending order

Elena Stepanova created issue - 2020-05-30 19:27

Andrei Elkin made changes - 2020-06-04 17:08

Field	Original Value	New Value
Status	Open [ 1 ]	In Progress [ 3 ]

Andrei Elkin added a comment - 2020-06-08 08:52

Sergei, the patch is a74e724e061a, which also covers ~~MDEV-22430~~.

Andrei Elkin added a comment - 2020-06-08 08:52 Sergei, the patch is a74e724e061a, which also covers MDEV-22430 .

Andrei Elkin made changes - 2020-06-08 08:52

Assignee	Andrei Elkin [ elkin ]	Sergei Golubchik [ serg ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Sergei Golubchik made changes - 2020-06-16 22:04

Assignee	Sergei Golubchik [ serg ]	Andrei Elkin [ elkin ]
Status	In Review [ 10002 ]	Stalled [ 10000 ]

Roel Van de Paar added a comment - 2020-07-14 00:41

# mysqld options required for replay: --log-bin

USE test;

#SET SQL_MODE='';

CREATE TABLE t1 (a INT, KEY(a)) ENGINE=MyISAM;

CREATE TABLE t2 (a INT, b INT) ENGINE=InnoDB;

XA START 'a';

INSERT INTO t2 VALUES (1);

SAVEPOINT sp;

INSERT INTO t2 VALUES (1,1);

ROLLBACK TO sp;

INSERT INTO t1 VALUES (1);

XA END 'a';

XA PREPARE 'a';

Leads to:

10.5.5 e1013725ce0f3f947e728491eef75d9985e8db2f
mysqld: /test/10.5_dbg/sql/log.cc:10156: virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool): Assertion `!binlog \|\| exist_hton_without_prepare' failed.

10.5.5 e1013725ce0f3f947e728491eef75d9985e8db2f
Core was generated by `/test/MD250620-mariadb-10.5.5-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'.
Program terminated with signal SIGABRT, Aborted.
#0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6)
at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
[Current thread is 1 (Thread 0x151831c83700 (LWP 135616))]
(gdb) bt
#0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57
#1 0x0000561d7d45a7d0 in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518
#2 0x0000561d7cc1347a in handle_fatal_signal (sig=6) at /test/10.5_dbg/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 0x000015182ff648b1 in __GI_abort () at abort.c:79
#6 0x000015182ff5442a in __assert_fail_base (fmt=0x1518300dba38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x561d7d797580 "!binlog \|\| exist_hton_without_prepare", file=file@entry=0x561d7d793967 "/test/10.5_dbg/sql/log.cc", line=line@entry=10156, function=function@entry=0x561d7d798640 <MYSQL_BIN_LOG::unlog_xa_prepare(THD, bool)::__PRETTY_FUNCTION__> "virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD, bool)") at assert.c:92
#7 0x000015182ff544a2 in __GI___assert_fail (assertion=assertion@entry=0x561d7d797580 "!binlog \|\| exist_hton_without_prepare", file=file@entry=0x561d7d793967 "/test/10.5_dbg/sql/log.cc", line=line@entry=10156, function=function@entry=0x561d7d798640 <MYSQL_BIN_LOG::unlog_xa_prepare(THD, bool)::__PRETTY_FUNCTION__> "virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD, bool)") at assert.c:101
#8 0x0000561d7cd57990 in MYSQL_BIN_LOG::unlog_xa_prepare (this=0x561d7e1db940 <mysql_bin_log>, thd=0x15180dc15088, all=<optimized out>) at /test/10.5_dbg/sql/log.cc:10156
#9 0x0000561d7cc2bcd4 in ha_prepare (thd=thd@entry=0x15180dc15088) at /test/10.5_dbg/sql/handler.cc:1399
#10 0x0000561d7cb7ebf2 in trans_xa_prepare (thd=thd@entry=0x15180dc15088) at /test/10.5_dbg/sql/xa.cc:531
#11 0x0000561d7c96d740 in mysql_execute_command (thd=thd@entry=0x15180dc15088) at /test/10.5_dbg/sql/sql_parse.cc:5805
#12 0x0000561d7c975638 in mysql_parse (thd=thd@entry=0x15180dc15088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x151831c82350, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7995
#13 0x0000561d7c962110 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x15180dc15088, packet=packet@entry=0x15180dc67089 "XA PREPARE 'a'", packet_length=packet_length@entry=14, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1874
#14 0x0000561d7c9608ea in do_command (thd=0x15180dc15088) at /test/10.5_dbg/sql/sql_parse.cc:1355
#15 0x0000561d7cabc15f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x151810cd9f08, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411
#16 0x0000561d7cabc87b in handle_one_connection (arg=arg@entry=0x151810cd9f08) at /test/10.5_dbg/sql/sql_connect.cc:1313
#17 0x0000561d7cf1f11c in pfs_spawn_thread (arg=0x15182e846788) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201
#18 0x0000151830c476db in start_thread (arg=0x151831c83700) at pthread_create.c:463
#19 0x0000151830045a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Bug confirmed present in:
MariaDB: 10.5.5 (dbg)

Bug confirmed not present in:
MariaDB: 10.1.46 (dbg), 10.1.46 (opt), 10.2.33 (dbg), 10.2.33 (opt), 10.3.24 (dbg), 10.3.24 (opt), 10.4.14 (dbg), 10.4.14 (opt), 10.5.5 (opt)
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

Roel Van de Paar added a comment - 2020-07-14 00:41 # mysqld options required for replay: --log-bin USE test; #SET SQL_MODE=''; CREATE TABLE t1 (a INT, KEY(a)) ENGINE=MyISAM; CREATE TABLE t2 (a INT, b INT) ENGINE=InnoDB; XA START 'a'; INSERT INTO t2 VALUES (1); SAVEPOINT sp; INSERT INTO t2 VALUES (1,1); ROLLBACK TO sp; INSERT INTO t1 VALUES (1); XA END 'a'; XA PREPARE 'a'; Leads to: 10.5.5 e1013725ce0f3f947e728491eef75d9985e8db2f mysqld: /test/10.5_dbg/sql/log.cc:10156: virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool): Assertion `!binlog || exist_hton_without_prepare' failed. 10.5.5 e1013725ce0f3f947e728491eef75d9985e8db2f Core was generated by `/test/MD250620-mariadb-10.5.5-linux-x86_64-dbg/bin/mysqld --no-defaults --core-'. Program terminated with signal SIGABRT, Aborted. #0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57 [Current thread is 1 (Thread 0x151831c83700 (LWP 135616))] (gdb) bt #0 __pthread_kill (threadid=<optimized out>, signo=signo@entry=6) at ../sysdeps/unix/sysv/linux/pthread_kill.c:57 #1 0x0000561d7d45a7d0 in my_write_core (sig=sig@entry=6) at /test/10.5_dbg/mysys/stacktrace.c:518 #2 0x0000561d7cc1347a in handle_fatal_signal (sig=6) at /test/10.5_dbg/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 0x000015182ff648b1 in __GI_abort () at abort.c:79 #6 0x000015182ff5442a in __assert_fail_base (fmt=0x1518300dba38 "%s%s%s:%u: %s%sAssertion `%s' failed.\n%n", assertion=assertion@entry=0x561d7d797580 "!binlog || exist_hton_without_prepare", file=file@entry=0x561d7d793967 "/test/10.5_dbg/sql/log.cc", line=line@entry=10156, function=function@entry=0x561d7d798640 <MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool)::__PRETTY_FUNCTION__> "virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool)") at assert.c:92 #7 0x000015182ff544a2 in __GI___assert_fail (assertion=assertion@entry=0x561d7d797580 "!binlog || exist_hton_without_prepare", file=file@entry=0x561d7d793967 "/test/10.5_dbg/sql/log.cc", line=line@entry=10156, function=function@entry=0x561d7d798640 <MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool)::__PRETTY_FUNCTION__> "virtual int MYSQL_BIN_LOG::unlog_xa_prepare(THD*, bool)") at assert.c:101 #8 0x0000561d7cd57990 in MYSQL_BIN_LOG::unlog_xa_prepare (this=0x561d7e1db940 <mysql_bin_log>, thd=0x15180dc15088, all=<optimized out>) at /test/10.5_dbg/sql/log.cc:10156 #9 0x0000561d7cc2bcd4 in ha_prepare (thd=thd@entry=0x15180dc15088) at /test/10.5_dbg/sql/handler.cc:1399 #10 0x0000561d7cb7ebf2 in trans_xa_prepare (thd=thd@entry=0x15180dc15088) at /test/10.5_dbg/sql/xa.cc:531 #11 0x0000561d7c96d740 in mysql_execute_command (thd=thd@entry=0x15180dc15088) at /test/10.5_dbg/sql/sql_parse.cc:5805 #12 0x0000561d7c975638 in mysql_parse (thd=thd@entry=0x15180dc15088, rawbuf=<optimized out>, length=<optimized out>, parser_state=parser_state@entry=0x151831c82350, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:7995 #13 0x0000561d7c962110 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x15180dc15088, packet=packet@entry=0x15180dc67089 "XA PREPARE 'a'", packet_length=packet_length@entry=14, is_com_multi=is_com_multi@entry=false, is_next_command=is_next_command@entry=false) at /test/10.5_dbg/sql/sql_parse.cc:1874 #14 0x0000561d7c9608ea in do_command (thd=0x15180dc15088) at /test/10.5_dbg/sql/sql_parse.cc:1355 #15 0x0000561d7cabc15f in do_handle_one_connection (connect=<optimized out>, connect@entry=0x151810cd9f08, put_in_cache=put_in_cache@entry=true) at /test/10.5_dbg/sql/sql_connect.cc:1411 #16 0x0000561d7cabc87b in handle_one_connection (arg=arg@entry=0x151810cd9f08) at /test/10.5_dbg/sql/sql_connect.cc:1313 #17 0x0000561d7cf1f11c in pfs_spawn_thread (arg=0x15182e846788) at /test/10.5_dbg/storage/perfschema/pfs.cc:2201 #18 0x0000151830c476db in start_thread (arg=0x151831c83700) at pthread_create.c:463 #19 0x0000151830045a3f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95 Bug confirmed present in: MariaDB: 10.5.5 (dbg) Bug confirmed not present in: MariaDB: 10.1.46 (dbg), 10.1.46 (opt), 10.2.33 (dbg), 10.2.33 (opt), 10.3.24 (dbg), 10.3.24 (opt), 10.4.14 (dbg), 10.4.14 (opt), 10.5.5 (opt) MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.47 (dbg), 5.6.47 (opt), 5.7.29 (dbg), 5.7.29 (opt), 8.0.19 (dbg), 8.0.19 (opt)

Roel Van de Paar added a comment - 2020-07-14 00:47

Elkin is this bug waiting for you or for serg ?

Roel Van de Paar added a comment - 2020-07-14 00:47 Elkin is this bug waiting for you or for serg ?

Andrei Elkin made changes - 2020-07-14 06:29

Status

Stalled [ 10000 ]

In Progress [ 3 ]

Andrei Elkin added a comment - 2020-07-14 06:31

Serg, howdy. I got to bounce it back to you, as there's no changes from your round of review
has been requested (as you explained you got to interrupt it actually).

Roel - Salve! This must answer your question . And thank you for heads up!

Andrei Elkin added a comment - 2020-07-14 06:31 Serg, howdy. I got to bounce it back to you, as there's no changes from your round of review has been requested (as you explained you got to interrupt it actually). Roel - Salve! This must answer your question . And thank you for heads up!

Andrei Elkin made changes - 2020-07-14 06:31

Assignee	Andrei Elkin [ elkin ]	Sergei Golubchik [ serg ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Sergei Golubchik added a comment - 2020-10-22 11:46

back to Elkin as per slack chat on June 17th

Sergei Golubchik added a comment - 2020-10-22 11:46 back to Elkin as per slack chat on June 17th

Sergei Golubchik made changes - 2020-10-22 11:46

Assignee	Sergei Golubchik [ serg ]	Andrei Elkin [ elkin ]
Status	In Review [ 10002 ]	Stalled [ 10000 ]

Alice Sherepa made changes - 2021-04-16 16:15

Link

This issue relates to ~~MDEV-22430~~ [ ~~MDEV-22430~~ ]

Andrei Elkin added a comment - 2021-04-18 14:09

Roel: Your provision by https://jira.mariadb.org/browse/MDEV-22757?focusedCommentId=159815&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-159815 is really helpful.
Yet it would be close to perfect when a to-be-errored-out statement like

INSERT INTO t2 VALUES (1);

would be marked as such, preferably with the mtr style

--error 1136
INSERT INTO t2 VALUES (1)

Andrei Elkin added a comment - 2021-04-18 14:09 Roel : Your provision by https://jira.mariadb.org/browse/MDEV-22757?focusedCommentId=159815&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-159815 is really helpful. Yet it would be close to perfect when a to-be-errored-out statement like INSERT INTO t2 VALUES (1); would be marked as such, preferably with the mtr style --error 1136 INSERT INTO t2 VALUES (1)

Andrei Elkin added a comment - 2021-04-18 14:13

Although an experienced sql-reader might see the error without sending the query to the server,
being fool-proof never hurts but more germane saves our time.

Cheers !

Andrei Elkin added a comment - 2021-04-18 14:13 Although an experienced sql-reader might see the error without sending the query to the server, being fool-proof never hurts but more germane saves our time. Cheers !

Andrei Elkin added a comment - 2021-04-19 19:04

675c22c065 pushed.

Andrei Elkin added a comment - 2021-04-19 19:04 675c22c065 pushed.

Andrei Elkin made changes - 2021-04-19 19:04

Fix Version/s		10.5.10 [ 25204 ]
Fix Version/s	10.5 [ 23123 ]
Resolution		Fixed [ 1 ]
Status	Stalled [ 10000 ]	Closed [ 6 ]

Sergei Golubchik made changes - 2021-12-06 21:51

Workflow

MariaDB v3 [ 109330 ]

MariaDB v4 [ 157881 ]

People

Assignee:: Andrei Elkin

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: 2020-05-30 19:27

Updated:: 2021-04-19 19:07

Resolved:: 2021-04-19 19:04

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server