the second node boot time 2
| ++ hostname -f
| + NODE_NAME=fb7e1fdcb1e5
| + NODE_PORT=3306
| Registering in the discovery service
| + '[' -n '' ']'
| + '[' -n etcdnode:2379 ']'
| + echo 'Registering in the discovery service'
| ++ hostname -I
| ++ awk ' { print $1 } '
| + NODE_IP=10.180.0.190
| + '[' etcd '!=' http ']'
| + DISCOVERY_SERVICE=http://etcdnode:2379
| + curl http://etcdnode:2379/v2/keys/pxc-cluster/queue/mysql_cluster01 -XPOST -d value=10.180.0.190 -d ttl=60
| % Total % Received % Xferd Average Speed Time Time Time Current
| Dload Upload Total Spent Left Speed
| {"action":"create","node":{"key":"/pxc-cluster/queue/mysql_cluster01/00000000000000000153","value":"10.180.0.190","expiration":"2023-06-03T09:57:18.870876689Z","ttl":60,"modifiedIndex":153,"createdIndex":153}}
100 235 100 210 100 25 52500 6250 --:--:-- --:--:-- --:--:-- 58750
| ++ curl http://etcdnode:2379/v2/keys/pxc-cluster/queue/mysql_cluster01
| ++ jq -r '.node.nodes[].value'
| % Total % Received % Xferd Average Speed Time Time Time Current
| Dload Upload Total Spent Left Speed
100 490 100 490 0 0 159k 0 --:--:-- --:--:-- --:--:-- 239k
| + i='10.180.0.189
| 10.180.0.190'
| + i1='10.180.0.189
| '
| + curl http://etcdnode:2379/v2/keys/pxc-cluster/mysql_cluster01/10.180.0.190/ipaddr -XPUT -d value=10.180.0.190 -d ttl=30
| % Total % Received % Xferd Average Speed Time Time Time Current
| Dload Upload Total Spent Left Speed
100 225 100 200 100 25 66666 8333 --:--:-- --:--:-- --:--:-- 75000
| {"action":"set","node":{"key":"/pxc-cluster/mysql_cluster01/10.180.0.190/ipaddr","value":"10.180.0.190","expiration":"2023-06-03T09:56:48.900739854Z","ttl":30,"modifiedIndex":154,"createdIndex":154}}
| + curl http://etcdnode:2379/v2/keys/pxc-cluster/mysql_cluster01/10.180.0.190/hostname -XPUT -d value=fb7e1fdcb1e5 -d ttl=30
| % Total % Received % Xferd Average Speed Time Time Time Current
| Dload Upload Total Spent Left Speed
| {"action":"set","node":{"key":"/pxc-cluster/mysql_cluster01/10.180.0.190/hostname","value":"fb7e1fdcb1e5","expiration":"2023-06-03T09:56:48.915279874Z","ttl":30,"modifiedIndex":155,"createdIndex":155}}
100 227 100 202 100 25 67333 8333 --:--:-- --:--:-- --:--:-- 75666
| + curl http://etcdnode:2379/v2/keys/pxc-cluster/mysql_cluster01/10.180.0.190 -XPUT -d ttl=30 -d dir=true -d prevExist=true
| % Total % Received % Xferd Average Speed Time Time Time Current
| Dload Upload Total Spent Left Speed
100 327 100 297 100 30 99000 10000 --:--:-- --:--:-- --:--:-- 106k
| {"action":"update","node":{"key":"/pxc-cluster/mysql_cluster01/10.180.0.190","dir":true,"expiration":"2023-06-03T09:56:48.929061194Z","ttl":30,"modifiedIndex":156,"createdIndex":154},"prevNode":{"key":"/pxc-cluster/mysql_cluster01/10.180.0.190","dir":true,"modifiedIndex":154,"createdIndex":154}}
| ++ curl 'http://etcdnode:2379/v2/keys/pxc-cluster/mysql_cluster01/?quorum=true'
| ++ jq -r '.node.nodes[]?.key'
| ++ awk -F/ '{print $(NF)}'
| % Total % Received % Xferd Average Speed Time Time Time Current
| Dload Upload Total Spent Left Speed
100 429 100 429 0 0 104k 0 --:--:-- --:--:-- --:--:-- 139k
| + i='10.180.0.181
| 10.180.0.190'
| + i2='10.180.0.181
| '
| ++ join , 10.180.0.189 10.180.0.181
| ++ local IFS=,
| ++ shift
| +++ tr , '\n'
| +++ tr '\n' ,
| +++ sort -u
| ++ joined=10.180.0.181,10.180.0.189,
| ++ echo 10.180.0.181,10.180.0.189
| + CLUSTER_JOIN=10.180.0.181,10.180.0.189
| + sed -r 's|^[#]?wsrep_node_address=.*$|wsrep_node_address=10.180.0.190|' /etc/mysql/node.cnf
| + sed -r 's|^[#]?wsrep_cluster_name=.*$|wsrep_cluster_name=mysql_cluster01|' /etc/mysql/node.cnf
| + sed -r 's|^[#]?wsrep_cluster_address=.*$|wsrep_cluster_address=gcomm://10.180.0.181,10.180.0.189|' /etc/mysql/node.cnf
| + sed -r 's|^[#]?wsrep_node_incoming_address=.*$|wsrep_node_incoming_address=fb7e1fdcb1e5:3306|' /etc/mysql/node.cnf
| + sed -r 's|^[#]?wsrep_sst_auth=.*$|wsrep_sst_auth='\''xtrabackup:xtrabackup'\''|' /etc/mysql/node.cnf
| + /usr/bin/clustercheckcron clustercheck clustercheck 1 /var/lib/mysql/clustercheck.log 1
| + '[' -z 10.180.0.181,10.180.0.189 ']'
| + '[' mysqld = mysqld -a -z '' ']'
| + mysqld --version
| + tee /tmp/version_info
| mysqld Ver 5.7.41-44-57 for Linux on x86_64 (Percona XtraDB Cluster (GPL), Release rel44, Revision b46a1c3, WSREP version 31.65, wsrep_31.65)
| ++ _get_config datadir mysqld
| ++ local conf=datadir
| ++ shift
| +++ mktemp -u
| ++ awk '$1 == "datadir" && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
| ++ mysqld --verbose --help --wsrep-provider=none --log-bin-index=/tmp/tmp.KjD73FQdMa
| + DATADIR=/var/lib/mysql/
| + '[' -f /var/lib/mysql//version_info ']'
| + mysqld --version
| + grep -v wsrep_sst_auth /etc/mysql/node.cnf
| [mysqld]
|
| ignore-db-dir=lost+found
| datadir=/var/lib/mysql
| socket=/tmp/mysql.sock
| skip-host-cache
|
| #coredumper
| #server_id=0
| binlog_format=ROW
| default_storage_engine=InnoDB
|
| innodb_flush_log_at_trx_commit = 0
| innodb_flush_method = O_DIRECT
| innodb_file_per_table = 1
| innodb_autoinc_lock_mode=2
|
| bind_address = 0.0.0.0
|
| wsrep_slave_threads=2
| wsrep_cluster_address=gcomm://10.180.0.181,10.180.0.189
| wsrep_provider=/usr/lib64/galera3/libgalera_smm.so
|
| wsrep_cluster_name=mysql_cluster01
| wsrep_node_address=10.180.0.190
| wsrep_node_incoming_address=fb7e1fdcb1e5:3306
|
| wsrep_sst_method=xtrabackup-v2
|
| [client]
| socket=/tmp/mysql.sock
|
| [sst]
| progress=/var/lib/mysql/sst_in_progress
| + wsrep_start_position_opt=
| + '[' mysqld = mysqld -a -z '' ']'
| ++ _get_config datadir mysqld
| ++ local conf=datadir
| ++ shift
| ++ awk '$1 == "datadir" && /^[^ \t]/ { sub(/^[^ \t]+[ \t]+/, ""); print; exit }'
| +++ mktemp -u
| ++ mysqld --verbose --help --wsrep-provider=none --log-bin-index=/tmp/tmp.ztwWJpkdBo
| + DATADIR=/var/lib/mysql/
| + grastate_loc=/var/lib/mysql//grastate.dat
| + '[' -s /var/lib/mysql//grastate.dat -a -d /var/lib/mysql//mysql ']'
| + '[' -z '' -a -d /var/lib/mysql//mysql ']'
| + exec mysqld
| 2023-06-03T09:56:19.287942Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
| 2023-06-03T09:56:19.290680Z 0 [Note] mysqld (mysqld 5.7.41-44-57) starting as process 1 ...
| 2023-06-03T09:56:19.295615Z 0 [Note] WSREP: Setting wsrep_ready to false
| 2023-06-03T09:56:19.295645Z 0 [Note] WSREP: No pre-stored wsrep-start position found. Skipping position initialization.
| 2023-06-03T09:56:19.295654Z 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera3/libgalera_smm.so'
| 2023-06-03T09:56:19.296511Z 0 [Note] WSREP: wsrep_load(): Galera 3.65(rf47405c) by Codership Oy <info@codership.com> loaded successfully.
| 2023-06-03T09:56:19.296592Z 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
| 2023-06-03T09:56:19.296903Z 0 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
| 2023-06-03T09:56:19.296959Z 0 [Warning] WSREP: No persistent state found. Bootstraping with default state
| 2023-06-03T09:56:19.297043Z 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
| 2023-06-03T09:56:19.301509Z 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 10.180.0.190; 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 = 128M; 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 = auto; socket.send_buf_size = auto;
| 2023-06-03T09:56:19.313084Z 0 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 00000000-0000-0000-0000-000000000000:-1
| 2023-06-03T09:56:19.313452Z 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
| 2023-06-03T09:56:19.313501Z 0 [Note] WSREP: Preparing to initiate SST/IST
| 2023-06-03T09:56:19.313510Z 0 [Note] WSREP: Starting replication
| 2023-06-03T09:56:19.313523Z 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
| 2023-06-03T09:56:19.314051Z 0 [Note] WSREP: Using CRC-32C for message checksums.
| 2023-06-03T09:56:19.314260Z 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
| 2023-06-03T09:56:19.314382Z 0 [Note] 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
| 2023-06-03T09:56:19.314397Z 0 [Note] WSREP: Restoring primary-component from disk failed. Either node is booting for first time or re-booting after a graceful shutdown
| 2023-06-03T09:56:19.314615Z 0 [Note] WSREP: GMCast version 0
| 2023-06-03T09:56:19.314784Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
| 2023-06-03T09:56:19.314795Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
| 2023-06-03T09:56:19.315097Z 0 [Note] WSREP: EVS version 0
| 2023-06-03T09:56:19.315229Z 0 [Note] WSREP: gcomm: connecting to group 'mysql_cluster01', peer '10.180.0.181:,10.180.0.189:'
| 2023-06-03T09:56:22.317564Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.181:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799777432 cwnd: 1 last_queued_since: 800077431840533 last_delivered_since: 800077431840533 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:22.317706Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.189:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799777433 cwnd: 1 last_queued_since: 800077432036472 last_delivered_since: 800077432036472 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:22.317752Z 0 [Note] WSREP: announce period timed out (pc.announce_timeout)
| 2023-06-03T09:56:22.317895Z 0 [Warning] WSREP: no nodes coming from prim view, prim not possible
| 2023-06-03T09:56:22.317917Z 0 [Note] WSREP: Current view of cluster as seen by this node
| view (view_id(NON_PRIM,e35b9df6,1)
| memb {
| e35b9df6,0
| }
| joined {
| }
| left {
| }
| partitioned {
| }
| )
| 2023-06-03T09:56:22.818024Z 0 [Warning] WSREP: last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT3.50293S), skipping check
| 2023-06-03T09:56:26.320114Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.181:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799781435 cwnd: 1 last_queued_since: 800081434413530 last_delivered_since: 800081434413530 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:29.321435Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.189:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799784436 cwnd: 1 last_queued_since: 800084435733227 last_delivered_since: 800084435733227 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:32.324989Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.181:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799787440 cwnd: 1 last_queued_since: 800087439289949 last_delivered_since: 800087439289949 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:35.329268Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.189:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799790444 cwnd: 1 last_queued_since: 800090443569990 last_delivered_since: 800090443569990 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:38.333020Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.181:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799793448 cwnd: 1 last_queued_since: 800093447320452 last_delivered_since: 800093447320452 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:41.336601Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.189:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799796451 cwnd: 1 last_queued_since: 800096450903395 last_delivered_since: 800096450903395 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:44.340521Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.181:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799799455 cwnd: 1 last_queued_since: 800099454823278 last_delivered_since: 800099454823278 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:47.345374Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.189:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799802460 cwnd: 1 last_queued_since: 800102459675135 last_delivered_since: 800102459675135 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:50.349677Z 0 [Note] WSREP: (e35b9df6, 'tcp://0.0.0.0:4567') connection to peer 00000000 with addr tcp://10.180.0.181:4567 timed out, no messages seen in PT3S (gmcast.peer_timeout), socket stats: rtt: 0 rttvar: 250000 rto: 2000000 lost: 1 last_data_recv: 799805464 cwnd: 1 last_queued_since: 800105463978814 last_delivered_since: 800105463978814 send_queue_length: 0 send_queue_bytes: 0
| 2023-06-03T09:56:52.352834Z 0 [Note] WSREP: Current view of cluster as seen by this node
| view ((empty))
| 2023-06-03T09:56:52.353034Z 0 [ERROR] WSREP: failed to open gcomm backend connection: 110: failed to reach primary view (pc.wait_prim_timeout): 110 (Connection timed out)
| at gcomm/src/pc.cpp:connect():161
| 2023-06-03T09:56:52.353052Z 0 [ERROR] WSREP: gcs/src/gcs_core.cpp:gcs_core_open():209: Failed to open backend connection: -110 (Connection timed out)
| 2023-06-03T09:56:53.353270Z 0 [Note] WSREP: gcomm: terminating thread
| 2023-06-03T09:56:53.353330Z 0 [Note] WSREP: gcomm: joining thread
| 2023-06-03T09:56:53.353444Z 0 [ERROR] WSREP: gcs/src/gcs.cpp:gcs_open():1578: Failed to open channel 'mysql_cluster01' at 'gcomm://10.180.0.181,10.180.0.189': -110 (Connection timed out)
| 2023-06-03T09:56:53.353504Z 0 [ERROR] WSREP: gcs connect failed: Connection timed out
| 2023-06-03T09:56:53.353515Z 0 [ERROR] WSREP: Provider/Node (gcomm://10.180.0.181,10.180.0.189) failed to establish connection with cluster (reason: 7)
| 2023-06-03T09:56:53.353521Z 0 [ERROR] Aborting
|
| 2023-06-03T09:56:53.353526Z 0 [Note] Giving 0 client threads a chance to die gracefully
| 2023-06-03T09:56:53.353533Z 0 [Note] WSREP: Waiting for active wsrep applier to exit
| 2023-06-03T09:56:53.353538Z 0 [Note] WSREP: Service disconnected.
| 2023-06-03T09:56:53.353543Z 0 [Note] WSREP: Waiting to close threads......
| 2023-06-03T09:56:58.353745Z 0 [Note] WSREP: Some threads may fail to exit.
| 2023-06-03T09:56:58.361621Z 0 [Note] WSREP: Service thread queue flushed.
| 2023-06-03T09:56:58.361893Z 0 [Note] WSREP: MemPool(SlaveTrxHandle): hit ratio: 0, misses: 0, in use: 0, in pool: 0
| 2023-06-03T09:56:58.362104Z 0 [Note] WSREP: Shifting CLOSED -> DESTROYED (TO: 0)
| 2023-06-03T09:56:58.363727Z 0 [Note] Binlog end
| 2023-06-03T09:56:58.364380Z 0 [Note] mysqld: Shutdown complete
|