youdowell / k8s-galera-init

Example of MariaDB Galera init container for Kubernetes StatefulSet
8 stars 1 forks source link

Secondary replicas always restart once #4

Open neverfox opened 7 years ago

neverfox commented 7 years ago

When running the example on Minikube, mysql-1 and mysql-2 always restart once and then run fine.

Running Docker for Mac 17.06.0-ce-rc5-mac16, minikube version v0.19.0 (xhyve)

The logs from the first try to boot up show this:

Initializing database
2017-06-21 20:02:30 140636133906368 [Note] /usr/sbin/mysqld (mysqld 10.1.24-MariaDB-1~jessie) starting as process 66 ...
2017-06-21 20:02:30 140636133906368 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-06-21 20:02:30 140636133906368 [Note] WSREP: wsrep_load(): loading provider library 'none'
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: The InnoDB memory heap is disabled
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: Using Linux native AIO
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: Using SSE crc32 instructions
2017-06-21 20:02:30 140636133906368 [Note] InnoDB: Initializing buffer pool, size = 2.8G
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Completed initialization of buffer pool
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Setting log file ./ib_logfile101 size to 64 MB
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Setting log file ./ib_logfile1 size to 64 MB
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-06-21 20:02:31 140636133906368 [Warning] InnoDB: New log files created, LSN=45883
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Doublewrite buffer not found: creating new
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Doublewrite buffer created
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: 128 rollback segment(s) are active.
2017-06-21 20:02:31 140636133906368 [Warning] InnoDB: Creating foreign key constraint system tables.
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Foreign key constraint system tables created
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Creating tablespace and datafile system tables.
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Tablespace and datafile system tables created.
2017-06-21 20:02:31 140636133906368 [Note] InnoDB: Waiting for purge to start
2017-06-21 20:02:31 140636133906368 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.0 started; log sequence number 0
2017-06-21 20:02:32 140632551061248 [Note] InnoDB: Dumping buffer pool(s) not yet started
2017-06-21 20:02:35 139862238455744 [Note] /usr/sbin/mysqld (mysqld 10.1.24-MariaDB-1~jessie) starting as process 94 ...
2017-06-21 20:02:35 139862238455744 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-06-21 20:02:35 139862238455744 [Note] WSREP: wsrep_load(): loading provider library 'none'
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: The InnoDB memory heap is disabled
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: Using Linux native AIO
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: Using SSE crc32 instructions
2017-06-21 20:02:35 139862238455744 [Note] InnoDB: Initializing buffer pool, size = 2.8G
2017-06-21 20:02:36 139862238455744 [Note] InnoDB: Completed initialization of buffer pool
2017-06-21 20:02:36 139862238455744 [Note] InnoDB: Highest supported file format is Barracuda.
2017-06-21 20:02:36 139862238455744 [Note] InnoDB: 128 rollback segment(s) are active.
2017-06-21 20:02:36 139862238455744 [Note] InnoDB: Waiting for purge to start
2017-06-21 20:02:36 139862238455744 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.0 started; log sequence number 1616799
2017-06-21 20:02:36 139858676782848 [Note] InnoDB: Dumping buffer pool(s) not yet started
2017-06-21 20:02:40 140525904095168 [Note] /usr/sbin/mysqld (mysqld 10.1.24-MariaDB-1~jessie) starting as process 123 ...
2017-06-21 20:02:40 140525904095168 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-06-21 20:02:40 140525904095168 [Note] WSREP: wsrep_load(): loading provider library 'none'
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: The InnoDB memory heap is disabled
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Using Linux native AIO
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Using SSE crc32 instructions
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Initializing buffer pool, size = 2.8G
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Completed initialization of buffer pool
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Highest supported file format is Barracuda.
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: 128 rollback segment(s) are active.
2017-06-21 20:02:40 140525904095168 [Note] InnoDB: Waiting for purge to start
2017-06-21 20:02:40 140525904095168 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.0 started; log sequence number 1616809
2017-06-21 20:02:40 140522341504768 [Note] InnoDB: Dumping buffer pool(s) not yet started

PLEASE REMEMBER TO SET A PASSWORD FOR THE MariaDB root USER !
To do so, start the server, then issue the following commands:

'/usr/bin/mysqladmin' -u root password 'new-password'
'/usr/bin/mysqladmin' -u root -h  password 'new-password'

Alternatively you can run:
'/usr/bin/mysql_secure_installation'

which will also give you the option of removing the test
databases and anonymous user created by default.  This is
strongly recommended for production servers.

See the MariaDB Knowledgebase at http://mariadb.com/kb or the
MySQL manual for more instructions.

Please report any problems at http://mariadb.org/jira

The latest information about MariaDB is available at http://mariadb.org/.
You can find additional information about the MySQL part at:
http://dev.mysql.com
Consider joining MariaDB's strong and vibrant community:
https://mariadb.org/get-involved/

Database initialized
MySQL init process in progress...
2017-06-21 20:02:44 140004201490368 [Note] mysqld (mysqld 10.1.24-MariaDB-1~jessie) starting as process 156 ...
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-06-21 20:02:44 140004201490368 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
2017-06-21 20:02:44 140004201490368 [Note] WSREP: wsrep_load(): Galera 25.3.20(r3703) by Codership Oy <info@codership.com> loaded successfully.
2017-06-21 20:02:44 140004201490368 [Note] WSREP: CRC-32C: using hardware acceleration.
2017-06-21 20:02:44 140004201490368 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootsrap: 1
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = mysql-1.mysql.default.svc.cluster.local; 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
2017-06-21 20:02:44 140004201490368 [Note] WSREP: GCache history reset: old(00000000-0000-0000-0000-000000000000:0) -> new(00000000-0000-0000-0000-000000000000:-1)
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2017-06-21 20:02:44 140004201490368 [Note] WSREP: wsrep_sst_grab()
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Start replication
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2017-06-21 20:02:44 140004201490368 [Note] WSREP: protonet asio version 0
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Using CRC-32C for message checksums.
2017-06-21 20:02:44 140004201490368 [Note] WSREP: backend: asio
2017-06-21 20:02:44 140004201490368 [Note] WSREP: gcomm thread scheduling priority set to other:0
2017-06-21 20:02:44 140004201490368 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
2017-06-21 20:02:44 140004201490368 [Note] WSREP: restore pc from disk failed
2017-06-21 20:02:44 140004201490368 [Note] WSREP: GMCast version 0
2017-06-21 20:02:44 140004201490368 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2017-06-21 20:02:44 140004201490368 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2017-06-21 20:02:44 140004201490368 [Note] WSREP: EVS version 0
2017-06-21 20:02:44 140004201490368 [Note] WSREP: gcomm: connecting to group 'mysql', peer 'mysql-0.mysql.default.svc.cluster.local:'
2017-06-21 20:02:44 140004201490368 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') connection established to 769cae23 tcp://172.17.0.7:4567
2017-06-21 20:02:44 140004201490368 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2017-06-21 20:02:44 140004201490368 [Note] WSREP: declaring 769cae23 at tcp://172.17.0.7:4567 stable
2017-06-21 20:02:44 140004201490368 [Note] WSREP: Node 769cae23 state prim
2017-06-21 20:02:44 140004201490368 [Note] WSREP: view(view_id(PRIM,769cae23,2) memb {
    769cae23,0
    96f79dad,0
} joined {
} left {
} partitioned {
})
2017-06-21 20:02:44 140004201490368 [Note] WSREP: save pc into disk
MySQL init process in progress...
2017-06-21 20:02:45 140004201490368 [Note] WSREP: gcomm: connected
2017-06-21 20:02:45 140004201490368 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2017-06-21 20:02:45 140004201490368 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2017-06-21 20:02:45 140004201490368 [Note] WSREP: Opened channel 'mysql'
2017-06-21 20:02:45 140004201490368 [Note] WSREP: Waiting for SST to complete.
2017-06-21 20:02:45 140003921356544 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2017-06-21 20:02:45 140003921356544 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2017-06-21 20:02:45 140003921356544 [Note] WSREP: STATE EXCHANGE: sent state msg: 9744b2d6-56bc-11e7-a92a-d31cda1fa9d4
2017-06-21 20:02:45 140003921356544 [Note] WSREP: STATE EXCHANGE: got state msg: 9744b2d6-56bc-11e7-a92a-d31cda1fa9d4 from 0 (mysql-0)
2017-06-21 20:02:45 140003921356544 [Note] WSREP: STATE EXCHANGE: got state msg: 9744b2d6-56bc-11e7-a92a-d31cda1fa9d4 from 1 (mysql-1)
2017-06-21 20:02:45 140003921356544 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 1,
    members    = 1/2 (joined/total),
    act_id     = 6,
    last_appl. = -1,
    protocols  = 0/7/3 (gcs/repl/appl),
    group UUID = 737eec26-56bc-11e7-af21-0b272c1e52f7
2017-06-21 20:02:45 140003921356544 [Note] WSREP: Flow-control interval: [23, 23]
2017-06-21 20:02:45 140003921356544 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 6)
2017-06-21 20:02:45 140004201175808 [Note] WSREP: State transfer required:
    Group state: 737eec26-56bc-11e7-af21-0b272c1e52f7:6
    Local state: 00000000-0000-0000-0000-000000000000:-1
2017-06-21 20:02:45 140004201175808 [Note] WSREP: New cluster view: global state: 737eec26-56bc-11e7-af21-0b272c1e52f7:6, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
2017-06-21 20:02:45 140004201175808 [Warning] WSREP: Gap in state sequence. Need state transfer.
2017-06-21 20:02:45 140003892000512 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address 'mysql-1.mysql.default.svc.cluster.local' --datadir '/var/lib/mysql/'   --parent '156'  '' '
2017-06-21 20:02:45 140004201175808 [Note] WSREP: Prepared SST request: rsync|mysql-1.mysql.default.svc.cluster.local:4444/rsync_sst
2017-06-21 20:02:45 140004201175808 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-06-21 20:02:45 140004201175808 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-06-21 20:02:45 140004201175808 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
2017-06-21 20:02:45 140003979392768 [Note] WSREP: Service thread queue flushed.
2017-06-21 20:02:45 140004201175808 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (737eec26-56bc-11e7-af21-0b272c1e52f7): 1 (Operation not permitted)
     at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
2017-06-21 20:02:45 140003921356544 [Note] WSREP: Member 1.0 (mysql-1) requested state transfer from '*any*'. Selected 0.0 (mysql-0)(SYNCED) as donor.
2017-06-21 20:02:45 140003921356544 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 6)
2017-06-21 20:02:45 140004201175808 [Note] WSREP: Requesting state transfer: success, donor: 0
2017-06-21 20:02:45 140004201175808 [Note] WSREP: GCache history reset: old(00000000-0000-0000-0000-000000000000:0) -> new(737eec26-56bc-11e7-af21-0b272c1e52f7:6)
MySQL init process in progress...
2017-06-21 20:02:46 140003921356544 [Note] WSREP: 0.0 (mysql-0): State transfer to 1.0 (mysql-1) complete.
2017-06-21 20:02:46 140003921356544 [Note] WSREP: Member 0.0 (mysql-0) synced with group.
MySQL init process in progress...
2017-06-21 20:02:47 140003929749248 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') turning message relay requesting off
WSREP_SST: [INFO] Joiner cleanup. rsync PID: 201 (20170621 20:02:47.539)
WSREP_SST: [INFO] Joiner cleanup done. (20170621 20:02:48.047)
2017-06-21 20:02:48 140004201490368 [Note] WSREP: SST complete, seqno: 6
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: The InnoDB memory heap is disabled
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Using Linux native AIO
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Using SSE crc32 instructions
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Initializing buffer pool, size = 2.8G
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Completed initialization of buffer pool
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Highest supported file format is Barracuda.
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: The log sequence numbers 1617965 and 1617965 in ibdata files do not match the log sequence number 1618129 in the ib_logfiles!
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
MySQL init process in progress...
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: 128 rollback segment(s) are active.
2017-06-21 20:02:48 140004201490368 [Note] InnoDB: Waiting for purge to start
2017-06-21 20:02:48 140004201490368 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.0 started; log sequence number 1618129
2017-06-21 20:02:48 140000398124800 [Note] InnoDB: Dumping buffer pool(s) not yet started
2017-06-21 20:02:48 140004201490368 [Note] Plugin 'FEEDBACK' is disabled.
2017-06-21 20:02:48 140004201490368 [Warning] 'proxies_priv' entry '@% root@mysql-0' ignored in --skip-name-resolve mode.
2017-06-21 20:02:48 140004201490368 [Note] WSREP: Signalling provider to continue.
2017-06-21 20:02:48 140004201490368 [Note] WSREP: SST received: 737eec26-56bc-11e7-af21-0b272c1e52f7:6
2017-06-21 20:02:48 140003921356544 [Note] WSREP: 1.0 (mysql-1): State transfer from 0.0 (mysql-0) complete.
2017-06-21 20:02:48 140003921356544 [Note] WSREP: Shifting JOINER -> JOINED (TO: 6)
2017-06-21 20:02:48 140003921356544 [Note] WSREP: Member 1.0 (mysql-1) synced with group.
2017-06-21 20:02:48 140003921356544 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 6)
2017-06-21 20:02:48 140004201175808 [Note] WSREP: Synchronized with group, ready for connections
2017-06-21 20:02:48 140004201175808 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-06-21 20:02:48 140004201490368 [Note] mysqld: ready for connections.
Version: '10.1.24-MariaDB-1~jessie'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  mariadb.org binary distribution
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process in progress...
MySQL init process failed.

After the automatic restart:

2017-06-21 20:03:18 140129295955904 [Note] mysqld (mysqld 10.1.24-MariaDB-1~jessie) starting as process 1 ...
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-06-21 20:03:18 140129295955904 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
2017-06-21 20:03:18 140129295955904 [Note] WSREP: wsrep_load(): Galera 25.3.20(r3703) by Codership Oy <info@codership.com> loaded successfully.
2017-06-21 20:03:18 140129295955904 [Note] WSREP: CRC-32C: using hardware acceleration.
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Found saved state: 737eec26-56bc-11e7-af21-0b272c1e52f7:-1, safe_to_bootsrap: 0
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = mysql-1.mysql.default.svc.cluster.local; 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
2017-06-21 20:03:18 140129295955904 [Note] WSREP: GCache history reset: old(737eec26-56bc-11e7-af21-0b272c1e52f7:0) -> new(737eec26-56bc-11e7-af21-0b272c1e52f7:-1)
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2017-06-21 20:03:18 140129295955904 [Note] WSREP: wsrep_sst_grab()
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Start replication
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2017-06-21 20:03:18 140129295955904 [Note] WSREP: protonet asio version 0
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Using CRC-32C for message checksums.
2017-06-21 20:03:18 140129295955904 [Note] WSREP: backend: asio
2017-06-21 20:03:18 140129295955904 [Note] WSREP: gcomm thread scheduling priority set to other:0
2017-06-21 20:03:18 140129295955904 [Note] WSREP: restore pc from disk successfully
2017-06-21 20:03:18 140129295955904 [Note] WSREP: GMCast version 0
2017-06-21 20:03:18 140129295955904 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2017-06-21 20:03:18 140129295955904 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2017-06-21 20:03:18 140129295955904 [Note] WSREP: EVS version 0
2017-06-21 20:03:18 140129295955904 [Note] WSREP: gcomm: connecting to group 'mysql', peer 'mysql-0.mysql.default.svc.cluster.local:'
2017-06-21 20:03:18 140129295955904 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') connection established to 769cae23 tcp://172.17.0.7:4567
2017-06-21 20:03:18 140129295955904 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2017-06-21 20:03:18 140129295955904 [Note] WSREP: gcomm: connected
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Opened channel 'mysql'
2017-06-21 20:03:18 140129295955904 [Note] WSREP: Waiting for SST to complete.
2017-06-21 20:03:20 140129020671744 [Warning] WSREP: no nodes coming from prim view, prim not possible
2017-06-21 20:03:20 140129020671744 [Note] WSREP: view(view_id(NON_PRIM,96f79dad,4) memb {
    96f79dad,0
} joined {
} left {
} partitioned {
})
2017-06-21 20:03:20 140129003894528 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2017-06-21 20:03:20 140129003894528 [Note] WSREP: Flow-control interval: [16, 16]
2017-06-21 20:03:20 140129003894528 [Note] WSREP: Received NON-PRIMARY.
2017-06-21 20:03:20 140129295641344 [Note] WSREP: New cluster view: global state: :-1, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version -1
2017-06-21 20:03:20 140129295641344 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-06-21 20:03:21 140129020671744 [Note] WSREP: (96f79dad, 'tcp://0.0.0.0:4567') turning message relay requesting off
2017-06-21 20:03:22 140129020671744 [Note] WSREP: declaring 769cae23 at tcp://172.17.0.7:4567 stable
2017-06-21 20:03:22 140129020671744 [Note] WSREP: re-bootstrapping prim from partitioned components
2017-06-21 20:03:22 140129020671744 [Note] WSREP: view(view_id(PRIM,769cae23,5) memb {
    769cae23,0
    96f79dad,0
} joined {
} left {
} partitioned {
})
2017-06-21 20:03:22 140129020671744 [Note] WSREP: save pc into disk
2017-06-21 20:03:22 140129020671744 [Note] WSREP: clear restored view
2017-06-21 20:03:22 140129003894528 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2017-06-21 20:03:22 140129003894528 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2017-06-21 20:03:22 140129003894528 [Note] WSREP: STATE EXCHANGE: sent state msg: ad6a1cca-56bc-11e7-9bd9-5af6aeef94b7
2017-06-21 20:03:22 140129003894528 [Note] WSREP: STATE EXCHANGE: got state msg: ad6a1cca-56bc-11e7-9bd9-5af6aeef94b7 from 0 (mysql-0)
2017-06-21 20:03:22 140129003894528 [Note] WSREP: STATE EXCHANGE: got state msg: ad6a1cca-56bc-11e7-9bd9-5af6aeef94b7 from 1 (mysql-1)
2017-06-21 20:03:22 140129003894528 [Warning] WSREP: Quorum: No node with complete state:

    Version      : 4
    Flags        : 0x3
    Protocols    : 0 / 7 / 3
    State        : NON-PRIMARY
    Desync count : 0
    Prim state   : SYNCED
    Prim UUID    : 9744b2d6-56bc-11e7-a92a-d31cda1fa9d4
    Prim  seqno  : 2
    First seqno  : -1
    Last  seqno  : 6
    Prim JOINED  : 2
    State UUID   : ad6a1cca-56bc-11e7-9bd9-5af6aeef94b7
    Group UUID   : 737eec26-56bc-11e7-af21-0b272c1e52f7
    Name         : 'mysql-0'
    Incoming addr: 'mysql-0.mysql.default.svc.cluster.local:3306'

    Version      : 4
    Flags        : 00
    Protocols    : 0 / 7 / 3
    State        : NON-PRIMARY
    Desync count : 0
    Prim state   : NON-PRIMARY
    Prim UUID    : 00000000-0000-0000-0000-000000000000
    Prim  seqno  : -1
    First seqno  : -1
    Last  seqno  : -1
    Prim JOINED  : 0
    State UUID   : ad6a1cca-56bc-11e7-9bd9-5af6aeef94b7
    Group UUID   : 00000000-0000-0000-0000-000000000000
    Name         : 'mysql-1'
    Incoming addr: 'mysql-1.mysql.default.svc.cluster.local:3306'

2017-06-21 20:03:22 140129003894528 [Note] WSREP: Partial re-merge of primary 9744b2d6-56bc-11e7-a92a-d31cda1fa9d4 found: 1 of 2.
2017-06-21 20:03:22 140129003894528 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 2,
    members    = 1/2 (joined/total),
    act_id     = 6,
    last_appl. = -1,
    protocols  = 0/7/3 (gcs/repl/appl),
    group UUID = 737eec26-56bc-11e7-af21-0b272c1e52f7
2017-06-21 20:03:22 140129003894528 [Note] WSREP: Flow-control interval: [23, 23]
2017-06-21 20:03:22 140129003894528 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 6)
2017-06-21 20:03:22 140129295641344 [Note] WSREP: State transfer required:
    Group state: 737eec26-56bc-11e7-af21-0b272c1e52f7:6
    Local state: 737eec26-56bc-11e7-af21-0b272c1e52f7:-1
2017-06-21 20:03:22 140129295641344 [Note] WSREP: New cluster view: global state: 737eec26-56bc-11e7-af21-0b272c1e52f7:6, view# 3: Primary, number of nodes: 2, my index: 1, protocol version 3
2017-06-21 20:03:22 140129295641344 [Warning] WSREP: Gap in state sequence. Need state transfer.
2017-06-21 20:03:22 140128974534400 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address 'mysql-1.mysql.default.svc.cluster.local' --datadir '/var/lib/mysql/'   --parent '1'  '' '
2017-06-21 20:03:22 140129295641344 [Note] WSREP: Prepared SST request: rsync|mysql-1.mysql.default.svc.cluster.local:4444/rsync_sst
2017-06-21 20:03:22 140129295641344 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-06-21 20:03:22 140129295641344 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-06-21 20:03:22 140129295641344 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
2017-06-21 20:03:22 140129070315264 [Note] WSREP: Service thread queue flushed.
2017-06-21 20:03:22 140129295641344 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state seqno is undefined: 1 (Operation not permitted)
     at galera/src/replicator_str.cpp:prepare_for_IST():491. IST will be unavailable.
2017-06-21 20:03:22 140129003894528 [Note] WSREP: Member 1.0 (mysql-1) requested state transfer from '*any*'. Selected 0.0 (mysql-0)(SYNCED) as donor.
2017-06-21 20:03:22 140129003894528 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 6)
2017-06-21 20:03:22 140129295641344 [Note] WSREP: Requesting state transfer: success, donor: 0
2017-06-21 20:03:22 140129295641344 [Note] WSREP: GCache history reset: old(737eec26-56bc-11e7-af21-0b272c1e52f7:0) -> new(737eec26-56bc-11e7-af21-0b272c1e52f7:6)
2017-06-21 20:03:23 140129003894528 [Note] WSREP: 0.0 (mysql-0): State transfer to 1.0 (mysql-1) complete.
2017-06-21 20:03:23 140129003894528 [Note] WSREP: Member 0.0 (mysql-0) synced with group.
WSREP_SST: [INFO] Joiner cleanup. rsync PID: 70 (20170621 20:03:24.189)
WSREP_SST: [INFO] Joiner cleanup done. (20170621 20:03:24.695)
2017-06-21 20:03:24 140129295955904 [Note] WSREP: SST complete, seqno: 6
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: The InnoDB memory heap is disabled
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Using Linux native AIO
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Using SSE crc32 instructions
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Initializing buffer pool, size = 2.8G
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Completed initialization of buffer pool
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Highest supported file format is Barracuda.
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: The log sequence numbers 1617965 and 1617965 in ibdata files do not match the log sequence number 1618129 in the ib_logfiles!
2017-06-21 20:03:24 140129295955904 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
2017-06-21 20:03:25 140129295955904 [Note] InnoDB: 128 rollback segment(s) are active.
2017-06-21 20:03:25 140129295955904 [Note] InnoDB: Waiting for purge to start
2017-06-21 20:03:25 140129295955904 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.0 started; log sequence number 1618129
2017-06-21 20:03:25 140125484852992 [Note] InnoDB: Dumping buffer pool(s) not yet started
2017-06-21 20:03:25 140129295955904 [Note] Plugin 'FEEDBACK' is disabled.
2017-06-21 20:03:25 140129295955904 [Note] Recovering after a crash using tc.log
2017-06-21 20:03:25 140129295955904 [Note] Starting crash recovery...
2017-06-21 20:03:25 140129295955904 [Note] Crash recovery finished.
2017-06-21 20:03:25 140129295955904 [Note] Server socket created on IP: '0.0.0.0'.
2017-06-21 20:03:25 140129295955904 [Warning] 'proxies_priv' entry '@% root@mysql-0' ignored in --skip-name-resolve mode.
2017-06-21 20:03:25 140129295955904 [Note] WSREP: Signalling provider to continue.
2017-06-21 20:03:25 140129295955904 [Note] WSREP: SST received: 737eec26-56bc-11e7-af21-0b272c1e52f7:6
2017-06-21 20:03:25 140129003894528 [Note] WSREP: 1.0 (mysql-1): State transfer from 0.0 (mysql-0) complete.
2017-06-21 20:03:25 140129003894528 [Note] WSREP: Shifting JOINER -> JOINED (TO: 6)
2017-06-21 20:03:25 140129003894528 [Note] WSREP: Member 1.0 (mysql-1) synced with group.
2017-06-21 20:03:25 140129003894528 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 6)
2017-06-21 20:03:25 140129295641344 [Note] WSREP: Synchronized with group, ready for connections
2017-06-21 20:03:25 140129295641344 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-06-21 20:03:25 140129295955904 [Note] mysqld: ready for connections.
Version: '10.1.24-MariaDB-1~jessie'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution