[MDEV-31059] "Slave SQL" errors upon concurrent DML and erroneous ALTER Created: 2023-04-16  Updated: 2023-08-16  Resolved: 2023-08-16

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Alter Table, Virtual Columns
Affects Version/s: N/A
Fix Version/s: 11.2.1

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Nikita Malyavin
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Problem/Incident
is caused by MDEV-16329 Engine-independent online ALTER TABLE Closed
Relates
relates to MDEV-28808 Test MDEV-16329 (ALTER ONLINE TABLE) ... Stalled

 Description   

Notes:

  • A fix for MDEV-31043 is already in the branch.
  • Reproducible with at least InnoDB, MyISAM, Aria. The test case is not applicable to HEAP.
  • The test case is non-deterministic, run with --repeat=N. It usually fails for me right away, but it can vary on different machines and builds. If it doesn't fail, try to change the sleep time or make it deterministic by synchronization. Don't put it into the regression suite with non-deterministic concurrency.
  • The extra logic with grepping the log is needed, because MTR globally suppresses this kind of errors in the log. The suppression was added in 2009. It may need to be reconsidered.
  • The behavior of SQL itself doesn't look wrong at the first glance, at least not wronger than it was before the "online" ALTER. The test case attempts to insert-ignore a row which violates the datatype of the generated column and alter the table to add a new column. If ALTER happens first, it of course succeeds, and then INSERT IGNORE converts a non-numeric value into 0, as it usually does. If INSERT IGNORE happens first, then ALTER fails. It still seems to be happening this way even with "online" ALTER, but while failing, it produces the error messages which this bug report is about, and which really shouldn't be there.

CREATE TABLE t (f CHAR(8) DEFAULT '0', vf INT GENERATED ALWAYS AS (f) STORED);
INSERT INTO t (f) VALUES ('1');
 
--connect (con1,localhost,root,,)
--send
  ALTER TABLE t ADD COLUMN a INT, ALGORITHM=COPY, LOCK=NONE;
 
--connection default
--sleep 0.001
INSERT IGNORE INTO t (f) VALUES ('');
 
--connection con1
--error ER_TRUNCATED_WRONG_VALUE_FOR_FIELD
--reap
 
--error 0,1
--exec grep 'Slave SQL' $MYSQLTEST_VARDIR/log/mysqld.1.err
--let $err= $sys_errno
 
# Cleanup
DROP TABLE t;
--disconnect con1
 
if ($err == 0)
{
  --die # Found Slave SQL errors in the log
}

bb-11.0-oalter 6f5427417eff with MyISAM

2023-04-16 14:33:29 5 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table test.t; Incorrect integer value: '' for column `test`.`t`.`vf` at row 2, Error_code: 1366; Got error 1 "Operation not permitted" from storage engine MyISAM, Error_code: 1030; handler error No Error!; the event's master log FIRST, end_log_pos 39, Internal MariaDB error code: 1366

with Aria

2023-04-16 14:34:02 5 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table test.t; Incorrect integer value: '' for column `test`.`t`.`vf` at row 2, Error_code: 1366; Got error 1 "Operation not permitted" from storage engine Aria, Error_code: 1030; handler error No Error!; the event's master log FIRST, end_log_pos 39, Internal MariaDB error code: 1366

with InnoDB

2023-04-16 14:34:27 5 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table test.t; Incorrect integer value: '' for column `test`.`t`.`vf` at row 2, Error_code: 1366; Got error 1 "Operation not permitted" from storage engine InnoDB, Error_code: 1030; handler error No Error!; the event's master log FIRST, end_log_pos 39, Internal MariaDB error code: 1366



 Comments   
Comment by Sergei Golubchik [ 2023-05-24 ]

064ec60235d is ok to push

Generated at Thu Feb 08 10:20:58 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.