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

            People

            • Assignee:
              jplindst Jan Lindström
              Reporter:
              wmnnd Philipp
            • Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: