2019-08-05T08:34:25.228093Z 0 [Note] WSREP: Received shutdown signal. Will sleep for 10 secs before initiating shutdown. pxc_maint_mode switched to SHUTDOWN 2019-08-05T08:34:35.229402Z 0 [Note] WSREP: Stop replication 2019-08-05T08:34:35.229444Z 0 [Note] WSREP: Closing send monitor... 2019-08-05T08:34:35.229449Z 0 [Note] WSREP: Closed send monitor. 2019-08-05T08:34:35.229594Z 0 [Note] WSREP: gcomm: terminating thread 2019-08-05T08:34:35.229605Z 0 [Note] WSREP: gcomm: joining thread 2019-08-05T08:34:35.230433Z 0 [Note] WSREP: gcomm: closing backend 2019-08-05T08:34:35.231185Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,56901470,411) memb { e1547183,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T08:34:35.231211Z 0 [Note] WSREP: Current view of cluster as seen by this node view ((empty)) 2019-08-05T08:34:35.231377Z 0 [Note] WSREP: gcomm: closed 2019-08-05T08:34:35.231424Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T08:34:35.231472Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T08:34:35.231488Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T08:34:35.231490Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T08:34:35.231492Z 0 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 31365461664) 2019-08-05T08:34:35.231501Z 0 [Note] WSREP: Received self-leave message. 2019-08-05T08:34:35.231701Z 0 [Note] WSREP: Flow-control interval: [0, 0] 2019-08-05T08:34:35.231726Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T08:34:35.231726Z 4 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31365461664, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3 2019-08-05T08:34:35.231731Z 0 [Note] WSREP: Received SELF-LEAVE. Closing connection. 2019-08-05T08:34:35.231748Z 4 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T08:34:35.231750Z 0 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 31365461664) 2019-08-05T08:34:35.231770Z 0 [Note] WSREP: RECV thread exiting 0: Success 2019-08-05T08:34:35.232201Z 0 [Note] WSREP: recv_thread() joined. 2019-08-05T08:34:35.232207Z 0 [Note] WSREP: Closing replication queue. 2019-08-05T08:34:35.232210Z 0 [Note] WSREP: Closing slave action queue. 2019-08-05T08:34:35.232364Z 0 [Note] WSREP: Waiting for active wsrep applier to exit 2019-08-05T08:34:35.250805Z 4 [ERROR] WSREP: Process completed with error: /srv/bin/galeranotify.py --status Undefined --uuid 7f4a4aab-e3df-11e6-9919-63561272760b --primary no --index 0 --members e1547183-9beb-11e9-967d-9eac5448bc40/jon/176.9.210.66:3306: 1 (Operation not permitted) 2019-08-05T08:34:35.250828Z 4 [ERROR] WSREP: Notification command failed: 1 (Operation not permitted): "/srv/bin/galeranotify.py --status Undefined --uuid 7f4a4aab-e3df-11e6-9919-63561272760b --primary no --index 0 --members e1547183-9beb-11e9-967d-9eac5448bc40/jon/176.9.210.66:3306" 2019-08-05T08:34:35.250842Z 4 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31365461664, view# -1: non-Primary, number of nodes: 0, my index: -1, protocol version 3 2019-08-05T08:34:35.250845Z 4 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T08:34:35.269799Z 4 [ERROR] WSREP: Process completed with error: /srv/bin/galeranotify.py --status Undefined --uuid 7f4a4aab-e3df-11e6-9919-63561272760b --primary no --index -1: 1 (Operation not permitted) 2019-08-05T08:34:35.269817Z 4 [ERROR] WSREP: Notification command failed: 1 (Operation not permitted): "/srv/bin/galeranotify.py --status Undefined --uuid 7f4a4aab-e3df-11e6-9919-63561272760b --primary no --index -1" 2019-08-05T08:34:35.312352Z 4 [Note] WSREP: applier thread exiting (code:0) 2019-08-05T08:34:35.312955Z 3 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.312960Z 9 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.312975Z 7 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.312975Z 10 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.312976Z 6 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.312976Z 1 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.312960Z 5 [Note] WSREP: applier thread exiting (code:6) 2019-08-05T08:34:35.313358Z 2 [Note] WSREP: rollbacker thread exiting 2019-08-05T08:34:35.314164Z 0 [Note] Giving 0 client threads a chance to die gracefully 2019-08-05T08:34:35.314178Z 0 [Note] Shutting down slave threads 2019-08-05T08:34:35.314317Z 0 [Note] Forcefully disconnecting 0 remaining clients 2019-08-05T08:34:35.314471Z 0 [Note] Event Scheduler: Purging the queue. 0 events 2019-08-05T08:34:35.328125Z 0 [Note] WSREP: Service thread queue flushed. 2019-08-05T08:34:35.333940Z 0 [Note] WSREP: MemPool(SlaveTrxHandle): hit ratio: 0.975565, misses: 367527, in use: 0, in pool: 2048 2019-08-05T08:34:35.334560Z 0 [Note] WSREP: Shifting CLOSED -> DESTROYED (TO: 31365461664) 2019-08-05T08:34:35.437004Z 0 [Note] Binlog end 2019-08-05T08:34:35.517941Z 0 [Note] Shutting down plugin 'ngram' 2019-08-05T08:34:35.517956Z 0 [Note] Shutting down plugin 'partition' 2019-08-05T08:34:35.517958Z 0 [Note] Shutting down plugin 'BLACKHOLE' 2019-08-05T08:34:35.519427Z 0 [Note] Shutting down plugin 'ARCHIVE' 2019-08-05T08:34:35.519431Z 0 [Note] Shutting down plugin 'MRG_MYISAM' 2019-08-05T08:34:35.521709Z 0 [Note] Shutting down plugin 'MyISAM' 2019-08-05T08:34:35.523888Z 0 [Note] Shutting down plugin 'INNODB_TABLESPACES_SCRUBBING' 2019-08-05T08:34:35.526811Z 0 [Note] Shutting down plugin 'INNODB_TABLESPACES_ENCRYPTION' 2019-08-05T08:34:35.528881Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL' 2019-08-05T08:34:35.528901Z 0 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES' 2019-08-05T08:34:35.528903Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES' 2019-08-05T08:34:35.528905Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES' 2019-08-05T08:34:35.528921Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS' 2019-08-05T08:34:35.528922Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN' 2019-08-05T08:34:35.528924Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS' 2019-08-05T08:34:35.528926Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS' 2019-08-05T08:34:35.528927Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES' 2019-08-05T08:34:35.528944Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS' 2019-08-05T08:34:35.528946Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES' 2019-08-05T08:34:35.528947Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE' 2019-08-05T08:34:35.528949Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE' 2019-08-05T08:34:35.528951Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG' 2019-08-05T08:34:35.528953Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED' 2019-08-05T08:34:35.528954Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED' 2019-08-05T08:34:35.528956Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD' 2019-08-05T08:34:35.528958Z 0 [Note] Shutting down plugin 'INNODB_METRICS' 2019-08-05T08:34:35.528959Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO' 2019-08-05T08:34:35.528961Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS' 2019-08-05T08:34:35.528963Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU' 2019-08-05T08:34:35.528964Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE' 2019-08-05T08:34:35.528966Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET' 2019-08-05T08:34:35.528968Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX' 2019-08-05T08:34:35.528970Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET' 2019-08-05T08:34:35.528971Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM' 2019-08-05T08:34:35.528973Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET' 2019-08-05T08:34:35.528974Z 0 [Note] Shutting down plugin 'INNODB_CMP' 2019-08-05T08:34:35.528976Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS' 2019-08-05T08:34:35.528978Z 0 [Note] Shutting down plugin 'INNODB_LOCKS' 2019-08-05T08:34:35.528980Z 0 [Note] Shutting down plugin 'INNODB_TRX' 2019-08-05T08:34:35.528996Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS' 2019-08-05T08:34:35.529002Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT' 2019-08-05T08:34:35.529003Z 0 [Note] Shutting down plugin 'XTRADB_RSEG' 2019-08-05T08:34:35.529005Z 0 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES' 2019-08-05T08:34:35.529007Z 0 [Note] Shutting down plugin 'XTRADB_READ_VIEW' 2019-08-05T08:34:35.529008Z 0 [Note] Shutting down plugin 'InnoDB' 2019-08-05T08:34:35.580835Z 0 [Note] InnoDB: FTS optimize thread exiting. 2019-08-05T08:34:35.599364Z 0 [Note] InnoDB: Starting shutdown... 2019-08-05T08:34:35.703314Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool 2019-08-05T08:34:35.847006Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 190805 10:34:35 2019-08-05T08:34:36.000081Z 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool 2019-08-05T08:35:12.693302Z 0 [Note] InnoDB: Shutdown completed; log sequence number 45417092985891 2019-08-05T08:35:12.694794Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2019-08-05T08:35:12.694832Z 0 [Note] Shutting down plugin 'MEMORY' 2019-08-05T08:35:12.694836Z 0 [Note] Shutting down plugin 'CSV' 2019-08-05T08:35:12.694839Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA' 2019-08-05T08:35:12.694854Z 0 [Note] Shutting down plugin 'sha256_password' 2019-08-05T08:35:12.694857Z 0 [Note] Shutting down plugin 'mysql_native_password' 2019-08-05T08:35:12.694859Z 0 [Note] Shutting down plugin 'wsrep' 2019-08-05T08:35:12.694961Z 0 [Note] Shutting down plugin 'binlog' 2019-08-05T08:35:12.717326Z 0 [Note] /usr/sbin/mysqld: Shutdown complete 2019-08-05T08:36:10.171857Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.26-29-57-log) starting as process 2144 ... 2019-08-05T08:36:10.177407Z 0 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T08:36:10.177428Z 0 [Note] WSREP: No pre-stored wsrep-start position found. Skipping position initialization. 2019-08-05T08:36:10.177433Z 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/libgalera_smm.so' 2019-08-05T08:36:10.183427Z 0 [Note] WSREP: wsrep_load(): Galera 3.37(rff05089) by Codership Oy loaded successfully. 2019-08-05T08:36:10.183469Z 0 [Note] WSREP: CRC-32C: using hardware acceleration. 2019-08-05T08:36:10.184010Z 0 [Note] WSREP: Found saved state: 7f4a4aab-e3df-11e6-9919-63561272760b:31365461664, safe_to_bootstrap: 0 2019-08-05T08:36:10.192952Z 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 176.9.210.66; base_port = 4567; cert.log_conflicts = no; cert.optimistic_pa = yes; 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 = 10; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 4; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.freeze_purge_at_seqno = -1; 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 = 1024M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1; gcs.fc_limit = 100; 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 = true; 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 = 9; socket.checksum = 2; socket.recv_buf_size = 212992; 2019-08-05T08:36:10.200971Z 0 [Note] WSREP: GCache history reset: 7f4a4aab-e3df-11e6-9919-63561272760b:0 -> 7f4a4aab-e3df-11e6-9919-63561272760b:31365461664 2019-08-05T08:36:10.203158Z 0 [Note] WSREP: Assign initial position for certification: 31365461664, protocol version: -1 2019-08-05T08:36:10.203173Z 0 [Note] WSREP: Preparing to initiate SST/IST 2019-08-05T08:36:10.203176Z 0 [Note] WSREP: Starting replication 2019-08-05T08:36:10.203182Z 0 [Note] WSREP: Setting initial position to 7f4a4aab-e3df-11e6-9919-63561272760b:31365461664 2019-08-05T08:36:10.203534Z 0 [Note] WSREP: Using CRC-32C for message checksums. 2019-08-05T08:36:10.203589Z 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 2019-08-05T08:36:10.203966Z 0 [Warning] WSREP: Fail to access the file (/var/lib/mysql//gvwstate.dat) error (No such file or directory). It is possible if node is booting for first time or re-booting after a graceful shutdown 2019-08-05T08:36:10.203971Z 0 [Note] WSREP: Restoring primary-component from disk failed. Either node is booting for first time or re-booting after a graceful shutdown 2019-08-05T08:36:10.204084Z 0 [Note] WSREP: GMCast version 0 2019-08-05T08:36:10.204188Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567 2019-08-05T08:36:10.204192Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') multicast: , ttl: 1 2019-08-05T08:36:10.204349Z 0 [Note] WSREP: EVS version 0 2019-08-05T08:36:10.204392Z 0 [Note] WSREP: gcomm: connecting to group 'trabber-cluster', peer '176.9.25.20:,176.9.63.4:,176.9.210.66:' 2019-08-05T08:36:10.205034Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 1369194f tcp://176.9.210.66:4567 2019-08-05T08:36:10.205044Z 0 [Warning] WSREP: (1369194f, 'tcp://0.0.0.0:4567') address 'tcp://176.9.210.66:4567' points to own listening address, blacklisting 2019-08-05T08:36:10.205879Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 577e118a tcp://176.9.63.4:4567 2019-08-05T08:36:10.205931Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 56901470 tcp://176.9.25.20:4567 2019-08-05T08:36:10.206067Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 2019-08-05T08:36:10.234885Z 0 [Note] WSREP: declaring 56901470 at tcp://176.9.25.20:4567 stable 2019-08-05T08:36:10.234900Z 0 [Note] WSREP: declaring 577e118a at tcp://176.9.63.4:4567 stable 2019-08-05T08:36:10.235182Z 0 [Note] WSREP: Node 56901470 state primary 2019-08-05T08:36:10.235514Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(PRIM,1369194f,413) memb { 1369194f,0 56901470,0 577e118a,0 } joined { } left { } partitioned { } ) 2019-08-05T08:36:10.235522Z 0 [Note] WSREP: Save the discovered primary-component to disk 2019-08-05T08:36:10.705032Z 0 [Note] WSREP: gcomm: connected 2019-08-05T08:36:10.705127Z 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2019-08-05T08:36:10.705175Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3 2019-08-05T08:36:10.705202Z 0 [Note] WSREP: Waiting for SST/IST to complete. 2019-08-05T08:36:10.705276Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 13b59363-b75c-11e9-bf44-8e321dd9ba9c 2019-08-05T08:36:10.705282Z 0 [Warning] WSREP: Action message in non-primary configuration from member 1 2019-08-05T08:36:10.706045Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 13b59363-b75c-11e9-bf44-8e321dd9ba9c 2019-08-05T08:36:10.706437Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 13b59363-b75c-11e9-bf44-8e321dd9ba9c from 0 (jon) 2019-08-05T08:36:10.706448Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 13b59363-b75c-11e9-bf44-8e321dd9ba9c from 1 (sam) 2019-08-05T08:36:10.706452Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 13b59363-b75c-11e9-bf44-8e321dd9ba9c from 2 (garb) 2019-08-05T08:36:10.706456Z 0 [Note] WSREP: Quorum results: version = 4, component = PRIMARY, conf_id = 346, members = 2/3 (primary/total), act_id = 31365490947, last_appl. = -1, protocols = 0/9/3 (gcs/repl/appl), group UUID = 7f4a4aab-e3df-11e6-9919-63561272760b 2019-08-05T08:36:10.706460Z 0 [Note] WSREP: Flow-control interval: [141, 141] 2019-08-05T08:36:10.706462Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T08:36:10.706465Z 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 31365490947) 2019-08-05T08:36:10.706554Z 2 [Note] WSREP: State transfer required: Group state: 7f4a4aab-e3df-11e6-9919-63561272760b:31365490947 Local state: 7f4a4aab-e3df-11e6-9919-63561272760b:31365461664 2019-08-05T08:36:10.706568Z 2 [Note] WSREP: REPL Protocols: 9 (4, 2) 2019-08-05T08:36:10.706574Z 2 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31365490947, view# 347: Primary, number of nodes: 3, my index: 0, protocol version 3 2019-08-05T08:36:10.706578Z 2 [Note] WSREP: Setting wsrep_ready to true 2019-08-05T08:36:10.706581Z 2 [Warning] WSREP: Gap in state sequence. Need state transfer. 2019-08-05T08:36:10.706583Z 2 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T08:36:10.706656Z 0 [Note] WSREP: Initiating SST/IST transfer on JOINER side (wsrep_sst_xtrabackup-v2 --role 'joiner' --address '176.9.210.66' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' --parent '2144' --mysqld-version '5.7.26-29-57' '' ) 2019-08-05T08:36:11.154356Z 2 [Note] WSREP: Prepared SST/IST request: xtrabackup-v2|176.9.210.66:4444/xtrabackup_sst//1 2019-08-05T08:36:11.154387Z 2 [Note] WSREP: Auto Increment Offset/Increment re-align with cluster membership change (Offset: 1 -> 1) (Increment: 1 -> 3) 2019-08-05T08:36:11.325245Z 2 [Note] WSREP: Assign initial position for certification: 31365490947, protocol version: 4 2019-08-05T08:36:11.325330Z 0 [Note] WSREP: Service thread queue flushed. 2019-08-05T08:36:11.325350Z 2 [Note] WSREP: Check if state gap can be serviced using IST 2019-08-05T08:36:11.325460Z 2 [Note] WSREP: IST receiver addr using tcp://176.9.210.66:4568 2019-08-05T08:36:11.325536Z 2 [Note] WSREP: Prepared IST receiver, listening at: tcp://176.9.210.66:4568 2019-08-05T08:36:11.325546Z 2 [Note] WSREP: State gap can be likely serviced using IST. SST request though present would be void. 2019-08-05T08:36:11.334145Z 0 [Note] WSREP: may fallback to sst. ist_seqno [31365461664] < safe_ist_seqno [31365490876] 2019-08-05T08:36:11.334158Z 0 [Note] WSREP: Member 0.0 (jon) requested state transfer from '*any*'. Selected 1.0 (sam)(SYNCED) as donor. 2019-08-05T08:36:11.334161Z 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 31365491085) 2019-08-05T08:36:11.334221Z 2 [Note] WSREP: Requesting state transfer: success, donor: 1 2019-08-05T08:36:11.334232Z 2 [Note] WSREP: GCache history reset: 7f4a4aab-e3df-11e6-9919-63561272760b:0 -> 7f4a4aab-e3df-11e6-9919-63561272760b:31365490947 2019-08-05T08:36:11.716303Z WSREP_SST: [INFO] Proceeding with SST......... 2019-08-05T08:36:12.030375Z WSREP_SST: [INFO] ............Waiting for SST streaming to complete! 2019-08-05T08:36:13.705648Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting off 2019-08-05T09:32:01.601752Z 0 [Note] WSREP: Created page /var/lib/mysql/gcache.page.000000 of size 134217728 bytes 2019-08-05T09:35:24.105366Z 0 [Note] WSREP: 1.0 (sam): State transfer to 0.0 (jon) complete. 2019-08-05T09:35:24.105875Z 0 [Note] WSREP: Member 1.0 (sam) synced with group. 2019-08-05T09:35:24.127586Z WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql//.sst 2019-08-05T09:37:53.272787Z 0 [Warning] WSREP: last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT25.5009S), skipping check 2019-08-05T09:37:53.772981Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://176.9.63.4:4567 2019-08-05T09:37:54.773170Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') reconnecting to 577e118a (tcp://176.9.63.4:4567), attempt 0 2019-08-05T09:37:54.774702Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 577e118a tcp://176.9.63.4:4567 2019-08-05T09:37:54.914036Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 56901470 tcp://176.9.25.20:4567 2019-08-05T09:37:58.273789Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting off 2019-08-05T09:37:58.273822Z 0 [Note] WSREP: declaring node with index 1 suspected, timeout PT5S (evs.suspect_timeout) 2019-08-05T09:37:58.273826Z 0 [Note] WSREP: declaring node with index 2 suspected, timeout PT5S (evs.suspect_timeout) 2019-08-05T09:37:58.273831Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,413)) suspecting node: 56901470 2019-08-05T09:37:58.273835Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,413)) suspected node without join message, declaring inactive 2019-08-05T09:37:58.273839Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,413)) suspecting node: 577e118a 2019-08-05T09:37:58.273842Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,413)) suspected node without join message, declaring inactive 2019-08-05T09:37:58.773892Z 0 [Note] WSREP: declaring node with index 1 inactive (evs.inactive_timeout) 2019-08-05T09:37:58.773911Z 0 [Note] WSREP: declaring node with index 2 inactive (evs.inactive_timeout) 2019-08-05T09:37:59.274148Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,413) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:37:59.274240Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T09:37:59.274254Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T09:37:59.274257Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:37:59.274259Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T09:37:59.274261Z 0 [Note] WSREP: Shifting JOINER -> OPEN (TO: 31366301505) 2019-08-05T09:37:59.274261Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,414) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:37:59.274278Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T09:37:59.274281Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T09:37:59.274283Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:37:59.274285Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T09:37:59.275850Z 0 [Note] WSREP: declaring 56901470 at tcp://176.9.25.20:4567 stable 2019-08-05T09:37:59.275868Z 0 [Note] WSREP: declaring 577e118a at tcp://176.9.63.4:4567 stable 2019-08-05T09:37:59.276141Z 0 [Note] WSREP: Node 56901470 state primary 2019-08-05T09:37:59.276522Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(PRIM,1369194f,415) memb { 1369194f,0 56901470,0 577e118a,0 } joined { } left { } partitioned { } ) 2019-08-05T09:37:59.276530Z 0 [Note] WSREP: Save the discovered primary-component to disk 2019-08-05T09:38:03.325331Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection to peer 56901470 with addr tcp://176.9.25.20:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout) 2019-08-05T09:38:03.325344Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3 2019-08-05T09:38:03.325415Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection to peer 577e118a with addr tcp://176.9.63.4:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout) 2019-08-05T09:38:03.325432Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://176.9.25.20:4567 tcp://176.9.63.4:4567 2019-08-05T09:38:03.325470Z 0 [Warning] WSREP: last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT4.55159S), skipping check 2019-08-05T09:38:03.325509Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: b89a74b0-b764-11e9-bf3a-db5191f12f71 2019-08-05T09:38:03.391903Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 577e118a tcp://176.9.63.4:4567 2019-08-05T09:38:03.393031Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 56901470 tcp://176.9.25.20:4567 2019-08-05T09:38:04.277357Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: b89a74b0-b764-11e9-bf3a-db5191f12f71 2019-08-05T09:38:04.277797Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: b89a74b0-b764-11e9-bf3a-db5191f12f71 from 0 (jon) 2019-08-05T09:38:04.277806Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: b89a74b0-b764-11e9-bf3a-db5191f12f71 from 1 (sam) 2019-08-05T09:38:04.277997Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: b89a74b0-b764-11e9-bf3a-db5191f12f71 from 2 (garb) 2019-08-05T09:38:04.278006Z 0 [Note] WSREP: Quorum results: version = 4, component = PRIMARY, conf_id = 348, members = 2/3 (primary/total), act_id = 31366307450, last_appl. = 31366301440, protocols = 0/9/3 (gcs/repl/appl), group UUID = 7f4a4aab-e3df-11e6-9919-63561272760b 2019-08-05T09:38:04.278011Z 0 [Note] WSREP: Flow-control interval: [141, 141] 2019-08-05T09:38:04.278014Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:38:04.278022Z 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 31366307450) 2019-08-05T09:38:06.825801Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting off 2019-08-05T09:38:31.415971Z 0 [Warning] WSREP: last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT11.5882S), skipping check 2019-08-05T09:38:31.916114Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://176.9.63.4:4567 2019-08-05T09:38:32.434424Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') reconnecting to 577e118a (tcp://176.9.63.4:4567), attempt 0 2019-08-05T09:38:32.435943Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 577e118a tcp://176.9.63.4:4567 2019-08-05T09:38:32.569481Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 56901470 tcp://176.9.25.20:4567 2019-08-05T09:38:35.935522Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting off 2019-08-05T09:38:36.435565Z 0 [Note] WSREP: declaring node with index 1 suspected, timeout PT5S (evs.suspect_timeout) 2019-08-05T09:38:36.435583Z 0 [Note] WSREP: declaring node with index 2 suspected, timeout PT5S (evs.suspect_timeout) 2019-08-05T09:38:36.435589Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,415)) suspecting node: 56901470 2019-08-05T09:38:36.435593Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,415)) suspected node without join message, declaring inactive 2019-08-05T09:38:36.435597Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,415)) suspecting node: 577e118a 2019-08-05T09:38:36.435600Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,415)) suspected node without join message, declaring inactive 2019-08-05T09:38:36.935665Z 0 [Note] WSREP: declaring node with index 1 inactive (evs.inactive_timeout) 2019-08-05T09:38:36.935685Z 0 [Note] WSREP: declaring node with index 2 inactive (evs.inactive_timeout) 2019-08-05T09:38:37.435752Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,415) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:38:37.435833Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T09:38:37.435846Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T09:38:37.435863Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:38:37.435865Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T09:38:37.435868Z 0 [Note] WSREP: Shifting PRIMARY -> OPEN (TO: 31366313194) 2019-08-05T09:38:37.435876Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,416) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:38:37.435929Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T09:38:37.435938Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T09:38:37.435941Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:38:37.435943Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T09:38:37.437179Z 0 [Note] WSREP: declaring 56901470 at tcp://176.9.25.20:4567 stable 2019-08-05T09:38:37.437193Z 0 [Note] WSREP: declaring 577e118a at tcp://176.9.63.4:4567 stable 2019-08-05T09:38:37.437450Z 0 [Note] WSREP: Node 56901470 state primary 2019-08-05T09:38:37.437843Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(PRIM,1369194f,417) memb { 1369194f,0 56901470,0 577e118a,0 } joined { } left { } partitioned { } ) 2019-08-05T09:38:37.437854Z 0 [Note] WSREP: Save the discovered primary-component to disk 2019-08-05T09:38:47.491128Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection to peer 56901470 with addr tcp://176.9.25.20:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout) 2019-08-05T09:38:47.491139Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3 2019-08-05T09:38:47.491222Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection to peer 577e118a with addr tcp://176.9.63.4:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout) 2019-08-05T09:38:47.491252Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://176.9.25.20:4567 tcp://176.9.63.4:4567 2019-08-05T09:38:47.491329Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: d2ed9f44-b764-11e9-9999-c7811fd7cb62 2019-08-05T09:38:47.491422Z 0 [Warning] WSREP: last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT10.5558S), skipping check 2019-08-05T09:38:47.991633Z 0 [Note] WSREP: declaring node with index 1 suspected, timeout PT5S (evs.suspect_timeout) 2019-08-05T09:38:47.991651Z 0 [Note] WSREP: declaring node with index 2 suspected, timeout PT5S (evs.suspect_timeout) 2019-08-05T09:38:47.991657Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,417)) suspecting node: 56901470 2019-08-05T09:38:47.991661Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,417)) suspected node without join message, declaring inactive 2019-08-05T09:38:47.991669Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,417)) suspecting node: 577e118a 2019-08-05T09:38:47.991672Z 0 [Note] WSREP: evs::proto(1369194f, OPERATIONAL, view_id(REG,1369194f,417)) suspected node without join message, declaring inactive 2019-08-05T09:38:48.491716Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') reconnecting to 56901470 (tcp://176.9.25.20:4567), attempt 0 2019-08-05T09:38:48.491828Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') reconnecting to 577e118a (tcp://176.9.63.4:4567), attempt 0 2019-08-05T09:38:48.491903Z 0 [Note] WSREP: declaring node with index 1 inactive (evs.inactive_timeout) 2019-08-05T09:38:48.491908Z 0 [Note] WSREP: declaring node with index 2 inactive (evs.inactive_timeout) 2019-08-05T09:38:48.991936Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,417) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:38:48.992002Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,418) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:38:48.992013Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T09:38:48.992025Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T09:38:48.992028Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:38:48.992030Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T09:38:48.992048Z 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2019-08-05T09:38:48.992051Z 0 [Note] WSREP: Flow-control interval: [100, 100] 2019-08-05T09:38:48.992053Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:38:48.992055Z 0 [Note] WSREP: Received NON-PRIMARY. 2019-08-05T09:38:51.492499Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection to peer 56901470 with addr tcp://176.9.25.20:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout) 2019-08-05T09:38:51.992510Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection to peer 577e118a with addr tcp://176.9.63.4:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout) 2019-08-05T09:38:52.493684Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 56901470 tcp://176.9.25.20:4567 2019-08-05T09:38:52.662906Z 0 [Note] WSREP: declaring 56901470 at tcp://176.9.25.20:4567 stable 2019-08-05T09:38:52.662946Z 0 [Note] WSREP: declaring 577e118a at tcp://176.9.63.4:4567 stable 2019-08-05T09:38:52.663731Z 0 [Note] WSREP: Node 56901470 state primary 2019-08-05T09:38:52.664449Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(PRIM,1369194f,419) memb { 1369194f,0 56901470,0 577e118a,0 } joined { } left { } partitioned { } ) 2019-08-05T09:38:52.664458Z 0 [Note] WSREP: Save the discovered primary-component to disk 2019-08-05T09:38:52.705872Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3 2019-08-05T09:38:52.705938Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: d60953bb-b764-11e9-8038-2a49847999b7 2019-08-05T09:38:52.800608Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: d60953bb-b764-11e9-8038-2a49847999b7 2019-08-05T09:38:52.800640Z 0 [Warning] WSREP: Action message in non-primary configuration from member 1 2019-08-05T09:38:52.801347Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d60953bb-b764-11e9-8038-2a49847999b7 from 0 (jon) 2019-08-05T09:38:52.801465Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d60953bb-b764-11e9-8038-2a49847999b7 from 1 (sam) 2019-08-05T09:38:52.801474Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: d60953bb-b764-11e9-8038-2a49847999b7 from 2 (garb) 2019-08-05T09:38:52.801478Z 0 [Note] WSREP: Quorum results: version = 4, component = PRIMARY, conf_id = 351, members = 2/3 (primary/total), act_id = 31366320102, last_appl. = 31366313088, protocols = 0/9/3 (gcs/repl/appl), group UUID = 7f4a4aab-e3df-11e6-9919-63561272760b 2019-08-05T09:38:52.801482Z 0 [Note] WSREP: Flow-control interval: [141, 141] 2019-08-05T09:38:52.801485Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:38:52.801487Z 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 31366320102) 2019-08-05T09:38:52.902271Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') connection established to 577e118a tcp://176.9.63.4:4567 2019-08-05T09:38:52.947976Z WSREP_SST: [INFO] Moving the backup to /var/lib/mysql/ 2019-08-05T09:38:53.153181Z WSREP_SST: [INFO] Galera co-ords from recovery: 7f4a4aab-e3df-11e6-9919-63561272760b:31366274350 2019-08-05T09:38:53.160365Z 0 [Note] WSREP: SST complete, seqno: 31366274350 2019-08-05T09:38:53.214447Z 0 [Note] InnoDB: PUNCH HOLE support available 2019-08-05T09:38:53.214469Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2019-08-05T09:38:53.214472Z 0 [Note] InnoDB: Uses event mutexes 2019-08-05T09:38:53.214474Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2019-08-05T09:38:53.214476Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2019-08-05T09:38:53.214478Z 0 [Note] InnoDB: Using Linux native AIO 2019-08-05T09:38:53.215306Z 0 [Note] InnoDB: Number of pools: 1 2019-08-05T09:38:53.216974Z 0 [Note] InnoDB: Using CPU crc32 instructions 2019-08-05T09:38:53.222213Z 0 [Note] InnoDB: Initializing buffer pool, total size = 45G, instances = 8, chunk size = 128M 2019-08-05T09:38:54.204931Z 0 [Note] InnoDB: Completed initialization of buffer pool 2019-08-05T09:38:54.542822Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2019-08-05T09:38:54.555654Z 0 [Note] InnoDB: Crash recovery did not find the parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite 2019-08-05T09:38:54.556191Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 2019-08-05T09:38:54.920808Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite, size 31457280 bytes 2019-08-05T09:38:55.486060Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2019-08-05T09:38:55.486071Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2019-08-05T09:38:55.486095Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2019-08-05T09:38:55.535376Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2019-08-05T09:38:55.535819Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 2019-08-05T09:38:55.535824Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 2019-08-05T09:38:55.536565Z 0 [Note] InnoDB: Waiting for purge to start 2019-08-05T09:38:55.587182Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.26-29 started; log sequence number 45436538388008 2019-08-05T09:38:55.587303Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool 2019-08-05T09:38:55.587850Z 0 [Note] Plugin 'FEDERATED' is disabled. 2019-08-05T09:38:55.612743Z 0 [Note] Salting uuid generator variables, current_pid: 2144, server_start_time: 1564994170, bytes_sent: 0, 2019-08-05T09:38:55.613092Z 0 [Note] Generated uuid: 'd7c4ee5e-b764-11e9-ac54-901b0ec18c46', server_start_time: 603482351632642778, bytes_sent: 94704374400608 2019-08-05T09:38:55.613106Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: d7c4ee5e-b764-11e9-ac54-901b0ec18c46. 2019-08-05T09:38:55.623978Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them. 2019-08-05T09:38:55.623987Z 0 [Note] Skipping generation of SSL certificates as certificate files are present in data directory. 2019-08-05T09:38:55.624647Z 0 [Warning] CA certificate ca.pem is self signed. 2019-08-05T09:38:55.624664Z 0 [Note] Skipping generation of RSA key pair as key files are present in data directory. 2019-08-05T09:38:55.624853Z 0 [Note] Server hostname (bind-address): '176.9.210.66'; port: 3306 2019-08-05T09:38:55.624859Z 0 [Note] - '176.9.210.66' resolves to '176.9.210.66'; 2019-08-05T09:38:55.624869Z 0 [Note] Server socket created on IP: '176.9.210.66'. 2019-08-05T09:38:55.626482Z 0 [Warning] 'user' entry 'root@jon' ignored in --skip-name-resolve mode. 2019-08-05T09:38:55.631249Z 0 [Note] Failed to start slave threads for channel '' 2019-08-05T09:38:55.634696Z 0 [Note] Event Scheduler: Loaded 0 events 2019-08-05T09:38:55.634767Z 0 [Note] WSREP: Signalling provider to continue on SST completion. 2019-08-05T09:38:55.634778Z 0 [Note] WSREP: Initialized wsrep sidno 2 2019-08-05T09:38:55.634791Z 0 [Note] WSREP: SST received: 7f4a4aab-e3df-11e6-9919-63561272760b:31366274350 2019-08-05T09:38:55.635621Z 0 [Note] /usr/sbin/mysqld: ready for connections. Version: '5.7.26-29-57-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Percona XtraDB Cluster (GPL), Release rel29, Revision 03540a3, WSREP version 31.37, wsrep_31.37 2019-08-05T09:38:55.649706Z 0 [Warning] WSREP: Rejecting JOIN message from 0.0 (jon): new State Transfer required. 2019-08-05T09:38:55.992956Z 0 [Note] WSREP: (1369194f, 'tcp://0.0.0.0:4567') turning message relay requesting off 2019-08-05T09:39:05.050214Z 2 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366301505, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3 2019-08-05T09:39:05.050226Z 2 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T09:39:05.162502Z 2 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366301505, view# -1: non-Primary, number of nodes: 1, my index: 0, protocol version 3 2019-08-05T09:39:05.162516Z 2 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T09:39:05.239374Z 2 [Note] WSREP: State transfer required: Group state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366307450 Local state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366301505 2019-08-05T09:39:05.239388Z 2 [Note] WSREP: REPL Protocols: 9 (4, 2) 2019-08-05T09:39:05.239392Z 2 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366307450, view# 349: Primary, number of nodes: 3, my index: 0, protocol version 3 2019-08-05T09:39:05.239395Z 2 [Note] WSREP: Setting wsrep_ready to true 2019-08-05T09:39:05.239398Z 2 [Warning] WSREP: Gap in state sequence. Need state transfer. 2019-08-05T09:39:05.239400Z 2 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T09:39:05.239403Z 2 [Note] WSREP: You have configured 'xtrabackup-v2' state snapshot transfer method which cannot be performed on a running server. Wsrep provider won't be able to fall back to it if other means of state transfer are unavailable. In that case you will need to restart the server. 2019-08-05T09:39:05.239406Z 2 [Note] WSREP: Auto Increment Offset/Increment re-align with cluster membership change (Offset: 1 -> 1) (Increment: 3 -> 3) 2019-08-05T09:39:05.314265Z 2 [Note] WSREP: Assign initial position for certification: 31366307450, protocol version: 4 2019-08-05T09:39:05.314348Z 0 [Note] WSREP: Service thread queue flushed. 2019-08-05T09:39:05.314424Z 2 [Note] WSREP: Check if state gap can be serviced using IST 2019-08-05T09:39:05.314486Z 2 [Note] WSREP: IST receiver addr using tcp://176.9.210.66:4568 2019-08-05T09:39:05.314560Z 2 [Note] WSREP: Prepared IST receiver, listening at: tcp://176.9.210.66:4568 2019-08-05T09:39:05.314569Z 2 [Note] WSREP: State gap can be likely serviced using IST. SST request though present would be void. 2019-08-05T09:39:05.315080Z 0 [Note] WSREP: may fallback to sst. ist_seqno [31366301505] < safe_ist_seqno [31366320000] 2019-08-05T09:39:05.315103Z 0 [Note] WSREP: Member 0.0 (jon) requested state transfer from '*any*'. Selected 1.0 (sam)(SYNCED) as donor. 2019-08-05T09:39:05.315107Z 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 31366322297) 2019-08-05T09:39:05.315165Z 2 [Note] WSREP: Requesting state transfer: success, donor: 1 2019-08-05T09:39:05.315176Z 2 [Note] WSREP: GCache history reset: 7f4a4aab-e3df-11e6-9919-63561272760b:31366301505 -> 7f4a4aab-e3df-11e6-9919-63561272760b:31366307450 2019-08-05T09:39:05.324006Z 2 [Note] WSREP: Receiving IST: 5945 writesets, seqnos 31366301505-31366307450 2019-08-05T09:39:05.324009Z 0 [Warning] WSREP: 1.0 (sam): State transfer to 0.0 (jon) failed: -61 (No data available) 2019-08-05T09:39:05.324028Z 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():762: State transfer request failed unrecoverably because the donor seqno had gone forward during IST, but SST request was not prepared from our side due to selected state transfer method (which do not supports SST during node operation). Restart required. 2019-08-05T09:39:05.324033Z 0 [Note] WSREP: gcomm: terminating thread 2019-08-05T09:39:05.324052Z 0 [Note] WSREP: gcomm: joining thread 2019-08-05T09:39:05.324141Z 0 [Note] WSREP: gcomm: closing backend 2019-08-05T09:39:05.324553Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(NON_PRIM,1369194f,419) memb { 1369194f,0 } joined { } left { } partitioned { 56901470,0 577e118a,0 } ) 2019-08-05T09:39:05.324572Z 0 [Note] WSREP: Current view of cluster as seen by this node view ((empty)) 2019-08-05T09:39:05.324661Z 0 [Note] WSREP: gcomm: closed 2019-08-05T09:39:05.324671Z 0 [Note] WSREP: /usr/sbin/mysqld: Terminated. Log of wsrep recovery (--wsrep-recover): 2019-08-05T09:39:20.707652Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.26-29-57-log) starting as process 4118 ... 2019-08-05T09:39:20.739087Z 0 [Note] InnoDB: PUNCH HOLE support available 2019-08-05T09:39:20.739107Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2019-08-05T09:39:20.739109Z 0 [Note] InnoDB: Uses event mutexes 2019-08-05T09:39:20.739112Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2019-08-05T09:39:20.739114Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2019-08-05T09:39:20.739116Z 0 [Note] InnoDB: Using Linux native AIO 2019-08-05T09:39:20.739509Z 0 [Note] InnoDB: Number of pools: 1 2019-08-05T09:39:20.739571Z 0 [Note] InnoDB: Using CPU crc32 instructions 2019-08-05T09:39:20.763408Z 0 [Note] InnoDB: Initializing buffer pool, total size = 45G, instances = 8, chunk size = 128M 2019-08-05T09:39:21.680432Z 0 [Note] InnoDB: Completed initialization of buffer pool 2019-08-05T09:39:22.004402Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2019-08-05T09:39:22.016531Z 0 [Note] InnoDB: Recovering partial pages from the parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite 2019-08-05T09:39:22.035054Z 0 [Note] InnoDB: Highest supported file format is Barracuda. 2019-08-05T09:39:22.272442Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 45436538388027 2019-08-05T09:39:22.342637Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436543630848 2019-08-05T09:39:22.375348Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436548873728 2019-08-05T09:39:22.418697Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436554116608 2019-08-05T09:39:22.450165Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436559359488 2019-08-05T09:39:22.492204Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436564602368 2019-08-05T09:39:22.527871Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436569845248 2019-08-05T09:39:22.556157Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436575088128 2019-08-05T09:39:22.589797Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436580331008 2019-08-05T09:39:22.654562Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 45436585106312 2019-08-05T09:39:22.657353Z 0 [Note] InnoDB: Database was not shutdown normally! 2019-08-05T09:39:22.657357Z 0 [Note] InnoDB: Starting crash recovery. 2019-08-05T09:39:27.240833Z 0 [Note] InnoDB: Created parallel doublewrite buffer at /var/lib/mysql/xb_doublewrite, size 31457280 bytes 2019-08-05T09:39:27.568745Z 0 [Note] InnoDB: Transaction 41261828727 was in the XA prepared state. 2019-08-05T09:39:27.575336Z 0 [Note] InnoDB: Transaction 41261828729 was in the XA prepared state. 2019-08-05T09:39:27.575346Z 0 [Note] InnoDB: Transaction 41261828730 was in the XA prepared state. 2019-08-05T09:39:27.575350Z 0 [Note] InnoDB: Transaction 41261828731 was in the XA prepared state. 2019-08-05T09:39:27.575354Z 0 [Note] InnoDB: Transaction 41261828732 was in the XA prepared state. 2019-08-05T09:39:27.575525Z 0 [Note] InnoDB: Transaction 41261828733 was in the XA prepared state. 2019-08-05T09:39:27.575544Z 0 [Note] InnoDB: Transaction 41261828734 was in the XA prepared state. 2019-08-05T09:39:27.575551Z 0 [Note] InnoDB: 8 transaction(s) which must be rolled back or cleaned up in total 6163 row operations to undo 2019-08-05T09:39:27.575553Z 0 [Note] InnoDB: Trx id counter is 41261829120 2019-08-05T09:39:27.577530Z 0 [Note] InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percent: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 2019-08-05T09:39:29.860177Z 0 [Note] InnoDB: Apply batch completed 2019-08-05T09:39:29.860210Z 0 [Note] InnoDB: Last MySQL binlog file position 0 34989326, file name binlog.000001 2019-08-05T09:39:30.238014Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2019-08-05T09:39:30.238026Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2019-08-05T09:39:30.238027Z 0 [Note] InnoDB: Starting in background the rollback of uncommitted transactions 2019-08-05T09:39:30.238044Z 0 [Note] InnoDB: Rolling back trx with id 41261828728, 6163 rows to undo 2019-08-05T09:39:30.238049Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... InnoDB: Progress in percents: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 372019-08-05T09:39:31.245446Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2019-08-05T09:39:31.246054Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active. 2019-08-05T09:39:31.246066Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active. 2019-08-05T09:39:31.246185Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop took 9242ms. The settings might not be optimal. (flushed=0, during the time.) 2019-08-05T09:39:31.246847Z 0 [Note] InnoDB: Waiting for purge to start 38 39 40 412019-08-05T09:39:31.297009Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.26-29 started; log sequence number 45436585106312 2019-08-05T09:39:31.297044Z 0 [Warning] InnoDB: Skipping buffer pool dump/restore during wsrep recovery. 2019-08-05T09:39:31.297336Z 0 [Note] Plugin 'FEDERATED' is disabled. 422019-08-05T09:39:31.304615Z 0 [Note] Recovering after a crash using binlog 2019-08-05T09:39:31.304629Z 0 [Note] WSREP: Before binlog recovery (wsrep position 7f4a4aab-e3df-11e6-9919-63561272760b:31366297918) 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 692019-08-05T09:39:31.366882Z 0 [Note] Starting crash recovery... 2019-08-05T09:39:31.366899Z 0 [Note] InnoDB: Starting recovery for XA transactions... 2019-08-05T09:39:31.366903Z 0 [Note] InnoDB: Transaction 41261828734 in prepared state after recovery 2019-08-05T09:39:31.366906Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366908Z 0 [Note] InnoDB: Transaction 41261828733 in prepared state after recovery 2019-08-05T09:39:31.366910Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366913Z 0 [Note] InnoDB: Transaction 41261828732 in prepared state after recovery 2019-08-05T09:39:31.366915Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366917Z 0 [Note] InnoDB: Transaction 41261828731 in prepared state after recovery 2019-08-05T09:39:31.366919Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366922Z 0 [Note] InnoDB: Transaction 41261828730 in prepared state after recovery 2019-08-05T09:39:31.366924Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366926Z 0 [Note] InnoDB: Transaction 41261828729 in prepared state after recovery 2019-08-05T09:39:31.366928Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366930Z 0 [Note] InnoDB: Transaction 41261828727 in prepared state after recovery 2019-08-05T09:39:31.366932Z 0 [Note] InnoDB: Transaction contains changes to 1 rows 2019-08-05T09:39:31.366934Z 0 [Note] InnoDB: 7 transactions in prepared state after recovery 2019-08-05T09:39:31.366936Z 0 [Note] Found 7 prepared transaction(s) in InnoDB 2019-08-05T09:39:31.366974Z 0 [Note] Crash recovery finished. 2019-08-05T09:39:31.366984Z 0 [Note] WSREP: After binlog recovery (wsrep position 7f4a4aab-e3df-11e6-9919-63561272760b:31366297926) 2019-08-05T09:39:31.367124Z 0 [Note] WSREP: Recovered position: 7f4a4aab-e3df-11e6-9919-63561272760b:31366297926 2019-08-05T09:39:31.367132Z 0 [Note] Binlog end 2019-08-05T09:39:31.367178Z 0 [Note] Shutting down plugin 'ngram' 2019-08-05T09:39:31.367181Z 0 [Note] Shutting down plugin 'partition' 2019-08-05T09:39:31.367183Z 0 [Note] Shutting down plugin 'BLACKHOLE' 2019-08-05T09:39:31.367190Z 0 [Note] Shutting down plugin 'ARCHIVE' 2019-08-05T09:39:31.367191Z 0 [Note] Shutting down plugin 'MRG_MYISAM' 2019-08-05T09:39:31.367193Z 0 [Note] Shutting down plugin 'MyISAM' 2019-08-05T09:39:31.367199Z 0 [Note] Shutting down plugin 'INNODB_TABLESPACES_SCRUBBING' 2019-08-05T09:39:31.367201Z 0 [Note] Shutting down plugin 'INNODB_TABLESPACES_ENCRYPTION' 2019-08-05T09:39:31.367202Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL' 2019-08-05T09:39:31.367204Z 0 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES' 2019-08-05T09:39:31.367206Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES' 2019-08-05T09:39:31.367207Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES' 2019-08-05T09:39:31.367209Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS' 2019-08-05T09:39:31.367210Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN' 2019-08-05T09:39:31.367212Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS' 2019-08-05T09:39:31.367214Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS' 2019-08-05T09:39:31.367215Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES' 2019-08-05T09:39:31.367217Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS' 2019-08-05T09:39:31.367218Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES' 2019-08-05T09:39:31.367220Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE' 2019-08-05T09:39:31.367221Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE' 2019-08-05T09:39:31.367223Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG' 2019-08-05T09:39:31.367224Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED' 2019-08-05T09:39:31.367226Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED' 2019-08-05T09:39:31.367228Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD' 2019-08-05T09:39:31.367229Z 0 [Note] Shutting down plugin 'INNODB_METRICS' 2019-08-05T09:39:31.367231Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO' 2019-08-05T09:39:31.367232Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS' 2019-08-05T09:39:31.367234Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU' 2019-08-05T09:39:31.367236Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE' 2019-08-05T09:39:31.367237Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET' 2019-08-05T09:39:31.367239Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX' 2019-08-05T09:39:31.367240Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET' 2019-08-05T09:39:31.367242Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM' 2019-08-05T09:39:31.367244Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET' 2019-08-05T09:39:31.367245Z 0 [Note] Shutting down plugin 'INNODB_CMP' 2019-08-05T09:39:31.367247Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS' 2019-08-05T09:39:31.367248Z 0 [Note] Shutting down plugin 'INNODB_LOCKS' 2019-08-05T09:39:31.367250Z 0 [Note] Shutting down plugin 'INNODB_TRX' 2019-08-05T09:39:31.367251Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS' 2019-08-05T09:39:31.367254Z 0 [Note] Shutting down plugin 'XTRADB_ZIP_DICT' 2019-08-05T09:39:31.367255Z 0 [Note] Shutting down plugin 'XTRADB_RSEG' 2019-08-05T09:39:31.367257Z 0 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES' 2019-08-05T09:39:31.367258Z 0 [Note] Shutting down plugin 'XTRADB_READ_VIEW' 2019-08-05T09:39:31.367260Z 0 [Note] Shutting down plugin 'InnoDB' 70 71 722019-08-05T09:39:31.378690Z 0 [Note] InnoDB: FTS optimize thread exiting. 2019-08-05T09:39:31.378773Z 0 [Note] InnoDB: Starting shutdown... 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 1002019-08-05T09:39:31.500671Z 0 [Note] InnoDB: Rollback of trx with id 41261828728 completed 2019-08-05T09:39:31.500695Z 0 [Note] InnoDB: Rollback of non-prepared transactions completed 2019-08-05T09:39:32.279733Z 0 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool 2019-08-05T09:40:03.835540Z 0 [Note] InnoDB: Shutdown completed; log sequence number 45436587415640 2019-08-05T09:40:03.835588Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2019-08-05T09:40:03.835594Z 0 [Note] Shutting down plugin 'MEMORY' 2019-08-05T09:40:03.835603Z 0 [Note] Shutting down plugin 'CSV' 2019-08-05T09:40:03.835605Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA' 2019-08-05T09:40:03.835631Z 0 [Note] Shutting down plugin 'sha256_password' 2019-08-05T09:40:03.835634Z 0 [Note] Shutting down plugin 'mysql_native_password' 2019-08-05T09:40:03.835635Z 0 [Note] Shutting down plugin 'wsrep' 2019-08-05T09:40:03.835738Z 0 [Note] Shutting down plugin 'binlog' 2019-08-05T09:40:03.840774Z 0 [Note] /usr/sbin/mysqld: Shutdown complete 2019-08-05T09:40:04.076934Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.26-29-57-log) starting as process 4473 ... 2019-08-05T09:40:04.078322Z 0 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T09:40:04.078330Z 0 [Note] WSREP: No pre-stored wsrep-start position found. Skipping position initialization. 2019-08-05T09:40:04.078332Z 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/libgalera_smm.so' 2019-08-05T09:40:04.079789Z 0 [Note] WSREP: wsrep_load(): Galera 3.37(rff05089) by Codership Oy loaded successfully. 2019-08-05T09:40:04.079815Z 0 [Note] WSREP: CRC-32C: using hardware acceleration. 2019-08-05T09:40:04.079984Z 0 [Note] WSREP: Found saved state: 7f4a4aab-e3df-11e6-9919-63561272760b:-1, safe_to_bootstrap: 0 2019-08-05T09:40:04.114688Z 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 176.9.210.66; base_port = 4567; cert.log_conflicts = no; cert.optimistic_pa = yes; 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 = 10; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 4; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.freeze_purge_at_seqno = -1; 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 = 1024M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1; gcs.fc_limit = 100; 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 = true; 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 = 9; socket.checksum = 2; socket.recv_buf_size = 212992; 2019-08-05T09:40:04.131571Z 0 [Note] WSREP: GCache history reset: 7f4a4aab-e3df-11e6-9919-63561272760b:0 -> 7f4a4aab-e3df-11e6-9919-63561272760b:31366297926 2019-08-05T09:40:04.134116Z 0 [Note] WSREP: Assign initial position for certification: 31366297926, protocol version: -1 2019-08-05T09:40:04.134130Z 0 [Note] WSREP: Preparing to initiate SST/IST 2019-08-05T09:40:04.134133Z 0 [Note] WSREP: Starting replication 2019-08-05T09:40:04.134139Z 0 [Note] WSREP: Setting initial position to 7f4a4aab-e3df-11e6-9919-63561272760b:31366297926 2019-08-05T09:40:04.134259Z 0 [Note] WSREP: Using CRC-32C for message checksums. 2019-08-05T09:40:04.134306Z 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 2019-08-05T09:40:04.134382Z 0 [Warning] WSREP: Fail to access the file (/var/lib/mysql//gvwstate.dat) error (No such file or directory). It is possible if node is booting for first time or re-booting after a graceful shutdown 2019-08-05T09:40:04.134387Z 0 [Note] WSREP: Restoring primary-component from disk failed. Either node is booting for first time or re-booting after a graceful shutdown 2019-08-05T09:40:04.134490Z 0 [Note] WSREP: GMCast version 0 2019-08-05T09:40:04.134594Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567 2019-08-05T09:40:04.134599Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') multicast: , ttl: 1 2019-08-05T09:40:04.134757Z 0 [Note] WSREP: EVS version 0 2019-08-05T09:40:04.134798Z 0 [Note] WSREP: gcomm: connecting to group 'trabber-cluster', peer '176.9.25.20:,176.9.63.4:,176.9.210.66:' 2019-08-05T09:40:04.135302Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') connection established to 009c73e7 tcp://176.9.210.66:4567 2019-08-05T09:40:04.135311Z 0 [Warning] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') address 'tcp://176.9.210.66:4567' points to own listening address, blacklisting 2019-08-05T09:40:04.135894Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') connection established to 56901470 tcp://176.9.25.20:4567 2019-08-05T09:40:04.136000Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 2019-08-05T09:40:04.136050Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') connection established to 577e118a tcp://176.9.63.4:4567 2019-08-05T09:40:04.137309Z 0 [Note] WSREP: declaring 56901470 at tcp://176.9.25.20:4567 stable 2019-08-05T09:40:04.137319Z 0 [Note] WSREP: declaring 577e118a at tcp://176.9.63.4:4567 stable 2019-08-05T09:40:04.137575Z 0 [Note] WSREP: Node 56901470 state primary 2019-08-05T09:40:04.137929Z 0 [Note] WSREP: Current view of cluster as seen by this node view (view_id(PRIM,009c73e7,421) memb { 009c73e7,0 56901470,0 577e118a,0 } joined { } left { } partitioned { } ) 2019-08-05T09:40:04.137938Z 0 [Note] WSREP: Save the discovered primary-component to disk 2019-08-05T09:40:04.635086Z 0 [Note] WSREP: gcomm: connected 2019-08-05T09:40:04.635165Z 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2019-08-05T09:40:04.635202Z 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3 2019-08-05T09:40:04.635252Z 0 [Note] WSREP: Waiting for SST/IST to complete. 2019-08-05T09:40:04.635306Z 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 00e8df48-b765-11e9-a7f0-a29142645d9e 2019-08-05T09:40:04.635311Z 0 [Warning] WSREP: Last Applied Action message in non-primary configuration from member 1 2019-08-05T09:40:04.635445Z 0 [Warning] WSREP: Action message in non-primary configuration from member 1 2019-08-05T09:40:04.635837Z 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 00e8df48-b765-11e9-a7f0-a29142645d9e 2019-08-05T09:40:04.636178Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 00e8df48-b765-11e9-a7f0-a29142645d9e from 0 (jon) 2019-08-05T09:40:04.636186Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 00e8df48-b765-11e9-a7f0-a29142645d9e from 1 (sam) 2019-08-05T09:40:04.636190Z 0 [Note] WSREP: STATE EXCHANGE: got state msg: 00e8df48-b765-11e9-a7f0-a29142645d9e from 2 (garb) 2019-08-05T09:40:04.636194Z 0 [Note] WSREP: Quorum results: version = 4, component = PRIMARY, conf_id = 353, members = 2/3 (primary/total), act_id = 31366348012, last_appl. = -1, protocols = 0/9/3 (gcs/repl/appl), group UUID = 7f4a4aab-e3df-11e6-9919-63561272760b 2019-08-05T09:40:04.636197Z 0 [Note] WSREP: Flow-control interval: [141, 141] 2019-08-05T09:40:04.636199Z 0 [Note] WSREP: Trying to continue unpaused monitor 2019-08-05T09:40:04.636202Z 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 31366348012) 2019-08-05T09:40:04.636242Z 1 [Note] WSREP: State transfer required: Group state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366348012 Local state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366297926 2019-08-05T09:40:04.636267Z 1 [Note] WSREP: REPL Protocols: 9 (4, 2) 2019-08-05T09:40:04.636273Z 1 [Note] WSREP: New cluster view: global state: 7f4a4aab-e3df-11e6-9919-63561272760b:31366348012, view# 354: Primary, number of nodes: 3, my index: 0, protocol version 3 2019-08-05T09:40:04.636277Z 1 [Note] WSREP: Setting wsrep_ready to true 2019-08-05T09:40:04.636280Z 1 [Warning] WSREP: Gap in state sequence. Need state transfer. 2019-08-05T09:40:04.636282Z 1 [Note] WSREP: Setting wsrep_ready to false 2019-08-05T09:40:04.636351Z 0 [Note] WSREP: Initiating SST/IST transfer on JOINER side (wsrep_sst_xtrabackup-v2 --role 'joiner' --address '176.9.210.66' --datadir '/var/lib/mysql/' --defaults-file '/etc/mysql/my.cnf' --defaults-group-suffix '' --parent '4473' --mysqld-version '5.7.26-29-57' '' ) 2019-08-05T09:40:05.080931Z 1 [Note] WSREP: Prepared SST/IST request: xtrabackup-v2|176.9.210.66:4444/xtrabackup_sst//1 2019-08-05T09:40:05.080943Z 1 [Note] WSREP: Auto Increment Offset/Increment re-align with cluster membership change (Offset: 1 -> 1) (Increment: 1 -> 3) 2019-08-05T09:40:05.189330Z 1 [Note] WSREP: Assign initial position for certification: 31366348012, protocol version: 4 2019-08-05T09:40:05.189411Z 0 [Note] WSREP: Service thread queue flushed. 2019-08-05T09:40:05.189475Z 1 [Note] WSREP: Check if state gap can be serviced using IST 2019-08-05T09:40:05.189557Z 1 [Note] WSREP: IST receiver addr using tcp://176.9.210.66:4568 2019-08-05T09:40:05.189641Z 1 [Note] WSREP: Prepared IST receiver, listening at: tcp://176.9.210.66:4568 2019-08-05T09:40:05.189649Z 1 [Note] WSREP: State gap can be likely serviced using IST. SST request though present would be void. 2019-08-05T09:40:05.195798Z 0 [Note] WSREP: may fallback to sst. ist_seqno [31366297926] < safe_ist_seqno [31366347885] 2019-08-05T09:40:05.195806Z 0 [Note] WSREP: Member 0.0 (jon) requested state transfer from '*any*'. Selected 1.0 (sam)(SYNCED) as donor. 2019-08-05T09:40:05.195809Z 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 31366348609) 2019-08-05T09:40:05.195867Z 1 [Note] WSREP: Requesting state transfer: success, donor: 1 2019-08-05T09:40:05.195879Z 1 [Note] WSREP: GCache history reset: 7f4a4aab-e3df-11e6-9919-63561272760b:0 -> 7f4a4aab-e3df-11e6-9919-63561272760b:31366348012 2019-08-05T09:40:05.566183Z WSREP_SST: [INFO] Proceeding with SST......... 2019-08-05T09:40:06.484030Z WSREP_SST: [INFO] ............Waiting for SST streaming to complete! 2019-08-05T09:40:07.635403Z 0 [Note] WSREP: (009c73e7, 'tcp://0.0.0.0:4567') turning message relay requesting off