[MDEV-32126] Assertion `!writer.checksum_len || writer.remains == 0' fails upon concurrent online ALTER and transactions with failing statements and binary log enabled - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Blocker
Resolution: Fixed
Affects Version/s: 11.2(EOL)
Fix Version/s: 11.2.2
Component/s: Data Definition - Alter Table
Labels:
- regression

Description

Set to blocker as it's a bug in a new feature in a soon-to-be GA.

--source include/have_binlog_format_mixed.inc

--source include/have_innodb.inc

--source include/have_debug_sync.inc

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

CREATE TABLE t2 (a INT, b INT, c CHAR(8), d TEXT, UNIQUE(a)) ENGINE=InnoDB;

--connect (con1,localhost,root,,test)

START TRANSACTION;

CREATE TEMPORARY TABLE tmp (id INT, PRIMARY KEY(id)) ENGINE=InnoDB;

INSERT INTO t1 VALUES (1, REPEAT('x',8000)),(2, REPEAT('x',8000));

UPDATE t2 SET b = NULL ORDER BY b LIMIT 2;

INSERT INTO t1 VALUES (3, REPEAT('x',8000));

DELETE FROM t1;

INSERT INTO t2 VALUES (1,1,'f','e'),(1000,1000,'c','b');

COMMIT;

--send

  SET debug_sync= 'NOW WAIT_FOR go_trx';

--connection default

SET debug_sync= 'alter_table_online_progress SIGNAL go_trx WAIT_FOR go_alter';

--send

  ALTER TABLE t2 FORCE, ALGORITHM=COPY, LOCK=NONE;

--connection con1

--reap

START TRANSACTION;

DROP TEMPORARY TABLE IF EXISTS tmp;

--error ER_DUP_ENTRY

INSERT INTO t2 VALUES (3,3,'a','x'), (3,3,'a','x');

COMMIT;

set debug_sync= 'NOW SIGNAL go_alter';

--connection default

--reap

# Cleanup

DROP TABLE t1, t2;

11.2 9ad7c899
mariadbd: /data/src/11.2/sql/log.cc:8052: int Event_log::write_cache(THD, IO_CACHE): Assertion `!writer.checksum_len \|\| writer.remains == 0' failed.
230907 20:29:34 [ERROR] mysqld got signal 6 ;

#9 0x00007f18bb453df2 in __GI___assert_fail (assertion=0x5583e5c76de0 "!writer.checksum_len \|\| writer.remains == 0", file=0x5583e5c6bf20 "/data/src/11.2/sql/log.cc", line=8052, function=0x5583e5c76b60 "int Event_log::write_cache(THD, IO_CACHE)") at ./assert/assert.c:101
#10 0x00005583e425af27 in Event_log::write_cache (this=0x5583e7af1f28 <mysql_bin_log+8>, thd=0x62c000240218, cache=0x61b000040038) at /data/src/11.2/sql/log.cc:8052
#11 0x00005583e4262515 in MYSQL_BIN_LOG::write_transaction_or_stmt (this=0x5583e7af1f20 <mysql_bin_log>, entry=0x7f18a3249830, commit_id=0) at /data/src/11.2/sql/log.cc:9182
#12 0x00005583e425fc6f in MYSQL_BIN_LOG::trx_group_commit_leader (this=0x5583e7af1f20 <mysql_bin_log>, leader=0x7f18a3249830) at /data/src/11.2/sql/log.cc:8902
#13 0x00005583e425e773 in MYSQL_BIN_LOG::write_transaction_to_binlog_events (this=0x5583e7af1f20 <mysql_bin_log>, entry=0x7f18a3249830) at /data/src/11.2/sql/log.cc:8694
#14 0x00005583e425c5d1 in MYSQL_BIN_LOG::write_transaction_to_binlog (this=0x5583e7af1f20 <mysql_bin_log>, thd=0x62c000240218, cache_mngr=0x61b00003fe98, end_ev=0x7f18a3249cc0, all=true, using_stmt_cache=false, using_trx_cache=true, is_ro_1pc=true) at /data/src/11.2/sql/log.cc:8291
#15 0x00005583e4232bf1 in binlog_flush_cache (thd=0x62c000240218, cache_mngr=0x61b00003fe98, end_ev=0x7f18a3249cc0, all=true, using_stmt=false, using_trx=true, is_ro_1pc=true) at /data/src/11.2/sql/log.cc:1907
#16 0x00005583e42339f7 in binlog_commit_flush_trx_cache (thd=0x62c000240218, all=true, cache_mngr=0x61b00003fe98, ro_1pc=true) at /data/src/11.2/sql/log.cc:2006
#17 0x00005583e4236c1c in binlog_commit (thd=0x62c000240218, all=true, ro_1pc=true) at /data/src/11.2/sql/log.cc:2418
#18 0x00005583e3efc181 in commit_one_phase_2 (thd=0x62c000240218, all=true, trans=0x62c000243cc0, is_real_trans=true) at /data/src/11.2/sql/handler.cc:2131
#19 0x00005583e3efbdd7 in ha_commit_one_phase (thd=0x62c000240218, all=true) at /data/src/11.2/sql/handler.cc:2093
#20 0x00005583e3efa048 in ha_commit_trans (thd=0x62c000240218, all=true) at /data/src/11.2/sql/handler.cc:1887
#21 0x00005583e3ac52a3 in trans_commit (thd=0x62c000240218) at /data/src/11.2/sql/transaction.cc:266
#22 0x00005583e35d1925 in mysql_execute_command (thd=0x62c000240218, is_called_from_prepared_stmt=false) at /data/src/11.2/sql/sql_parse.cc:5403
#23 0x00005583e35e10d7 in mysql_parse (thd=0x62c000240218, rawbuf=0x6290002e9238 "COMMIT", length=6, parser_state=0x7f18a324b9f0) at /data/src/11.2/sql/sql_parse.cc:7811
#24 0x00005583e35b9491 in dispatch_command (command=COM_QUERY, thd=0x62c000240218, packet=0x6290002df219 "COMMIT", packet_length=6, blocking=true) at /data/src/11.2/sql/sql_parse.cc:1893
#25 0x00005583e35b61ce in do_command (thd=0x62c000240218, blocking=true) at /data/src/11.2/sql/sql_parse.cc:1406
#26 0x00005583e3a81fac in do_handle_one_connection (connect=0x608000003cb8, put_in_cache=true) at /data/src/11.2/sql/sql_connect.cc:1445
#27 0x00005583e3a8196d in handle_one_connection (arg=0x608000003cb8) at /data/src/11.2/sql/sql_connect.cc:1347
#28 0x00005583e46aa652 in pfs_spawn_thread (arg=0x617000008c98) at /data/src/11.2/storage/perfschema/pfs.cc:2201
#29 0x00007f18bb4a7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#30 0x00007f18bb5285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81

Attachments

Issue Links

is caused by

MDEV-16329 Engine-independent online ALTER TABLE

Closed

Activity

Ascending order - Click to sort in descending order

Elena Stepanova created issue - 2023-09-07 17:39

Elena Stepanova made changes - 2023-09-07 17:39

Field	Original Value	New Value
Link		This issue is caused by ~~MDEV-16329~~ [ ~~MDEV-16329~~ ]

Elena Stepanova made changes - 2023-09-07 17:51

Description

_Set to blocker as it's a bug in a new feature which in a soon-to-be GA._

{code:sql}
--source include/have_binlog_format_mixed.inc
--source include/have_innodb.inc
--source include/have_debug_sync.inc

CREATE TABLE t1 (a INT, b TEXT) ENGINE=InnoDB;
CREATE TABLE t2 (a INT, b INT, c CHAR(8), d TEXT, UNIQUE(a)) ENGINE=InnoDB;

--connect (con1,localhost,root,,test)
START TRANSACTION;
CREATE TEMPORARY TABLE tmp (id INT, PRIMARY KEY(id)) ENGINE=InnoDB;
INSERT INTO t1 VALUES (1, REPEAT('x',8000)),(2, REPEAT('x',8000));
UPDATE t2 SET b = NULL ORDER BY b LIMIT 2;
INSERT INTO t1 VALUES (3, REPEAT('x',8000));
DELETE FROM t1;
INSERT INTO t2 VALUES (1,1,'f','e'),(1000,1000,'c','b');
COMMIT;
--send
SET debug_sync= 'NOW WAIT_FOR go_trx';

--connection default
SET debug_sync= 'alter_table_online_progress SIGNAL go_trx WAIT_FOR go_alter';
--send
ALTER TABLE t2 FORCE, ALGORITHM=COPY, LOCK=NONE;

--connection con1
--reap
START TRANSACTION;
DROP TEMPORARY TABLE IF EXISTS tmp;
--error ER_DUP_ENTRY
INSERT INTO t2 VALUES (3,3,'a','x'), (3,3,'a','x');
COMMIT;
set debug_sync= 'NOW SIGNAL go_alter';

--connection default
--reap

# Cleanup
DROP TABLE t1, t2;
{code}

{noformat:title=11.2 9ad7c899}
mariadbd: /data/src/11.2/sql/log.cc:8052: int Event_log::write_cache(THD*, IO_CACHE*): Assertion `!writer.checksum_len || writer.remains == 0' failed.
230907 20:29:34 [ERROR] mysqld got signal 6 ;

#9 0x00007f18bb453df2 in __GI___assert_fail (assertion=0x5583e5c76de0 "!writer.checksum_len || writer.remains == 0", file=0x5583e5c6bf20 "/data/src/11.2/sql/log.cc", line=8052, function=0x5583e5c76b60 "int Event_log::write_cache(THD*, IO_CACHE*)") at ./assert/assert.c:101
#10 0x00005583e425af27 in Event_log::write_cache (this=0x5583e7af1f28 <mysql_bin_log+8>, thd=0x62c000240218, cache=0x61b000040038) at /data/src/11.2/sql/log.cc:8052
#11 0x00005583e4262515 in MYSQL_BIN_LOG::write_transaction_or_stmt (this=0x5583e7af1f20 <mysql_bin_log>, entry=0x7f18a3249830, commit_id=0) at /data/src/11.2/sql/log.cc:9182
#12 0x00005583e425fc6f in MYSQL_BIN_LOG::trx_group_commit_leader (this=0x5583e7af1f20 <mysql_bin_log>, leader=0x7f18a3249830) at /data/src/11.2/sql/log.cc:8902
#13 0x00005583e425e773 in MYSQL_BIN_LOG::write_transaction_to_binlog_events (this=0x5583e7af1f20 <mysql_bin_log>, entry=0x7f18a3249830) at /data/src/11.2/sql/log.cc:8694
#14 0x00005583e425c5d1 in MYSQL_BIN_LOG::write_transaction_to_binlog (this=0x5583e7af1f20 <mysql_bin_log>, thd=0x62c000240218, cache_mngr=0x61b00003fe98, end_ev=0x7f18a3249cc0, all=true, using_stmt_cache=false, using_trx_cache=true, is_ro_1pc=true) at /data/src/11.2/sql/log.cc:8291
#15 0x00005583e4232bf1 in binlog_flush_cache (thd=0x62c000240218, cache_mngr=0x61b00003fe98, end_ev=0x7f18a3249cc0, all=true, using_stmt=false, using_trx=true, is_ro_1pc=true) at /data/src/11.2/sql/log.cc:1907
#16 0x00005583e42339f7 in binlog_commit_flush_trx_cache (thd=0x62c000240218, all=true, cache_mngr=0x61b00003fe98, ro_1pc=true) at /data/src/11.2/sql/log.cc:2006
#17 0x00005583e4236c1c in binlog_commit (thd=0x62c000240218, all=true, ro_1pc=true) at /data/src/11.2/sql/log.cc:2418
#18 0x00005583e3efc181 in commit_one_phase_2 (thd=0x62c000240218, all=true, trans=0x62c000243cc0, is_real_trans=true) at /data/src/11.2/sql/handler.cc:2131
#19 0x00005583e3efbdd7 in ha_commit_one_phase (thd=0x62c000240218, all=true) at /data/src/11.2/sql/handler.cc:2093
#20 0x00005583e3efa048 in ha_commit_trans (thd=0x62c000240218, all=true) at /data/src/11.2/sql/handler.cc:1887
#21 0x00005583e3ac52a3 in trans_commit (thd=0x62c000240218) at /data/src/11.2/sql/transaction.cc:266
#22 0x00005583e35d1925 in mysql_execute_command (thd=0x62c000240218, is_called_from_prepared_stmt=false) at /data/src/11.2/sql/sql_parse.cc:5403
#23 0x00005583e35e10d7 in mysql_parse (thd=0x62c000240218, rawbuf=0x6290002e9238 "COMMIT", length=6, parser_state=0x7f18a324b9f0) at /data/src/11.2/sql/sql_parse.cc:7811
#24 0x00005583e35b9491 in dispatch_command (command=COM_QUERY, thd=0x62c000240218, packet=0x6290002df219 "COMMIT", packet_length=6, blocking=true) at /data/src/11.2/sql/sql_parse.cc:1893
#25 0x00005583e35b61ce in do_command (thd=0x62c000240218, blocking=true) at /data/src/11.2/sql/sql_parse.cc:1406
#26 0x00005583e3a81fac in do_handle_one_connection (connect=0x608000003cb8, put_in_cache=true) at /data/src/11.2/sql/sql_connect.cc:1445
#27 0x00005583e3a8196d in handle_one_connection (arg=0x608000003cb8) at /data/src/11.2/sql/sql_connect.cc:1347
#28 0x00005583e46aa652 in pfs_spawn_thread (arg=0x617000008c98) at /data/src/11.2/storage/perfschema/pfs.cc:2201
#29 0x00007f18bb4a7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#30 0x00007f18bb5285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
{noformat}

_Set to blocker as it's a bug in a new feature in a soon-to-be GA._

{code:sql}
--source include/have_binlog_format_mixed.inc
--source include/have_innodb.inc
--source include/have_debug_sync.inc

CREATE TABLE t1 (a INT, b TEXT) ENGINE=InnoDB;
CREATE TABLE t2 (a INT, b INT, c CHAR(8), d TEXT, UNIQUE(a)) ENGINE=InnoDB;

--connect (con1,localhost,root,,test)
START TRANSACTION;
CREATE TEMPORARY TABLE tmp (id INT, PRIMARY KEY(id)) ENGINE=InnoDB;
INSERT INTO t1 VALUES (1, REPEAT('x',8000)),(2, REPEAT('x',8000));
UPDATE t2 SET b = NULL ORDER BY b LIMIT 2;
INSERT INTO t1 VALUES (3, REPEAT('x',8000));
DELETE FROM t1;
INSERT INTO t2 VALUES (1,1,'f','e'),(1000,1000,'c','b');
COMMIT;
--send
SET debug_sync= 'NOW WAIT_FOR go_trx';

--connection default
SET debug_sync= 'alter_table_online_progress SIGNAL go_trx WAIT_FOR go_alter';
--send
ALTER TABLE t2 FORCE, ALGORITHM=COPY, LOCK=NONE;

--connection con1
--reap
START TRANSACTION;
DROP TEMPORARY TABLE IF EXISTS tmp;
--error ER_DUP_ENTRY
INSERT INTO t2 VALUES (3,3,'a','x'), (3,3,'a','x');
COMMIT;
set debug_sync= 'NOW SIGNAL go_alter';

--connection default
--reap

# Cleanup
DROP TABLE t1, t2;
{code}

{noformat:title=11.2 9ad7c899}
mariadbd: /data/src/11.2/sql/log.cc:8052: int Event_log::write_cache(THD*, IO_CACHE*): Assertion `!writer.checksum_len || writer.remains == 0' failed.
230907 20:29:34 [ERROR] mysqld got signal 6 ;

#9 0x00007f18bb453df2 in __GI___assert_fail (assertion=0x5583e5c76de0 "!writer.checksum_len || writer.remains == 0", file=0x5583e5c6bf20 "/data/src/11.2/sql/log.cc", line=8052, function=0x5583e5c76b60 "int Event_log::write_cache(THD*, IO_CACHE*)") at ./assert/assert.c:101
#10 0x00005583e425af27 in Event_log::write_cache (this=0x5583e7af1f28 <mysql_bin_log+8>, thd=0x62c000240218, cache=0x61b000040038) at /data/src/11.2/sql/log.cc:8052
#11 0x00005583e4262515 in MYSQL_BIN_LOG::write_transaction_or_stmt (this=0x5583e7af1f20 <mysql_bin_log>, entry=0x7f18a3249830, commit_id=0) at /data/src/11.2/sql/log.cc:9182
#12 0x00005583e425fc6f in MYSQL_BIN_LOG::trx_group_commit_leader (this=0x5583e7af1f20 <mysql_bin_log>, leader=0x7f18a3249830) at /data/src/11.2/sql/log.cc:8902
#13 0x00005583e425e773 in MYSQL_BIN_LOG::write_transaction_to_binlog_events (this=0x5583e7af1f20 <mysql_bin_log>, entry=0x7f18a3249830) at /data/src/11.2/sql/log.cc:8694
#14 0x00005583e425c5d1 in MYSQL_BIN_LOG::write_transaction_to_binlog (this=0x5583e7af1f20 <mysql_bin_log>, thd=0x62c000240218, cache_mngr=0x61b00003fe98, end_ev=0x7f18a3249cc0, all=true, using_stmt_cache=false, using_trx_cache=true, is_ro_1pc=true) at /data/src/11.2/sql/log.cc:8291
#15 0x00005583e4232bf1 in binlog_flush_cache (thd=0x62c000240218, cache_mngr=0x61b00003fe98, end_ev=0x7f18a3249cc0, all=true, using_stmt=false, using_trx=true, is_ro_1pc=true) at /data/src/11.2/sql/log.cc:1907
#16 0x00005583e42339f7 in binlog_commit_flush_trx_cache (thd=0x62c000240218, all=true, cache_mngr=0x61b00003fe98, ro_1pc=true) at /data/src/11.2/sql/log.cc:2006
#17 0x00005583e4236c1c in binlog_commit (thd=0x62c000240218, all=true, ro_1pc=true) at /data/src/11.2/sql/log.cc:2418
#18 0x00005583e3efc181 in commit_one_phase_2 (thd=0x62c000240218, all=true, trans=0x62c000243cc0, is_real_trans=true) at /data/src/11.2/sql/handler.cc:2131
#19 0x00005583e3efbdd7 in ha_commit_one_phase (thd=0x62c000240218, all=true) at /data/src/11.2/sql/handler.cc:2093
#20 0x00005583e3efa048 in ha_commit_trans (thd=0x62c000240218, all=true) at /data/src/11.2/sql/handler.cc:1887
#21 0x00005583e3ac52a3 in trans_commit (thd=0x62c000240218) at /data/src/11.2/sql/transaction.cc:266
#22 0x00005583e35d1925 in mysql_execute_command (thd=0x62c000240218, is_called_from_prepared_stmt=false) at /data/src/11.2/sql/sql_parse.cc:5403
#23 0x00005583e35e10d7 in mysql_parse (thd=0x62c000240218, rawbuf=0x6290002e9238 "COMMIT", length=6, parser_state=0x7f18a324b9f0) at /data/src/11.2/sql/sql_parse.cc:7811
#24 0x00005583e35b9491 in dispatch_command (command=COM_QUERY, thd=0x62c000240218, packet=0x6290002df219 "COMMIT", packet_length=6, blocking=true) at /data/src/11.2/sql/sql_parse.cc:1893
#25 0x00005583e35b61ce in do_command (thd=0x62c000240218, blocking=true) at /data/src/11.2/sql/sql_parse.cc:1406
#26 0x00005583e3a81fac in do_handle_one_connection (connect=0x608000003cb8, put_in_cache=true) at /data/src/11.2/sql/sql_connect.cc:1445
#27 0x00005583e3a8196d in handle_one_connection (arg=0x608000003cb8) at /data/src/11.2/sql/sql_connect.cc:1347
#28 0x00005583e46aa652 in pfs_spawn_thread (arg=0x617000008c98) at /data/src/11.2/storage/perfschema/pfs.cc:2201
#29 0x00007f18bb4a7fd4 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#30 0x00007f18bb5285bc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
{noformat}

Nikita Malyavin made changes - 2023-09-15 09:42

Status

Open [ 1 ]

In Progress [ 3 ]

Nikita Malyavin made changes - 2023-09-19 09:35

Summary

Assertion `!writer.checksum_len || writer.remains == 0' fails upon concurrent online ALTER and transactions with binary log enabled

Assertion `!writer.checksum_len || writer.remains == 0' fails upon concurrent online ALTER and transactions with failing statements binary log enabled

Nikita Malyavin made changes - 2023-09-19 09:35

Summary

Assertion `!writer.checksum_len || writer.remains == 0' fails upon concurrent online ALTER and transactions with failing statements binary log enabled

Assertion `!writer.checksum_len || writer.remains == 0' fails upon concurrent online ALTER and transactions with failing statements and binary log enabled

Nikita Malyavin made changes - 2023-09-19 14:21

Assignee	Nikita Malyavin [ nikitamalyavin ]	Sergei Golubchik [ serg ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Sergei Golubchik made changes - 2023-09-21 16:05

Assignee	Sergei Golubchik [ serg ]	Nikita Malyavin [ nikitamalyavin ]
Status	In Review [ 10002 ]	Stalled [ 10000 ]

Nikita Malyavin made changes - 2023-09-22 07:37

Status

Stalled [ 10000 ]

In Progress [ 3 ]

Nikita Malyavin made changes - 2023-09-23 15:36

Assignee	Nikita Malyavin [ nikitamalyavin ]	Sergei Golubchik [ serg ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Sergei Golubchik made changes - 2023-09-29 19:15

Assignee	Sergei Golubchik [ serg ]	Nikita Malyavin [ nikitamalyavin ]
Status	In Review [ 10002 ]	Stalled [ 10000 ]

Nikita Malyavin made changes - 2023-10-09 14:45

Assignee	Nikita Malyavin [ nikitamalyavin ]	Sergei Golubchik [ serg ]
Status	Stalled [ 10000 ]	In Review [ 10002 ]

Nikita Malyavin made changes - 2023-10-09 15:28

Assignee

Sergei Golubchik [ serg ]

Nikita Malyavin [ nikitamalyavin ]

Nikita Malyavin made changes - 2023-10-09 15:28

Status

In Review [ 10002 ]

Stalled [ 10000 ]

Nikita Malyavin made changes - 2023-10-09 15:28

Status

Stalled [ 10000 ]

In Progress [ 3 ]

Nikita Malyavin made changes - 2023-10-09 15:28

Comment

[ Minor issues were fixed. Head is {{0b19594fba1}}, waiting for the verdict ]

Nikita Malyavin made changes - 2023-10-11 10:09

Assignee	Nikita Malyavin [ nikitamalyavin ]	Sergei Golubchik [ serg ]
Status	In Progress [ 3 ]	In Review [ 10002 ]

Sergei Golubchik made changes - 2023-10-13 13:14

Assignee	Sergei Golubchik [ serg ]	Nikita Malyavin [ nikitamalyavin ]
Status	In Review [ 10002 ]	Stalled [ 10000 ]

Sergei Golubchik made changes - 2023-10-25 14:32

Status

Stalled [ 10000 ]

In Testing [ 10301 ]

Nikita Malyavin made changes - 2023-11-04 08:48

Fix Version/s		11.2.2 [ 29035 ]
Fix Version/s	11.2 [ 28603 ]
Resolution		Fixed [ 1 ]
Status	In Testing [ 10301 ]	Closed [ 6 ]

People

Assignee:: Nikita Malyavin

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: 2023-09-07 17:39

Updated:: 2023-11-04 08:48

Resolved:: 2023-11-04 08:48

Git Integration

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

MariaDB Server

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration