[MDEV-5990] MariaDB Galera 5.5.36 Crashes on Recovery - JIRA

Details

Type: Bug
Status: Closed
Priority: Critical
Resolution: Duplicate
Affects Version/s: 5.5.36-galera
Fix Version/s: 5.5.38-galera
Component/s: None
Labels:
- galera
Environment:
CentOS 6.5

Description

In a 3 node cluster, one of the nodes is crashing when attempted an IST transfer. This was while testing various recovery scenarios and occurred while trying to start MariaDB after issuing a 'kill -9'.

I wasn't able to make this happen all the time, but typically inserting into the following test table on db1 and db2 whilst doing naughty things to db3 seems to cause it:

maindb1 mysql> show create table galeratest\G
*************************** 1. row ***************************
       Table: galeratest
Create Table: CREATE TABLE `galeratest` (
  `num1` bigint(20) unsigned NOT NULL AUTO_INCREMENT,
  UNIQUE KEY `num1` (`num1`)
) ENGINE=InnoDB AUTO_INCREMENT=275 DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

Errors from db3:

[root@maindb3 bin]# killall -9 mysqld mysqld_safe
[root@maindb3 bin]# /etc/init.d/mysql start
Starting MySQL.140331 10:16:16 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql/data
140331 10:16:16 mysqld_safe WSREP: Running position recovery with --log_error='/var/lib/mysql/data/wsrep_recovery.mqrPHR' --pid-file='/var/lib/mysql/data/maindb3.photobiz.com-recover.pid'
.........140331 10:16:27 mysqld_safe WSREP: Recovered position f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665
140331 10:16:27 [Note] WSREP: wsrep_start_position var submitted: 'f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665'
140331 10:16:27 [Note] WSREP: Read nil XID from storage engines, skipping position init
140331 10:16:27 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so'
140331 10:16:27 [Note] WSREP: wsrep_load(): Galera 25.3.2(r170) by Codership Oy <info@codership.com> loaded successfully.
140331 10:16:27 [Note] WSREP: CRC-32C: using hardware acceleration.
140331 10:16:27 [Note] WSREP: Found saved state: f961bfd5-ade2-11e3-8143-8a98c451d81e:-1
140331 10:16:27 [Note] WSREP: Passing config to GCS: base_host = 172.29.33.164; base_port = 4567; cert.log_conflicts = no; gcache.dir = /var/lib/mysql/data/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql/data//galera.cache; gcache.page_size = 128M; gcache.size = 128M; 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
140331 10:16:27 [Note] WSREP: Assign initial position for certification: 57804665, protocol version: -1
140331 10:16:27 [Note] WSREP: wsrep_sst_grab()
140331 10:16:27 [Note] WSREP: Start replication
140331 10:16:27 [Note] WSREP: Setting initial position to f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665
140331 10:16:27 [Note] WSREP: protonet asio version 0
140331 10:16:27 [Note] WSREP: Using CRC-32C (optimized) for message checksums.
140331 10:16:27 [Note] WSREP: backend: asio
140331 10:16:27 [Note] WSREP: GMCast version 0
140331 10:16:27 [Note] WSREP: (6de29923-b8e7-11e3-b07c-47cecf6fe60d, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
140331 10:16:27 [Note] WSREP: (6de29923-b8e7-11e3-b07c-47cecf6fe60d, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
140331 10:16:27 [Note] WSREP: EVS version 0
140331 10:16:27 [Note] WSREP: PC version 0
140331 10:16:27 [Note] WSREP: gcomm: connecting to group 'photobiz_maindb', peer '172.29.33.160:,172.29.33.162:,172.29.33.164:'
140331 10:16:27 [Warning] WSREP: (6de29923-b8e7-11e3-b07c-47cecf6fe60d, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.164:4567' points to own listening address, blacklisting
140331 10:16:27 [Note] WSREP: (6de29923-b8e7-11e3-b07c-47cecf6fe60d, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.164:4567' pointing to uuid 6de29923-b8e7-11e3-b07c-47cecf6fe60d is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (6de29923-b8e7-11e3-b07c-47cecf6fe60d, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.164:4567' pointing to uuid 6de29923-b8e7-11e3-b07c-47cecf6fe60d is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (6de29923-b8e7-11e3-b07c-47cecf6fe60d, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.164:4567' pointing to uuid 6de29923-b8e7-11e3-b07c-47cecf6fe60d is blacklisted, skipping
140331 10:16:27 [Note] WSREP: declaring 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b stable
140331 10:16:27 [Note] WSREP: declaring d842191a-b8e2-11e3-850e-16101f715525 stable
140331 10:16:27 [Note] WSREP: Node 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b state prim
140331 10:16:27 [Note] WSREP: view(view_id(PRIM,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,53) memb {
	3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,0
	6de29923-b8e7-11e3-b07c-47cecf6fe60d,0
	d842191a-b8e2-11e3-850e-16101f715525,0
} joined {
} left {
} partitioned {
})
140331 10:16:27 [Note] WSREP: gcomm: connected
140331 10:16:27 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
140331 10:16:27 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
140331 10:16:27 [Note] WSREP: Opened channel 'photobiz_maindb'
140331 10:16:27 [Note] WSREP: Waiting for SST to complete.
140331 10:16:27 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 3
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: sent state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 0 (maindb1.photobiz.com)
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 2 (maindb2.photobiz.com)
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 1 (maindb3.photobiz.com)
140331 10:16:27 [Note] WSREP: Quorum results:
	version    = 3,
	component  = PRIMARY,
	conf_id    = 52,
	members    = 2/3 (joined/total),
	act_id     = 57805909,
	last_appl. = -1,
	protocols  = 0/5/2 (gcs/repl/appl),
	group UUID = f961bfd5-ade2-11e3-8143-8a98c451d81e
140331 10:16:27 [Note] WSREP: Flow-control interval: [28, 28]
140331 10:16:27 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 57805909)
140331 10:16:27 [Note] WSREP: State transfer required: 
	Group state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57805909
	Local state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665
140331 10:16:27 [Note] WSREP: New cluster view: global state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57805909, view# 53: Primary, number of nodes: 3, my index: 1, protocol version 2
140331 10:16:27 [Warning] WSREP: Gap in state sequence. Need state transfer.
..140331 10:16:29 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'joiner' --address '172.29.33.164' --auth 'galera:9AL4jDoVaW76LqXu' --datadir '/var/lib/mysql/data/' --defaults-file '/etc/my.cnf' --parent '5587''
WSREP_SST: [INFO] Streaming with tar (20140331 10:16:29.704)
WSREP_SST: [INFO] Note: Advanced xtrabackup features - encryption,compression etc. not available with tar. (20140331 10:16:29.708)
WSREP_SST: [INFO] However, xbstream requires manual cleanup of data directory before SST - lp:1193240. (20140331 10:16:29.711)
140331 10:16:29 [Note] WSREP: Prepared SST request: xtrabackup|172.29.33.164:4444/xtrabackup_sst
140331 10:16:29 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:29 [Note] WSREP: REPL Protocols: 5 (3, 1)
140331 10:16:29 [Note] WSREP: Assign initial position for certification: 57805909, protocol version: 3
140331 10:16:29 [Note] WSREP: Service thread queue flushed.
140331 10:16:29 [Note] WSREP: Prepared IST receiver, listening at: tcp://172.29.33.164:4568
140331 10:16:29 [Note] WSREP: Node 1.0 (maindb3.photobiz.com) requested state transfer from '*any*'. Selected 0.0 (maindb1.photobiz.com)(SYNCED) as donor.
140331 10:16:29 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 57806046)
140331 10:16:29 [Note] WSREP: Requesting state transfer: success, donor: 0
WSREP_SST: [INFO] xtrabackup_ist received from donor: Running IST (20140331 10:16:29.814)
WSREP_SST: [INFO] Killing nc pid  (20140331 10:16:29.847)
WSREP_SST: [INFO] Removing the sst_in_progress file (20140331 10:16:29.852)
140331 10:16:29 [Note] WSREP: SST complete, seqno: 57804665
140331 10:16:29 InnoDB: The InnoDB memory heap is disabled
140331 10:16:29 InnoDB: Mutexes and rw_locks use GCC atomic builtins
140331 10:16:29 InnoDB: Compressed tables use zlib 1.2.3
140331 10:16:29 InnoDB: Using Linux native AIO
140331 10:16:29 InnoDB: Initializing buffer pool, size = 48.0G
...140331 10:16:32 InnoDB: Completed initialization of buffer pool
140331 10:16:32 InnoDB: highest supported file format is Barracuda.
.140331 10:16:34  InnoDB: Waiting for the background threads to start
.140331 10:16:35 Percona XtraDB (http://www.percona.com) 5.5.36-MariaDB-33.0 started; log sequence number 4679195592469
.140331 10:16:35 [Note] Plugin 'FEEDBACK' is disabled.
140331 10:16:35 [Note] Server socket created on IP: '0.0.0.0'.
140331 10:16:35 [Note] Event Scheduler: Loaded 1 event
140331 10:16:35 [Note] WSREP: Signalling provider to continue.
140331 10:16:35 [Note] WSREP: SST received: f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665
140331 10:16:35 [Note] WSREP: Receiving IST: 1244 writesets, seqnos 57804665-57805909
140331 10:16:35 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.5.36-MariaDB-wsrep-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server, wsrep_25.9.r3961

mysqld: /home/buildbot/buildbot/build/mariadb-5.5.36/sql/wsrep_applier.cc:310: wsrep_cb_status_t wsrep_commit_cb(void*, uint32_t, const wsrep_trx_meta_t*, wsrep_bool_t*, bool): Assertion `meta->gtid.seqno == wsrep_thd_trx_seqno(thd)' failed.
140331 10:16:35 [ERROR] mysqld got signal 6 ;
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 http://kb.askmonty.org/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: 5.5.36-MariaDB-wsrep-log
key_buffer_size=67108864
read_buffer_size=1048576
max_used_connections=0
max_threads=302
thread_count=9
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 689546 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0x7f1041412000
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 = 0x7f105050d940 thread_stack 0x48000
/usr/sbin/mysqld(my_print_stacktrace+0x2b)[0xa9127b]
/usr/sbin/mysqld(handle_fatal_signal+0x398)[0x6ea128]
/lib64/libpthread.so.0[0x374800f710]
/lib64/libc.so.6(gsignal+0x35)[0x3747c32925]
/lib64/libc.so.6(abort+0x175)[0x3747c34105]
/lib64/libc.so.6[0x3747c2ba4e]
/lib64/libc.so.6(__assert_perror_fail+0x0)[0x3747c2bb10]
/usr/sbin/mysqld[0x69e568]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM9apply_trxEPvPNS_9TrxHandleE+0x552)[0x7f104e98bc02]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM8recv_ISTEPv+0x322)[0x7f104e996b82]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM22request_state_transferEPvRK10wsrep_uuidlPKvl+0x2e7)[0x7f104e999c17]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM19process_conf_changeEPvRK15wsrep_view_infoiNS_10Replicator5StateEl+0x923)[0x7f104e989a33]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera15GcsActionSource8dispatchEPvRK10gcs_actionRb+0x587)[0x7f104e9692c7]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera15GcsActionSource7processEPvRb+0x63)[0x7f104e9694e3]
/usr/lib64/galera/libgalera_smm.so(_ZN6galera13ReplicatorSMM10async_recvEPv+0x93)[0x7f104e985a23]
/usr/lib64/galera/libgalera_smm.so(galera_recv+0x23)[0x7f104e99f993]
/usr/sbin/mysqld[0x69e83f]
/usr/sbin/mysqld(start_wsrep_THD+0x385)[0x5270f5]
/lib64/libpthread.so.0[0x37480079d1]
/lib64/libc.so.6(clone+0x6d)[0x3747ce8b6d]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0): is an invalid pointer
Connection ID (thread ID): 2
Status: NOT_KILLED

Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=off

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
140331 10:16:35 mysqld_safe Number of processes running now: 0
140331 10:16:35 mysqld_safe WSREP: not restarting wsrep node automatically
140331 10:16:35 mysqld_safe mysqld from pid file /var/lib/mysql/data/maindb3.photobiz.com.pid ended

db1's output while this was going on:

maindb1 mysql> 140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:27 [Note] WSREP: declaring 6de29923-b8e7-11e3-b07c-47cecf6fe60d stable
140331 10:16:27 [Note] WSREP: declaring d842191a-b8e2-11e3-850e-16101f715525 stable
140331 10:16:27 [Note] WSREP: declaring 6de29923-b8e7-11e3-b07c-47cecf6fe60d stable
140331 10:16:27 [Note] WSREP: declaring d842191a-b8e2-11e3-850e-16101f715525 stable
140331 10:16:27 [Note] WSREP: Node 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b state prim
140331 10:16:27 [Note] WSREP: Node 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b state prim
140331 10:16:27 [Note] WSREP: view(view_id(PRIM,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,53) memb {
	3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,0
	6de29923-b8e7-11e3-b07c-47cecf6fe60d,0
	d842191a-b8e2-11e3-850e-16101f715525,0
} joined {
} left {
} partitioned {
})
140331 10:16:27 [Note] WSREP: view(view_id(PRIM,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,53) memb {
	3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,0
	6de29923-b8e7-11e3-b07c-47cecf6fe60d,0
	d842191a-b8e2-11e3-850e-16101f715525,0
} joined {
} left {
} partitioned {
})
140331 10:16:27 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
140331 10:16:27 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
140331 10:16:27 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 6de59ca0-b8e7-11e3-b6dd-425310268d01
140331 10:16:27 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 6de59ca0-b8e7-11e3-b6dd-425310268d01
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: sent state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: sent state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 0 (maindb1.photobiz.com)
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 2 (maindb2.photobiz.com)
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 0 (maindb1.photobiz.com)
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 2 (maindb2.photobiz.com)
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 1 (maindb3.photobiz.com)
140331 10:16:27 [Note] WSREP: Quorum results:
	version    = 3,
	component  = PRIMARY,
	conf_id    = 52,
	members    = 2/3 (joined/total),
	act_id     = 57805909,
	last_appl. = 57805819,
	protocols  = 0/5/2 (gcs/repl/appl),
	group UUID = f961bfd5-ade2-11e3-8143-8a98c451d81e
140331 10:16:27 [Note] WSREP: STATE EXCHANGE: got state msg: 6de59ca0-b8e7-11e3-b6dd-425310268d01 from 1 (maindb3.photobiz.com)
140331 10:16:27 [Note] WSREP: Quorum results:
	version    = 3,
	component  = PRIMARY,
	conf_id    = 52,
	members    = 2/3 (joined/total),
	act_id     = 57805909,
	last_appl. = 57805819,
	protocols  = 0/5/2 (gcs/repl/appl),
	group UUID = f961bfd5-ade2-11e3-8143-8a98c451d81e
140331 10:16:27 [Note] WSREP: Flow-control interval: [28, 28]
140331 10:16:27 [Note] WSREP: Flow-control interval: [28, 28]
140331 10:16:27 [Note] WSREP: New cluster view: global state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57805909, view# 53: Primary, number of nodes: 3, my index: 0, protocol version 2
140331 10:16:27 [Note] WSREP: New cluster view: global state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57805909, view# 53: Primary, number of nodes: 3, my index: 0, protocol version 2
140331 10:16:27 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:27 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:27 [Note] WSREP: REPL Protocols: 5 (3, 1)
140331 10:16:27 [Note] WSREP: REPL Protocols: 5 (3, 1)
140331 10:16:27 [Note] WSREP: Assign initial position for certification: 57805909, protocol version: 3
140331 10:16:27 [Note] WSREP: Assign initial position for certification: 57805909, protocol version: 3
140331 10:16:27 [Note] WSREP: Service thread queue flushed.
140331 10:16:27 [Note] WSREP: Service thread queue flushed.
140331 10:16:29 [Note] WSREP: Node 1.0 (maindb3.photobiz.com) requested state transfer from '*any*'. Selected 0.0 (maindb1.photobiz.com)(SYNCED) as donor.
140331 10:16:29 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 57806046)
140331 10:16:29 [Note] WSREP: Node 1.0 (maindb3.photobiz.com) requested state transfer from '*any*'. Selected 0.0 (maindb1.photobiz.com)(SYNCED) as donor.
140331 10:16:29 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 57806046)
140331 10:16:29 [Note] WSREP: IST request: f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665-57805909|tcp://172.29.33.164:4568
140331 10:16:29 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:29 [Note] WSREP: IST request: f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665-57805909|tcp://172.29.33.164:4568
140331 10:16:29 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:29 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'donor' --address '172.29.33.164:4444/xtrabackup_sst' --auth 'galera:9AL4jDoVaW76LqXu' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/data/' --defaults-file '/etc/my.cnf' --gtid 'f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665' --bypass'
140331 10:16:29 [Note] WSREP: Running: 'wsrep_sst_xtrabackup --role 'donor' --address '172.29.33.164:4444/xtrabackup_sst' --auth 'galera:9AL4jDoVaW76LqXu' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/data/' --defaults-file '/etc/my.cnf' --gtid 'f961bfd5-ade2-11e3-8143-8a98c451d81e:57804665' --bypass'
140331 10:16:29 [Note] WSREP: sst_donor_thread signaled with 0
140331 10:16:29 [Note] WSREP: sst_donor_thread signaled with 0
140331 10:16:29 [Note] WSREP: async IST sender starting to serve tcp://172.29.33.164:4568 sending 57804666-57805909
140331 10:16:29 [Note] WSREP: async IST sender starting to serve tcp://172.29.33.164:4568 sending 57804666-57805909
WSREP_SST: [INFO] Streaming with tar (20140331 10:16:29.761)
WSREP_SST: [INFO] Streaming with tar (20140331 10:16:29.761)
WSREP_SST: [INFO] Note: Advanced xtrabackup features - encryption,compression etc. not available with tar. (20140331 10:16:29.764)
WSREP_SST: [INFO] Note: Advanced xtrabackup features - encryption,compression etc. not available with tar. (20140331 10:16:29.764)
WSREP_SST: [INFO] Bypassing the SST for IST (20140331 10:16:29.777)
WSREP_SST: [INFO] Bypassing the SST for IST (20140331 10:16:29.777)
140331 10:16:35 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:35 [ERROR] WSREP: async IST sender failed to serve tcp://172.29.33.164:4568: ist send failed: 1', asio error 'Connection reset by peer': 104 (Connection reset by peer)
	 at galera/src/ist.cpp:send():743
140331 10:16:35 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:35 [ERROR] WSREP: async IST sender failed to serve tcp://172.29.33.164:4568: ist send failed: 1', asio error 'Connection reset by peer': 104 (Connection reset by peer)
	 at galera/src/ist.cpp:send():743
140331 10:16:35 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:35 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:35 [Note] WSREP: async IST sender served
140331 10:16:35 [Note] WSREP: async IST sender served
140331 10:16:35 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://172.29.33.164:4567 
140331 10:16:35 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://172.29.33.164:4567 
140331 10:16:36 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') reconnecting to 6de29923-b8e7-11e3-b07c-47cecf6fe60d (tcp://172.29.33.164:4567), attempt 0
140331 10:16:36 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') reconnecting to 6de29923-b8e7-11e3-b07c-47cecf6fe60d (tcp://172.29.33.164:4567), attempt 0
140331 10:16:36 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:36 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:38 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:38 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:39 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:39 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:41 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:41 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:41 [Note] WSREP: evs::proto(3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, GATHER, view_id(REG,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,53)) suspecting node: 6de29923-b8e7-11e3-b07c-47cecf6fe60d
140331 10:16:41 [Note] WSREP: evs::proto(3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, GATHER, view_id(REG,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,53)) suspecting node: 6de29923-b8e7-11e3-b07c-47cecf6fe60d
140331 10:16:41 [Warning] WSREP: 0.0 (maindb1.photobiz.com): State transfer to 1.0 (maindb3.photobiz.com) failed: -104 (Connection reset by peer)
140331 10:16:41 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 57806329)
140331 10:16:41 [Warning] WSREP: 0.0 (maindb1.photobiz.com): State transfer to 1.0 (maindb3.photobiz.com) failed: -104 (Connection reset by peer)
140331 10:16:41 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 57806329)
140331 10:16:41 [Note] WSREP: declaring d842191a-b8e2-11e3-850e-16101f715525 stable
140331 10:16:41 [Note] WSREP: declaring d842191a-b8e2-11e3-850e-16101f715525 stable
140331 10:16:41 [Note] WSREP: Node 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b state prim
140331 10:16:41 [Note] WSREP: Node 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b state prim
140331 10:16:41 [Note] WSREP: view(view_id(PRIM,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,54) memb {
	3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,0
	d842191a-b8e2-11e3-850e-16101f715525,0
} joined {
} left {
} partitioned {
	6de29923-b8e7-11e3-b07c-47cecf6fe60d,0
})
140331 10:16:41 [Note] WSREP: view(view_id(PRIM,3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,54) memb {
	3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b,0
	d842191a-b8e2-11e3-850e-16101f715525,0
} joined {
} left {
} partitioned {
	6de29923-b8e7-11e3-b07c-47cecf6fe60d,0
})
140331 10:16:41 [Note] WSREP: forgetting 6de29923-b8e7-11e3-b07c-47cecf6fe60d (tcp://172.29.33.164:4567)
140331 10:16:41 [Note] WSREP: forgetting 6de29923-b8e7-11e3-b07c-47cecf6fe60d (tcp://172.29.33.164:4567)
140331 10:16:41 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:41 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') address 'tcp://172.29.33.160:4567' pointing to uuid 3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b is blacklisted, skipping
140331 10:16:41 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') turning message relay requesting off
140331 10:16:41 [Note] WSREP: (3e9b3aa2-b8e3-11e3-82a9-6eebba7e2e7b, 'tcp://0.0.0.0:4567') turning message relay requesting off
140331 10:16:41 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
140331 10:16:41 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
140331 10:16:41 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f
140331 10:16:41 [Warning] WSREP: SYNC message from member 0 in non-primary configuration. Ignored.
140331 10:16:41 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f
140331 10:16:41 [Warning] WSREP: SYNC message from member 0 in non-primary configuration. Ignored.
140331 10:16:41 [Note] WSREP: STATE EXCHANGE: sent state msg: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f
140331 10:16:41 [Note] WSREP: STATE EXCHANGE: sent state msg: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f
140331 10:16:41 [Note] WSREP: STATE EXCHANGE: got state msg: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f from 0 (maindb1.photobiz.com)
140331 10:16:41 [Note] WSREP: STATE EXCHANGE: got state msg: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f from 0 (maindb1.photobiz.com)
140331 10:16:41 [Note] WSREP: STATE EXCHANGE: got state msg: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f from 1 (maindb2.photobiz.com)
140331 10:16:41 [Note] WSREP: STATE EXCHANGE: got state msg: 768c3a39-b8e7-11e3-8d37-17cc1d091e4f from 1 (maindb2.photobiz.com)
140331 10:16:41 [Note] WSREP: Quorum results:
	version    = 3,
	component  = PRIMARY,
	conf_id    = 53,
	members    = 2/2 (joined/total),
	act_id     = 57806330,
	last_appl. = 57806285,
	protocols  = 0/5/2 (gcs/repl/appl),
	group UUID = f961bfd5-ade2-11e3-8143-8a98c451d81e
140331 10:16:41 [Note] WSREP: Quorum results:
	version    = 3,
	component  = PRIMARY,
	conf_id    = 53,
	members    = 2/2 (joined/total),
	act_id     = 57806330,
	last_appl. = 57806285,
	protocols  = 0/5/2 (gcs/repl/appl),
	group UUID = f961bfd5-ade2-11e3-8143-8a98c451d81e
140331 10:16:41 [Note] WSREP: Flow-control interval: [23, 23]
140331 10:16:41 [Note] WSREP: Flow-control interval: [23, 23]
140331 10:16:41 [Note] WSREP: New cluster view: global state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57806330, view# 54: Primary, number of nodes: 2, my index: 0, protocol version 2
140331 10:16:41 [Note] WSREP: New cluster view: global state: f961bfd5-ade2-11e3-8143-8a98c451d81e:57806330, view# 54: Primary, number of nodes: 2, my index: 0, protocol version 2
140331 10:16:41 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:41 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:41 [Note] WSREP: REPL Protocols: 5 (3, 1)
140331 10:16:41 [Note] WSREP: REPL Protocols: 5 (3, 1)
140331 10:16:41 [Note] WSREP: Member 0 (maindb1.photobiz.com) synced with group.
140331 10:16:41 [Note] WSREP: Member 0 (maindb1.photobiz.com) synced with group.
140331 10:16:41 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 57806330)
140331 10:16:41 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 57806330)
140331 10:16:41 [Note] WSREP: Assign initial position for certification: 57806330, protocol version: 3
140331 10:16:41 [Note] WSREP: Assign initial position for certification: 57806330, protocol version: 3
140331 10:16:41 [Note] WSREP: Service thread queue flushed.
140331 10:16:41 [Note] WSREP: Service thread queue flushed.
140331 10:16:41 [Note] WSREP: Synchronized with group, ready for connections
140331 10:16:41 [Note] WSREP: Synchronized with group, ready for connections
140331 10:16:41 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:41 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
140331 10:16:47 [Note] WSREP:  cleaning up 6de29923-b8e7-11e3-b07c-47cecf6fe60d (tcp://172.29.33.164:4567)
140331 10:16:47 [Note] WSREP:  cleaning up 6de29923-b8e7-11e3-b07c-47cecf6fe60d (tcp://172.29.33.164:4567)

Gliffy Diagrams

Attachments

Options
- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

Attachments

my.cnf
3 kB
2014-03-31 18:39

Activity

Hide

Permalink

Nirbhay Choubey added a comment - 2014-04-29 19:25

Duplicate of lp:1284803 - Fixed in Galera 25.3.5.

Show

Nirbhay Choubey added a comment - 2014-04-29 19:25 Duplicate of lp:1284803 - Fixed in Galera 25.3.5.

People

Assignee:

Nirbhay Choubey

Reporter:

Tim Soderstrom

Votes:

0 Vote for this issue

Watchers:

2 Start watching this issue

Dates

Created:

2014-03-31 18:39

Updated:

2014-04-29 19:25

Resolved:

2014-04-29 19:25

Agile

View on Board