cluster node can't sst (xtrabackup) with wsrep_urls in /etc/my.cnf

Bug #1000214 reported by Jay Janssen
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC
Fix Released
Medium
Hrvoje Matijakovic

Bug Description

I believe the issue is that the xtradb mysqld can't understand the wsrep_urls variable.

120516 15:00:04 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql
120516 15:00:04 [Note] Flashcache bypass: disabled
120516 15:00:04 [Note] Flashcache setup error is : ioctl failed

120516 15:00:04 [Note] WSREP: Read nil XID from storage engines, skipping position init
120516 15:00:04 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/libgalera_smm.so'
120516 15:00:04 [Note] WSREP: wsrep_load(): Galera 2.1dev(r112) by Codership Oy <email address hidden> loaded succesfully.
120516 15:00:04 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1
120516 15:00:04 [Note] WSREP: Reusing existing '/var/lib/mysql//galera.cache'.
120516 15:00:04 [Note] WSREP: Passing config to GCS: base_host = 10.0.2.15; 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 = 128M; gcs.fc_debug = 0; gcs.fc_factor = 0.5; 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; replicator.causal_read_timeout = PT30S; replicator.commit_order = 3
120516 15:00:04 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
120516 15:00:04 [Note] WSREP: wsrep_sst_grab()
120516 15:00:04 [Note] WSREP: Start replication
120516 15:00:04 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
120516 15:00:04 [Note] WSREP: protonet asio version 0
120516 15:00:04 [Note] WSREP: backend: asio
120516 15:00:04 [Note] WSREP: GMCast version 0
120516 15:00:04 [Note] WSREP: (0e4a60e5-9f57-11e1-0800-b7eac9697238, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
120516 15:00:04 [Note] WSREP: (0e4a60e5-9f57-11e1-0800-b7eac9697238, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
120516 15:00:04 [Note] WSREP: EVS version 0
120516 15:00:04 [Note] WSREP: PC version 0
120516 15:00:04 [Note] WSREP: gcomm: connecting to group 'trimethylxanthine', peer '192.168.70.2:'
120516 15:00:04 [Note] WSREP: (0e4a60e5-9f57-11e1-0800-b7eac9697238, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://192.168.70.3:4567
120516 15:00:05 [Note] WSREP: declaring 1a92d07e-9f56-11e1-0800-f59148046fe4 stable
120516 15:00:05 [Note] WSREP: declaring bd9cd0f2-99e4-11e1-0800-6806eb833b63 stable
120516 15:00:05 [Note] WSREP: (0e4a60e5-9f57-11e1-0800-b7eac9697238, 'tcp://0.0.0.0:4567') turning message relay requesting off
120516 15:00:05 [Note] WSREP: view(view_id(PRIM,0e4a60e5-9f57-11e1-0800-b7eac9697238,10) memb {
 0e4a60e5-9f57-11e1-0800-b7eac9697238,
 1a92d07e-9f56-11e1-0800-f59148046fe4,
 bd9cd0f2-99e4-11e1-0800-6806eb833b63,
} joined {
} left {
} partitioned {
})
120516 15:00:05 [Note] WSREP: gcomm: connected
120516 15:00:05 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
120516 15:00:05 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
120516 15:00:05 [Note] WSREP: Opened channel 'trimethylxanthine'
120516 15:00:05 [Note] WSREP: Waiting for SST to complete.
120516 15:00:05 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
120516 15:00:05 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 0ee3aa83-9f57-11e1-0800-73682d4a05de
120516 15:00:05 [Note] WSREP: STATE EXCHANGE: sent state msg: 0ee3aa83-9f57-11e1-0800-73682d4a05de
120516 15:00:05 [Note] WSREP: STATE EXCHANGE: got state msg: 0ee3aa83-9f57-11e1-0800-73682d4a05de from 0 (percona3)
120516 15:00:05 [Note] WSREP: STATE EXCHANGE: got state msg: 0ee3aa83-9f57-11e1-0800-73682d4a05de from 1 (percona1)
120516 15:00:05 [Note] WSREP: STATE EXCHANGE: got state msg: 0ee3aa83-9f57-11e1-0800-73682d4a05de from 2 (percona2)
120516 15:00:05 [Note] WSREP: Quorum results:
 version = 2,
 component = PRIMARY,
 conf_id = 7,
 members = 2/3 (joined/total),
 act_id = 772,
 last_appl. = -1,
 protocols = 0/3/1 (gcs/repl/appl),
 group UUID = c19f6c17-99e2-11e1-0800-861728b65ef4
120516 15:00:05 [Note] WSREP: Flow-control interval: [14, 28]
120516 15:00:05 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 772)
120516 15:00:05 [Note] WSREP: State transfer required:
 Group state: c19f6c17-99e2-11e1-0800-861728b65ef4:772
 Local state: 00000000-0000-0000-0000-000000000000:-1
120516 15:00:05 [Note] WSREP: New cluster view: global state: c19f6c17-99e2-11e1-0800-861728b65ef4:772, view# 8: Primary, number of nodes: 3, my index: 0, protocol version 1
120516 15:00:05 [Warning] WSREP: Gap in state sequence. Need state transfer.
120516 15:00:07 [Note] WSREP: Running: 'wsrep_sst_xtrabackup 'joiner' '192.168.70.4' '' '/var/lib/mysql/' '/etc/my.cnf' '26692' 2>sst.err'
120516 15:00:07 [Note] WSREP: Prepared SST request: xtrabackup|192.168.70.4:4444/xtrabackup_sst
120516 15:00:07 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
120516 15:00:07 [Note] WSREP: Assign initial position for certification: 772, protocol version: 2
120516 15:00:07 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (c19f6c17-99e2-11e1-0800-861728b65ef4): 1 (Operation not permitted)
  at galera/src/replicator_str.cpp:prepare_for_IST():439. IST will be unavailable.
120516 15:00:07 [Note] WSREP: Node 0 (percona3) requested state transfer from '*any*'. Selected 1 (percona1)(SYNCED) as donor.
120516 15:00:07 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 772)
120516 15:00:07 [Note] WSREP: Requesting state transfer: success, donor: 1
120516 15:01:44 [Note] WSREP: 1 (percona1): State transfer to 0 (percona3) complete.
120516 15:01:44 [Note] WSREP: Member 1 (percona1) synced with group.
120516 15:01:56 [Note] WSREP: SST complete, seqno: 772
120516 15:01:56 [Warning] No argument was provided to --log-bin, and --log-bin-index was not used; so replication may break when this MySQL server acts as a master and has his hostname changed!! Please use '--log-bin=percona3-bin' to avoid this problem.
120516 15:01:56 [Note] Plugin 'FEDERATED' is disabled.
120516 15:01:56 InnoDB: The InnoDB memory heap is disabled
120516 15:01:56 InnoDB: Mutexes and rw_locks use GCC atomic builtins
120516 15:01:56 InnoDB: Compressed tables use zlib 1.2.3
120516 15:01:56 InnoDB: Using Linux native AIO
120516 15:01:56 InnoDB: Initializing buffer pool, size = 128.0M
120516 15:01:56 InnoDB: Completed initialization of buffer pool
120516 15:01:56 InnoDB: highest supported file format is Barracuda.
120516 15:01:56 InnoDB: Waiting for the background threads to start
120516 15:01:57 Percona XtraDB (http://www.percona.com) 1.1.8-rel25.3 started; log sequence number 2173783564
120516 15:01:57 [ERROR] /usr/sbin/mysqld: unknown variable 'wsrep_urls=gcomm://192.168.70.2,gcomm://192.168.70.3,gcomm://'
120516 15:01:57 [ERROR] Aborting

120516 15:01:59 [Note] WSREP: Closing send monitor...
120516 15:01:59 [Note] WSREP: Closed send monitor.
120516 15:01:59 [Note] WSREP: gcomm: terminating thread
120516 15:01:59 [Note] WSREP: gcomm: joining thread
120516 15:01:59 [Note] WSREP: gcomm: closing backend
120516 15:01:59 [Note] WSREP: view(view_id(NON_PRIM,0e4a60e5-9f57-11e1-0800-b7eac9697238,10) memb {
 0e4a60e5-9f57-11e1-0800-b7eac9697238,
} joined {
} left {
} partitioned {
 1a92d07e-9f56-11e1-0800-f59148046fe4,
 bd9cd0f2-99e4-11e1-0800-6806eb833b63,
})
120516 15:01:59 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
120516 15:01:59 [Note] WSREP: view((empty))
120516 15:01:59 [Note] WSREP: gcomm: closed
120516 15:01:59 [Note] WSREP: Flow-control interval: [8, 16]
120516 15:01:59 [Note] WSREP: Received NON-PRIMARY.
120516 15:01:59 [Note] WSREP: Shifting JOINER -> OPEN (TO: 772)
120516 15:01:59 [Note] WSREP: Received self-leave message.
120516 15:01:59 [Note] WSREP: Flow-control interval: [0, 0]
120516 15:01:59 [Note] WSREP: Received SELF-LEAVE. Closing connection.
120516 15:01:59 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 772)
120516 15:01:59 [Note] WSREP: RECV thread exiting 0: Success
120516 15:01:59 [Note] WSREP: recv_thread() joined.
120516 15:01:59 [Note] WSREP: Closing slave action queue.
120516 15:01:59 [Note] WSREP: Service disconnected.
120516 15:01:59 [Note] WSREP: rollbacker thread exiting
120516 15:02:00 [Note] WSREP: Some threads may fail to exit.
120516 15:02:00 InnoDB: Starting shutdown...
120516 15:02:02 InnoDB: Shutdown completed; log sequence number 2173783564
120516 15:02:02 [Note] /usr/sbin/mysqld: Shutdown complete

Error in my_thread_global_end(): 1 threads didn't exit
120516 15:02:07 mysqld_safe mysqld from pid file /var/lib/mysql/percona3.pid ended

# cat /etc/my.cnf
[mysqld]
datadir=/var/lib/mysql
user=mysql
log_error=error.log
binlog_format=ROW
wsrep_provider=/usr/lib64/libgalera_smm.so
wsrep_urls=gcomm://192.168.70.2,gcomm://192.168.70.3,gcomm://
#wsrep_cluster_address=gcomm://
wsrep_sst_receive_address=192.168.70.4
wsrep_node_incoming_address=192.168.70.4
wsrep_slave_threads=2
wsrep_cluster_name=trimethylxanthine
#wsrep_sst_method=rsync
wsrep_sst_method=xtrabackup
wsrep_node_name=percona3
innodb_locks_unsafe_for_binlog=1
innodb_autoinc_lock_mode=2
innodb_log_file_size=64M
bind-address=192.168.70.4

server-id=3
log-bin
log-slave-updates

[mysql]
user=root
prompt="percona3 mysql> "

Tags: doc

Related branches

Revision history for this message
Vadim Tkachenko (vadim-tk) wrote :

wsrep_urls= parameter is for [mysqld_safe] section.

Changed in percona-xtradb-cluster:
status: New → Invalid
status: Invalid → Confirmed
assignee: nobody → Hrvoje Matijakovic (hrvojem)
importance: Undecided → Medium
Revision history for this message
Vadim Tkachenko (vadim-tk) wrote :

Assigned to Hrvoje for proper documentation

Revision history for this message
Jay Janssen (jay-janssen) wrote :

Actually, looks like this isn't an sst 'xtrabackup' problem, it's a problem with /usr/sbin/mysqld in Percona-XtraDB-Cluster-server-5.5.23-23.5.333.rhel6.x86_64.

120516 15:13:44 [ERROR] /usr/sbin/mysqld: unknown variable 'wsrep_urls=gcomm://192.168.70.2,gcomm://192.168.70.3,gcomm://'
120516 15:13:44 [ERROR] Aborting

120516 15:13:44 [Note] WSREP: Service disconnected.
120516 15:13:45 [Note] WSREP: Some threads may fail to exit.
120516 15:13:45 InnoDB: Starting shutdown...
120516 15:13:48 InnoDB: Shutdown completed; log sequence number 2173783228
120516 15:13:48 [Note] /usr/sbin/mysqld: Shutdown complete

[root@percona3 mysql]# rpm -qf /usr/sbin/mysqld
Percona-XtraDB-Cluster-server-5.5.23-23.5.333.rhel6.x86_64

Revision history for this message
Jay Janssen (jay-janssen) wrote :

Aha, moving wsrep_urls to [mysqld_safe] in the my.cnf fixed it.

tags: added: doc
Changed in percona-xtradb-cluster:
status: Confirmed → In Progress
Changed in percona-xtradb-cluster:
status: In Progress → Fix Committed
Changed in percona-xtradb-cluster:
status: Fix Committed → Fix Released
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-1037

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.