hello.
I have set up Percona XtraDB Cluster 5.7.17.
There are four Percona XtraDB Cluster nodes.
I found that PXC nodes hang on shutdown when using pool-of-threads.
My PXC environment :
[root@PXC4 ~]# cat /etc/centos-release
CentOS Linux release 7.3.1611 (Core)
[root@PXC4 ~]# rpm -qa | grep -i percona
percona-release-0.1-4.noarch
Percona-XtraDB-Cluster-client-57-5.7.17-27.20.2.el7.x86_64
Percona-XtraDB-Cluster-shared-compat-57-5.7.17-27.20.2.el7.x86_64
percona-xtrabackup-24-2.4.6-2.el7.x86_64
Percona-XtraDB-Cluster-57-5.7.17-27.20.2.el7.x86_64
Percona-XtraDB-Cluster-shared-57-5.7.17-27.20.2.el7.x86_64
Percona-XtraDB-Cluster-server-57-5.7.17-27.20.2.el7.x86_64
The process of reproducing this phenomenon is as follows :
step1)
Having thread pool disabled:
/etc/my.cnf
# thread_handling = pool-of-threads
mysql> show variables like '%thread_handling';
+-----------------+---------------------------+
| Variable_name | Value |
+-----------------+---------------------------+
| thread_handling | one-thread-per-connection |
+-----------------+---------------------------+
1 row in set (0.03 sec)
[root@PXC4 ~]# service mysql stop
Redirecting to /bin/systemctl stop mysql.service
-> It is normal shutdown
error.log :
2017-03-23T05:23:13.563025Z 0 [Note] Recieved shutdown signal. Will sleep for 10 secs before initiating shutdown. pxc_maint_mode switched to SHUTDOWN
2017-03-23T05:23:23.563896Z 0 [Note] WSREP: Stop replication
2017-03-23T05:23:23.563959Z 0 [Note] WSREP: Closing send monitor...
2017-03-23T05:23:23.563969Z 0 [Note] WSREP: Closed send monitor.
2017-03-23T05:23:23.564082Z 0 [Note] WSREP: gcomm: terminating thread
2017-03-23T05:23:23.564145Z 0 [Note] WSREP: gcomm: joining thread
2017-03-23T05:23:23.564203Z 0 [Note] WSREP: gcomm: closing backend
2017-03-23T05:23:23.568531Z 0 [Note] WSREP: view(view_id(NON_PRIM,249e477d,16) memb {
b1763126,0
} joined {
} left {
} partitioned {
249e477d,0
a82719fe,0
c2b0fd4b,0
})
2017-03-23T05:23:23.568782Z 0 [Note] WSREP: view((empty))
2017-03-23T05:23:23.575908Z 0 [Note] WSREP: gcomm: closed
2017-03-23T05:23:23.576025Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2017-03-23T05:23:23.576047Z 0 [Note] WSREP: Flow-control interval: [16, 16]
2017-03-23T05:23:23.576055Z 0 [Note] WSREP: Received NON-PRIMARY.
2017-03-23T05:23:23.576060Z 0 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 16)
2017-03-23T05:23:23.576077Z 0 [Note] WSREP: Received self-leave message.
2017-03-23T05:23:23.576085Z 0 [Note] WSREP: Flow-control interval: [0, 0]
2017-03-23T05:23:23.576090Z 0 [Note] WSREP: Received SELF-LEAVE. Closing connection.
2017-03-23T05:23:23.576094Z 0 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 16)
2017-03-23T05:23:23.576389Z 0 [Note] WSREP: RECV thread exiting 0: Success
2017-03-23T05:23:23.576562Z 2 [Note] WSREP: New cluster view: global state: 0eb421f9-0f69-11e7-9e0d-c219fa284372:16, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3
2017-03-23T05:23:23.576579Z 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-03-23T05:23:23.576616Z 2 [Note] WSREP: New cluster view: global state: 0eb421f9-0f69-11e7-9e0d-c219fa284372:16, view# -1: non-Primary, number of nodes: 0, my index: -1, protocol version 3
2017-03-23T05:23:23.576622Z 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-03-23T05:23:23.577187Z 2 [Note] WSREP: applier thread exiting (code:0)
2017-03-23T05:23:23.577716Z 0 [Note] WSREP: recv_thread() joined.
2017-03-23T05:23:23.577793Z 0 [Note] WSREP: Closing replication queue.
2017-03-23T05:23:23.577804Z 0 [Note] WSREP: Closing slave action queue.
2017-03-23T05:23:23.577817Z 0 [Note] Giving 8 client threads a chance to die gracefully
2017-03-23T05:23:23.577846Z 7 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:23.578699Z 3 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:23.578822Z 8 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:23.578904Z 9 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:23.579320Z 5 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:23.579929Z 6 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:23.581352Z 10 [Note] WSREP: applier thread exiting (code:6)
2017-03-23T05:23:25.578751Z 0 [Note] WSREP: active appliers remaining
2017-03-23T05:23:25.578817Z 1 [Note] WSREP: rollbacker thread exiting
2017-03-23T05:23:26.579874Z 0 [Note] Giving 0 client threads a chance to die gracefully
2017-03-23T05:23:26.579953Z 0 [Note] Shutting down slave threads
2017-03-23T05:23:26.579967Z 0 [Note] Forcefully disconnecting 0 remaining clients
2017-03-23T05:23:26.579975Z 0 [Note] Event Scheduler: Purging the queue. 0 events
2017-03-23T05:23:26.580018Z 0 [Note] WSREP: dtor state: CLOSED
2017-03-23T05:23:26.583985Z 0 [Note] WSREP: apply mon: entered 0
2017-03-23T05:23:26.592890Z 0 [Note] WSREP: apply mon: entered 0
2017-03-23T05:23:26.617208Z 0 [Note] WSREP: mon: entered 4 oooe fraction 0 oool fraction 0
2017-03-23T05:23:26.617953Z 0 [Note] WSREP: cert index usage at exit 0
2017-03-23T05:23:26.618033Z 0 [Note] WSREP: cert trx map usage at exit 0
2017-03-23T05:23:26.618068Z 0 [Note] WSREP: deps set usage at exit 0
2017-03-23T05:23:26.618085Z 0 [Note] WSREP: avg deps dist 0
2017-03-23T05:23:26.618096Z 0 [Note] WSREP: avg cert interval 0
2017-03-23T05:23:26.618103Z 0 [Note] WSREP: cert index size 0
2017-03-23T05:23:26.618130Z 0 [Note] WSREP: Service thread queue flushed.
2017-03-23T05:23:26.618167Z 0 [Note] WSREP: wsdb trx map usage 0 conn query map usage 0
2017-03-23T05:23:26.618184Z 0 [Note] WSREP: MemPool(LocalTrxHandle): hit ratio: 0, misses: 0, in use: 0, in pool: 0
2017-03-23T05:23:26.618321Z 0 [Note] WSREP: MemPool(SlaveTrxHandle): hit ratio: 0, misses: 0, in use: 0, in pool: 0
2017-03-23T05:23:26.618783Z 0 [Note] WSREP: Shifting CLOSED -> DESTROYED (TO: 16)
2017-03-23T05:23:26.625745Z 0 [Note] WSREP: Flushing memory map to disk...
2017-03-23T05:23:26.631356Z 0 [Note] Binlog end
2017-03-23T05:23:26.652850Z 0 [Note] Shutting down plugin 'ngram'
2017-03-23T05:23:26.652967Z 0 [Note] Shutting down plugin 'partition'
2017-03-23T05:23:26.652994Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2017-03-23T05:23:26.653016Z 0 [Note] Shutting down plugin 'ARCHIVE'
2017-03-23T05:23:26.653041Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2017-03-23T05:23:26.653154Z 0 [Note] Shutting down plugin 'CSV'
2017-03-23T05:23:26.653167Z 0 [Note] Shutting down plugin 'MEMORY'
2017-03-23T05:23:26.653173Z 0 [Note] Shutting down plugin 'MyISAM'
2017-03-23T05:23:26.653196Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-03-23T05:23:26.653242Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2017-03-23T05:23:26.653257Z 0 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2017-03-23T05:23:26.653262Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-03-23T05:23:26.653266Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-03-23T05:23:26.653270Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-03-23T05:23:26.653274Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-03-23T05:23:26.653277Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-03-23T05:23:26.653281Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-03-23T05:23:26.653286Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-03-23T05:23:26.653290Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-03-23T05:23:26.653294Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-03-23T05:23:26.653298Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-03-23T05:23:26.653302Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-03-23T05:23:26.653306Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-03-23T05:23:26.653310Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-03-23T05:23:26.653314Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-03-23T05:23:26.653318Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-03-23T05:23:26.653322Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2017-03-23T05:23:26.653326Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2017-03-23T05:23:26.653330Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-03-23T05:23:26.653334Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-03-23T05:23:26.653337Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-03-23T05:23:26.653342Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-03-23T05:23:26.653347Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-03-23T05:23:26.653351Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-03-23T05:23:26.653378Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-03-23T05:23:26.653386Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-03-23T05:23:26.653390Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2017-03-23T05:23:26.653395Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-03-23T05:23:26.653398Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-03-23T05:23:26.653402Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2017-03-23T05:23:26.653406Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS'
2017-03-23T05:23:26.653411Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT'
2017-03-23T05:23:26.653437Z 0 [Note] Shutting down plugin 'XTRADB_RSEG'
2017-03-23T05:23:26.653463Z 0 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES'
2017-03-23T05:23:26.653470Z 0 [Note] Shutting down plugin 'XTRADB_READ_VIEW'
2017-03-23T05:23:26.653474Z 0 [Note] Shutting down plugin 'InnoDB'
2017-03-23T05:23:26.653700Z 0 [Note] InnoDB: FTS optimize thread exiting.
2017-03-23T05:23:26.654090Z 0 [Note] InnoDB: Starting shutdown...
2017-03-23T05:23:26.754696Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2017-03-23T05:23:26.755163Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 170323 14:23:26
2017-03-23T05:23:27.057512Z 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-03-23T05:23:28.385779Z 0 [Note] InnoDB: Shutdown completed; log sequence number 2512927
2017-03-23T05:23:28.386011Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-03-23T05:23:28.386041Z 0 [Note] Shutting down plugin 'sha256_password'
2017-03-23T05:23:28.386049Z 0 [Note] Shutting down plugin 'mysql_native_password'
2017-03-23T05:23:28.386055Z 0 [Note] Shutting down plugin 'wsrep'
2017-03-23T05:23:28.386327Z 0 [Note] Shutting down plugin 'binlog'
2017-03-23T05:23:28.387848Z 0 [Note] /usr/sbin/mysqld: Shutdown complete
step2)
Having thread pool enabled:
/etc/my.cnf
thread_handling = pool-of-threads
mysql> show variables like '%thread_handling';
+-----------------+-----------------+
| Variable_name | Value |
+-----------------+-----------------+
| thread_handling | pool-of-threads |
+-----------------+-----------------+
1 row in set (0.01 sec)
[root@PXC4 ~]# service mysql start
Redirecting to /bin/systemctl start mysql.service
-> mysqld started normal and joined to PXC-Cluster
error.log :
2017-03-23T05:24:29.678380Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-03-23T05:24:29.680096Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-11-57-log) starting as process 10396 ...
2017-03-23T05:24:29.683393Z 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-03-23T05:24:29.683419Z 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera3/libgalera_smm.so'
2017-03-23T05:24:29.696974Z 0 [Note] WSREP: wsrep_load(): Galera 3.20(r7e383f7) by Codership Oy <email address hidden> loaded successfully.
2017-03-23T05:24:29.697210Z 0 [Note] WSREP: CRC-32C: using hardware acceleration.
2017-03-23T05:24:29.699821Z 0 [Note] WSREP: Found saved state: 0eb421f9-0f69-11e7-9e0d-c219fa284372:16, safe_to_bootsrap: 0
2017-03-23T05:24:29.715394Z 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.25.136; 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_count = 0; 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; 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; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.recovery = 1; pc.version = 0; pc.wait_prim = true; pc.wait_prim_timeout = PT30S; pc.weight = 1; protonet.backend = asio; protonet.version = 0; repl.causal_read_timeout = PT30S; repl.commit_order = 3; repl.key_format = FLAT8; repl.max_ws_size = 2147483647; repl.proto_max = 7; socket.checksum = 2; socket.recv_buf_size = 212992;
2017-03-23T05:24:29.788404Z 0 [Note] WSREP: GCache history reset: old(0eb421f9-0f69-11e7-9e0d-c219fa284372:0) -> new(0eb421f9-0f69-11e7-9e0d-c219fa284372:16)
2017-03-23T05:24:29.797555Z 0 [Note] WSREP: Assign initial position for certification: 16, protocol version: -1
2017-03-23T05:24:29.800030Z 0 [Note] WSREP: wsrep_sst_grab()
2017-03-23T05:24:29.800416Z 0 [Note] WSREP: Start replication
2017-03-23T05:24:29.800869Z 0 [Note] WSREP: Setting initial position to 0eb421f9-0f69-11e7-9e0d-c219fa284372:16
2017-03-23T05:24:29.805645Z 0 [Note] WSREP: protonet asio version 0
2017-03-23T05:24:29.805902Z 0 [Note] WSREP: Using CRC-32C for message checksums.
2017-03-23T05:24:29.805991Z 0 [Note] WSREP: backend: asio
2017-03-23T05:24:29.806089Z 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
2017-03-23T05:24:29.806374Z 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
2017-03-23T05:24:29.806394Z 0 [Note] WSREP: restore pc from disk failed
2017-03-23T05:24:29.807717Z 0 [Note] WSREP: GMCast version 0
2017-03-23T05:24:29.808680Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2017-03-23T05:24:29.808780Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2017-03-23T05:24:29.809677Z 0 [Note] WSREP: EVS version 0
2017-03-23T05:24:29.813425Z 0 [Note] WSREP: gcomm: connecting to group 'PXC-Cluster', peer '192.168.25.130:,192.168.25.131:,192.168.25.132:,192.168.25.136:'
2017-03-23T05:24:29.861036Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to fd51f1fd tcp://192.168.25.136:4567
2017-03-23T05:24:29.861530Z 0 [Warning] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') address 'tcp://192.168.25.136:4567' points to own listening address, blacklisting
2017-03-23T05:24:29.890762Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to c2b0fd4b tcp://192.168.25.131:4567
2017-03-23T05:24:29.891386Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2017-03-23T05:24:29.900346Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to a82719fe tcp://192.168.25.130:4567
2017-03-23T05:24:29.931252Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to 249e477d tcp://192.168.25.132:4567
2017-03-23T05:24:29.934494Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to 249e477d tcp://192.168.25.132:4567
2017-03-23T05:24:30.328843Z 0 [Note] WSREP: declaring 249e477d at tcp://192.168.25.132:4567 stable
2017-03-23T05:24:30.329307Z 0 [Note] WSREP: declaring a82719fe at tcp://192.168.25.130:4567 stable
2017-03-23T05:24:30.329344Z 0 [Note] WSREP: declaring c2b0fd4b at tcp://192.168.25.131:4567 stable
2017-03-23T05:24:31.330830Z 0 [Note] WSREP: Node 249e477d state prim
2017-03-23T05:24:31.343667Z 0 [Note] WSREP: view(view_id(PRIM,249e477d,18) memb {
249e477d,0
a82719fe,0
c2b0fd4b,0
fd51f1fd,0
} joined {
} left {
} partitioned {
})
2017-03-23T05:24:31.345630Z 0 [Note] WSREP: save pc into disk
2017-03-23T05:24:31.820600Z 0 [Note] WSREP: gcomm: connected
2017-03-23T05:24:31.820709Z 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2017-03-23T05:24:31.820794Z 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2017-03-23T05:24:31.820806Z 0 [Note] WSREP: Opened channel 'PXC-Cluster'
2017-03-23T05:24:31.820939Z 0 [Note] WSREP: Waiting for SST to complete.
2017-03-23T05:24:31.821101Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 3, memb_num = 4
2017-03-23T05:24:31.821134Z 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2017-03-23T05:24:31.821222Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: d3418634-0f88-11e7-b104-02d94c8f226f
2017-03-23T05:24:31.821282Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d3418634-0f88-11e7-b104-02d94c8f226f from 0 (PXC3)
2017-03-23T05:24:31.821293Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d3418634-0f88-11e7-b104-02d94c8f226f from 2 (PXC2)
2017-03-23T05:24:31.821301Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d3418634-0f88-11e7-b104-02d94c8f226f from 1 (PXC1)
2017-03-23T05:24:31.834923Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d3418634-0f88-11e7-b104-02d94c8f226f from 3 (PXC4)
2017-03-23T05:24:31.834989Z 0 [Note] WSREP: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 17,
members = 4/4 (joined/total),
act_id = 16,
last_appl. = -1,
protocols = 0/7/3 (gcs/repl/appl),
group UUID = 0eb421f9-0f69-11e7-9e0d-c219fa284372
2017-03-23T05:24:31.835062Z 0 [Note] WSREP: Flow-control interval: [32, 32]
2017-03-23T05:24:31.835084Z 0 [Note] WSREP: Restored state OPEN -> JOINED (16)
2017-03-23T05:24:31.835188Z 1 [Note] WSREP: New cluster view: global state: 0eb421f9-0f69-11e7-9e0d-c219fa284372:16, view# 18: Primary, number of nodes: 4, my index: 3, protocol version 3
2017-03-23T05:24:31.835221Z 0 [Note] WSREP: SST complete, seqno: 16
2017-03-23T05:24:31.849068Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-03-23T05:24:31.849199Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-03-23T05:24:31.849210Z 0 [Note] InnoDB: Uses event mutexes
2017-03-23T05:24:31.849220Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-03-23T05:24:31.849229Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2017-03-23T05:24:31.849237Z 0 [Note] InnoDB: Using Linux native AIO
2017-03-23T05:24:31.851456Z 0 [Note] InnoDB: Number of pools: 1
2017-03-23T05:24:31.851815Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-03-23T05:24:31.867529Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-03-23T05:24:31.878558Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-03-23T05:24:31.883983Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-03-23T05:24:31.890947Z 0 [Note] WSREP: Member 3.0 (PXC4) synced with group.
2017-03-23T05:24:31.891447Z 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 16)
2017-03-23T05:24:31.941625Z 0 [Note] InnoDB: Crash recovery did not find the parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite
2017-03-23T05:24:31.952275Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-23T05:24:31.986017Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite, size 3932160 bytes
2017-03-23T05:24:32.072690Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-03-23T05:24:32.072930Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-03-23T05:24:32.115427Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-03-23T05:24:32.116542Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-03-23T05:24:32.116693Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-03-23T05:24:32.118348Z 0 [Note] InnoDB: Waiting for purge to start
2017-03-23T05:24:32.172709Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.17-11 started; log sequence number 2512927
2017-03-23T05:24:32.173323Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-03-23T05:24:32.173441Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-03-23T05:24:32.214250Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2017-03-23T05:24:32.214297Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
2017-03-23T05:24:32.232862Z 0 [Warning] CA certificate ca.pem is self signed.
2017-03-23T05:24:32.233111Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
2017-03-23T05:24:32.233512Z 0 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
2017-03-23T05:24:32.233565Z 0 [Note] - '0.0.0.0' resolves to '0.0.0.0';
2017-03-23T05:24:32.233628Z 0 [Note] Server socket created on IP: '0.0.0.0'.
2017-03-23T05:24:32.263639Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.263853Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.263907Z 0 [Warning] 'user' entry 'sstuser@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.263923Z 0 [Warning] 'user' entry 'bkpuser@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.263958Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.263990Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.268335Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:24:32.293652Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170323 14:24:32
2017-03-23T05:24:32.311307Z 0 [Note] Event Scheduler: Loaded 0 events
2017-03-23T05:24:32.313893Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-03-23T05:24:32.314064Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-03-23T05:24:32.343628Z 1 [Note] WSREP: Initialized wsrep sidno 2
2017-03-23T05:24:32.343963Z 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-03-23T05:24:32.344206Z 1 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-03-23T05:24:32.345028Z 1 [Note] WSREP: Assign initial position for certification: 16, protocol version: 3
2017-03-23T05:24:32.346149Z 0 [Note] WSREP: Service thread queue flushed.
2017-03-23T05:24:32.350063Z 1 [Note] WSREP: Synchronized with group, ready for connections
2017-03-23T05:24:32.350151Z 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-03-23T05:24:32.389633Z 0 [Note] End of list of non-natively partitioned tables
2017-03-23T05:24:32.391908Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.17-11-57-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona XtraDB Cluster (GPL), Release rel11, Revision e2a7fdd, WSREP version 27.20, wsrep_27.20
2017-03-23T05:24:33.339711Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection to peer fd51f1fd with addr tcp://192.168.25.136:4567 timed out, no messages seen in PT3S
2017-03-23T05:24:33.340096Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') turning message relay requesting off
step3)
Having thread pool enabled:
/etc/my.cnf
thread_handling = pool-of-threads
mysql> show variables like '%thread_handling';
+-----------------+-----------------+
| Variable_name | Value |
+-----------------+-----------------+
| thread_handling | pool-of-threads |
+-----------------+-----------------+
1 row in set (0.01 sec)
[root@PXC4 ~]# service mysql stop
Redirecting to /bin/systemctl stop mysql.service
^C
-> mysqld has been automatically restarted.
-> it hangs until killed.
error.log :
Log of wsrep recovery (--wsrep-recover):
2017-03-23T05:27:23.263454Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-03-23T05:27:23.265542Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-11-57-log) starting as process 10531 ...
2017-03-23T05:27:23.273807Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-03-23T05:27:23.273867Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-03-23T05:27:23.273871Z 0 [Note] InnoDB: Uses event mutexes
2017-03-23T05:27:23.273875Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-03-23T05:27:23.273878Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2017-03-23T05:27:23.273882Z 0 [Note] InnoDB: Using Linux native AIO
2017-03-23T05:27:23.276552Z 0 [Note] InnoDB: Number of pools: 1
2017-03-23T05:27:23.276793Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-03-23T05:27:23.279055Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-03-23T05:27:23.284179Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-03-23T05:27:23.286320Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-03-23T05:27:23.307974Z 0 [Note] InnoDB: Recovering partial pages from the parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite
2017-03-23T05:27:23.323781Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-23T05:27:23.326771Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2513100
2017-03-23T05:27:23.326842Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 2513109
2017-03-23T05:27:23.327309Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 2513109
2017-03-23T05:27:23.327334Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-03-23T05:27:23.327338Z 0 [Note] InnoDB: Starting crash recovery.
2017-03-23T05:27:23.503116Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite, size 3932160 bytes
2017-03-23T05:27:23.585770Z 0 [Note] InnoDB: Last MySQL binlog file position 0 966, file name mysql-bin.000001
2017-03-23T05:27:23.618196Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-03-23T05:27:23.618247Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-03-23T05:27:23.618355Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-03-23T05:27:23.667972Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-03-23T05:27:23.669423Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-03-23T05:27:23.669452Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-03-23T05:27:23.671157Z 0 [Note] InnoDB: Waiting for purge to start
2017-03-23T05:27:23.722576Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.17-11 started; log sequence number 2513109
2017-03-23T05:27:23.722655Z 0 [Warning] InnoDB: Skipping buffer pool dump/restore during wsrep recovery.
2017-03-23T05:27:23.723342Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-03-23T05:27:23.732128Z 0 [Note] Recovering after a crash using /var/lib/mysql/mysql-bin
2017-03-23T05:27:23.732152Z 0 [Note] WSREP: Binlog recovery, found wsrep position 0eb421f9-0f69-11e7-9e0d-c219fa284372:16
2017-03-23T05:27:23.732171Z 0 [Note] WSREP: Binlog recovery scan stopped at Xid event -1
2017-03-23T05:27:23.732174Z 0 [Note] Starting crash recovery...
2017-03-23T05:27:23.732346Z 0 [Note] Crash recovery finished.
2017-03-23T05:27:23.736638Z 0 [Note] WSREP: Recovered position: 0eb421f9-0f69-11e7-9e0d-c219fa284372:16
2017-03-23T05:27:23.736669Z 0 [Note] Binlog end
2017-03-23T05:27:23.737603Z 0 [Note] Shutting down plugin 'ngram'
2017-03-23T05:27:23.737630Z 0 [Note] Shutting down plugin 'partition'
2017-03-23T05:27:23.737636Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2017-03-23T05:27:23.737641Z 0 [Note] Shutting down plugin 'ARCHIVE'
2017-03-23T05:27:23.737644Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2017-03-23T05:27:23.737662Z 0 [Note] Shutting down plugin 'CSV'
2017-03-23T05:27:23.737668Z 0 [Note] Shutting down plugin 'MEMORY'
2017-03-23T05:27:23.737675Z 0 [Note] Shutting down plugin 'MyISAM'
2017-03-23T05:27:23.737690Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-03-23T05:27:23.737880Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2017-03-23T05:27:23.737890Z 0 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2017-03-23T05:27:23.737893Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-03-23T05:27:23.737895Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-03-23T05:27:23.737897Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-03-23T05:27:23.737900Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-03-23T05:27:23.737902Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-03-23T05:27:23.737904Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-03-23T05:27:23.737906Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-03-23T05:27:23.737909Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-03-23T05:27:23.737911Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-03-23T05:27:23.737913Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-03-23T05:27:23.737915Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-03-23T05:27:23.737929Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-03-23T05:27:23.737930Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-03-23T05:27:23.737932Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-03-23T05:27:23.737934Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-03-23T05:27:23.737936Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2017-03-23T05:27:23.737938Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2017-03-23T05:27:23.737940Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-03-23T05:27:23.737943Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-03-23T05:27:23.737945Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-03-23T05:27:23.737947Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-03-23T05:27:23.737949Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-03-23T05:27:23.737951Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-03-23T05:27:23.737953Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-03-23T05:27:23.737955Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-03-23T05:27:23.737957Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2017-03-23T05:27:23.737959Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-03-23T05:27:23.737961Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-03-23T05:27:23.737963Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2017-03-23T05:27:23.737966Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS'
2017-03-23T05:27:23.737968Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT'
2017-03-23T05:27:23.737970Z 0 [Note] Shutting down plugin 'XTRADB_RSEG'
2017-03-23T05:27:23.737972Z 0 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES'
2017-03-23T05:27:23.737974Z 0 [Note] Shutting down plugin 'XTRADB_READ_VIEW'
2017-03-23T05:27:23.737977Z 0 [Note] Shutting down plugin 'InnoDB'
2017-03-23T05:27:23.738103Z 0 [Note] InnoDB: FTS optimize thread exiting.
2017-03-23T05:27:23.738259Z 0 [Note] InnoDB: Starting shutdown...
2017-03-23T05:27:24.847357Z 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-03-23T05:27:25.962864Z 0 [Note] InnoDB: Shutdown completed; log sequence number 2513128
2017-03-23T05:27:25.962970Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-03-23T05:27:25.962985Z 0 [Note] Shutting down plugin 'sha256_password'
2017-03-23T05:27:25.962988Z 0 [Note] Shutting down plugin 'mysql_native_password'
2017-03-23T05:27:25.962991Z 0 [Note] Shutting down plugin 'wsrep'
2017-03-23T05:27:25.963215Z 0 [Note] Shutting down plugin 'binlog'
2017-03-23T05:27:25.964829Z 0 [Note] /usr/sbin/mysqld: Shutdown complete
2017-03-23T05:27:26.265887Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-03-23T05:27:26.267661Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.17-11-57-log) starting as process 10567 ...
2017-03-23T05:27:26.270442Z 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
2017-03-23T05:27:26.270467Z 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera3/libgalera_smm.so'
2017-03-23T05:27:26.283283Z 0 [Note] WSREP: wsrep_load(): Galera 3.20(r7e383f7) by Codership Oy <email address hidden> loaded successfully.
2017-03-23T05:27:26.283562Z 0 [Note] WSREP: CRC-32C: using hardware acceleration.
2017-03-23T05:27:26.284628Z 0 [Note] WSREP: Found saved state: 0eb421f9-0f69-11e7-9e0d-c219fa284372:-1, safe_to_bootsrap: 0
2017-03-23T05:27:26.286566Z 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.25.136; 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_count = 0; 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; 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; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.recovery = 1; pc.version = 0; pc.wait_prim = true; pc.wait_prim_timeout = PT30S; pc.weight = 1; protonet.backend = asio; protonet.version = 0; repl.causal_read_timeout = PT30S; repl.commit_order = 3; repl.key_format = FLAT8; repl.max_ws_size = 2147483647; repl.proto_max = 7; socket.checksum = 2; socket.recv_buf_size = 212992;
2017-03-23T05:27:26.336792Z 0 [Note] WSREP: GCache history reset: old(0eb421f9-0f69-11e7-9e0d-c219fa284372:0) -> new(0eb421f9-0f69-11e7-9e0d-c219fa284372:16)
2017-03-23T05:27:26.338207Z 0 [Note] WSREP: Assign initial position for certification: 16, protocol version: -1
2017-03-23T05:27:26.338253Z 0 [Note] WSREP: wsrep_sst_grab()
2017-03-23T05:27:26.338259Z 0 [Note] WSREP: Start replication
2017-03-23T05:27:26.338278Z 0 [Note] WSREP: Setting initial position to 0eb421f9-0f69-11e7-9e0d-c219fa284372:16
2017-03-23T05:27:26.338451Z 0 [Note] WSREP: protonet asio version 0
2017-03-23T05:27:26.338789Z 0 [Note] WSREP: Using CRC-32C for message checksums.
2017-03-23T05:27:26.338879Z 0 [Note] WSREP: backend: asio
2017-03-23T05:27:26.338974Z 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
2017-03-23T05:27:26.339605Z 0 [Note] WSREP: restore pc from disk successfully
2017-03-23T05:27:26.340835Z 0 [Note] WSREP: GMCast version 0
2017-03-23T05:27:26.341781Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2017-03-23T05:27:26.341873Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2017-03-23T05:27:26.342620Z 0 [Note] WSREP: EVS version 0
2017-03-23T05:27:26.342887Z 0 [Note] WSREP: gcomm: connecting to group 'PXC-Cluster', peer '192.168.25.130:,192.168.25.131:,192.168.25.132:,192.168.25.136:'
2017-03-23T05:27:26.348551Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to fd51f1fd tcp://192.168.25.136:4567
2017-03-23T05:27:26.348666Z 0 [Warning] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') address 'tcp://192.168.25.136:4567' points to own listening address, blacklisting
2017-03-23T05:27:26.369984Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to c2b0fd4b tcp://192.168.25.131:4567
2017-03-23T05:27:26.371635Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2017-03-23T05:27:26.399967Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to 249e477d tcp://192.168.25.132:4567
2017-03-23T05:27:26.411759Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection established to a82719fe tcp://192.168.25.130:4567
2017-03-23T05:27:26.853772Z 0 [Note] WSREP: declaring 249e477d at tcp://192.168.25.132:4567 stable
2017-03-23T05:27:26.854136Z 0 [Note] WSREP: declaring a82719fe at tcp://192.168.25.130:4567 stable
2017-03-23T05:27:26.854652Z 0 [Note] WSREP: declaring c2b0fd4b at tcp://192.168.25.131:4567 stable
2017-03-23T05:27:26.859706Z 0 [Note] WSREP: Node 249e477d state prim
2017-03-23T05:27:26.879487Z 0 [Note] WSREP: view(view_id(PRIM,249e477d,20) memb {
249e477d,0
a82719fe,0
c2b0fd4b,0
fd51f1fd,0
} joined {
} left {
} partitioned {
})
2017-03-23T05:27:26.879739Z 0 [Note] WSREP: save pc into disk
2017-03-23T05:27:26.883238Z 0 [Note] WSREP: clear restored view
2017-03-23T05:27:27.348509Z 0 [Note] WSREP: gcomm: connected
2017-03-23T05:27:27.348592Z 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2017-03-23T05:27:27.348648Z 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2017-03-23T05:27:27.348653Z 0 [Note] WSREP: Opened channel 'PXC-Cluster'
2017-03-23T05:27:27.348817Z 0 [Note] WSREP: Waiting for SST to complete.
2017-03-23T05:27:27.348883Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 3, memb_num = 4
2017-03-23T05:27:27.348900Z 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2017-03-23T05:27:27.349129Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3b9b9a16-0f89-11e7-af66-3f38cf00ddfc
2017-03-23T05:27:27.349154Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3b9b9a16-0f89-11e7-af66-3f38cf00ddfc from 0 (PXC3)
2017-03-23T05:27:27.349165Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3b9b9a16-0f89-11e7-af66-3f38cf00ddfc from 2 (PXC2)
2017-03-23T05:27:27.349186Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3b9b9a16-0f89-11e7-af66-3f38cf00ddfc from 1 (PXC1)
2017-03-23T05:27:27.354133Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3b9b9a16-0f89-11e7-af66-3f38cf00ddfc from 3 (PXC4)
2017-03-23T05:27:27.354206Z 0 [Note] WSREP: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 19,
members = 4/4 (joined/total),
act_id = 16,
last_appl. = -1,
protocols = 0/7/3 (gcs/repl/appl),
group UUID = 0eb421f9-0f69-11e7-9e0d-c219fa284372
2017-03-23T05:27:27.354230Z 0 [Note] WSREP: Flow-control interval: [32, 32]
2017-03-23T05:27:27.354245Z 0 [Note] WSREP: Restored state OPEN -> JOINED (16)
2017-03-23T05:27:27.354393Z 2 [Note] WSREP: New cluster view: global state: 0eb421f9-0f69-11e7-9e0d-c219fa284372:16, view# 20: Primary, number of nodes: 4, my index: 3, protocol version 3
2017-03-23T05:27:27.354431Z 0 [Note] WSREP: SST complete, seqno: 16
2017-03-23T05:27:27.361410Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-03-23T05:27:27.361499Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-03-23T05:27:27.361512Z 0 [Note] InnoDB: Uses event mutexes
2017-03-23T05:27:27.361519Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-03-23T05:27:27.361525Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2017-03-23T05:27:27.361536Z 0 [Note] InnoDB: Using Linux native AIO
2017-03-23T05:27:27.364210Z 0 [Note] InnoDB: Number of pools: 1
2017-03-23T05:27:27.364778Z 0 [Note] InnoDB: Using CPU crc32 instructions
2017-03-23T05:27:27.379766Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-03-23T05:27:27.390096Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-03-23T05:27:27.396192Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-03-23T05:27:27.432141Z 0 [Note] WSREP: Member 3.0 (PXC4) synced with group.
2017-03-23T05:27:27.432229Z 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 16)
2017-03-23T05:27:27.452722Z 0 [Note] InnoDB: Crash recovery did not find the parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite
2017-03-23T05:27:27.460690Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-23T05:27:27.499300Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite, size 3932160 bytes
2017-03-23T05:27:27.588198Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-03-23T05:27:27.588332Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-03-23T05:27:27.626579Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-03-23T05:27:27.628123Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2017-03-23T05:27:27.628209Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2017-03-23T05:27:27.630292Z 0 [Note] InnoDB: Waiting for purge to start
2017-03-23T05:27:27.681839Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.17-11 started; log sequence number 2513128
2017-03-23T05:27:27.683181Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2017-03-23T05:27:27.683364Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-03-23T05:27:27.716319Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2017-03-23T05:27:27.716386Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory.
2017-03-23T05:27:27.738148Z 0 [Warning] CA certificate ca.pem is self signed.
2017-03-23T05:27:27.738406Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory.
2017-03-23T05:27:27.738753Z 0 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
2017-03-23T05:27:27.738795Z 0 [Note] - '0.0.0.0' resolves to '0.0.0.0';
2017-03-23T05:27:27.738845Z 0 [Note] Server socket created on IP: '0.0.0.0'.
2017-03-23T05:27:27.781040Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.781140Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.781257Z 0 [Warning] 'user' entry 'sstuser@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.781327Z 0 [Warning] 'user' entry 'bkpuser@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.781385Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.781410Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.783616Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
2017-03-23T05:27:27.785509Z 0 [Note] InnoDB: Buffer pool(s) load completed at 170323 14:27:27
2017-03-23T05:27:27.802435Z 0 [Note] Event Scheduler: Loaded 0 events
2017-03-23T05:27:27.802808Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-03-23T05:27:27.802825Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-03-23T05:27:27.832886Z 2 [Note] WSREP: Initialized wsrep sidno 2
2017-03-23T05:27:27.832955Z 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-03-23T05:27:27.832997Z 2 [Note] WSREP: REPL Protocols: 7 (3, 2)
2017-03-23T05:27:27.833012Z 2 [Note] WSREP: Assign initial position for certification: 16, protocol version: 3
2017-03-23T05:27:27.833048Z 0 [Note] WSREP: Service thread queue flushed.
2017-03-23T05:27:27.833101Z 2 [Note] WSREP: Synchronized with group, ready for connections
2017-03-23T05:27:27.833106Z 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2017-03-23T05:27:27.873225Z 0 [Note] End of list of non-natively partitioned tables
2017-03-23T05:27:27.873702Z 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '5.7.17-11-57-log' socket: '/var/lib/mysql/mysql.sock' port: 3306 Percona XtraDB Cluster (GPL), Release rel11, Revision e2a7fdd, WSREP version 27.20, wsrep_27.20
2017-03-23T05:27:29.352064Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') connection to peer fd51f1fd with addr tcp://192.168.25.136:4567 timed out, no messages seen in PT3S
2017-03-23T05:27:29.852412Z 0 [Note] WSREP: (fd51f1fd, 'tcp://0.0.0.0:4567') turning message relay requesting off
Could be related to PS bug - https:/