rsync doesn't work
Hello :)
I am using latest version on both nodes and when i start the second node i am getting this on my Centos 64bit:
When i strat mysql on second node i am getting this:
Starting MySQL......SST in progress, setting sleep higher.......................................
I have only a very small db that i create for test but it seems that needs a lot of time for the transfer :(
Error log:
140427 05:16:00 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
140427 05:16:00 mysqld_safe WSREP: Running position recovery with --log_error='/var/lib/mysql/
wsrep_recovery.PYSPfs' --pid-file='/var/lib/mysql/server4.koslifestyle.com-recover.pid'
140427 05:16:02 mysqld_safe WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
140427 5:16:02 [Note] WSREP: wsrep_start_position var submitted: '00000000-0000-0000-0000-000000000000:-1'
140427 5:16:02 [Note] WSREP: Read nil XID from storage engines, skipping position init
140427 5:16:02 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so'
140427 5:16:02 [Note] WSREP: wsrep_load(): Galera 25.3.2(r170) by Codership Oy <info@codership.com> loaded successfully.
140427 5:16:02 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
140427 5:16:02 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
140427 5:16:02 [Note] WSREP: Passing config to GCS: base_host = 95.85.62.14; base_port = 4567; cert.log_conflicts = no; 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.size = 4G; gcs.fc_debug = 0; gcs.fc_factor = 1; 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; repl.causal_read_timeout = PT30S; repl.commit_order = 3; repl.key_format = FLAT8; repl.proto_max = 5
140427 5:16:02 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
140427 5:16:02 [Note] WSREP: wsrep_sst_grab()
140427 5:16:02 [Note] WSREP: Start replication
140427 5:16:02 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
140427 5:16:02 [Note] WSREP: protonet asio version 0
140427 5:16:02 [Note] WSREP: Using CRC-32C (optimized) for message checksums.
140427 5:16:02 [Note] WSREP: backend: asio
140427 5:16:02 [Note] WSREP: GMCast version 0
140427 5:16:02 [Note] WSREP: (8dcfca56-cdec-11e3-957d-fff4633e0de8, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
140427 5:16:02 [Note] WSREP: (8dcfca56-cdec-11e3-957d-fff4633e0de8, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
140427 5:16:02 [Note] WSREP: EVS version 0
140427 5:16:02 [Note] WSREP: PC version 0
140427 5:16:02 [Note] WSREP: gcomm: connecting to group 'my_galera_cluster', peer '95.85.10.218:'
140427 5:16:02 [Note] WSREP: declaring f845a085-cd8c-11e3-bf60-d30224fc50dc stable
140427 5:16:02 [Note] WSREP: Node f845a085-cd8c-11e3-bf60-d30224fc50dc state prim
140427 5:16:02 [Note] WSREP: view(view_id(PRIM,8dcfca56-cdec-11e3-957d-fff4633e0de8,8) memb {
8dcfca56-cdec-11e3-957d-fff4633e0de8,0
f845a085-cd8c-11e3-bf60-d30224fc50dc,0
} joined {
} left {
} partitioned {
})
140427 5:16:03 [Note] WSREP: gcomm: connected
140427 5:16:03 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
140427 5:16:03 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
140427 5:16:03 [Note] WSREP: Opened channel 'my_galera_cluster'
140427 5:16:03 [Note] WSREP: Waiting for SST to complete.
140427 5:16:03 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
140427 5:16:03 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 8e1d0859-cdec-11e3-8a24-939a37d47c5b
140427 5:16:03 [Note] WSREP: STATE EXCHANGE: sent state msg: 8e1d0859-cdec-11e3-8a24-939a37d47c5b
140427 5:16:03 [Note] WSREP: STATE EXCHANGE: got state msg: 8e1d0859-cdec-11e3-8a24-939a37d47c5b from 0 (node2)
140427 5:16:03 [Note] WSREP: STATE EXCHANGE: got state msg: 8e1d0859-cdec-11e3-8a24-939a37d47c5b from 1 (node1)
140427 5:16:03 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 7,
members = 1/2 (joined/total),
act_id = 12400,
last_appl. = -1,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = bce54dfa-cd74-11e3-89db-e320068d8477
140427 5:16:03 [Note] WSREP: Flow-control interval: [23, 23]
140427 5:16:03 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 12400)
140427 5:16:03 [Note] WSREP: State transfer required:
Group state: bce54dfa-cd74-11e3-89db-e320068d8477:12400
Local state: 00000000-0000-0000-0000-000000000000:-1
140427 5:16:03 [Note] WSREP: New cluster view: global state: bce54dfa-cd74-11e3-89db-e320068d8477:12400, view# 8: Primary, number of nodes: 2, my index: 0, protocol version 2
140427 5:16:03 [Warning] WSREP: Gap in state sequence. Need state transfer.
140427 5:16:05 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '95.85.62.14' --auth '' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --parent '24824''
cat: /var/lib/mysql//rsync_sst.pid: No such file or directory
140427 5:16:05 [Note] WSREP: Prepared SST request: rsync|95.85.62.14:4444/rsync_sst
140427 5:16:05 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140427 5:16:05 [Note] WSREP: REPL Protocols: 5 (3, 1)
140427 5:16:05 [Note] WSREP: Assign initial position for certification: 12400, protocol version: 3
140427 5:16:05 [Note] WSREP: Service thread queue flushed.
140427 5:16:05 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (bce54dfa-cd74-11e3-89db-e320068d8477): 1 (Operation not permitted)
at galera/src/replicator_str.cpp:prepare_for_IST():445. IST will be unavailable.
140427 5:16:05 [Note] WSREP: Node 0.0 (node2) requested state transfer from '*any*'. Selected 1.0 (node1)(SYNCED) as donor.
140427 5:16:05 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 12400)
140427 5:16:05 [Note] WSREP: Requesting state transfer: success, donor: 1
140427 5:16:05 [Warning] WSREP: 1.0 (node1): State transfer to 0.0 (node2) failed: -1 (Operation not permitted)
140427 5:16:05 [ERROR] WSREP: gcs/src/gcs_group.c:gcs_group_handle_join_msg():723: Will never receive state. Need to abort.
140427 5:16:05 [Note] WSREP: gcomm: terminating thread
140427 5:16:05 [Note] WSREP: gcomm: joining thread
140427 5:16:05 [Note] WSREP: gcomm: closing backend
140427 5:16:06 [Note] WSREP: view(view_id(NON_PRIM,8dcfca56-cdec-11e3-957d-fff4633e0de8,8) memb {
8dcfca56-cdec-11e3-957d-fff4633e0de8,0
} joined {
} left {
} partitioned {
f845a085-cd8c-11e3-bf60-d30224fc50dc,0
})
140427 5:16:06 [Note] WSREP: view((empty))
140427 5:16:06 [Note] WSREP: gcomm: closed
140427 5:16:06 [Note] WSREP: /usr/sbin/mysqld: Terminated.
140427 05:16:06 mysqld_safe mysqld from pid file /var/lib/mysql/server4.koslifestyle.com.pid ended
WSREP_SST: [ERROR] Parent mysqld process (PID:24824) terminated unexpectedly. (20140427 05:16:07.331)
WSREP_SST: [INFO] Joiner cleanup. (20140427 05:16:07.335)
WSREP_SST: [INFO] Joiner cleanup done. (20140427 05:16:07.849)
140427 05:16:02 mysqld_safe WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
140427 5:16:02 [Note] WSREP: wsrep_start_position var submitted: '00000000-0000-0000-0000-000000000000:-1'
140427 5:16:02 [Note] WSREP: Read nil XID from storage engines, skipping position init
140427 5:16:02 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so'
140427 5:16:02 [Note] WSREP: wsrep_load(): Galera 25.3.2(r170) by Codership Oy <info@codership.com> loaded successfully.
140427 5:16:02 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
140427 5:16:02 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
140427 5:16:02 [Note] WSREP: Passing config to GCS: base_host = 95.85.62.14; base_port = 4567; cert.log_conflicts = no; 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.size = 4G; gcs.fc_debug = 0; gcs.fc_factor = 1; 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; repl.causal_read_timeout = PT30S; repl.commit_order = 3; repl.key_format = FLAT8; repl.proto_max = 5
140427 5:16:02 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
140427 5:16:02 [Note] WSREP: wsrep_sst_grab()
140427 5:16:02 [Note] WSREP: Start replication
140427 5:16:02 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
140427 5:16:02 [Note] WSREP: protonet asio version 0
140427 5:16:02 [Note] WSREP: Using CRC-32C (optimized) for message checksums.
140427 5:16:02 [Note] WSREP: backend: asio
140427 5:16:02 [Note] WSREP: GMCast version 0
140427 5:16:02 [Note] WSREP: (8dcfca56-cdec-11e3-957d-fff4633e0de8, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
140427 5:16:02 [Note] WSREP: (8dcfca56-cdec-11e3-957d-fff4633e0de8, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
140427 5:16:02 [Note] WSREP: EVS version 0
140427 5:16:02 [Note] WSREP: PC version 0
140427 5:16:02 [Note] WSREP: gcomm: connecting to group 'my_galera_cluster', peer '95.85.10.218:'
140427 5:16:02 [Note] WSREP: declaring f845a085-cd8c-11e3-bf60-d30224fc50dc stable
140427 5:16:02 [Note] WSREP: Node f845a085-cd8c-11e3-bf60-d30224fc50dc state prim
140427 5:16:02 [Note] WSREP: view(view_id(PRIM,8dcfca56-cdec-11e3-957d-fff4633e0de8,8) memb {
8dcfca56-cdec-11e3-957d-fff4633e0de8,0
f845a085-cd8c-11e3-bf60-d30224fc50dc,0
} joined {
} left {
} partitioned {
})
140427 5:16:03 [Note] WSREP: gcomm: connected
140427 5:16:03 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
140427 5:16:03 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
140427 5:16:03 [Note] WSREP: Opened channel 'my_galera_cluster'
140427 5:16:03 [Note] WSREP: Waiting for SST to complete.
140427 5:16:03 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
140427 5:16:03 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 8e1d0859-cdec-11e3-8a24-939a37d47c5b
140427 5:16:03 [Note] WSREP: STATE EXCHANGE: sent state msg: 8e1d0859-cdec-11e3-8a24-939a37d47c5b
140427 5:16:03 [Note] WSREP: STATE EXCHANGE: got state msg: 8e1d0859-cdec-11e3-8a24-939a37d47c5b from 0 (node2)
140427 5:16:03 [Note] WSREP: STATE EXCHANGE: got state msg: 8e1d0859-cdec-11e3-8a24-939a37d47c5b from 1 (node1)
140427 5:16:03 [Note] WSREP: Quorum results:
version = 3,
component = PRIMARY,
conf_id = 7,
members = 1/2 (joined/total),
act_id = 12400,
last_appl. = -1,
protocols = 0/5/2 (gcs/repl/appl),
group UUID = bce54dfa-cd74-11e3-89db-e320068d8477
140427 5:16:03 [Note] WSREP: Flow-control interval: [23, 23]
140427 5:16:03 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 12400)
140427 5:16:03 [Note] WSREP: State transfer required:
Group state: bce54dfa-cd74-11e3-89db-e320068d8477:12400
Local state: 00000000-0000-0000-0000-000000000000:-1
140427 5:16:03 [Note] WSREP: New cluster view: global state: bce54dfa-cd74-11e3-89db-e320068d8477:12400, view# 8: Primary, number of nodes: 2, my index: 0, protocol version 2
140427 5:16:03 [Warning] WSREP: Gap in state sequence. Need state transfer.
140427 5:16:05 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '95.85.62.14' --auth '' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --parent '24824''
cat: /var/lib/mysql//rsync_sst.pid: No such file or directory
140427 5:16:05 [Note] WSREP: Prepared SST request: rsync|95.85.62.14:4444/rsync_sst
140427 5:16:05 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140427 5:16:05 [Note] WSREP: REPL Protocols: 5 (3, 1)
140427 5:16:05 [Note] WSREP: Assign initial position for certification: 12400, protocol version: 3
140427 5:16:05 [Note] WSREP: Service thread queue flushed.
140427 5:16:05 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (bce54dfa-cd74-11e3-89db-e320068d8477): 1 (Operation not permitted)
at galera/src/replicator_str.cpp:prepare_for_IST():445. IST will be unavailable.
140427 5:16:05 [Note] WSREP: Node 0.0 (node2) requested state transfer from '*any*'. Selected 1.0 (node1)(SYNCED) as donor.
140427 5:16:05 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 12400)
140427 5:16:05 [Note] WSREP: Requesting state transfer: success, donor: 1
140427 5:16:05 [Warning] WSREP: 1.0 (node1): State transfer to 0.0 (node2) failed: -1 (Operation not permitted)
140427 5:16:05 [ERROR] WSREP: gcs/src/gcs_group.c:gcs_group_handle_join_msg():723: Will never receive state. Need to abort.
140427 5:16:05 [Note] WSREP: gcomm: terminating thread
140427 5:16:05 [Note] WSREP: gcomm: joining thread
140427 5:16:05 [Note] WSREP: gcomm: closing backend
140427 5:16:06 [Note] WSREP: view(view_id(NON_PRIM,8dcfca56-cdec-11e3-957d-fff4633e0de8,8) memb {
8dcfca56-cdec-11e3-957d-fff4633e0de8,0
} joined {
} left {
} partitioned {
f845a085-cd8c-11e3-bf60-d30224fc50dc,0
})
140427 5:16:06 [Note] WSREP: view((empty))
140427 5:16:06 [Note] WSREP: gcomm: closed
140427 5:16:06 [Note] WSREP: /usr/sbin/mysqld: Terminated.
140427 05:16:06 mysqld_safe mysqld from pid file /var/lib/mysql/server4.koslifestyle.com.pid ended
WSREP_SST: [ERROR] Parent mysqld process (PID:24824) terminated unexpectedly. (20140427 05:16:07.331)
WSREP_SST: [INFO] Joiner cleanup. (20140427 05:16:07.335)
WSREP_SST: [INFO] Joiner cleanup done. (20140427 05:16:07.849)
Any ideas?
Thank you
-
Hi Dimitris,
1. Make sure rsync is installed on both donor and joiner nodes.
2. There may be also a problem where the rsync daemon does not stop properly. It needs to be killed manually to free up the 4444 port. Check with ps command.
3. Make sure firewall allows SST, Galera and IST ports: 4444,4567,4568
Regards,
Ashraf
Please sign in to leave a comment.
Comments
1 comment