[MDEV-26633] rpl.rpl_delayed_slave failed in bb, Test assertion failed Created: 2021-09-17  Updated: 2023-11-28

Status: Open
Project: MariaDB Server
Component/s: Replication, Tests
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Angelique Sklavounos (Inactive)
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-27950 rpl.rpl_delayed_slave failed for test... Open

 Description   

https://buildbot.mariadb.org/#/builders/208/builds/2159/steps/6/logs/stdio

[Revision hash: 5b0a76078a8ea38e8e19e3e2c49f0f7e091e2f72]
 
rpl.rpl_delayed_slave 'nonparallel,stmt' w1 [ fail ]
        Test ended at 2021-09-17 04:15:46
 
CURRENT_TEST: rpl.rpl_delayed_slave
mysqltest: In included file "./include/rpl_assert.inc": 
included from /buildbot/amd64-ubuntu-1804-bigtest/build/mysql-test/suite/rpl/t/rpl_delayed_slave.test at line 241:
At line 109: Test assertion failed in rpl_assertion.inc
 
The result from queries just before the failure was:
< snip >
master-bin.000001	2233	Query	1	2306	COMMIT
master-bin.000001	2306	Gtid	1	2348	BEGIN GTID 0-1-9
master-bin.000001	2348	Query	1	2457	use `test`; INSERT INTO t1 VALUES ('Syncing slave', 5)
master-bin.000001	2457	Query	1	2530	COMMIT
master-bin.000001	2530	Gtid	1	2572	BEGIN GTID 0-1-10
master-bin.000001	2572	Query	1	2683	use `test`; INSERT INTO t1 VALUES (delay_on_slave(1), 6)
master-bin.000001	2683	Query	1	2756	COMMIT
master-bin.000001	2756	Gtid	1	2798	BEGIN GTID 0-1-11
master-bin.000001	2798	Query	1	2925	use `test`; INSERT INTO t1 VALUES ('stop slave and start slave: DML', 7)
master-bin.000001	2925	Query	1	2998	COMMIT
 
**** SHOW RELAYLOG EVENTS on server_1 ****
relaylog_name = 'No such row'
SHOW RELAYLOG EVENTS IN 'No such row';
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
connection slave;
Assertion text: 'STOP SLAVE should finish quickly, not wait for the ongoing sleep to finish'
Assertion condition: 'UNIX_TIMESTAMP() - 1631852132 < 10'
Assertion condition, interpolated: 'UNIX_TIMESTAMP() - 1631852132 < 10'
Assertion result: '0'



 Comments   
Comment by Andrei Elkin [ 2022-03-01 ]

angelique.sklavounos, hopefully this failure indeed relates to MDEV-27950 one.

Comment by Angelique Sklavounos (Inactive) [ 2022-03-11 ]

Was able to reproduce this locally while also having a separate test suite running at the same time (asan build, 3 parallel workers, rpl suite). My environment was noticeably slow when the test failed (the suite was running rpl.rpl_start_alter_mysqbinglog_2 and failed with ERROR 2013 and 2006). It did not fail at the exact same point in the file, but at the second assertion for the replica to stop quickly. The difference in the timestamps was 56 s.

Elkin I think it is related to MDEV-27950. With both, the test usually seems to be retry-pass, indicating that the test passes with less load on the system.

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