[MDEV-19926] Galera SST tests fail Created: 2019-07-02  Updated: 2020-05-05  Resolved: 2019-09-09

Status: Closed
Project: MariaDB Server
Component/s: Galera, Galera SST
Affects Version/s: 10.2
Fix Version/s: 10.2.28, 10.3.19, 10.4.9

Type: Bug Priority: Major
Reporter: Jan Lindström (Inactive) Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None


 Description   

Effected tests:

  • galera.galera_ist_mariabackup_innodb_flush_logs
  • galera.galera_autoinc_sst_mariabackup
  • galera.galera_ist_innodb_flush_logs
  • galera.galera_sst_mariabackup
  • galera.galera_sst_mariabackup_encrypt_with_key
  • galera.galera_sst_mariabackup_table_options
  • galera.galera_ist_xtrabackup-v2
  • galera.galera_sst_xtrabackup-v2-options
  • galera.galera_sst_xtrabackup-v2_encrypt_with_key


 Comments   
Comment by Jan Lindström (Inactive) [ 2019-07-02 ]

2019-07-02 13:34:37 139798450767616 [ERROR] WSREP: Failed to read 'ready <addr>' from: wsrep_sst_mariabackup --role 'joiner' --address '127.0.0.1:16047' --datadir '/home/jan/mysql/10.2-sst/mysql-test/var/3/mysqld.2/data/'  --defaults-file '/home/jan/mysql/10.2-sst/mysql-test/var/3/my.cnf' --defaults-group-suffix '.2'  --parent '18310'  '' --binlog-index 'mysqld-bin.index'
2019-07-02 13:34:37 139798450767616 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '127.0.0.1:16047' --datadir '/home/jan/mysql/10.2-sst/mysql-test/var/3/mysqld.2/data/'  --defaults-file '/home/jan/mysql/10.2-sst/mysql-test/var/3/my.cnf' --defaults-group-suffix '.2'  --parent '18310'  '' --binlog-index 'mysqld-bin.index': 2 (No such file or directory)
2019-07-02 13:34:37 139798707975936 [ERROR] WSREP: Failed to prepare for 'mariabackup' SST. Unrecoverable.
2019-07-02 13:34:37 139798707975936 [ERROR] Aborting

Comment by Jan Lindström (Inactive) [ 2019-07-02 ]

 - saving '/home/jan/mysql/10.2-sst/mysql-test/var/2/log/galera.galera_sst_xtrabackup-v2_encrypt_with_key-innodb/' to '/home/jan/mysql/10.2-sst/mysql-test/var/log/galera.galera_sst_xtrabackup-v2_encrypt_with_key-innodb/'
***Warnings generated in error logs during shutdown after running tests: galera.galera_sst_xtrabackup-v2_encrypt_with_key
 
WSREP_SST: [ERROR] ******** FATAL ERROR ***********************  (20190702 13:43:25.680)
WSREP_SST: [ERROR] * Using SSL encryption (encrypt= 2, 3, or 4)  (20190702 13:43:25.682)
WSREP_SST: [ERROR] * is not supported when using nc(netcat).     (20190702 13:43:25.683)
WSREP_SST: [ERROR] ********************************************  (20190702 13:43:25.684)
2019-07-02 13:43:25 140256317794048 [ERROR] WSREP: Failed to read 'ready <addr>' from: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '127.0.0.1:16007' --datadir '/home/jan/mysql/10.2-sst/mysql-test/var/2/mysqld.2/data/'  --defaults-file '/home/jan/mysql/10.2-sst/mysql-test/var/2/my.cnf' --defaults-group-suffix '.2'  --parent '7500'  '' --binlog-index 'mysqld-bin.index'
2019-07-02 13:43:25 140256317794048 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '127.0.0.1:16007' --datadir '/home/jan/mysql/10.2-sst/mysql-test/var/2/mysqld.2/data/'  --defaults-file '/home/jan/mysql/10.2-sst/mysql-test/var/2/my.cnf' --defaults-group-suffix '.2'  --parent '7500'  '' --binlog-index 'mysqld-bin.index': 22 (Invalid argument)
2019-07-02 13:43:25 140256525534976 [ERROR] WSREP: Failed to prepare for 'xtrabackup-v2' SST. Unrecoverable.
2019-07-02 13:43:25 140256525534976 [ERROR] Aborting

Comment by Jan Lindström (Inactive) [ 2019-07-03 ]
  • Branch: 10.2
  • Commit: a946b36601368265188811b3fdf31d443ab25484
  • How to repeat: ./mtr --suite=galera --force --parallel=8 --max-test-fail=0 --big-test
Comment by Jan Lindström (Inactive) [ 2019-07-03 ]

CURRENT_TEST: galera.galera_autoinc_sst_mariabackup
2019-07-02  3:46:04 140479345969408 [Warning] WSREP: option --wsrep-causal-reads is deprecated
2019-07-02  3:46:04 140479345969408 [Note] /mnt/buildbot/build/mariadb-10.2.26/sql/mysqld (mysqld 10.2.26-MariaDB-log) starting as process 2786 ...
2019-07-02  3:46:04 140479345969408 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4186)
2019-07-02  3:46:04 140479345969408 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2019-07-02  3:46:04 140479345969408 [Warning] setrlimit could not change the size of core files to 'infinity';  We may not be able to generate a core file on signals
2019-07-02  3:46:04 140479345969408 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:16007' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members.
2019-07-02  3:46:04 140479345969408 [Note] WSREP: Read nil XID from storage engines, skipping position init
2019-07-02  3:46:04 140479345969408 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
2019-07-02  3:46:04 140479345969408 [Note] WSREP: wsrep_load(): Galera 25.3.26(r3857) by Codership Oy <info@codership.com> loaded successfully.
2019-07-02  3:46:04 140479345969408 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
2019-07-02  3:46:04 140479345969408 [Warning] WSREP: Could not open state file for reading: '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data//grastate.dat'
2019-07-02  3:46:04 140479345969408 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2019-07-02  3:46:05 140479345969408 [Note] WSREP: Passing config to GCS: base_dir = /mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data/; base_host = 127.0.0.1; base_port = 16005; cert.log_conflicts = no; cert.optimistic_pa = yes; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 1; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_h
2019-07-02  3:46:05 140479345969408 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 00000000-0000-0000-0000-000000000000:-1
2019-07-02  3:46:05 140479345969408 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2019-07-02  3:46:05 140479345969408 [Note] WSREP: wsrep_sst_grab()
2019-07-02  3:46:05 140479345969408 [Note] WSREP: Start replication
2019-07-02  3:46:05 140479345969408 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2019-07-02  3:46:05 140479345969408 [Note] WSREP: protonet asio version 0
2019-07-02  3:46:05 140479345969408 [Note] WSREP: Using CRC-32C for message checksums.
2019-07-02  3:46:05 140479345969408 [Note] WSREP: backend: asio
2019-07-02  3:46:05 140479345969408 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2019-07-02  3:46:05 140479345969408 [Warning] WSREP: access file(/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data//gvwstate.dat) failed(No such file or directory)
2019-07-02  3:46:05 140479345969408 [Note] WSREP: restore pc from disk failed
2019-07-02  3:46:05 140479345969408 [Note] WSREP: GMCast version 0
2019-07-02  3:46:05 140479345969408 [Note] WSREP: (725ab3d4, 'tcp://0.0.0.0:16005') listening at tcp://0.0.0.0:16005
2019-07-02  3:46:05 140479345969408 [Note] WSREP: (725ab3d4, 'tcp://0.0.0.0:16005') multicast: , ttl: 1
2019-07-02  3:46:05 140479345969408 [Note] WSREP: EVS version 0
2019-07-02  3:46:05 140479345969408 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:16002'
2019-07-02  3:46:05 140479345969408 [Note] WSREP: (725ab3d4, 'tcp://0.0.0.0:16005') connection established to 72555639 tcp://127.0.0.1:16002
2019-07-02  3:46:05 140479345969408 [Note] WSREP: (725ab3d4, 'tcp://0.0.0.0:16005') turning message relay requesting on, nonlive peers: 
2019-07-02  3:46:05 140479345969408 [Note] WSREP: declaring 72555639 at tcp://127.0.0.1:16002 stable
2019-07-02  3:46:05 140479345969408 [Note] WSREP: Node 72555639 state prim
2019-07-02  3:46:05 140479345969408 [Note] WSREP: view(view_id(PRIM,72555639,2) memb {
	72555639,0
	725ab3d4,0
} joined {
} left {
} partitioned {
})
2019-07-02  3:46:05 140479345969408 [Note] WSREP: save pc into disk
2019-07-02  3:46:06 140479345969408 [Note] WSREP: gcomm: connected
2019-07-02  3:46:06 140479345969408 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2019-07-02  3:46:06 140479345969408 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2019-07-02  3:46:06 140479345969408 [Note] WSREP: Opened channel 'my_wsrep_cluster'
2019-07-02  3:46:06 140479345969408 [Note] WSREP: Waiting for SST to complete.
2019-07-02  3:46:06 140479117248256 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2019-07-02  3:46:06 140479117248256 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2019-07-02  3:46:06 140479117248256 [Note] WSREP: STATE EXCHANGE: sent state msg: 72b27177-9c9d-11e9-b3df-66508a9ff449
2019-07-02  3:46:06 140479117248256 [Note] WSREP: STATE EXCHANGE: got state msg: 72b27177-9c9d-11e9-b3df-66508a9ff449 from 0 (ubuntu-xenial-amd64)
2019-07-02  3:46:06 140479117248256 [Note] WSREP: STATE EXCHANGE: got state msg: 72b27177-9c9d-11e9-b3df-66508a9ff449 from 1 (ubuntu-xenial-amd64)
2019-07-02  3:46:06 140479117248256 [Note] WSREP: Quorum results:
	version    = 4,
	component  = PRIMARY,
	conf_id    = 1,
	members    = 1/2 (joined/total),
	act_id     = 0,
	last_appl. = -1,
	protocols  = 0/9/3 (gcs/repl/appl),
	group UUID = 725c592c-9c9d-11e9-b6ce-bbaf8428dedb
2019-07-02  3:46:06 140479117248256 [Note] WSREP: Flow-control interval: [23, 23]
2019-07-02  3:46:06 140479117248256 [Note] WSREP: Trying to continue unpaused monitor
2019-07-02  3:46:06 140479117248256 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 0)
2019-07-02  3:46:06 140479108208384 [Note] WSREP: State transfer required: 
	Group state: 725c592c-9c9d-11e9-b6ce-bbaf8428dedb:0
	Local state: 00000000-0000-0000-0000-000000000000:-1
2019-07-02  3:46:06 140479108208384 [Note] WSREP: New cluster view: global state: 725c592c-9c9d-11e9-b6ce-bbaf8428dedb:0, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
2019-07-02  3:46:06 140479108208384 [Warning] WSREP: Gap in state sequence. Need state transfer.
2019-07-02  3:46:06 140479107680000 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'joiner' --address '127.0.0.1:16007' --datadir '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data/'  --defaults-file '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/my.cnf' --defaults-group-suffix '.2'  --parent '2786'  '' --binlog-index 'mysqld-bin.index''
2019-07-02  3:46:08 140479125858048 [Note] WSREP: (725ab3d4, 'tcp://0.0.0.0:16005') turning message relay requesting off
WSREP_SST: [INFO] Streaming with xbstream (20190702 03:46:10.260)
2019-07-02  3:46:10 140479107680000 [ERROR] WSREP: Failed to read 'ready <addr>' from: wsrep_sst_mariabackup --role 'joiner' --address '127.0.0.1:16007' --datadir '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data/'  --defaults-file '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/my.cnf' --defaults-group-suffix '.2'  --parent '2786'  '' --binlog-index 'mysqld-bin.index'
	Read: ''socat' not found in PATH'
2019-07-02  3:46:10 140479107680000 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '127.0.0.1:16007' --datadir '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/mysqld.2/data/'  --defaults-file '/mnt/buildbot/build/mariadb-10.2.26/mysql-test/var/1/my.cnf' --defaults-group-suffix '.2'  --parent '2786'  '' --binlog-index 'mysqld-bin.index': 2 (No such file or directory)
2019-07-02  3:46:10 140479108208384 [ERROR] WSREP: Failed to prepare for 'mariabackup' SST. Unrecoverable.
2019-07-02  3:46:10 140479108208384 [ERROR] Aborting

Generated at Thu Feb 08 08:55:25 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.