[MDEV-30620] Parallel rpl tests failing in BB with mysqld got signal 6 on SHOW SLAVE STATUS Created: 2023-02-08  Updated: 2023-05-25  Resolved: 2023-04-25

Status: Closed
Project: MariaDB Server
Component/s: Replication, Tests
Affects Version/s: 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11, 11.0
Fix Version/s: 10.11.3, 10.4.29, 10.5.20, 10.6.13, 10.9.6, 10.10.4

Type: Bug Priority: Critical
Reporter: Angelique Sklavounos (Inactive) Assignee: Andrei Elkin
Resolution: Fixed Votes: 0
Labels: None

Attachments: Text File 10.6-hang.txt     File error_logs.tar.gz    

 Description   

10.4 493f2bca7

binlog_encryption.rpl_parallel 'innodb,mix' w4 [ fail ]
        Test ended at 2023-02-08 12:10:21
 
CURRENT_TEST: binlog_encryption.rpl_parallel
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from ./suite/rpl/include/rpl_parallel.inc at line 2022:
included from /home/buildbot/buildbot/build/mariadb-10.4.29/mysql-test/suite/binlog_encryption/rpl_parallel.test at line 2:
At line 90: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
SET GLOBAL debug_dbug= '+d,inject_analyze_table_sleep';
connection server_1;
SET @old_dbug_slave= @@SESSION.debug_dbug;
SET SESSION debug_dbug="+d,binlog_force_commit_id";
SET @commit_id= 10000;
ANALYZE TABLE t2;
Table	Op	Msg_type	Msg_text
test.t2	analyze	status	Engine-independent statistics collected
test.t2	analyze	status	OK
INSERT INTO t3 VALUES (120, 0);
SET @commit_id= 10001;
INSERT INTO t3 VALUES (121, 0);
SET SESSION debug_dbug=@old_dbug_slave;
SELECT * FROM t3 WHERE a >= 120 ORDER BY a;
a	b
120	0
121	0
include/save_master_gtid.inc
connection server_2;
include/start_slave.inc
 
More results from queries before failure can be found in /dev/shm/var/4/log/rpl_parallel.log
 
 
Server [mysqld.2 - pid: 2985, winpid: 2985, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
$ /home/buildbot/buildbot/build/mariadb-10.4.29/sql/mysqld --defaults-group-suffix=.2 --defaults-file=/dev/shm/var/4/my.cnf --log-output=file --binlog-format=mixed --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --log-bin=slave-bin --core-file --loose-debug-sync-timeout=300
2023-02-08 12:10:07 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
2023-02-08 12:10:07 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2023-02-08 12:10:07 0 [Note] Starting MariaDB 10.4.29-MariaDB-debug-log source revision 493f2bca76116c1696d42823e2218b1552aeaf8c as process 2986
2023-02-08 12:10:07 0 [Note] Plugin 'partition' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'SEQUENCE' is disabled.
2023-02-08 12:10:07 0 [Note] InnoDB: Using Linux native AIO
2023-02-08 12:10:07 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2023-02-08 12:10:07 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2023-02-08 12:10:07 0 [Note] InnoDB: Uses event mutexes
2023-02-08 12:10:07 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
2023-02-08 12:10:07 0 [Note] InnoDB: Number of pools: 1
2023-02-08 12:10:07 0 [Note] InnoDB: Using generic crc32 instructions
2023-02-08 12:10:07 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
2023-02-08 12:10:07 0 [Note] InnoDB: Completed initialization of buffer pool
2023-02-08 12:10:07 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2023-02-08 12:10:07 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2023-02-08 12:10:07 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2023-02-08 12:10:07 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2023-02-08 12:10:07 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2023-02-08 12:10:07 0 [Note] InnoDB: 10.4.29 started; log sequence number 68738; transaction id 33
2023-02-08 12:10:07 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var/4/mysqld.2/data/ib_buffer_pool
2023-02-08 12:10:07 0 [Note] InnoDB: Buffer pool(s) load completed at 230208 12:10:07
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_CMP' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'FEEDBACK' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'user_variables' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2023-02-08 12:10:07 0 [Note] Plugin 'unix_socket' is disabled.
2023-02-08 12:10:07 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.29/sql/mysqld: unknown option '--loose-pam-debug'
2023-02-08 12:10:07 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.29/sql/mysqld: unknown option '--loose-aria'
2023-02-08 12:10:07 0 [Note] Server socket created on IP: '127.0.0.1'.
2023-02-08 12:10:07 0 [Note] Reading of all Master_info entries succeeded
2023-02-08 12:10:07 0 [Note] Added new Master_info '' to hash table
2023-02-08 12:10:07 0 [Note] /home/buildbot/buildbot/build/mariadb-10.4.29/sql/mysqld: ready for connections.
Version: '10.4.29-MariaDB-debug-log'  socket: '/dev/shm/var/tmp/4/mysqld.2.sock'  port: 16021  Source distribution
2023-02-08 12:10:08 10 [Note] Deleted Master_info file '/dev/shm/var/4/mysqld.2/data/master.info'.
2023-02-08 12:10:08 10 [Note] Deleted Master_info file '/dev/shm/var/4/mysqld.2/data/relay-log.info'.
2023-02-08 12:10:08 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-02-08 12:10:08 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000001', master_log_pos='4'.
2023-02-08 12:10:08 12 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 4
2023-02-08 12:10:08 13 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
2023-02-08 12:10:08 12 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication started in log 'master-bin.000001' at position 4
2023-02-08 12:10:08 13 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:08 13 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 369
2023-02-08 12:10:08 13 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:08 12 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 369
2023-02-08 12:10:08 12 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:08 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-02-08 12:10:08 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000001', master_log_pos='369'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000001', master_log_pos='369'.
2023-02-08 12:10:08 10 [Note] Previous Using_Gtid=No. New Using_Gtid=Slave_Pos
2023-02-08 12:10:08 16 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 369
2023-02-08 12:10:08 16 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position ''
2023-02-08 12:10:09 17 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 369, relay log './slave-relay-bin.000001' position: 4; GTID position ''
2023-02-08 12:10:09 17 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:09 17 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 369; GTID position ''
2023-02-08 12:10:09 17 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 16 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 369; GTID position 
2023-02-08 12:10:09 16 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 28 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 369
2023-02-08 12:10:09 28 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position ''
2023-02-08 12:10:09 29 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 369, relay log './slave-relay-bin.000001' position: 4; GTID position ''
2023-02-08 12:10:09 29 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:09 29 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 2171; GTID position '0-1-9,1-1-1'
2023-02-08 12:10:09 29 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 28 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 2171; GTID position 1-1-1,0-1-9
2023-02-08 12:10:09 28 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 41 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 2171
2023-02-08 12:10:09 41 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-1,0-1-9'
2023-02-08 12:10:09 42 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 2171, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-9,1-1-1'
2023-02-08 12:10:09 42 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:09 42 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 2754; GTID position '0-1-9,1-1-2,2-1-1'
2023-02-08 12:10:09 42 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 41 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 2754; GTID position 1-1-2,2-1-1,0-1-9
2023-02-08 12:10:09 41 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 54 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 2754
2023-02-08 12:10:09 54 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-9,2-1-1'
2023-02-08 12:10:09 55 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 2754, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-9,1-1-2,2-1-1'
2023-02-08 12:10:09 55 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:09 55 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 1560; GTID position '0-1-14,1-1-2,2-1-1'
2023-02-08 12:10:09 55 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:09 54 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 1560; GTID position 1-1-2,0-1-14,2-1-1
2023-02-08 12:10:09 54 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 68 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 1560
2023-02-08 12:10:10 68 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-14,2-1-1'
2023-02-08 12:10:10 69 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 1560, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-14,1-1-2,2-1-1'
2023-02-08 12:10:10 69 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:10 69 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 2009; GTID position '0-1-15,1-1-2,2-1-1'
2023-02-08 12:10:10 69 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 68 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 2347; GTID position 1-1-2,0-1-17,2-1-1
2023-02-08 12:10:10 68 [Note] master was 127.0.0.1:16020
handle_slave_sql: mutex: LOCK_wait_commit (0x62b0003e16f8) unlocking
2023-02-08 12:10:10 80 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 2009
2023-02-08 12:10:10 80 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-15,2-1-1'
2023-02-08 12:10:10 81 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 2009, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-15,1-1-2,2-1-1'
2023-02-08 12:10:10 81 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:10 81 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 2347; GTID position '0-1-17,1-1-2,2-1-1'
2023-02-08 12:10:10 81 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 80 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 2347; GTID position 1-1-2,0-1-17,2-1-1
2023-02-08 12:10:10 80 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 92 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 2347
2023-02-08 12:10:10 92 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-17,2-1-1'
2023-02-08 12:10:10 93 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 2347, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-17,1-1-2,2-1-1'
2023-02-08 12:10:10 102 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-19, Internal MariaDB error code: 1927
2023-02-08 12:10:10 102 [Warning] Slave: Connection was killed Error_code: 1927
2023-02-08 12:10:10 102 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 2347; GTID position '0-1-17,1-1-2,2-1-1'
2023-02-08 12:10:10 93 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:10 101 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:10 101 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:10 101 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 2642; GTID position '0-1-18,1-1-2,2-1-1'
2023-02-08 12:10:10 93 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 2642; GTID position '0-1-18,1-1-2,2-1-1'
2023-02-08 12:10:10 93 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 92 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 3273; GTID position 1-1-2,0-1-20,2-1-1
2023-02-08 12:10:10 92 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 104 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 2642
2023-02-08 12:10:10 104 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-18,2-1-1'
2023-02-08 12:10:10 105 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 2642, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-18,1-1-2,2-1-1'
2023-02-08 12:10:10 105 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:10 105 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 3441; GTID position '0-1-21,1-1-2,2-1-1'
2023-02-08 12:10:10 105 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 104 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 3441; GTID position 1-1-2,0-1-21,2-1-1
2023-02-08 12:10:10 104 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:10 116 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 3441
2023-02-08 12:10:10 116 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-21,2-1-1'
2023-02-08 12:10:10 117 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 3441, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-21,1-1-2,2-1-1'
2023-02-08 12:10:10 126 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-23, Internal MariaDB error code: 1927
2023-02-08 12:10:10 126 [Warning] Slave: Connection was killed Error_code: 1927
2023-02-08 12:10:10 126 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 3441; GTID position '0-1-21,1-1-2,2-1-1'
2023-02-08 12:10:10 117 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:10 125 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:10 125 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:10 125 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 3441; GTID position '0-1-21,1-1-2,2-1-1'
2023-02-08 12:10:10 117 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 3736; GTID position '0-1-22,1-1-2,2-1-1'
2023-02-08 12:10:10 117 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 128 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 3736, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-22,1-1-2,2-1-1'
2023-02-08 12:10:11 128 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:11 128 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 4535; GTID position '0-1-25,1-1-2,2-1-1'
2023-02-08 12:10:11 128 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 116 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 4535; GTID position 1-1-2,0-1-25,2-1-1
2023-02-08 12:10:11 116 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 139 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 4535
2023-02-08 12:10:11 139 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-25,2-1-1'
2023-02-08 12:10:11 140 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 4535, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-25,1-1-2,2-1-1'
2023-02-08 12:10:11 140 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:11 140 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 4535; GTID position '0-1-25,1-1-2,2-1-1'
2023-02-08 12:10:11 140 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 139 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 4535; GTID position 1-1-2,0-1-25,2-1-1
2023-02-08 12:10:11 139 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-02-08 12:10:11 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000002', master_log_pos='4535'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000002', master_log_pos='4535'.
2023-02-08 12:10:11 10 [Note] Previous Using_Gtid=Slave_Pos. New Using_Gtid=No
2023-02-08 12:10:11 151 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 4535
2023-02-08 12:10:11 151 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication started in log 'master-bin.000002' at position 4535
2023-02-08 12:10:11 152 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 4535, relay log './slave-relay-bin.000001' position: 4
2023-02-08 12:10:11 161 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-27, Internal MariaDB error code: 1927
2023-02-08 12:10:11 161 [Warning] Slave: Connection was killed Error_code: 1927
2023-02-08 12:10:11 161 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 4535
2023-02-08 12:10:11 152 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:11 160 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:11 160 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:11 160 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 4535
2023-02-08 12:10:11 152 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 4830
2023-02-08 12:10:11 152 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 163 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 4830, relay log './slave-relay-bin.000002' position: 851
2023-02-08 12:10:11 163 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:11 163 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 5629
2023-02-08 12:10:11 163 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:11 151 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 5629
2023-02-08 12:10:11 151 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-02-08 12:10:12 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000002', master_log_pos='5629'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000002', master_log_pos='5629'.
2023-02-08 12:10:12 10 [Note] Previous Using_Gtid=No. New Using_Gtid=Slave_Pos
2023-02-08 12:10:12 174 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 5629
2023-02-08 12:10:12 174 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-29,2-1-1'
2023-02-08 12:10:12 175 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 5629, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-29,1-1-2,2-1-1'
2023-02-08 12:10:12 175 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:12 175 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 5629; GTID position '0-1-29,1-1-2,2-1-1'
2023-02-08 12:10:12 175 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 174 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 5629; GTID position 1-1-2,0-1-29,2-1-1
2023-02-08 12:10:12 174 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 186 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 5629
2023-02-08 12:10:12 186 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-2,0-1-29,2-1-1'
2023-02-08 12:10:12 187 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 5629, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-29,1-1-2,2-1-1'
2023-02-08 12:10:12 190 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-33, Internal MariaDB error code: 1927
2023-02-08 12:10:12 190 [Warning] Slave: Connection was killed Error_code: 1927
2023-02-08 12:10:12 190 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 7341; GTID position '0-1-30,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 187 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:12 191 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:12 191 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
2023-02-08 12:10:12 191 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 7596; GTID position '0-1-31,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 187 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 7596; GTID position '0-1-31,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 187 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 186 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 8151; GTID position 1-1-3,0-1-34,3-1-1,2-1-2
2023-02-08 12:10:12 186 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 192 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 7596
2023-02-08 12:10:12 192 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-31,3-1-1,2-1-2'
2023-02-08 12:10:12 193 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 7596, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-31,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 193 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:12 193 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 8321; GTID position '0-1-35,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 193 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 192 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 8321; GTID position 1-1-3,0-1-35,3-1-1,2-1-2
2023-02-08 12:10:12 192 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 204 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 8321
2023-02-08 12:10:12 204 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-35,3-1-1,2-1-2'
2023-02-08 12:10:12 205 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 8321, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-35,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 205 [ERROR] Slave SQL: Connection was killed, Internal MariaDB error code: 1927
2023-02-08 12:10:12 205 [Warning] Slave: Connection was killed Error_code: 1927
2023-02-08 12:10:12 205 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 8321; GTID position '0-1-35,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 205 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 8560; GTID position '0-1-36,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:12 205 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 204 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 18738; GTID position 1-1-3,0-1-37,3-1-1,2-1-2
2023-02-08 12:10:12 204 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:12 216 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 8560
2023-02-08 12:10:12 216 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-36,3-1-1,2-1-2'
2023-02-08 12:10:12 217 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 8560, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-36,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 217 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 217 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 18906; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 217 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 216 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 18906; GTID position 1-1-3,0-1-38,3-1-1,2-1-2
2023-02-08 12:10:13 216 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 228 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 18906
2023-02-08 12:10:13 228 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-38,3-1-1,2-1-2'
2023-02-08 12:10:13 229 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 18906, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 229 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 229 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 18906; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 229 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 228 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 18906; GTID position 1-1-3,0-1-38,3-1-1,2-1-2
2023-02-08 12:10:13 228 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 240 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 18906
2023-02-08 12:10:13 240 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-38,3-1-1,2-1-2'
2023-02-08 12:10:13 241 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 18906, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 241 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 241 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 20190; GTID position '0-1-44,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 241 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 240 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 20190; GTID position 1-1-3,0-1-44,3-1-1,2-1-2
2023-02-08 12:10:13 240 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 244 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 20190
2023-02-08 12:10:13 244 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-44,3-1-1,2-1-2'
2023-02-08 12:10:13 245 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 20190, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-44,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 245 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 245 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 20618; GTID position '0-1-46,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 245 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 244 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 20618; GTID position 1-1-3,0-1-46,3-1-1,2-1-2
2023-02-08 12:10:13 244 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 248 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 20618
2023-02-08 12:10:13 248 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-46,3-1-1,2-1-2'
2023-02-08 12:10:13 249 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 20618, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-46,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 259 [ERROR] Slave SQL: Error 'Duplicate entry '111' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t3 VALUES (111, 2)', Gtid 0-1-48, Internal MariaDB error code: 1062
2023-02-08 12:10:13 259 [Warning] Slave: Duplicate entry '111' for key 'PRIMARY' Error_code: 1062
2023-02-08 12:10:13 259 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000002' position 20788; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 249 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 249 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 20788; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 249 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 260 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 20788, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 260 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 260 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 21132; GTID position '0-1-49,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 260 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 248 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 21132; GTID position 1-1-3,0-1-49,3-1-1,2-1-2
2023-02-08 12:10:13 248 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 271 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 21132
2023-02-08 12:10:13 271 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-49,3-1-1,2-1-2'
2023-02-08 12:10:13 272 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 21132, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-49,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 272 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 272 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 21865; GTID position '0-1-53,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 272 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 271 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 21865; GTID position 1-1-3,0-1-53,3-1-1,2-1-2
2023-02-08 12:10:13 271 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 283 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 21865
2023-02-08 12:10:13 283 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-53,3-1-1,2-1-2'
2023-02-08 12:10:13 284 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 21865, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-53,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 284 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:13 284 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 22574; GTID position '0-1-57,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:13 284 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:13 283 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 22574; GTID position 1-1-3,0-1-57,3-1-1,2-1-2
2023-02-08 12:10:13 283 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 296 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 22574
2023-02-08 12:10:14 296 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-57,3-1-1,2-1-2'
2023-02-08 12:10:14 297 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 22574, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-57,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 297 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:14 297 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 23324; GTID position '0-1-61,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 297 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 296 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 23324; GTID position 1-1-3,0-1-61,3-1-1,2-1-2
2023-02-08 12:10:14 296 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 308 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000002' at position 23324
2023-02-08 12:10:14 309 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 23324, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-61,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 308 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-61,3-1-1,2-1-2'
2023-02-08 12:10:14 310 [ERROR] Slave SQL: Query partially completed on the master (error on master: 1317) and was aborted. There is a chance that your master is inconsistent at this point. If you are sure that your master is ok, run this query manually on the slave and then restart the slave with SET GLOBAL SQL_SLAVE_SKIP_COUNTER=1; START SLAVE; . Query: 'INSERT INTO t6 VALUES (1), (2), (3)', Gtid 0-1-68, Internal MariaDB error code: 1317
2023-02-08 12:10:14 310 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000003' position 837; GTID position '0-1-67,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 309 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:14 309 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 837; GTID position '0-1-67,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 309 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 308 [Note] Slave I/O thread exiting, read up to log 'master-bin.000003', position 1054; GTID position 1-1-3,0-1-68,3-1-1,2-1-2
2023-02-08 12:10:14 308 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 311 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000003' at position 837
2023-02-08 12:10:14 311 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-68,3-1-1,2-1-2'
2023-02-08 12:10:14 312 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 837, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-68,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 312 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:14 312 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 312 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 311 [Note] Slave I/O thread exiting, read up to log 'master-bin.000003', position 1427; GTID position 1-1-3,0-1-70,3-1-1,2-1-2
2023-02-08 12:10:14 311 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 314 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000003' at position 1427
2023-02-08 12:10:14 314 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-70,3-1-1,2-1-2'
2023-02-08 12:10:14 315 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1427, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 315 [ERROR] Slave SQL: Error 'Duplicate entry '32' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t2 VALUES (32)', Gtid 0-1-71, Internal MariaDB error code: 1062
2023-02-08 12:10:14 315 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
2023-02-08 12:10:14 315 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000003' position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 315 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 315 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 314 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
2023-02-08 12:10:14 314 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 807; GTID position 1-1-3,0-1-73,3-1-1,2-1-2
2023-02-08 12:10:14 314 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:14 316 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000003' at position 1427
2023-02-08 12:10:14 316 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-70,3-1-1,2-1-2'
2023-02-08 12:10:14 317 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1427, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 327 [ERROR] Slave SQL: Error 'Duplicate entry '32' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t2 VALUES (32)', Gtid 0-1-71, Internal MariaDB error code: 1062
2023-02-08 12:10:14 327 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
2023-02-08 12:10:14 327 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000003' position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 317 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:14 317 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:14 317 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:15 328 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1427, relay log './slave-relay-bin.000002' position: 4; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:15 338 [ERROR] Slave SQL: Error 'Duplicate entry '32' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t2 VALUES (32)', Gtid 0-1-71, Internal MariaDB error code: 1062
2023-02-08 12:10:15 338 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
2023-02-08 12:10:15 338 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000003' position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:15 328 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1427; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:15 328 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:15 316 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 807; GTID position 1-1-3,0-1-73,3-1-1,2-1-2
2023-02-08 12:10:15 316 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:15 339 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000003' at position 1427
2023-02-08 12:10:15 339 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-71,3-1-1,2-1-2'
2023-02-08 12:10:15 340 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1427, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-71,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:15 340 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:15 340 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 1167; GTID position '0-1-75,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:15 340 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:15 339 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 1167; GTID position 1-1-3,0-1-75,3-1-1,2-1-2
2023-02-08 12:10:15 339 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:15 351 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000004' at position 1167
2023-02-08 12:10:15 351 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-75,3-1-1,2-1-2'
2023-02-08 12:10:15 352 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 1167, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-75,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:16 352 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:16 352 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 1550; GTID position '0-1-77,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:16 352 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:16 351 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 1550; GTID position 1-1-3,0-1-77,3-1-1,2-1-2
2023-02-08 12:10:16 351 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:16 363 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000004' at position 1550
2023-02-08 12:10:16 363 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-77,3-1-1,2-1-2'
2023-02-08 12:10:16 364 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 1550, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-77,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:16 364 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:16 364 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 1716; GTID position '0-1-78,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:16 364 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:16 363 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 1716; GTID position 1-1-3,0-1-78,3-1-1,2-1-2
2023-02-08 12:10:16 363 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:16 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-02-08 12:10:16 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000004', master_log_pos='1716'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000004', master_log_pos='1716'.
2023-02-08 12:10:16 10 [Note] Previous Using_Gtid=Slave_Pos. New Using_Gtid=No
2023-02-08 12:10:16 375 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000004' at position 1716
2023-02-08 12:10:16 375 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication started in log 'master-bin.000004' at position 1716
2023-02-08 12:10:16 376 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 1716, relay log './slave-relay-bin.000001' position: 4
2023-02-08 12:10:16 376 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:16 376 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 2213
2023-02-08 12:10:16 376 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:16 375 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 807
2023-02-08 12:10:16 375 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:16 387 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 807
2023-02-08 12:10:16 387 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication started in log 'master-bin.000005' at position 807
2023-02-08 12:10:16 388 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 2213, relay log './slave-relay-bin.000002' position: 1053
2023-02-08 12:10:17 388 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:17 388 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 807
2023-02-08 12:10:17 388 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 387 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 807
2023-02-08 12:10:17 387 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-02-08 12:10:17 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000005', master_log_pos='807'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000005', master_log_pos='807'.
2023-02-08 12:10:17 10 [Note] Previous Using_Gtid=No. New Using_Gtid=Slave_Pos
2023-02-08 12:10:17 399 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 807
2023-02-08 12:10:17 399 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-100,3-1-1,2-1-2'
2023-02-08 12:10:17 400 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 807, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-100,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 400 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:17 400 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 807; GTID position '0-1-100,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 400 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 399 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 807; GTID position 1-1-3,0-1-100,3-1-1,2-1-2
2023-02-08 12:10:17 399 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 411 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 807
2023-02-08 12:10:17 411 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-100,3-1-1,2-1-2'
2023-02-08 12:10:17 412 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 807, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-100,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 412 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:17 412 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 2010; GTID position '0-1-104,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 412 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 411 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 2010; GTID position 1-1-3,0-1-104,3-1-1,2-1-2
2023-02-08 12:10:17 411 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 416 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 2010
2023-02-08 12:10:17 416 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-104,3-1-1,2-1-2'
2023-02-08 12:10:17 417 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 2010, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-104,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 417 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:17 417 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 2010; GTID position '0-1-104,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 417 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 416 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 2010; GTID position 1-1-3,0-1-104,3-1-1,2-1-2
2023-02-08 12:10:17 416 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 428 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 2010
2023-02-08 12:10:17 428 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-104,3-1-1,2-1-2'
2023-02-08 12:10:17 429 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 2010, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-104,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 429 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:17 429 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 3217; GTID position '0-1-108,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 429 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 428 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 3217; GTID position 1-1-3,0-1-108,3-1-1,2-1-2
2023-02-08 12:10:17 428 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 433 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 3217
2023-02-08 12:10:17 433 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-108,3-1-1,2-1-2'
2023-02-08 12:10:17 434 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 3217, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-108,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 434 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:17 434 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 3217; GTID position '0-1-108,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 434 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 433 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 3217; GTID position 1-1-3,0-1-108,3-1-1,2-1-2
2023-02-08 12:10:17 433 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:17 445 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 3217
2023-02-08 12:10:17 445 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-108,3-1-1,2-1-2'
2023-02-08 12:10:17 446 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 3217, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-108,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:17 445 [Warning] Unexpected break of being relay-logged GTID 0-1-1000 event group by the current GTID event 0-1-1001
queue_event: info: Adjust master_log_pos 4261->4261 to account for master-side filtering
queue_event: mutex: LOCK_log (0x62a0000563b0) locking
queue_event: mutex: LOCK_log (0x62a0000563b0) locked
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locked
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) unlocking
MYSQL_BIN_LOG::write_event_buffer: info: max_size: 1073741824
my_b_flush_io_cache: enter: cache: 0x62a000056740
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) locked
my_write: my: fd: 91  Buffer: 0x629000be2208  Count: 42  MyFlags: 564
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1791
my_tell: exit: pos: 1791
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) unlocking
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locked
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1791
my_tell: exit: pos: 1791
my_seek: my: fd: 91 Pos: 0  Whence: 2  MyFlags: 0
my_seek: exit: pos: 1791
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1791
my_tell: exit: pos: 1791
my_seek: my: fd: 91 Pos: 1791  Whence: 0  MyFlags: 0
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) unlocking
queue_event: info: master_log_pos: 4261
harvest_bytes_written: info: counter: 2100  bytes_written: 42
queue_event: mutex: LOCK_log (0x62a0000563b0) unlocking
queue_event: mutex: data_lock (0x62a000055b10) unlocking
queue_event: info: error: 0
handle_slave_io: info: log_space_limit=0 log_space_total=2100 ignore_log_space_limit=0
handle_slave_io: THD::enter_stage: Waiting for master to send event at /home/buildbot/buildbot/build/mariadb-10.4.29/sql/slave.cc:4772
vio_is_blocking: exit: 0
vio_read_buff: enter: sd: 75  buf: 0x629000bd6208  size:4
read_event: packet_header: Memory: 0x629000bd6208  Bytes: (4)
5F 00 00 1B 
vio_read_buff: enter: sd: 75  buf: 0x629000bd6208  size:95
read_event: exit: len: 95  net->read_pos[4]: 99
handle_slave_io: THD::enter_stage: Queueing master event to the relay log at /home/buildbot/buildbot/build/mariadb-10.4.29/sql/slave.cc:4809
queue_event: info: crc: 1328544467
queue_event: mutex: data_lock (0x62a000055b10) locking
queue_event: mutex: data_lock (0x62a000055b10) locked
queue_event: mutex: LOCK_log (0x62a0000563b0) locking
queue_event: mutex: LOCK_log (0x62a0000563b0) locked
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locked
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) unlocking
MYSQL_BIN_LOG::write_event_buffer: info: max_size: 1073741824
my_b_flush_io_cache: enter: cache: 0x62a000056740
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) locked
my_write: my: fd: 91  Buffer: 0x629000be2208  Count: 94  MyFlags: 564
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1885
my_tell: exit: pos: 1885
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) unlocking
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locked
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1885
my_tell: exit: pos: 1885
my_seek: my: fd: 91 Pos: 0  Whence: 2  MyFlags: 0
my_seek: exit: pos: 1885
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1885
my_tell: exit: pos: 1885
my_seek: my: fd: 91 Pos: 1885  Whence: 0  MyFlags: 0
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) unlocking
queue_event: info: master_log_pos: 4355
harvest_bytes_written: info: counter: 2194  bytes_written: 94
queue_event: mutex: LOCK_log (0x62a0000563b0) unlocking
queue_event: mutex: data_lock (0x62a000055b10) unlocking
queue_event: info: error: 0
handle_slave_io: info: log_space_limit=0 log_space_total=2194 ignore_log_space_limit=0
handle_slave_io: THD::enter_stage: Waiting for master to send event at /home/buildbot/buildbot/build/mariadb-10.4.29/sql/slave.cc:4772
vio_is_blocking: exit: 0
vio_read_buff: enter: sd: 75  buf: 0x629000bd6208  size:4
read_event: packet_header: Memory: 0x629000bd6208  Bytes: (4)
20 00 00 1C 
vio_read_buff: enter: sd: 75  buf: 0x629000bd6208  size:32
read_event: exit: len: 32  net->read_pos[4]: 99
handle_slave_io: THD::enter_stage: Queueing master event to the relay log at /home/buildbot/buildbot/build/mariadb-10.4.29/sql/slave.cc:4809
queue_event: info: crc: 3603682371
queue_event: mutex: data_lock (0x62a000055b10) locking
queue_event: mutex: data_lock (0x62a000055b10) locked
queue_event: mutex: LOCK_log (0x62a0000563b0) locking
queue_event: mutex: LOCK_log (0x62a0000563b0) locked
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locked
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) unlocking
MYSQL_BIN_LOG::write_event_buffer: info: max_size: 1073741824
my_b_flush_io_cache: enter: cache: 0x62a000056740
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) locked
my_write: my: fd: 91  Buffer: 0x629000be2208  Count: 31  MyFlags: 564
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1916
my_tell: exit: pos: 1916
my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000056790) unlocking
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locking
my_hash_first_from_hash_value: exit: found key at 1
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) locked
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1916
my_tell: exit: pos: 1916
my_seek: my: fd: 91 Pos: 0  Whence: 2  MyFlags: 0
my_seek: exit: pos: 1916
my_tell: my: fd: 91  MyFlags: 0
my_seek: my: fd: 91 Pos: 0  Whence: 1  MyFlags: 0
my_seek: exit: pos: 1916
my_tell: exit: pos: 1916
my_seek: my: fd: 91 Pos: 1916  Whence: 0  MyFlags: 0
MYSQL_BIN_LOG::write_event_buffer: mutex: info->append_buffer_lock (0x62a000056790) unlocking
queue_event: info: master_log_pos: 4386
harvest_bytes_written: info: counter: 2225  bytes_written: 31
queue_event: mutex: LOCK_log (0x62a0000563b0) unlocking
my_hash_first_from_hash_value: exit: found key at 1
my_hash_first_from_hash_value: exit: found key at 1
queue_event: m

Traceback from the slave error log: https://buildbot.mariadb.net/buildbot/builders/kvm-asan/builds/9898/steps/mtr_nm/logs/mysqld.2.err.4

2023-02-08 12:10:18 473 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 8395
2023-02-08 12:10:18 473 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-3,0-1-1025,3-1-1,2-1-2'
2023-02-08 12:10:18 474 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 8395, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-1025,1-1-3,2-1-2,3-1-1'
2023-02-08 12:10:18 474 [Note] Error reading relay log event: slave SQL thread was killed
2023-02-08 12:10:18 474 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000005' at position 10581; GTID position '0-1-1025,1-1-10,2-1-8,3-1-1'
2023-02-08 12:10:18 474 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:18 473 [Note] Slave I/O thread exiting, read up to log 'master-bin.000005', position 10581; GTID position 1-1-10,0-1-1025,3-1-1,2-1-8
2023-02-08 12:10:18 473 [Note] master was 127.0.0.1:16020
2023-02-08 12:10:18 485 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000005' at position 10581
2023-02-08 12:10:18 485 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication starts at GTID position '1-1-10,0-1-1025,3-1-1,2-1-8'
2023-02-08 12:10:18 486 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000005' at position 10581, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-1025,1-1-10,2-1-8,3-1-1'
safe_mutex: Trying to lock uninitialized mutex at /home/buildbot/buildbot/build/mariadb-10.4.29/sql/rpl_parallel.cc, line 2424
230208 12:10:18 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
Server version: 10.4.29-MariaDB-debug-log source revision: 493f2bca76116c1696d42823e2218b1552aeaf8c
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=7
max_threads=153
thread_count=25
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63657 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x62b0000af208
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7fb40e7b3810 thread_stack 0x5fc00
/lib/x86_64-linux-gnu/libasan.so.5(+0x6cd30)[0x7fb42585fd30]
mysys/stacktrace.c:174(my_print_stacktrace)[0x5631da5cc062]
sql/signal_handler.cc:234(handle_fatal_signal)[0x5631d910601c]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x153c0)[0x7fb42565a3c0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb)[0x7fb42514618b]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x12b)[0x7fb425125859]
mysys/thr_mutex.c:250(safe_mutex_lock)[0x5631da5d84ba]
psi/mysql_thread.h:717(inline_mysql_mutex_lock)[0x5631d8e8b9d6]
sql/rpl_parallel.cc:2425(rpl_parallel::workers_idle())[0x5631d8e9c239]
sql/slave.cc:3190(send_show_master_info_data(THD*, Master_info*, bool, String*))[0x5631d86d765c]
sql/slave.cc:2837(show_master_info(THD*, Master_info*, bool))[0x5631d86d472f]
sql/sql_parse.cc:4185(mysql_execute_command(THD*))[0x5631d8961948]
sql/sql_parse.cc:7986(mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool))[0x5631d897c3cf]
sql/sql_parse.cc:1860(dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool))[0x5631d8952c16]
sql/sql_parse.cc:1378(do_command(THD*))[0x5631d894f716]
sql/sql_connect.cc:1420(do_handle_one_connection(CONNECT*))[0x5631d8d5235d]
sql/sql_connect.cc:1325(handle_one_connection)[0x5631d8d51c01]
perfschema/pfs.cc:1871(pfs_spawn_thread)[0x5631d9a5b2ab]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x9609)[0x7fb42564e609]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7fb425222293]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x62b0000b6228): SHOW SLAVE STATUS



 Comments   
Comment by Angelique Sklavounos (Inactive) [ 2023-02-09 ]

Possible similar test failures:
binlog_encryption.rpl_parallel_slave_bgc_kill
https://buildbot.mariadb.net/buildbot/builders/kvm-fulltest2/builds/39675

binlog_encryption.rpl_parallel_slave_bgc_kill 'innodb,stmt' w2 [ fail ]
        Test ended at 2023-01-30 17:05:38
 
CURRENT_TEST: binlog_encryption.rpl_parallel_slave_bgc_kill
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from ./suite/rpl/include/rpl_parallel_slave_bgc_kill.inc at line 172:
included from /mnt/buildbot/build/mariadb-10.5.19/mysql-test/suite/binlog_encryption/rpl_parallel_slave_bgc_kill.test at line 2:
At line 90: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
STOP SLAVE IO_THREAD;
SELECT * FROM t3 WHERE a >= 30 ORDER BY a;
a	b
31	31
SET debug_sync='RESET';
SET GLOBAL slave_parallel_threads=0;
SET GLOBAL slave_parallel_threads=10;
SET sql_log_bin=0;
DROP FUNCTION foo;
CREATE FUNCTION foo(x INT, d1 VARCHAR(500), d2 VARCHAR(500))
RETURNS INT DETERMINISTIC
BEGIN
RETURN x;
END
||
SET sql_log_bin=1;
connection server_1;
INSERT INTO t3 VALUES (39,0);
connection server_2;
include/start_slave.inc

rpl.rpl_parallel_retry
https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10241

rpl.rpl_parallel_retry 'innodb,mix'      w3 [ fail ]
        Test ended at 2023-01-31 10:37:41
 
CURRENT_TEST: rpl.rpl_parallel_retry
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /usr/share/mysql-test/suite/rpl/t/rpl_parallel_retry.test at line 252:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
 
The result from queries just before the failure was:
< snip >
*** MDEV-7065: Incorrect relay log position in parallel replication after retry of transaction ***
connection server_2;
include/stop_slave.inc
connection server_1;
BEGIN;
INSERT INTO t1 VALUES (100, 0);
INSERT INTO t1 VALUES (101, 0);
INSERT INTO t1 VALUES (102, 0);
INSERT INTO t1 VALUES (103, 0);
COMMIT;
SELECT * FROM t1 WHERE a >= 100 ORDER BY a;
a	b
100	0
101	0
102	0
103	0
connection server_2;
SET @old_dbug= @@GLOBAL.debug_dbug;
SET GLOBAL debug_dbug="+d,rpl_parallel_simulate_temp_err_xid";
include/start_slave.inc

rpl.rpl_parallel_optimistic
https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10259

rpl.rpl_parallel_optimistic 'innodb,row' w2 [ fail ]
        Test ended at 2023-02-02 07:21:48
 
CURRENT_TEST: rpl.rpl_parallel_optimistic
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /usr/share/mysql-test/suite/rpl/t/rpl_parallel_optimistic.test at line 387:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
 
The result from queries just before the failure was:
< snip >
16	4
17	4
18	4
19	4
20	4
21	5
22	5
SELECT * FROM t2 ORDER BY a;
a	b
1	1
2	1
3	1
4	1
5	1
SELECT * FROM t3 ORDER BY a;
a	b
1	3
include/save_master_gtid.inc
connection server_2;
include/start_slave.inc

rpl.rpl_parallel_multilevel
https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10260

rpl.rpl_parallel_multilevel 'innodb,mix' w4 [ fail ]
        Test ended at 2023-02-02 09:52:30
 
CURRENT_TEST: rpl.rpl_parallel_multilevel
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /usr/share/mysql-test/suite/rpl/t/rpl_parallel_multilevel.test at line 100:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
 
The result from queries just before the failure was:
< snip >
include/sync_with_master_gtid.inc
SELECT * FROM t1 ORDER BY a;
a	b
1	1
2	11
3	1
status
Ok, no retry
connection server_3;
include/start_slave.inc
include/sync_with_master_gtid.inc
SELECT * FROM t1 ORDER BY a;
a	b
1	1
2	11
3	1
status
Ok, no retry
connection server_4;
include/start_slave.inc

rpl.parallel_backup
https://buildbot.mariadb.net/buildbot/builders/kvm-fulltest2/builds/39792

rpl.parallel_backup 'innodb,mix'         w4 [ fail ]
        Test ended at 2023-02-07 04:39:25
 
CURRENT_TEST: rpl.parallel_backup
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /mnt/buildbot/build/mariadb-10.10.4/mysql-test/suite/rpl/t/parallel_backup.test at line 87:
At line 90: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: <Unknown> (2013): Lost connection to server during query
 
The result from queries just before the failure was:
< snip >
SET @@global.slave_transaction_retries=0;
include/start_slave.inc
connection aux_slave;
# Xid '1' must be in the output:
XA RECOVER;
formatID	gtrid_length	bqual_length	data
1	1	0	1
connection backup_slave;
BACKUP STAGE START;
BACKUP STAGE BLOCK_COMMIT;
connection aux_slave;
ROLLBACK;
connection backup_slave;
BACKUP STAGE END;
connection slave;
include/stop_slave.inc
SET @@global.innodb_lock_wait_timeout = @sav_innodb_lock_wait_timeout;
SET @@global.slave_transaction_retries= @sav_slave_transaction_retries;
connection slave;
include/start_slave.inc

rpl.rpl_mdev6386
https://buildbot.mariadb.net/buildbot/builders/kvm-fulltest2/builds/39825

rpl.rpl_mdev6386 'innodb,mix'            w2 [ fail ]
        Test ended at 2023-02-08 16:47:45
 
CURRENT_TEST: rpl.rpl_mdev6386
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_sql_error.inc at line 41:
included from /mnt/buildbot/build/mariadb-10.6.13/mysql-test/suite/rpl/t/rpl_mdev6386.test at line 48:
At line 90: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: <Unknown> (2013): Lost connection to server during query
 
The result from queries just before the failure was:
< snip >
INSERT INTO t2 VALUE (2, 1);
INSERT INTO t2 VALUE (3, 1);
INSERT INTO t2 VALUE (4, 1);
INSERT INTO t2 VALUE (5, 1);
INSERT INTO t1 SELECT * FROM t2;
DROP TEMPORARY TABLE t2;
INSERT INTO t1 VALUE (6, 3);
include/save_master_gtid.inc
Contents on master:
SELECT * FROM t1 ORDER BY a;
a	b
1	1
2	1
3	1
4	1
5	1
6	3
connection slave;
START SLAVE;
include/wait_for_slave_sql_error.inc [errno=1062]

rpl.rpl_delayed_slave2
https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10308

rpl.rpl_delayed_slave2 'innodb,row'      w4 [ fail ]
        Test ended at 2023-02-09 12:34:35
 
CURRENT_TEST: rpl.rpl_delayed_slave2
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /usr/share/mysql-test/suite/rpl/t/rpl_delayed_slave2.test at line 51:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
SET timestamp= 0;
include/save_master_gtid.inc
connection slave;
CHANGE MASTER TO master_delay=1;
include/start_slave.inc
SELECT MASTER_GTID_WAIT('GTID1');
MASTER_GTID_WAIT('GTID1')
0
SELECT MASTER_GTID_WAIT('GTID2', 2);
MASTER_GTID_WAIT('GTID2', 2)
-1
include/stop_slave.inc
SELECT * FROM t1 ORDER BY a;
a	b
1	a
2	b
3	b
4	b
CHANGE MASTER TO master_delay=0;
include/start_slave.inc

rpl.rpl_parallel
https://buildbot.mariadb.net/buildbot/builders/kvm-rpm-centos74-amd64-debug/builds/10310

Comment by Angelique Sklavounos (Inactive) [ 2023-02-22 ]

rpl.rpl_parallel_gtid_slave_pos_update_fail
https://buildbot.mariadb.net/buildbot/builders/kvm-fulltest2/builds/40011

Comment by Andrei Elkin [ 2023-02-24 ]

Marko reports as it's seen on https://buildbot.mariadb.org/#/builders/534/builds/3931/steps/7/logs/stdio

rpl.rpl_parallel_domain_slave_single_grp 'innodb,mix' w7 [ fail ]
        Test ended at 2023-02-24 08:25:56
CURRENT_TEST: rpl.rpl_parallel_domain_slave_single_grp
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /home/buildbot/amd64-ubuntu-2204-debug-ps/build/mysql-test/suite/rpl/include/rpl_parallel_domain_slave_single_grp.inc at line 78:
included from /home/buildbot/amd64-ubuntu-2204-debug-ps/build/mysql-test/suite/rpl/t/rpl_parallel_domain_slave_single_grp.test at line 2:
At line 90: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: 2013: Lost connection to MySQL server during query
safe_mutex: Trying to lock uninitialized mutex at /home/buildbot/amd64-ubuntu-2204-debug-ps/build/sql/rpl_parallel.cc, line 2437
psi/mysql_thread.h:765(inline_mysql_mutex_lock)[0x55bd479db9b9]
sql/rpl_parallel.cc:2438(rpl_parallel::workers_idle())[0x55bd479e2f57]
sql/slave.cc:3228(send_show_master_info_data(THD*, Master_info*, bool, String*))[0x55bd476acf0e]
sql/slave.cc:2875(show_master_info(THD*, Master_info*, bool))[0x55bd476aaa0f]
sql/slave.cc:1530(Sql_cmd_show_slave_status::execute(THD*))[0x55bd476a6a9e]
sql/sql_parse.cc:6061(mysql_execute_command(THD*))[0x55bd477bea0d]

Comment by Andrei Elkin [ 2023-03-23 ]

bb-10.4-MDEV-30620 has the commit.

One note though, as it deals with concurrent insert and search in that hash, you may find yourself wondering how the concurrent accesses themself are ruled out correctly.
I am not sure about real chances to hit an issue in that regard, but to cover that part, the current "normal" hash obviously needs conversion to the lock-free one.
I might implement that in the 2nd commit.

Comment by Brandon Nesterenko [ 2023-04-13 ]

Approved.

Comment by Marko Mäkelä [ 2023-04-20 ]

Two test failures in one run:

11.0 c7fe8e51de4e67f8515b3cf8b6bcd1c5bf1d184b

binlog_encryption.rpl_parallel_deadlock_corrupt_binlog 'innodb,row' w27 [ fail ]
        Test ended at 2023-04-17 13:56:06
CURRENT_TEST: binlog_encryption.rpl_parallel_deadlock_corrupt_binlog
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from ./suite/rpl/t/rpl_parallel_deadlock_corrupt_binlog.test at line 65:
included from /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/binlog_encryption/rpl_parallel_deadlock_corrupt_binlog.test at line 2:
At line 90: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: <Unknown> (2013): Lost connection to server during query
safe_mutex: Trying to lock uninitialized mutex at /home/buildbot/amd64-ubuntu-2004-debug/build/sql/rpl_parallel.cc, line 2772

11.0 c7fe8e51de4e67f8515b3cf8b6bcd1c5bf1d184b

rpl.parallel_backup_lsu_off 'innodb,mix' w17 [ fail ]
        Test ended at 2023-04-17 13:57:21
CURRENT_TEST: rpl.parallel_backup_lsu_off
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/rpl/t/parallel_backup.test at line 45:
included from /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/rpl/t/parallel_backup_lsu_off.test at line 8:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
safe_mutex: Trying to lock uninitialized mutex at /home/buildbot/amd64-ubuntu-2004-debug/build/sql/rpl_parallel.cc, line 2772

Comment by Marko Mäkelä [ 2023-04-25 ]

One more test joins the club:

10.6 818d5e48146b7938a7ccca4ccf819afe3ea8a005

rpl.rpl_parallel_multilevel 'innodb,row' w23 [ fail ]
        Test ended at 2023-04-25 10:30:57
CURRENT_TEST: rpl.rpl_parallel_multilevel
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/rpl/t/rpl_parallel_multilevel.test at line 239:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
2023-04-25 10:30:56 24 [Note] Slave SQL thread initialized, starting replication in log 'slave-bin.000001' at position 3453, relay log './mysqld-relay-bin.000001' position: 4; GTID position '0-1-14'
safe_mutex: Trying to lock uninitialized mutex at /home/buildbot/amd64-ubuntu-2004-debug/build/sql/rpl_parallel.cc, line 2535
230425 10:30:56 [ERROR] mysqld got signal 6 ;

Comment by Marko Mäkelä [ 2023-04-26 ]

One more:

10.8 c15c8ef3e357a3e01f775f20027fdac9b227099f

rpl.rpl_start_alter_restart_master 'innodb,mix' w9 [ fail ]
        Test ended at 2023-04-26 11:09:29
CURRENT_TEST: rpl.rpl_start_alter_restart_master
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_io_to_start.inc at line 40:
included from ./include/wait_for_slave_to_start.inc at line 26:
included from ./include/start_slave.inc at line 35:
included from /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/suite/rpl/t/rpl_start_alter_restart_master.test at line 54:
At line 75: query 'let $_slave_check_configured= query_get_value("SHOW SLAVE STATUS", Slave_IO_Running, 1)' failed: <Unknown> (2013): Lost connection to server during query
2023-04-26 11:09:28 17 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16100',replication started in log 'master-bin.000001' at position 840
2023-04-26 11:09:28 18 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 840, relay log './slave-relay-bin.000003' position: 1067
safe_mutex: Trying to lock uninitialized mutex at /home/buildbot/amd64-ubuntu-2004-debug/build/sql/rpl_parallel.cc, line 2772
230426 11:09:28 [ERROR] mysqld got signal 6 ;

Comment by Marko Mäkelä [ 2023-04-27 ]

Today, this is finally merged up to 10.9. On 10.6 there was a hang in a parallel replication test; I hope that you can open another ticket for that or point to an existing ticket about it.

10.6 bb1d1dc84652d43f8b6b92ba722ba8f246ce7124

binlog_encryption.rpl_parallel_gco_wait_kill 'innodb,stmt' w7 [ fail ]  timeout after 900 seconds
        Test ended at 2023-04-27 07:27:41
Test case timeout after 900 seconds
== /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/var/7/log/rpl_parallel_gco_wait_kill.log == 
66	66
67	67
68	68
69	69
70	70
100	100
SET debug_sync='RESET';
connection server_2;
SET debug_sync='now SIGNAL d0_cont';
SET debug_sync='now WAIT_FOR t1_waiting';
SET debug_sync='now SIGNAL d3_cont';
SET debug_sync='now WAIT_FOR t2_waiting';
SET debug_sync='now SIGNAL d1_cont';
SET debug_sync='now WAIT_FOR t3_waiting';
SET debug_sync='now SIGNAL d2_cont';
SET debug_sync='now WAIT_FOR t4_waiting';
KILL THD_ID;
SET debug_sync='now WAIT_FOR t3_killed';
SET debug_sync='now SIGNAL t1_cont';
include/wait_for_slave_sql_error.inc [errno=1317,1927,1964]
 == /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/var/7/tmp/analyze-timeout-mysqld.1.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/var/tmp/' (111)
 == /home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/var/7/tmp/analyze-timeout-mysqld.2.err ==
mysqltest: Could not open connection 'default' after 500 attempts: 2002 Can't connect to local server through socket '/home/buildbot/amd64-ubuntu-2004-debug/build/mysql-test/var/tmp/' (111)

The thread apply all backtrace full output is in 10.6-hang.txt.

Comment by Andrei Elkin [ 2023-04-27 ]

marko, the last comment fits to MDEV-25450 description.

Comment by Andrei Elkin [ 2023-05-25 ]

The description rpl suite failures must have been triggered by MDEV-29639 changes that started updating last_master_timestamp - which is consulted to compute Seconds-behind-master of SSS - more often and eagerly.

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