[MDEV-24440] galera_3nodes.galera_ipv6_mariabackup MTR fails sporadically: Failed to read from: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16028/xtrabackup_sst//1' Created: 2020-12-18  Updated: 2023-04-27

Status: Open
Project: MariaDB Server
Component/s: Galera, Tests
Affects Version/s: 10.2.37, 10.3.28, 10.4.18, 10.5.9, 10.6.0
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Major
Reporter: Stepan Patryshev (Inactive) Assignee: Julius Goryavsky
Resolution: Unresolved Votes: 0
Labels: None
Environment:

kvm-deb-stretch-amd64, kvm-rpm-centos74-aarch64

Attachments: Zip Archive MDEV-24440_102_logs_201217.zip     Zip Archive MDEV-24440_104_logs_201211.zip    
Issue Links:
Blocks
blocks MDEV-19937 Galera test failures on 10.2/10.3 Closed

 Description   

galera_3nodes.galera_ipv6_mariabackup failed on BB 10.2 CS, BB 10.3 CS and BB 10.5 CS: "WSREP: Failed to read from: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16028/xtrabackup_sst//1'".
It seems to be a sporadic issue.

stdio.log:

10.2.37, 6628435e94f11116909163f1e135f86a64f2b6cb, kvm-deb-stretch-amd64

 
galera_3nodes.galera_ipv6_mariabackup 'innodb' w2 [ fail ]
 
        Test ended at 2020-11-17 20:40:43
 
 
 
CURRENT_TEST: galera_3nodes.galera_ipv6_mariabackup
 
 
 
 
 
Failed to start mysqld.2
 
mysqltest failed but provided no output
 
 
 
 
 
 - saving '/dev/shm/var/2/log/galera_3nodes.galera_ipv6_mariabackup-innodb/' to '/dev/shm/var/log/galera_3nodes.galera_ipv6_mariabackup-innodb/'
 
 
 
Retrying test galera_3nodes.galera_ipv6_mariabackup, attempt(2/3)...
 
 
 
worker[2] > Restart  - not started
 
worker[2] > Restart  - not started
 
worker[2] > Restart  - not started
 
***Warnings generated in error logs during shutdown after running tests: galera_3nodes.galera_ipv6_mariabackup
 
 
 
WSREP_SST: [ERROR] /usr//bin/mariabackup finished with error: 1.  Check syslog or /dev/shm/var/2/mysqld.1/data//mariabackup.backup.log for details (20201117 20:40:34.970)
 
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20201117 20:40:34.973)
 
2020-11-17 20:40:34 140293856798464 [ERROR] WSREP: Failed to read from: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16028/xtrabackup_sst//1' --socket '/dev/shm/var/tmp/2/mysqld.1.sock' --datadir '/dev/shm/var/2/mysqld.1/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.1' --gtid '066123c0-293f-11eb-9fe6-ab9099bb5967:0' --gtid-domain-id '0' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300
 
2020-11-17 20:40:34 140293856798464 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16028/xtrabackup_sst//1' --socket '/dev/shm/var/tmp/2/mysqld.1.sock' --datadir '/dev/shm/var/2/mysqld.1/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.1' --gtid '066123c0-293f-11eb-9fe6-ab9099bb5967:0' --gtid-domain-id '0' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300: 22 (Invalid argument)
 
2020-11-17 20:40:34 140293856798464 [ERROR] WSREP: sst sent called when not SST donor, state CONNECTED
 
2020-11-17 20:40:34 140293856798464 [ERROR] WSREP: Command did not run: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16028/xtrabackup_sst//1' --socket '/dev/shm/var/tmp/2/mysqld.1.sock' --datadir '/dev/shm/var/2/mysqld.1/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.1' --gtid '066123c0-293f-11eb-9fe6-ab9099bb5967:0' --gtid-domain-id '0' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300
 
WSREP_SST: [ERROR] xtrabackup_checkpoints missing, failed innobackupex/SST on donor (20201117 20:40:35.093)
 
WSREP_SST: [ERROR] Cleanup after exit with status:2 (20201117 20:40:35.096)
 
2020-11-17 20:40:35 140637445785344 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '[::1]:16028' --datadir '/dev/shm/var/2/mysqld.2/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.2' --parent '24063' --binlog-index 'mysqld-bin.index' --mysqld-args --defaults-group-suffix=.2 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300: 2 (No such file or directory)
 
2020-11-17 20:40:35 140637445785344 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
 
2020-11-17 20:40:35 140637832320064 [ERROR] WSREP: SST failed: 2 (No such file or directory)
 
2020-11-17 20:40:35 140637832320064 [ERROR] Aborting
 
Warning: Memory not freed: 77080
 
 
 
galera_3nodes.galera_parallel_apply_3nodes 'innodb' w1 [ pass ]   3024
 
galera_3nodes.galera_var_dirty_reads2 'innodb' w1 [ pass ]  19456
 
worker[1] > Restart [mysqld.1 - pid: 23050, winpid: 23050] - using different config file
 
worker[1] > Restart [mysqld.2 - pid: 23052, winpid: 23052] - using different config file
 
worker[1] > Restart [mysqld.3 - pid: 23054, winpid: 23054] - using different config file
 
worker[2] mysql-test-run: WARNING: Process [mysqld.3 - pid: 25393, winpid: 25393, exit: 256] died after mysql-test-run waited 0.1 seconds for /dev/shm/var/2/run/mysqld.3.pid to be created.
 
galera_3nodes.galera_ipv6_mariabackup 'innodb' w2 [ retry-fail ]
 
        Test ended at 2020-11-17 20:41:24
 
 
 
CURRENT_TEST: galera_3nodes.galera_ipv6_mariabackup
 
 
 
 
 
Failed to start mysqld.3
 
mysqltest failed but provided no output
 
 
 
 
 
 - skipping '/dev/shm/var/2/log/galera_3nodes.galera_ipv6_mariabackup-innodb/'
 
 
 
Test galera_3nodes.galera_ipv6_mariabackup has failed 2 times, no more retries!
 
 
 
worker[2] > Restart  - using different config file
 
worker[2] > Restart  - using different config file
 
worker[2] > Restart  - using different config file
 
***Warnings generated in error logs during shutdown after running tests: galera_3nodes.galera_ipv6_mariabackup
 
 
 
WSREP_SST: [ERROR] /usr//bin/mariabackup finished with error: 1.  Check syslog or /dev/shm/var/2/mysqld.1/data//mariabackup.backup.log for details (20201117 20:41:09.695)
 
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20201117 20:41:09.697)
 
2020-11-17 20:41:09 140232024389376 [ERROR] WSREP: Failed to read from: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16031/xtrabackup_sst//1' --socket '/dev/shm/var/tmp/2/mysqld.1.sock' --datadir '/dev/shm/var/2/mysqld.1/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.1' --gtid '1281c7e5-293f-11eb-8ae4-630b557b6ffc:0' --gtid-domain-id '0' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300
 
2020-11-17 20:41:09 140232024389376 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16031/xtrabackup_sst//1' --socket '/dev/shm/var/tmp/2/mysqld.1.sock' --datadir '/dev/shm/var/2/mysqld.1/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.1' --gtid '1281c7e5-293f-11eb-8ae4-630b557b6ffc:0' --gtid-domain-id '0' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300: 22 (Invalid argument)
 
2020-11-17 20:41:09 140232024389376 [ERROR] WSREP: Command did not run: wsrep_sst_mariabackup --role 'donor' --address '[::1]:16031/xtrabackup_sst//1' --socket '/dev/shm/var/tmp/2/mysqld.1.sock' --datadir '/dev/shm/var/2/mysqld.1/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.1' --gtid '1281c7e5-293f-11eb-8ae4-630b557b6ffc:0' --gtid-domain-id '0' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300
 
2020-11-17 20:41:09 140232719431424 [Warning] WSREP: 1.0 (node_1): State transfer to -1.-1 (left the group) failed: -22 (Invalid argument)
 
2020-11-17 20:41:09 140211682006784 [Warning] WSREP: 1.0 (node_1): State transfer to -1.-1 (left the group) failed: -22 (Invalid argument)
 
WSREP_SST: [ERROR] Error while getting data from donor node:  exit codes: 1 0 (20201117 20:40:59.306)
 
WSREP_SST: [ERROR] Cleanup after exit with status:32 (20201117 20:40:59.307)
 
2020-11-17 20:40:59 139769971463936 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '[::1]:16031' --datadir '/dev/shm/var/2/mysqld.3/data/' --defaults-file '/dev/shm/var/2/my.cnf' --defaults-group-suffix '.3' --parent '25394' --binlog-index 'mysqld-bin.index' --mysqld-args --defaults-group-suffix=.3 --defaults-file=/dev/shm/var/2/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --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 --core-file --loose-debug-sync-timeout=300: 32 (Broken pipe)
 
2020-11-17 20:40:59 139769971463936 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
 
2020-11-17 20:40:59 139770358473792 [ERROR] WSREP: SST failed: 32 (Broken pipe)
 
2020-11-17 20:40:59 139770358473792 [ERROR] Aborting
 
Warning: Memory not freed: 77080

10.2 CS Server logs.

galera_3nodes.galera_ipv6_mariabackup failed on BB 10.4 CS and BB 10.6 CS with another output.

stdio.log:

10.4.18, 4addd31531f722438b8b702c9cd00c28b61efce3, kvm-rpm-centos74-aarch64

 
galera_3nodes.galera_ipv6_mariabackup 'innodb' w1 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2020-12-11 21:09:52
 
line
 
2020-12-11 21:09:22 0 [Warning] WSREP: server: node_1 unallowed state transition: joined -> joined
 
^ Found warnings in /dev/shm/var/1/log/mysqld.1.err
 
ok
 
 
 
 - saving '/dev/shm/var/1/log/galera_3nodes.galera_ipv6_mariabackup-innodb/' to '/dev/shm/var/log/galera_3nodes.galera_ipv6_mariabackup-innodb/'
 
 
 
Retrying test galera_3nodes.galera_ipv6_mariabackup, attempt(2/3)...
 
 
 
worker[1] > Restart  - not started
 
worker[1] > Restart  - not started
 
worker[1] > Restart  - not started
 
galera_3nodes.galera_wsrep_schema 'innodb' w2 [ pass ]  11708
 
worker[2] > Restart [mysqld.1 - pid: 24822, winpid: 24822] - using different config file
 
worker[2] > Restart [mysqld.2 - pid: 28997, winpid: 28997] - using different config file
 
worker[2] > Restart [mysqld.3 - pid: 24860, winpid: 24860] - using different config file
 
galera_3nodes.galera_ipv6_mariabackup 'innodb' w1 [ retry-pass ]  13608
 
 
 
Retrying test galera_3nodes.galera_ipv6_mariabackup, attempt(3/3)...
 
 
 
worker[1] > Restart  - not started
 
worker[1] > Restart  - not started
 
worker[1] > Restart  - not started

10.4 CS Server logs.
Generated at Thu Feb 08 09:30:00 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.