017-02-21 13:26:54.162 INFO: CRC-32C: using hardware acceleration.
2017-02-21 13:26:54.162 INFO: Read config:
daemon: 0
name: garb
address: gcomm://dgalera-sql-001:4567?gmcast.listen_addr=tcp://
0.0.0.0:4444 group: galera
sst: xtrabackup
donor: galera1
options: gcs.fc_limit=9999999; gcs.fc_factor=1.0; gcs.fc_master_slave=yes
cfg:
log:
2017-02-21 13:26:54.165 INFO: protonet asio version 0
2017-02-21 13:26:54.165 INFO: Using CRC-32C for message checksums.
2017-02-21 13:26:54.166 INFO: backend: asio
2017-02-21 13:26:54.166 INFO: gcomm thread scheduling priority set to other:0
2017-02-21 13:26:54.166 WARN: access file(./gvwstate.dat) failed(No such file or directory)
2017-02-21 13:26:54.166 INFO: restore pc from disk failed
2017-02-21 13:26:54.168 INFO: GMCast version 0
2017-02-21 13:26:54.170 INFO: (691c4d47, 'tcp://
0.0.0.0:4444') multicast: , ttl: 1
2017-02-21 13:26:54.171 INFO: EVS version 0
2017-02-21 13:26:54.172 INFO: gcomm: connecting to group 'galera', peer 'galera1:4567'
2017-02-21 13:26:54.362 INFO: declaring 69b5a251 at tcp://
8.8.8.7:4567 stable
2017-02-21 13:26:54.363 INFO: declaring a3b7a69d at tcp://
8.8.8.8:4567 stable
2017-02-21 13:26:54.363 INFO: declaring b2113ed7 at tcp://
10.3.71.150:4567 stable
2017-02-21 13:26:54.363 INFO: declaring e2bbd2bb at tcp://
8.8.8.9:4567 stable
2017-02-21 13:26:54.366 INFO: Node 69b5a251 state prim
2017-02-21 13:26:54.395 INFO: view(view_id(PRIM,691c4d47,19) memb {
691c4d47,0
69b5a251,0
a3b7a69d,1
b2113ed7,1
e2bbd2bb,1
} joined {
} left {
} partitioned {
})
2017-02-21 13:26:54.395 INFO: save pc into disk
2017-02-21 13:26:54.673 INFO: gcomm: connected
2017-02-21 13:26:54.673 INFO: Changing maximum packet size to 64500, resulting msg size: 32636
2017-02-21 13:26:54.674 INFO: Shifting CLOSED -> OPEN (TO: 0)
2017-02-21 13:26:54.674 INFO: Opened channel 'galera'
2017-02-21 13:26:54.674 INFO: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 5
2017-02-21 13:26:54.675 INFO: STATE_EXCHANGE: sent state UUID: 6969c80d-f839-11e6-8c64-6b225d74d978
2017-02-21 13:26:54.677 INFO: STATE EXCHANGE: sent state msg: 6969c80d-f839-11e6-8c64-6b225d74d978
2017-02-21 13:26:54.678 INFO: STATE EXCHANGE: got state msg: 6969c80d-f839-11e6-8c64-6b225d74d978 from 1 (garb)
2017-02-21 13:26:54.678 INFO: STATE EXCHANGE: got state msg: 6969c80d-f839-11e6-8c64-6b225d74d978 from 2 (dkcph-t-galera-sql-002)
2017-02-21 13:26:54.678 INFO: STATE EXCHANGE: got state msg: 6969c80d-f839-11e6-8c64-6b225d74d978 from 3 (dkcph-t-galera-sql-001)
2017-02-21 13:26:54.678 INFO: STATE EXCHANGE: got state msg: 6969c80d-f839-11e6-8c64-6b225d74d978 from 4 (dkcph-t-galera-sql-003)
2017-02-21 13:26:54.679 INFO: STATE EXCHANGE: got state msg: 6969c80d-f839-11e6-8c64-6b225d74d978 from 0 (garb)
2017-02-21 13:26:54.679 INFO: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 18,
members = 4/5 (joined/total),
act_id = 75895172,
last_appl. = -1,
protocols = 0/7/3 (gcs/repl/appl),
group UUID = 14d8aedd-e93d-11e6-816c-525ae11f96b7
2017-02-21 13:26:54.679 INFO: Flow-control interval: [9999999, 9999999]
2017-02-21 13:26:54.679 INFO: Shifting OPEN -> PRIMARY (TO: 75895172)
2017-02-21 13:26:54.679 INFO: Sending state transfer request: 'xtrabackup', size: 10
2017-02-21 13:26:54.680 INFO: Member 0.0 (garb) requested state transfer from 'dkcph-t-galera-sql-001'. Selected 3.1 (dkcph-t-galera-sql-001)(SYNCED) as donor.
2017-02-21 13:26:54.680 INFO: Shifting PRIMARY -> JOINER (TO: 75895172)
2017-02-21 13:26:54.680 INFO: Closing send monitor...
2017-02-21 13:26:54.680 INFO: Closed send monitor.
2017-02-21 13:26:54.680 INFO: gcomm: terminating thread
2017-02-21 13:26:54.680 INFO: gcomm: joining thread
2017-02-21 13:26:54.680 INFO: gcomm: closing backend
2017-02-21 13:26:54.685 INFO: 0.0 (garb): State transfer from 3.1 (dkcph-t-galera-sql-001) complete.
2017-02-21 13:26:54.685 INFO: Shifting JOINER -> JOINED (TO: 75895172)
2017-02-21 13:26:54.685 INFO: view(view_id(NON_PRIM,691c4d47,19) memb {
691c4d47,0
} joined {
} left {
} partitioned {
69b5a251,0
a3b7a69d,1
b2113ed7,1
e2bbd2bb,1
})
2017-02-21 13:26:54.686 INFO: view((empty))
2017-02-21 13:26:54.686 INFO: gcomm: closed
2017-02-21 13:26:54.686 WARN: 0x2638098 down context(s) not set
2017-02-21 13:26:54.686 WARN: Failed to send SYNC signal: -107 (Transport endpoint is not connected)
2017-02-21 13:26:54.686 INFO: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2017-02-21 13:26:54.686 INFO: Flow-control interval: [9999999, 9999999]
2017-02-21 13:26:54.686 INFO: Received NON-PRIMARY.
2017-02-21 13:26:54.686 INFO: Shifting JOINED -> OPEN (TO: 75895172)
2017-02-21 13:26:54.686 INFO: Received self-leave message.
2017-02-21 13:26:54.686 INFO: Flow-control interval: [9999999, 9999999]
2017-02-21 13:26:54.687 INFO: Received SELF-LEAVE. Closing connection.
2017-02-21 13:26:54.687 INFO: Shifting OPEN -> CLOSED (TO: 75895172)
2017-02-21 13:26:54.687 INFO: RECV thread exiting 0: Success
2017-02-21 13:26:54.687 INFO: recv_thread() joined.
2017-02-21 13:26:54.687 INFO: Closing replication queue.
2017-02-21 13:26:54.687 INFO: Closing slave action queue.
2017-02-21 13:26:54.687 WARN: Attempt to close a closed connection
2017-02-21 13:26:54.687 INFO: Exiting main loop
2017-02-21 13:26:54.687 INFO: Shifting CLOSED -> DESTROYED (TO: 75895172)
on donor
2017-02-21 13:26:55 140110903371520 [Note] WSREP: Flow-control interval: [32, 32]
2017-02-21 13:26:55 140110892575488 [Note] WSREP: New cluster view: global state: 14d8aedd-e93d-11e6-816c-525ae11f96b7:75895172, view# 20: Primary, number of nodes: 4, my index: 2, protocol version 3
2017-02-21 13:26:55 140110892575488 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-02-21 13:26:55 140110892575488 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-02-21 13:26:55 140110892575488 [Note] WSREP: Assign initial position for certification: 75895172, protocol version: 3
2017-02-21 13:26:55 140110964193024 [Note] WSREP: Service thread queue flushed.
WSREP_SST: [ERROR] innobackupex finished with error: 1. Check /var/lib/mysql//innobackup.backup.log (20170221 13:26:57.302)
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20170221 13:26:57.303)
2017-02-21 13:26:57 140110100166400 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup --role 'donor' --address '' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --binlog '/var/mysqlbinlog/mysql-bin' --gtid '14d8aedd-e93d-11e6-816c-525ae11f96b7:75895172' --gtid-domain-id '0'
2017-02-21 13:26:57 140110100166400 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup --role 'donor' --address '' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --binlog '/var/mysqlbinlog/mysql-bin' --gtid '14d8aedd-e93d-11e6-816c-525ae11f96b7:75895172' --gtid-domain-id '0': 22 (Invalid argument)
2017-02-21 13:26:57 140110100166400 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup --role 'donor' --address '' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --binlog '/var/mysqlbinlog/mysql-bin' --gtid '14d8aedd-e93d-11e6-816c-525ae11f96b7:75895172' --gtid-domain-id '0'
2017-02-21 13:26:57 140110903371520 [Warning] WSREP: Could not find peer: 691c4d47-f839-11e6-b349-c2fe1a316eee
2017-02-21 13:26:57 140110903371520 [Warning] WSREP: 2.1 (galarea1): State transfer to -1.-1 (left the group) failed: -22 (Invalid argument)
2017-02-21 13:26:57 140110903371520 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 75895172)
2017-02-21 13:26:57 140110903371520 [Note] WSREP: Member 2.1 (galera1) synced with group.
2017-02-21 13:26:57 140110903371520 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 75895172)
2017-02-21 13:26:57 140110892575488 [Note] WSREP: Synchronized with group, ready for connections
2017-02-21 13:26:57 140110892575488 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-02-21 13:26:57 140110913861376 [Note] WSREP: (b2113ed7, 'tcp://
0.0.0.0:4567') turning message relay requesting off
2017-02-21 13:27:00 140110913861376 [Note] WSREP: cleaning up 691c4d47 (tcp://
8.8.8.7:4444)
and
/var/lib/mysql//innobackup.backup.log
170221 13:26:55 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!".
170221 13:26:56 version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;mysql_socket=/var/lib/mysql/mysql.sock' as 'root' (using password: YES).
170221 13:26:56 version_check Connected to MySQL server
170221 13:26:56 version_check Executing a version check against the server...
170221 13:26:56 version_check Done.
170221 13:26:56 Connecting to MySQL server host: localhost, user: root, password: set, port: 0, socket: /var/lib/mysql/mysql.sock
Using server version 10.1.21-MariaDB
innobackupex version 2.4.4 based on MySQL server 5.7.13 Linux (x86_64) (revision id: df58cf2)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 0, set to 90000
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
InnoDB: Number of pools: 1
xtrabackup: Generating a list of tablespaces
InnoDB: Allocated tablespace ID 780 for testsd/sbtest1, old maximum was 0
innobackupex: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
archive_write_header() failed.
[01] xtrabackup: error: cannot open the destination stream for ibdata1
[01] xtrabackup: Error: xtrabackup_copy_datafile() failed.
[01] xtrabackup: Error: failed to copy datafile.