rpl.rpl_stm_000001 Fails on Windows Buildbot

rpl.rpl_stm_000001 'stmt'                w55 [ fail ]

        Test ended at 2024-03-07 13:27:57

CURRENT_TEST: rpl.rpl_stm_000001

analyze: sync_with_master

mysqltest: At line 38: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 4080, 300, '')' returned -1 indicating timeout after 300 seconds

The result from queries just before the failure was:

< snip >

abandon

abandoned

abandoning

abandonment

abandons

connection slave;

stop slave;

connection master;

create temporary table tmp select * from mysql.global_priv where host="localhost" and user="root";

set password for root@"localhost" = password('foo');

connection slave;

start slave;

connection master;

replace into mysql.global_priv select * from tmp;

Warnings:

Note  1592  Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. REPLACE... SELECT is unsafe because the order in which rows are retrieved by the SELECT determines which (if any) rows are replaced. This order cannot be predicted and may differ on master and the slave

drop temporary table tmp;

flush privileges;

create table t3(n int);

insert into t3 values(1),(2);

More results from queries before failure can be found in D:\Buildbot\amd64-windows-packages\build\mysql-test\var\55\log\rpl_stm_000001.log

 == D:/Buildbot/amd64-windows-packages/build/mysql-test/var/55/tmp/analyze-sync_with_master-mysqld.2.err ==

############################## default ##############################

**** SHOW WARNINGS on default ****

SHOW WARNINGS;

Level Code  Message

**** SELECT replication-related variables on default ****

SELECT NOW(), @@SERVER_ID;

NOW() @@SERVER_ID

2024-03-07 13:27:57 2

**** SHOW SLAVE STATUS on default ****

SHOW SLAVE STATUS;

Slave_IO_State

Master_Host 127.0.0.1

Master_User root

Master_Port 17080

Connect_Retry 1

Master_Log_File master-bin.000001

Read_Master_Log_Pos 2829

Relay_Log_File  slave-relay-bin.000002

Relay_Log_Pos 3129

Relay_Master_Log_File master-bin.000001

Slave_IO_Running  No

Slave_SQL_Running Yes

Replicate_Do_DB

Replicate_Ignore_DB

Replicate_Do_Table

Replicate_Ignore_Table

Replicate_Wild_Do_Table

Replicate_Wild_Ignore_Table

Last_Errno  0

Last_Error

Skip_Counter  0

Exec_Master_Log_Pos 2829

Relay_Log_Space 3438

Until_Condition None

Until_Log_File

Until_Log_Pos 0

Master_SSL_Allowed  No

Master_SSL_CA_File

Master_SSL_CA_Path

Master_SSL_Cert

Master_SSL_Cipher

Master_SSL_Key

Seconds_Behind_Master NULL

Master_SSL_Verify_Server_Cert No

Last_IO_Errno 1045

Last_IO_Error error connecting to master 'root@127.0.0.1:17080' - retry-time: 1  maximum-retries: 10  message: Access denied for user 'root'@'localhost' (using password: NO)

Last_SQL_Errno  0

Last_SQL_Error

Replicate_Ignore_Server_Ids

Master_Server_Id  1

Master_SSL_Crl

Master_SSL_Crlpath

Using_Gtid  No

Gtid_IO_Pos

Replicate_Do_Domain_Ids

Replicate_Ignore_Domain_Ids

Parallel_Mode optimistic

SQL_Delay 0

SQL_Remaining_Delay NULL

Slave_SQL_Running_State Slave has read all relay log; waiting for more updates

Slave_DDL_Groups  1

Slave_Non_Transactional_Groups  3

Slave_Transactional_Groups  0

**** SHOW MASTER STATUS on default ****

SHOW MASTER STATUS;

File  slave-bin.000001

Position  2786

Binlog_Do_DB

Binlog_Ignore_DB

**** SHOW SLAVE HOSTS on default ****

SHOW SLAVE HOSTS;

**** SHOW PROCESSLIST on default ****

SHOW PROCESSLIST;

Id  User  Host  db  Command Time  State Info  Progress

11  system user   NULL  Slave_SQL 312 Slave has read all relay log; waiting for more updates  NULL  0.000

12  root  localhost:55247 NULL  Query 0 starting  SHOW PROCESSLIST  0.000

**** SHOW BINARY LOGS on default ****

SHOW BINARY LOGS;

Log_name  File_size

slave-bin.000001  2786

**** SHOW BINLOG EVENTS on default ****

binlog_name = 'slave-bin.000001'

SHOW BINLOG EVENTS IN 'slave-bin.000001';

Log_name  Pos Event_type  Server_id End_log_pos Info

slave-bin.000001  4 Format_desc 2 256 Server ver: 10.5.25-MariaDB-log, Binlog ver: 4

slave-bin.000001  256 Gtid_list 2 285 []

slave-bin.000001  285 Binlog_checkpoint 2 328 slave-bin.000001

slave-bin.000001  328 Gtid  1 370 BEGIN GTID 0-1-1

slave-bin.000001  370 Query 1 642 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT' COLLATE 'latin1_swedish_ci'))

slave-bin.000001  642 Query 1 714 COMMIT

slave-bin.000001  714 Gtid  1 756 GTID 0-1-2

slave-bin.000001  756 Query 1 863 use `test`; create table t1 (word char(20) not null)

slave-bin.000001  863 Gtid  1 905 BEGIN GTID 0-1-3

slave-bin.000001  905 Begin_load_query  1 1513  ;file_id=1;block_len=581

slave-bin.000001  1513  Execute_load_query  1 1748  use `test`; LOAD DATA INFILE '../../tmp/SQL_LOAD-2-1-1.data' INTO TABLE `t1` FIELDS TERMINATED BY '\t' ENCLOSED BY '' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`word`) ;file_id=1

slave-bin.000001  1748  Query 1 1821  COMMIT

slave-bin.000001  1821  Gtid  1 1863  BEGIN GTID 0-1-4

slave-bin.000001  1863  Begin_load_query  1 2471  ;file_id=2;block_len=581

slave-bin.000001  2471  Execute_load_query  1 2713  use `test`; LOAD DATA INFILE '../../tmp/SQL_LOAD-2-1-2.data' IGNORE INTO TABLE `t1` FIELDS TERMINATED BY '\t' ENCLOSED BY '' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`word`) ;file_id=2

slave-bin.000001  2713  Query 1 2786  COMMIT

**** SHOW RELAYLOG EVENTS on default ****

relaylog_name = 'slave-relay-bin.000002'

SHOW RELAYLOG EVENTS IN 'slave-relay-bin.000002';

Log_name  Pos Event_type  Server_id End_log_pos Info

slave-relay-bin.000002  4 Format_desc 2 256 Server ver: 10.5.25-MariaDB-log, Binlog ver: 4

slave-relay-bin.000002  256 Rotate  1 0 master-bin.000001;pos=4

slave-relay-bin.000002  304 Format_desc 1 256 Server ver: 10.5.25-MariaDB-log, Binlog ver: 4

slave-relay-bin.000002  556 Gtid_list 1 285 []

slave-relay-bin.000002  585 Binlog_checkpoint 1 329 master-bin.000001

slave-relay-bin.000002  629 Gtid  1 371 BEGIN GTID 0-1-1

slave-relay-bin.000002  671 Query 1 643 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT' COLLATE 'latin1_swedish_ci'))

slave-relay-bin.000002  943 Query 1 715 COMMIT

slave-relay-bin.000002  1015  Gtid  1 757 GTID 0-1-2

slave-relay-bin.000002  1057  Query 1 864 use `test`; create table t1 (word char(20) not null)

slave-relay-bin.000002  1164  Gtid  1 906 BEGIN GTID 0-1-3

slave-relay-bin.000002  1206  Begin_load_query  1 1514  ;file_id=1;block_len=581

slave-relay-bin.000002  1814  Execute_load_query  1 1744  use `test`; LOAD DATA INFILE '../../std_data/words.dat' INTO TABLE `t1` FIELDS TERMINATED BY '\t' ENCLOSED BY '' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`word`) ;file_id=1

slave-relay-bin.000002  2044  Query 1 1817  COMMIT

slave-relay-bin.000002  2117  Gtid  1 1859  BEGIN GTID 0-1-4

slave-relay-bin.000002  2159  Begin_load_query  1 2467  ;file_id=2;block_len=581

slave-relay-bin.000002  2767  Execute_load_query  1 2756  use `test`; LOAD DATA LOCAL INFILE 'D:/Buildbot/amd64-windows-packages/build/mysql-test/std_data/words.dat' IGNORE INTO TABLE `t1` FIELDS TERMINATED BY '\t' ENCLOSED BY '' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`word`) ;file_id=2

slave-relay-bin.000002  3056  Query 1 2829  COMMIT

connection default;

 == D:/Buildbot/amd64-windows-packages/build/mysql-test/var/55/tmp/analyze-sync_with_master-mysqld.1.err ==

############################## default ##############################

**** SHOW WARNINGS on default ****

SHOW WARNINGS;

Level Code  Message

**** SELECT replication-related variables on default ****

SELECT NOW(), @@SERVER_ID;

NOW() @@SERVER_ID

2024-03-07 13:27:57 1

**** SHOW SLAVE STATUS on default ****

SHOW SLAVE STATUS;

**** SHOW MASTER STATUS on default ****

SHOW MASTER STATUS;

File  master-bin.000001

Position  4080

Binlog_Do_DB

Binlog_Ignore_DB

**** SHOW SLAVE HOSTS on default ****

SHOW SLAVE HOSTS;

**** SHOW PROCESSLIST on default ****

SHOW PROCESSLIST;

Id  User  Host  db  Command Time  State Info  Progress

20  root  localhost:55248 NULL  Query 0 starting  SHOW PROCESSLIST  0.000

**** SHOW BINARY LOGS on default ****

SHOW BINARY LOGS;

Log_name  File_size

master-bin.000001 4080

**** SHOW BINLOG EVENTS on default ****

binlog_name = 'master-bin.000001'

SHOW BINLOG EVENTS IN 'master-bin.000001';

Log_name  Pos Event_type  Server_id End_log_pos Info

master-bin.000001 4 Format_desc 1 256 Server ver: 10.5.25-MariaDB-log, Binlog ver: 4

master-bin.000001 256 Gtid_list 1 285 []

master-bin.000001 285 Binlog_checkpoint 1 329 master-bin.000001

master-bin.000001 329 Gtid  1 371 BEGIN GTID 0-1-1

master-bin.000001 371 Query 1 643 use `mtr`; INSERT INTO test_suppressions (pattern) VALUES ( NAME_CONST('pattern',_latin1'Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT' COLLATE 'latin1_swedish_ci'))

master-bin.000001 643 Query 1 715 COMMIT

master-bin.000001 715 Gtid  1 757 GTID 0-1-2

master-bin.000001 757 Query 1 864 use `test`; create table t1 (word char(20) not null)

master-bin.000001 864 Gtid  1 906 BEGIN GTID 0-1-3

master-bin.000001 906 Begin_load_query  1 1514  ;file_id=1;block_len=581

master-bin.000001 1514  Execute_load_query  1 1744  use `test`; LOAD DATA INFILE '../../std_data/words.dat' INTO TABLE `t1` FIELDS TERMINATED BY '\t' ENCLOSED BY '' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`word`) ;file_id=1

master-bin.000001 1744  Query 1 1817  COMMIT

master-bin.000001 1817  Gtid  1 1859  BEGIN GTID 0-1-4

master-bin.000001 1859  Begin_load_query  1 2467  ;file_id=2;block_len=581

master-bin.000001 2467  Execute_load_query  1 2756  use `test`; LOAD DATA LOCAL INFILE 'D:/Buildbot/amd64-windows-packages/build/mysql-test/std_data/words.dat' IGNORE INTO TABLE `t1` FIELDS TERMINATED BY '\t' ENCLOSED BY '' ESCAPED BY '\\' LINES TERMINATED BY '\n' (`word`) ;file_id=2

master-bin.000001 2756  Query 1 2829  COMMIT

master-bin.000001 2829  Gtid  1 2871  GTID 0-1-5

master-bin.000001 2871  Query 1 3035  use `test`; create temporary table tmp select * from mysql.global_priv where host="localhost" and user="root"

master-bin.000001 3035  Gtid  1 3077  GTID 0-1-6

master-bin.000001 3077  Query 1 3223  use `test`; SET PASSWORD FOR 'root'@'localhost'='*F3A2A51A9B0F2BE2468926B4132313728C250DBF'

master-bin.000001 3223  Gtid  1 3265  BEGIN GTID 0-1-7

master-bin.000001 3265  Query 1 3380  use `test`; replace into mysql.global_priv select * from tmp

master-bin.000001 3380  Query 1 3453  COMMIT

master-bin.000001 3453  Gtid  1 3495  GTID 0-1-8

master-bin.000001 3495  Query 1 3614  use `test`; DROP TEMPORARY TABLE `tmp` /* generated by server */

master-bin.000001 3614  Gtid  1 3656  GTID 0-1-9

master-bin.000001 3656  Query 1 3739  use `test`; flush privileges

master-bin.000001 3739  Gtid  1 3781  GTID 0-1-10

master-bin.000001 3781  Query 1 3870  use `test`; create table t3(n int)

master-bin.000001 3870  Gtid  1 3912  BEGIN GTID 0-1-11

master-bin.000001 3912  Query 1 4007  use `test`; insert into t3 values(1),(2)

master-bin.000001 4007  Query 1 4080  COMMIT

**** SHOW RELAYLOG EVENTS on default ****

relaylog_name = 'No such row'

SHOW RELAYLOG EVENTS IN 'No such row';

Log_name  Pos Event_type  Server_id End_log_pos Info

connection default;