Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-15774

MariaDB crashes when trying to sync with xtrabackup-v2

Details

    Description

      A second node trying to join a bootstrapped node with Galera and xtrabackup-v2 crashes the second node.
      If wsrep_sst_method=rsync is used on the second node, synchronization is successful.

      my.cnf of first node:

      [mysqld]
      		 
      bind-address=0.0.0.0
      		 
      binlog_format=ROW
      		 
      default_storage_engine=InnoDB
      		 
      innodb_autoinc_lock_mode=2
      		 
       
      		 
      ssl-key=/opt/cert/server-key.pem
      		 
      ssl-cert=/opt/cert/server-cert.pem
      		 
      ssl-ca=/opt/cert/ca.pem
      		 
       
      		 
      wsrep_on=ON
      		 
      wsrep_provider=/usr/lib/galera/libgalera_smm.so
      		 
      wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
      		 
      wsrep_node_address=$NODE_1_IP
      		 
      wsrep_sst_method=xtrabackup-v2
      		 
      wsrep_cluster_name=$CLUSTER_NAME
      		 
      wsrep_sst_auth="root:$ROOT_PASSWORD"
      		 
       
      		 
      [sst]
      		 
      encrypt=4

      my.cnf on second node:

      [mysqld]
      		 
      bind-address=0.0.0.0
      		 
      binlog_format=ROW
      		 
      default_storage_engine=InnoDB
      		 
      innodb_autoinc_lock_mode=2
      		 
       
      		 
      ssl-key=/opt/cert/server-key.pem
      		 
      ssl-cert=/opt/cert/server-cert.pem
      		 
      ssl-ca=/opt/cert/ca.pem
      		 
       
      		 
      wsrep_on=ON
      		 
      wsrep_provider=/usr/lib/galera/libgalera_smm.so
      		 
      wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
      		 
      wsrep_node_address=$NODE_2_IP
      		 
      wsrep_sst_method=xtrabackup-v2
      		 
      wsrep_cluster_name=$CLUSTER_NAME
      		 
      wsrep_sst_auth="root:$ROOT_PASSWORD"
      		 
       
      		 
      [sst]
      		 
      encrypt=4

      Log on first node after starting second node:

      2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') connection established to 3c222bce tcp://$NODE_2_IP:4567
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
      2018-04-04 10:09:18 0 [Note] WSREP: declaring 3c222bce at tcp://$NODE_2_IP:4567 stable
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
      		 
      	1ad38338,0
      		 
      	3c222bce,0
      		 
      } joined {
      		 
      } left {
      		 
      } partitioned {
      		 
      })
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 3c753758-37f0-11e8-b61a-67335338ccc2
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
      		 
      	version    = 4,
      		 
      	component  = PRIMARY,
      		 
      	conf_id    = 1,
      		 
      	members    = 1/2 (joined/total),
      		 
      	act_id     = 6,
      		 
      	last_appl. = 0,
      		 
      	protocols  = 0/8/3 (gcs/repl/appl),
      		 
      	group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
      		 
      2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 0, protocol version 3
      		 
      2018-04-04 10:09:18 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      		 
      2018-04-04 10:09:18 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
      		 
      2018-04-04 10:09:18 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Service thread queue flushed.
      		 
      2018-04-04 10:09:20 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') turning message relay requesting off
      		 
      2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
      		 
      2018-04-04 10:09:25 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 6)
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      		 
      2018-04-04 10:09:25 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0''
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: sst_donor_thread signaled with 0
      		 
      WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:26.334)
      		 
      WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:26.348)
      		 
      WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:26.382)
      		 
      WSREP_SST: [INFO] Encrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:26.416)
      		 
      WSREP_SST: [INFO] Using /tmp/tmp.V90pQr8bGX as innobackupex temporary directory (20180404 10:09:26.470)
      		 
      WSREP_SST: [INFO] Streaming GTID file before SST (20180404 10:09:26.495)
      		 
      WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.507)
      		 
      WSREP_SST: [INFO] Sleeping before data transfer for SST (20180404 10:09:26.690)
      		 
      WSREP_SST: [INFO] Streaming the backup to joiner at $NODE_2_IP 4444 (20180404 10:09:36.702)
      		 
      WSREP_SST: [INFO] Evaluating innobackupex    --no-version-check  $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:36.717)
      		 
      2018-04-04 10:09:36 10 [Warning] Aborted connection 10 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets)
      		 
      WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /var/lib/mysql//innobackup.backup.log (20180404 10:09:36.922)
      		 
      WSREP_SST: [ERROR] Cleanup after exit with status:22 (20180404 10:09:36.936)
      		 
      WSREP_SST: [INFO] Cleaning up temporary directories (20180404 10:09:36.944)
      		 
      2018-04-04 10:09:36 0 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
      		 
      2018-04-04 10:09:36 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0': 22 (Invalid argument)
      		 
      2018-04-04 10:09:36 0 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
      		 
      2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
      		 
      2018-04-04 10:09:36 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 6)
      		 
      2018-04-04 10:09:36 0 [Note] WSREP: Member 0.0 (1b0926f95d5d) synced with group.
      		 
      2018-04-04 10:09:36 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 6)
      		 
      2018-04-04 10:09:36 1 [Note] WSREP: Synchronized with group, ready for connections
      		 
      2018-04-04 10:09:36 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: Node 1ad38338 state prim
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: view(view_id(PRIM,1ad38338,3) memb {
      		 
      	1ad38338,0
      		 
      } joined {
      		 
      } left {
      		 
      } partitioned {
      		 
      	3c222bce,0
      		 
      })
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: save pc into disk
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 48516712-37f0-11e8-a527-1e78bdeed6e0
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: got state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0 from 0 (1b0926f95d5d)
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: Quorum results:
      		 
      	version    = 4,
      		 
      	component  = PRIMARY,
      		 
      	conf_id    = 2,
      		 
      	members    = 1/1 (joined/total),
      		 
      	act_id     = 6,
      		 
      	last_appl. = 0,
      		 
      	protocols  = 0/8/3 (gcs/repl/appl),
      		 
      	group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: Flow-control interval: [16, 16]
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: Trying to continue unpaused monitor
      		 
      2018-04-04 10:09:37 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 3: Primary, number of nodes: 1, my index: 0, protocol version 3
      		 
      2018-04-04 10:09:37 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      		 
      2018-04-04 10:09:37 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
      		 
      2018-04-04 10:09:37 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
      		 
      2018-04-04 10:09:37 0 [Note] WSREP: Service thread queue flushed.
      		 
      2018-04-04 10:09:41 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') connection established to 3c222bce tcp://$NODE_2_IP:4567
      		 
      2018-04-04 10:09:41 0 [Warning] WSREP: discarding established (time wait) 3c222bce (tcp://$NODE_2_IP:4567) 
      2018-04-04 10:09:43 0 [Note] WSREP:  cleaning up 3c222bce (tcp://$NODE_2_IP:4567)

      innobackup.backup.log on first node:

      180404 10:09:36 innobackupex: Starting the backup operation
      		 
       
      		 
      IMPORTANT: Please check that the backup run completes successfully.
      		 
                 At the end of a successful backup run innobackupex
      		 
                 prints "completed OK!".
      		 
       
      		 
      180404 10:09:36 Connecting to MySQL server host: localhost, user: root, password: set, port: 3306, socket: /var/run/mysqld/mysqld.sock
      		 
      Using server version 10.3.5-MariaDB-10.3.5+maria~jessie
      		 
      innobackupex version 2.4.10 based on MySQL server 5.7.19 Linux (x86_64) (revision id: 3198bce)
      		 
      xtrabackup: uses posix_fadvise().
      		 
      xtrabackup: cd to /var/lib/mysql
      		 
      xtrabackup: open files limit requested 0, set to 1048576
      		 
      xtrabackup: using the following InnoDB configuration:
      		 
      xtrabackup:   innodb_data_home_dir = .
      		 
      xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
      		 
      xtrabackup:   innodb_log_group_home_dir = ./
      		 
      xtrabackup:   innodb_log_files_in_group = 2
      		 
      xtrabackup:   innodb_log_file_size = 50331648
      		 
      xtrabackup: using O_DIRECT
      		 
      InnoDB: Number of pools: 1
      		 
      InnoDB: Unsupported redo log format. The redo log was created with MariaDB 10.3.5. Please follow the instructions at http://dev.mysql.com/doc/refman/5.7/en/upgrading-downgrading.html

      Log from start to crash of second node:

      2018-04-04 10:09:17 0 [Note] mysqld (mysqld 10.3.5-MariaDB-10.3.5+maria~jessie) starting as process 1 ...
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): Galera 25.3.23(r3789) by Codership Oy <info@codership.com> loaded successfully.
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: CRC-32C: using hardware acceleration.
      		 
      2018-04-04 10:09:17 0 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = $NODE_2_IP; base_port = 4567; cert.log_conflicts = no; 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 = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; 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_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 00000000-0000-0000-0000-000000000000:-1
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: wsrep_sst_grab()
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Start replication
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: protonet asio version 0
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: Using CRC-32C for message checksums.
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: backend: asio
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 
      2018-04-04 10:09:17 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: restore pc from disk failed
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: GMCast version 0
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: EVS version 0
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: gcomm: connecting to group '$CLUSTER_NAME', peer '$NODE_1_IP:,$NODE_2_IP:'
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') connection established to 3c222bce tcp://172.17.0.1:4567
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') connection established to 1ad38338 tcp://$NODE_1_IP:4567
      		 
      2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
      2018-04-04 10:09:18 0 [Note] WSREP: declaring 1ad38338 at tcp://$NODE_1_IP:4567 stable
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
      		 
      	1ad38338,0
      		 
      	3c222bce,0
      		 
      } joined {
      		 
      } left {
      		 
      } partitioned {
      		 
      })
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr without UUID: tcp://$NODE_2_IP:4567
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr proto entry 0x55c3215e0480
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: gcomm: connected
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Opened channel '$CLUSTER_NAME'
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Waiting for SST to complete.
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
      		 
      	version    = 4,
      		 
      	component  = PRIMARY,
      		 
      	conf_id    = 1,
      		 
      	members    = 1/2 (joined/total),
      		 
      	act_id     = 6,
      		 
      	last_appl. = -1,
      		 
      	protocols  = 0/8/3 (gcs/repl/appl),
      		 
      	group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 6)
      		 
      2018-04-04 10:09:18 1 [Note] WSREP: State transfer required: 
      	Group state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
      		 
      	Local state: 00000000-0000-0000-0000-000000000000:-1
      		 
      2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
      		 
      2018-04-04 10:09:18 1 [Warning] WSREP: Gap in state sequence. Need state transfer.
      		 
      2018-04-04 10:09:18 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/'   --parent '1'  '' '
      		 
      WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:19.950)
      		 
      WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:19.964)
      		 
      WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:20.064)
      		 
      WSREP_SST: [INFO] Decrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:20.180)
      		 
      WSREP_SST: [INFO] Evaluating timeout -k 110 100 socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:20.435)
      		 
      2018-04-04 10:09:21 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') turning message relay requesting off
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: Prepared SST request: xtrabackup-v2|$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
      		 
      2018-04-04 10:09:25 0 [Note] WSREP: Service thread queue flushed.
      		 
      2018-04-04 10:09:25 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (185e44d4-37f0-11e8-a1c3-17b30f5cc4f7): 1 (Operation not permitted)
      		 
      	 at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
      		 
      2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
      		 
      2018-04-04 10:09:25 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 6)
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: Requesting state transfer: success, donor: 0
      		 
      2018-04-04 10:09:25 1 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
      		 
      WSREP_SST: [INFO] Proceeding with SST (20180404 10:09:26.699)
      		 
      WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20180404 10:09:26.731)
      		 
      WSREP_SST: [INFO] Evaluating socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.734)
      		 
      removed directory: '/var/lib/mysql/mysql'
      		 
      WSREP_SST: [INFO] Waiting for SST streaming to complete! (20180404 10:09:26.870)
      		 
      WSREP_SST: [ERROR] xtrabackup_checkpoints missing, failed innobackupex/SST on donor (20180404 10:09:36.919)
      		 
      2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
      		 
      2018-04-04 10:09:36 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():737: Will never receive state. Need to abort.
      		 
      2018-04-04 10:09:36 0 [Note] WSREP: gcomm: terminating thread
      		 
      2018-04-04 10:09:36 0 [Note] WSREP: gcomm: joining thread
      		 
      2018-04-04 10:09:36 0 [Note] WSREP: gcomm: closing backend
      		 
      WSREP_SST: [ERROR] Cleanup after exit with status:2 (20180404 10:09:36.969)
      		 
      2018-04-04 10:09:37 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/'   --parent '1'  '' : 2 (No such file or directory)
      		 
      2018-04-04 10:09:37 0 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
      		 
      2018-04-04 10:09:37 0 [ERROR] WSREP: SST failed: 2 (No such file or directory)
      		 
      2018-04-04 10:09:37 0 [ERROR] Aborting
      		 
       
      		 
      180404 10:09:41 [ERROR] mysqld got signal 11 ;
      		 
      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.3.5-MariaDB-10.3.5+maria~jessie
      		 
      key_buffer_size=0
      		 
      read_buffer_size=2097152
      		 
      max_used_connections=0
      		 
      max_threads=102
      		 
      thread_count=2
      		 
      It is possible that mysqld could use up to 
      key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 628936 K  bytes of memory
      		 
      Hope that's ok; if not, decrease some variables in the equation.
      		 
       
      		 
      Thread pointer: 0x0
      		 
      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 = 0x0 thread_stack 0x49000
      		 
      mysqld(my_print_stacktrace+0x2e)[0x55c31fe779ee]
      		 
      mysqld(handle_fatal_signal+0x347)[0x55c31f907da7]

      Attachments

        Activity

          Ascending order - Click to sort in descending order
          wmnnd Philipp created issue -
          wmnnd Philipp made changes -
          Field Original Value New Value
          Description A second node trying to join a bootstrapped node with Galera and xtrabackup-v2 crashes the second node.
          If {{wsrep_sst_method=rsync}} is used on the second node, synchronization is successful.

          {{my.cnf}} of first node:
          {code}
          [mysqld]
          bind-address=0.0.0.0
          binlog_format=ROW
          default_storage_engine=InnoDB
          innodb_autoinc_lock_mode=2

          ssl-key=/opt/cert/server-key.pem
          ssl-cert=/opt/cert/server-cert.pem
          ssl-ca=/opt/cert/ca.pem

          wsrep_on=ON
          wsrep_provider=/usr/lib/galera/libgalera_smm.so
          wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
          wsrep_node_address=$NODE_1_IP
          wsrep_sst_method=xtrabackup-v2
          wsrep_cluster_name=pentacent-galera
          wsrep_sst_auth="root:$ROOT_PASSWORD"

          [sst]
          encrypt=4
          {code}

          {{my.cnf}} on second node:
          {code}
          [mysqld]
          bind-address=0.0.0.0
          binlog_format=ROW
          default_storage_engine=InnoDB
          innodb_autoinc_lock_mode=2

          ssl-key=/opt/cert/server-key.pem
          ssl-cert=/opt/cert/server-cert.pem
          ssl-ca=/opt/cert/ca.pem

          wsrep_on=ON
          wsrep_provider=/usr/lib/galera/libgalera_smm.so
          wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
          wsrep_node_address=$NODE_2_IP
          wsrep_sst_method=xtrabackup-v2
          wsrep_cluster_name=pentacent-galera
          wsrep_sst_auth="root:$ROOT_PASSWORD"

          [sst]
          encrypt=4
          {code}

          Log on first node after starting second node:
          {code}
          2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) connection established to 3c222bce tcp://$NODE_2_IP:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting on, nonlive peers:
          2018-04-04 10:09:18 0 [Note] WSREP: declaring 3c222bce at tcp://$NODE_2_IP:4567 stable
          2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
          2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
          1ad38338,0
          3c222bce,0
          } joined {
          } left {
          } partitioned {
          })
          2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
          2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 3c753758-37f0-11e8-b61a-67335338ccc2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
          2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
          version = 4,
          component = PRIMARY,
          conf_id = 1,
          members = 1/2 (joined/total),
          act_id = 6,
          last_appl. = 0,
          protocols = 0/8/3 (gcs/repl/appl),
          group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
          2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
          2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
          2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 0, protocol version 3
          2018-04-04 10:09:18 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:18 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
          2018-04-04 10:09:18 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
          2018-04-04 10:09:18 0 [Note] WSREP: Service thread queue flushed.
          2018-04-04 10:09:20 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting off
          2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
          2018-04-04 10:09:25 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 6)
          2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:25 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0''
          2018-04-04 10:09:25 1 [Note] WSREP: sst_donor_thread signaled with 0
          WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:26.334)
          WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:26.348)
          WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:26.382)
          WSREP_SST: [INFO] Encrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:26.416)
          WSREP_SST: [INFO] Using /tmp/tmp.V90pQr8bGX as innobackupex temporary directory (20180404 10:09:26.470)
          WSREP_SST: [INFO] Streaming GTID file before SST (20180404 10:09:26.495)
          WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.507)
          WSREP_SST: [INFO] Sleeping before data transfer for SST (20180404 10:09:26.690)
          WSREP_SST: [INFO] Streaming the backup to joiner at $NODE_2_IP 4444 (20180404 10:09:36.702)
          WSREP_SST: [INFO] Evaluating innobackupex --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:36.717)
          2018-04-04 10:09:36 10 [Warning] Aborted connection 10 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets)
          WSREP_SST: [ERROR] innobackupex finished with error: 1. Check /var/lib/mysql//innobackup.backup.log (20180404 10:09:36.922)
          WSREP_SST: [ERROR] Cleanup after exit with status:22 (20180404 10:09:36.936)
          WSREP_SST: [INFO] Cleaning up temporary directories (20180404 10:09:36.944)
          2018-04-04 10:09:36 0 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
          2018-04-04 10:09:36 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0': 22 (Invalid argument)
          2018-04-04 10:09:36 0 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
          2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
          2018-04-04 10:09:36 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 6)
          2018-04-04 10:09:36 0 [Note] WSREP: Member 0.0 (1b0926f95d5d) synced with group.
          2018-04-04 10:09:36 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 6)
          2018-04-04 10:09:36 1 [Note] WSREP: Synchronized with group, ready for connections
          2018-04-04 10:09:36 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
          2018-04-04 10:09:37 0 [Note] WSREP: Node 1ad38338 state prim
          2018-04-04 10:09:37 0 [Note] WSREP: view(view_id(PRIM,1ad38338,3) memb {
          1ad38338,0
          } joined {
          } left {
          } partitioned {
          3c222bce,0
          })
          2018-04-04 10:09:37 0 [Note] WSREP: save pc into disk
          2018-04-04 10:09:37 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
          2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
          2018-04-04 10:09:37 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 48516712-37f0-11e8-a527-1e78bdeed6e0
          2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0
          2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: got state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0 from 0 (1b0926f95d5d)
          2018-04-04 10:09:37 0 [Note] WSREP: Quorum results:
          version = 4,
          component = PRIMARY,
          conf_id = 2,
          members = 1/1 (joined/total),
          act_id = 6,
          last_appl. = 0,
          protocols = 0/8/3 (gcs/repl/appl),
          group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
          2018-04-04 10:09:37 0 [Note] WSREP: Flow-control interval: [16, 16]
          2018-04-04 10:09:37 0 [Note] WSREP: Trying to continue unpaused monitor
          2018-04-04 10:09:37 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 3: Primary, number of nodes: 1, my index: 0, protocol version 3
          2018-04-04 10:09:37 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:37 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
          2018-04-04 10:09:37 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
          2018-04-04 10:09:37 0 [Note] WSREP: Service thread queue flushed.
          2018-04-04 10:09:41 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) connection established to 3c222bce tcp://$NODE_2_IP:4567
          2018-04-04 10:09:41 0 [Warning] WSREP: discarding established (time wait) 3c222bce (tcp://$NODE_2_IP:4567)
          2018-04-04 10:09:43 0 [Note] WSREP: cleaning up 3c222bce (tcp://$NODE_2_IP:4567)
          {code}

          {{innobackup.backup.log}} on first node:
          {code}
          180404 10:09:36 innobackupex: Starting the backup operation

          IMPORTANT: Please check that the backup run completes successfully.
                     At the end of a successful backup run innobackupex
                     prints "completed OK!".

          180404 10:09:36 Connecting to MySQL server host: localhost, user: root, password: set, port: 3306, socket: /var/run/mysqld/mysqld.sock
          Using server version 10.3.5-MariaDB-10.3.5+maria~jessie
          innobackupex version 2.4.10 based on MySQL server 5.7.19 Linux (x86_64) (revision id: 3198bce)
          xtrabackup: uses posix_fadvise().
          xtrabackup: cd to /var/lib/mysql
          xtrabackup: open files limit requested 0, set to 1048576
          xtrabackup: using the following InnoDB configuration:
          xtrabackup: innodb_data_home_dir = .
          xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend
          xtrabackup: innodb_log_group_home_dir = ./
          xtrabackup: innodb_log_files_in_group = 2
          xtrabackup: innodb_log_file_size = 50331648
          xtrabackup: using O_DIRECT
          InnoDB: Number of pools: 1
          InnoDB: Unsupported redo log format. The redo log was created with MariaDB 10.3.5. Please follow the instructions at http://dev.mysql.com/doc/refman/5.7/en/upgrading-downgrading.html
          {code}

          Log from start to crash of second node:
          {code}
          2018-04-04 10:09:17 0 [Note] mysqld (mysqld 10.3.5-MariaDB-10.3.5+maria~jessie) starting as process 1 ...
          2018-04-04 10:09:17 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
          2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
          2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): Galera 25.3.23(r3789) by Codership Oy <info@codership.com> loaded successfully.
          2018-04-04 10:09:17 0 [Note] WSREP: CRC-32C: using hardware acceleration.
          2018-04-04 10:09:17 0 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
          2018-04-04 10:09:17 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
          2018-04-04 10:09:17 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = $NODE_2_IP; base_port = 4567; cert.log_conflicts = no; 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 = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; 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_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc
          2018-04-04 10:09:17 0 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 00000000-0000-0000-0000-000000000000:-1
          2018-04-04 10:09:17 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
          2018-04-04 10:09:17 0 [Note] WSREP: wsrep_sst_grab()
          2018-04-04 10:09:17 0 [Note] WSREP: Start replication
          2018-04-04 10:09:17 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
          2018-04-04 10:09:17 0 [Note] WSREP: protonet asio version 0
          2018-04-04 10:09:17 0 [Note] WSREP: Using CRC-32C for message checksums.
          2018-04-04 10:09:17 0 [Note] WSREP: backend: asio
          2018-04-04 10:09:17 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
          2018-04-04 10:09:17 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
          2018-04-04 10:09:17 0 [Note] WSREP: restore pc from disk failed
          2018-04-04 10:09:17 0 [Note] WSREP: GMCast version 0
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) listening at tcp://0.0.0.0:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) multicast: , ttl: 1
          2018-04-04 10:09:17 0 [Note] WSREP: EVS version 0
          2018-04-04 10:09:17 0 [Note] WSREP: gcomm: connecting to group 'pentacent-galera', peer '$NODE_1_IP:,$NODE_2_IP:'
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) connection established to 3c222bce tcp://172.17.0.1:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) connection established to 1ad38338 tcp://$NODE_1_IP:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting on, nonlive peers:
          2018-04-04 10:09:18 0 [Note] WSREP: declaring 1ad38338 at tcp://$NODE_1_IP:4567 stable
          2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
          2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
          1ad38338,0
          3c222bce,0
          } joined {
          } left {
          } partitioned {
          })
          2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
          2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr without UUID: tcp://$NODE_2_IP:4567
          2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr proto entry 0x55c3215e0480
          2018-04-04 10:09:18 0 [Note] WSREP: gcomm: connected
          2018-04-04 10:09:18 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
          2018-04-04 10:09:18 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
          2018-04-04 10:09:18 0 [Note] WSREP: Opened channel 'pentacent-galera'
          2018-04-04 10:09:18 0 [Note] WSREP: Waiting for SST to complete.
          2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
          2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
          version = 4,
          component = PRIMARY,
          conf_id = 1,
          members = 1/2 (joined/total),
          act_id = 6,
          last_appl. = -1,
          protocols = 0/8/3 (gcs/repl/appl),
          group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
          2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
          2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
          2018-04-04 10:09:18 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 6)
          2018-04-04 10:09:18 1 [Note] WSREP: State transfer required:
          Group state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
          Local state: 00000000-0000-0000-0000-000000000000:-1
          2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
          2018-04-04 10:09:18 1 [Warning] WSREP: Gap in state sequence. Need state transfer.
          2018-04-04 10:09:18 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/' --parent '1' '' '
          WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:19.950)
          WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:19.964)
          WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:20.064)
          WSREP_SST: [INFO] Decrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:20.180)
          WSREP_SST: [INFO] Evaluating timeout -k 110 100 socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:20.435)
          2018-04-04 10:09:21 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting off
          2018-04-04 10:09:25 1 [Note] WSREP: Prepared SST request: xtrabackup-v2|$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP
          2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:25 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
          2018-04-04 10:09:25 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
          2018-04-04 10:09:25 0 [Note] WSREP: Service thread queue flushed.
          2018-04-04 10:09:25 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (185e44d4-37f0-11e8-a1c3-17b30f5cc4f7): 1 (Operation not permitted)
          at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
          2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
          2018-04-04 10:09:25 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 6)
          2018-04-04 10:09:25 1 [Note] WSREP: Requesting state transfer: success, donor: 0
          2018-04-04 10:09:25 1 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
          WSREP_SST: [INFO] Proceeding with SST (20180404 10:09:26.699)
          WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20180404 10:09:26.731)
          WSREP_SST: [INFO] Evaluating socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.734)
          removed directory: '/var/lib/mysql/mysql'
          WSREP_SST: [INFO] Waiting for SST streaming to complete! (20180404 10:09:26.870)
          WSREP_SST: [ERROR] xtrabackup_checkpoints missing, failed innobackupex/SST on donor (20180404 10:09:36.919)
          2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
          2018-04-04 10:09:36 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():737: Will never receive state. Need to abort.
          2018-04-04 10:09:36 0 [Note] WSREP: gcomm: terminating thread
          2018-04-04 10:09:36 0 [Note] WSREP: gcomm: joining thread
          2018-04-04 10:09:36 0 [Note] WSREP: gcomm: closing backend
          WSREP_SST: [ERROR] Cleanup after exit with status:2 (20180404 10:09:36.969)
          2018-04-04 10:09:37 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/' --parent '1' '' : 2 (No such file or directory)
          2018-04-04 10:09:37 0 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
          2018-04-04 10:09:37 0 [ERROR] WSREP: SST failed: 2 (No such file or directory)
          2018-04-04 10:09:37 0 [ERROR] Aborting

          180404 10:09:41 [ERROR] mysqld got signal 11 ;
          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.3.5-MariaDB-10.3.5+maria~jessie
          key_buffer_size=0
          read_buffer_size=2097152
          max_used_connections=0
          max_threads=102
          thread_count=2
          It is possible that mysqld could use up to
          key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 628936 K bytes of memory
          Hope that's ok; if not, decrease some variables in the equation.

          Thread pointer: 0x0
          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 = 0x0 thread_stack 0x49000
          mysqld(my_print_stacktrace+0x2e)[0x55c31fe779ee]
          mysqld(handle_fatal_signal+0x347)[0x55c31f907da7]
          {code}           		A second node trying to join a bootstrapped node with Galera and xtrabackup-v2 crashes the second node.
          If {{wsrep_sst_method=rsync}} is used on the second node, synchronization is successful.

          {{my.cnf}} of first node:
          {code}
          [mysqld]
          bind-address=0.0.0.0
          binlog_format=ROW
          default_storage_engine=InnoDB
          innodb_autoinc_lock_mode=2

          ssl-key=/opt/cert/server-key.pem
          ssl-cert=/opt/cert/server-cert.pem
          ssl-ca=/opt/cert/ca.pem

          wsrep_on=ON
          wsrep_provider=/usr/lib/galera/libgalera_smm.so
          wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
          wsrep_node_address=$NODE_1_IP
          wsrep_sst_method=xtrabackup-v2
          wsrep_cluster_name=$CLUSTER_NAME
          wsrep_sst_auth="root:$ROOT_PASSWORD"

          [sst]
          encrypt=4
          {code}

          {{my.cnf}} on second node:
          {code}
          [mysqld]
          bind-address=0.0.0.0
          binlog_format=ROW
          default_storage_engine=InnoDB
          innodb_autoinc_lock_mode=2

          ssl-key=/opt/cert/server-key.pem
          ssl-cert=/opt/cert/server-cert.pem
          ssl-ca=/opt/cert/ca.pem

          wsrep_on=ON
          wsrep_provider=/usr/lib/galera/libgalera_smm.so
          wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
          wsrep_node_address=$NODE_2_IP
          wsrep_sst_method=xtrabackup-v2
          wsrep_cluster_name=$CLUSTER_NAME
          wsrep_sst_auth="root:$ROOT_PASSWORD"

          [sst]
          encrypt=4
          {code}

          Log on first node after starting second node:
          {code}
          2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) connection established to 3c222bce tcp://$NODE_2_IP:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting on, nonlive peers:
          2018-04-04 10:09:18 0 [Note] WSREP: declaring 3c222bce at tcp://$NODE_2_IP:4567 stable
          2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
          2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
          1ad38338,0
          3c222bce,0
          } joined {
          } left {
          } partitioned {
          })
          2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
          2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 3c753758-37f0-11e8-b61a-67335338ccc2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
          2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
          version = 4,
          component = PRIMARY,
          conf_id = 1,
          members = 1/2 (joined/total),
          act_id = 6,
          last_appl. = 0,
          protocols = 0/8/3 (gcs/repl/appl),
          group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
          2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
          2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
          2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 0, protocol version 3
          2018-04-04 10:09:18 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:18 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
          2018-04-04 10:09:18 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
          2018-04-04 10:09:18 0 [Note] WSREP: Service thread queue flushed.
          2018-04-04 10:09:20 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting off
          2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
          2018-04-04 10:09:25 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 6)
          2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:25 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0''
          2018-04-04 10:09:25 1 [Note] WSREP: sst_donor_thread signaled with 0
          WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:26.334)
          WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:26.348)
          WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:26.382)
          WSREP_SST: [INFO] Encrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:26.416)
          WSREP_SST: [INFO] Using /tmp/tmp.V90pQr8bGX as innobackupex temporary directory (20180404 10:09:26.470)
          WSREP_SST: [INFO] Streaming GTID file before SST (20180404 10:09:26.495)
          WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.507)
          WSREP_SST: [INFO] Sleeping before data transfer for SST (20180404 10:09:26.690)
          WSREP_SST: [INFO] Streaming the backup to joiner at $NODE_2_IP 4444 (20180404 10:09:36.702)
          WSREP_SST: [INFO] Evaluating innobackupex --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:36.717)
          2018-04-04 10:09:36 10 [Warning] Aborted connection 10 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets)
          WSREP_SST: [ERROR] innobackupex finished with error: 1. Check /var/lib/mysql//innobackup.backup.log (20180404 10:09:36.922)
          WSREP_SST: [ERROR] Cleanup after exit with status:22 (20180404 10:09:36.936)
          WSREP_SST: [INFO] Cleaning up temporary directories (20180404 10:09:36.944)
          2018-04-04 10:09:36 0 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
          2018-04-04 10:09:36 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0': 22 (Invalid argument)
          2018-04-04 10:09:36 0 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
          2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
          2018-04-04 10:09:36 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 6)
          2018-04-04 10:09:36 0 [Note] WSREP: Member 0.0 (1b0926f95d5d) synced with group.
          2018-04-04 10:09:36 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 6)
          2018-04-04 10:09:36 1 [Note] WSREP: Synchronized with group, ready for connections
          2018-04-04 10:09:36 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
          2018-04-04 10:09:37 0 [Note] WSREP: Node 1ad38338 state prim
          2018-04-04 10:09:37 0 [Note] WSREP: view(view_id(PRIM,1ad38338,3) memb {
          1ad38338,0
          } joined {
          } left {
          } partitioned {
          3c222bce,0
          })
          2018-04-04 10:09:37 0 [Note] WSREP: save pc into disk
          2018-04-04 10:09:37 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
          2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
          2018-04-04 10:09:37 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 48516712-37f0-11e8-a527-1e78bdeed6e0
          2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0
          2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: got state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0 from 0 (1b0926f95d5d)
          2018-04-04 10:09:37 0 [Note] WSREP: Quorum results:
          version = 4,
          component = PRIMARY,
          conf_id = 2,
          members = 1/1 (joined/total),
          act_id = 6,
          last_appl. = 0,
          protocols = 0/8/3 (gcs/repl/appl),
          group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
          2018-04-04 10:09:37 0 [Note] WSREP: Flow-control interval: [16, 16]
          2018-04-04 10:09:37 0 [Note] WSREP: Trying to continue unpaused monitor
          2018-04-04 10:09:37 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 3: Primary, number of nodes: 1, my index: 0, protocol version 3
          2018-04-04 10:09:37 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:37 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
          2018-04-04 10:09:37 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
          2018-04-04 10:09:37 0 [Note] WSREP: Service thread queue flushed.
          2018-04-04 10:09:41 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567&#39;) connection established to 3c222bce tcp://$NODE_2_IP:4567
          2018-04-04 10:09:41 0 [Warning] WSREP: discarding established (time wait) 3c222bce (tcp://$NODE_2_IP:4567)
          2018-04-04 10:09:43 0 [Note] WSREP: cleaning up 3c222bce (tcp://$NODE_2_IP:4567)
          {code}

          {{innobackup.backup.log}} on first node:
          {code}
          180404 10:09:36 innobackupex: Starting the backup operation

          IMPORTANT: Please check that the backup run completes successfully.
                     At the end of a successful backup run innobackupex
                     prints "completed OK!".

          180404 10:09:36 Connecting to MySQL server host: localhost, user: root, password: set, port: 3306, socket: /var/run/mysqld/mysqld.sock
          Using server version 10.3.5-MariaDB-10.3.5+maria~jessie
          innobackupex version 2.4.10 based on MySQL server 5.7.19 Linux (x86_64) (revision id: 3198bce)
          xtrabackup: uses posix_fadvise().
          xtrabackup: cd to /var/lib/mysql
          xtrabackup: open files limit requested 0, set to 1048576
          xtrabackup: using the following InnoDB configuration:
          xtrabackup: innodb_data_home_dir = .
          xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend
          xtrabackup: innodb_log_group_home_dir = ./
          xtrabackup: innodb_log_files_in_group = 2
          xtrabackup: innodb_log_file_size = 50331648
          xtrabackup: using O_DIRECT
          InnoDB: Number of pools: 1
          InnoDB: Unsupported redo log format. The redo log was created with MariaDB 10.3.5. Please follow the instructions at http://dev.mysql.com/doc/refman/5.7/en/upgrading-downgrading.html
          {code}

          Log from start to crash of second node:
          {code}
          2018-04-04 10:09:17 0 [Note] mysqld (mysqld 10.3.5-MariaDB-10.3.5+maria~jessie) starting as process 1 ...
          2018-04-04 10:09:17 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
          2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
          2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): Galera 25.3.23(r3789) by Codership Oy <info@codership.com> loaded successfully.
          2018-04-04 10:09:17 0 [Note] WSREP: CRC-32C: using hardware acceleration.
          2018-04-04 10:09:17 0 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
          2018-04-04 10:09:17 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
          2018-04-04 10:09:17 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = $NODE_2_IP; base_port = 4567; cert.log_conflicts = no; 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 = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; 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_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc
          2018-04-04 10:09:17 0 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 00000000-0000-0000-0000-000000000000:-1
          2018-04-04 10:09:17 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
          2018-04-04 10:09:17 0 [Note] WSREP: wsrep_sst_grab()
          2018-04-04 10:09:17 0 [Note] WSREP: Start replication
          2018-04-04 10:09:17 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
          2018-04-04 10:09:17 0 [Note] WSREP: protonet asio version 0
          2018-04-04 10:09:17 0 [Note] WSREP: Using CRC-32C for message checksums.
          2018-04-04 10:09:17 0 [Note] WSREP: backend: asio
          2018-04-04 10:09:17 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
          2018-04-04 10:09:17 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
          2018-04-04 10:09:17 0 [Note] WSREP: restore pc from disk failed
          2018-04-04 10:09:17 0 [Note] WSREP: GMCast version 0
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) listening at tcp://0.0.0.0:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) multicast: , ttl: 1
          2018-04-04 10:09:17 0 [Note] WSREP: EVS version 0
          2018-04-04 10:09:17 0 [Note] WSREP: gcomm: connecting to group '$CLUSTER_NAME', peer '$NODE_1_IP:,$NODE_2_IP:'
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) connection established to 3c222bce tcp://172.17.0.1:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) connection established to 1ad38338 tcp://$NODE_1_IP:4567
          2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting on, nonlive peers:
          2018-04-04 10:09:18 0 [Note] WSREP: declaring 1ad38338 at tcp://$NODE_1_IP:4567 stable
          2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
          2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
          1ad38338,0
          3c222bce,0
          } joined {
          } left {
          } partitioned {
          })
          2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
          2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr without UUID: tcp://$NODE_2_IP:4567
          2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr proto entry 0x55c3215e0480
          2018-04-04 10:09:18 0 [Note] WSREP: gcomm: connected
          2018-04-04 10:09:18 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
          2018-04-04 10:09:18 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
          2018-04-04 10:09:18 0 [Note] WSREP: Opened channel '$CLUSTER_NAME'
          2018-04-04 10:09:18 0 [Note] WSREP: Waiting for SST to complete.
          2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
          2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
          2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
          version = 4,
          component = PRIMARY,
          conf_id = 1,
          members = 1/2 (joined/total),
          act_id = 6,
          last_appl. = -1,
          protocols = 0/8/3 (gcs/repl/appl),
          group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
          2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
          2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
          2018-04-04 10:09:18 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 6)
          2018-04-04 10:09:18 1 [Note] WSREP: State transfer required:
          Group state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
          Local state: 00000000-0000-0000-0000-000000000000:-1
          2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
          2018-04-04 10:09:18 1 [Warning] WSREP: Gap in state sequence. Need state transfer.
          2018-04-04 10:09:18 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/' --parent '1' '' '
          WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:19.950)
          WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:19.964)
          WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:20.064)
          WSREP_SST: [INFO] Decrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:20.180)
          WSREP_SST: [INFO] Evaluating timeout -k 110 100 socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:20.435)
          2018-04-04 10:09:21 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567&#39;) turning message relay requesting off
          2018-04-04 10:09:25 1 [Note] WSREP: Prepared SST request: xtrabackup-v2|$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP
          2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
          2018-04-04 10:09:25 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
          2018-04-04 10:09:25 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
          2018-04-04 10:09:25 0 [Note] WSREP: Service thread queue flushed.
          2018-04-04 10:09:25 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (185e44d4-37f0-11e8-a1c3-17b30f5cc4f7): 1 (Operation not permitted)
          at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
          2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
          2018-04-04 10:09:25 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 6)
          2018-04-04 10:09:25 1 [Note] WSREP: Requesting state transfer: success, donor: 0
          2018-04-04 10:09:25 1 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
          WSREP_SST: [INFO] Proceeding with SST (20180404 10:09:26.699)
          WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20180404 10:09:26.731)
          WSREP_SST: [INFO] Evaluating socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.734)
          removed directory: '/var/lib/mysql/mysql'
          WSREP_SST: [INFO] Waiting for SST streaming to complete! (20180404 10:09:26.870)
          WSREP_SST: [ERROR] xtrabackup_checkpoints missing, failed innobackupex/SST on donor (20180404 10:09:36.919)
          2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
          2018-04-04 10:09:36 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():737: Will never receive state. Need to abort.
          2018-04-04 10:09:36 0 [Note] WSREP: gcomm: terminating thread
          2018-04-04 10:09:36 0 [Note] WSREP: gcomm: joining thread
          2018-04-04 10:09:36 0 [Note] WSREP: gcomm: closing backend
          WSREP_SST: [ERROR] Cleanup after exit with status:2 (20180404 10:09:36.969)
          2018-04-04 10:09:37 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/' --parent '1' '' : 2 (No such file or directory)
          2018-04-04 10:09:37 0 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
          2018-04-04 10:09:37 0 [ERROR] WSREP: SST failed: 2 (No such file or directory)
          2018-04-04 10:09:37 0 [ERROR] Aborting

          180404 10:09:41 [ERROR] mysqld got signal 11 ;
          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.3.5-MariaDB-10.3.5+maria~jessie
          key_buffer_size=0
          read_buffer_size=2097152
          max_used_connections=0
          max_threads=102
          thread_count=2
          It is possible that mysqld could use up to
          key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 628936 K bytes of memory
          Hope that's ok; if not, decrease some variables in the equation.

          Thread pointer: 0x0
          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 = 0x0 thread_stack 0x49000
          mysqld(my_print_stacktrace+0x2e)[0x55c31fe779ee]
          mysqld(handle_fatal_signal+0x347)[0x55c31f907da7]
          {code}
          elenst Elena Stepanova made changes -
          Fix Version/s 10.3 [ 22126 ]
          Assignee Sachin Setiya [ sachin.setiya.007 ]
          serg Sergei Golubchik made changes -
          Assignee Sachin Setiya [ sachin.setiya.007 ] Jan Lindström [ jplindst ]
          jplindst Jan Lindström (Inactive) added a comment -

          xtrabackup does not work with MariaDB 10.3, you should use MariaBackup.

          jplindst Jan Lindström (Inactive) added a comment - xtrabackup does not work with MariaDB 10.3, you should use MariaBackup.
          jplindst Jan Lindström (Inactive) made changes -
          Fix Version/s N/A [ 14700 ]
          Fix Version/s 10.3 [ 22126 ]
          Resolution Not a Bug [ 6 ]
          Status Open [ 1 ] Closed [ 6 ]
          serg Sergei Golubchik made changes -
          Workflow MariaDB v3 [ 86368 ] MariaDB v4 [ 154090 ]

          People

            jplindst Jan Lindström (Inactive)
            wmnnd Philipp
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.