[root@spray1:/usr/local/src/percona-xtradb-cluster-operator/deploy]# kubectl logs -f cluster1-xb-cron-cluster1-20200422025603-s923k-ppwlt -n pxc

  • GARBD_OPTS=
  • SOCAT_OPTS=TCP-LISTEN:4444,reuseaddr,retry=30
  • check_ssl
  • CA=/var/run/secrets/kubernetes.io/serviceaccount/ca.crt
  • '[' -f /var/run/secrets/kubernetes.io/serviceaccount/service-ca.crt ']'
  • SSL_DIR=/etc/mysql/ssl
  • '[' -f /etc/mysql/ssl/ca.crt ']'
  • CA=/etc/mysql/ssl/ca.crt
  • SSL_INTERNAL_DIR=/etc/mysql/ssl-internal
  • '[' -f /etc/mysql/ssl-internal/ca.crt ']'
  • CA=/etc/mysql/ssl-internal/ca.crt
  • KEY=/etc/mysql/ssl/tls.key
  • CERT=/etc/mysql/ssl/tls.crt
  • '[' -f /etc/mysql/ssl-internal/tls.key -a -f /etc/mysql/ssl-internal/tls.crt ']'
  • KEY=/etc/mysql/ssl-internal/tls.key
  • CERT=/etc/mysql/ssl-internal/tls.crt
  • '[' -f /etc/mysql/ssl-internal/ca.crt -a -f /etc/mysql/ssl-internal/tls.key -a -f /etc/mysql/ssl-internal/tls.crt ']'
  • GARBD_OPTS='socket.ssl_ca=/etc/mysql/ssl-internal/ca.crt;socket.ssl_cert=/etc/mysql/ssl-internal/tls.crt;socket.ssl_key=/etc/mysql/ssl-internal/tls.key;socket.ssl_cipher=;'
  • SOCAT_OPTS=openssl-listen:4444,reuseaddr,cert=/etc/mysql/ssl-internal/tls.crt,key=/etc/mysql/ssl-internal/tls.key,cafile=/etc/mysql/ssl-internal/ca.crt,verify=1,retry=30
  • '[' -n andy-bakckup-s3 ']'
  • backup_s3
  • S3_BUCKET_PATH=cluster1-2020-22-04-02:56:04-full
  • echo 'Backup to s3://andy-bakckup-s3/cluster1-2020-22-04-02:56:04-full started'
  • mc -C /tmp/mc config host add dest https://s3.amazonaws.com AKIAI3K33V5Q123HQR6A K8+JgeX0+DQCRvbFmbTNTwjtT123XnAtoP35ZBQx Backup to s3://andy-bakckup-s3/cluster1-2020-22-04-02:56:04-full started Added dest successfully.

+ xbcloud delete --storage=s3 --s3-bucket=andy-bakckup-s3 cluster1-2020-22-04-02:56:04-full

200422 02:56:09 xbcloud: Probe failed. Please check your credentials and endpoint settings.

  • :
  • request_streaming ++ hostname -i
  • local LOCAL_IP=172.19.4.236 ++ get_backup_source ++ peer-list -on-start=/usr/bin/get-pxc-state -service=cluster1-pxc ++ grep wsrep_ready:ON:wsrep_connected:ON:wsrep_local_state_comment:Synced:wsrep_cluster_status:Primary ++ sort ++ tail -1 ++ cut -d . -f 1 ++ cut -d : -f 2
  • local NODE_NAME=cluster1-pxc-2
  • '[' -z cluster1-pxc-2 ']'
  • timeout -k 25 20 garbd --address 'gcomm://cluster1-pxc-2.cluster1-pxc?gmcast.listen_addr=tcp://0.0.0.0:4444' --donor cluster1-pxc-2 --group cluster1-pxc --options 'socket.ssl_ca=/etc/mysql/ssl-internal/ca.crt;socket.ssl_cert=/etc/mysql/ssl-internal/tls.crt;socket.ssl_key=/etc/mysql/ssl-internal/tls.key;socket.ssl_cipher=;' --sst xtrabackup-v2:172.19.4.236:4444/xtrabackup_sst//1
  • tee /tmp/garbd.log 2020-04-22 02:56:12.786 INFO: CRC-32C: using hardware acceleration. 2020-04-22 02:56:12.786 INFO: Read config: daemon: 0 name: garb address: gcomm://cluster1-pxc-2.cluster1-pxc?gmcast.listen_addr=tcp://0.0.0.0:4444 group: cluster1-pxc sst: xtrabackup-v2:172.19.4.236:4444/xtrabackup_sst//1 donor: cluster1-pxc-2 options: socket.ssl_ca=/etc/mysql/ssl-internal/ca.crt;socket.ssl_cert=/etc/mysql/ssl-internal/tls.crt;socket.ssl_key=/etc/mysql/ssl-internal/tls.key;socket.ssl_cipher=;; gcs.fc_limit=9999999; gcs.fc_factor=1.0; gcs.fc_master_slave=yes cfg:
    log:

2020-04-22 02:56:12.787 INFO: Using CRC-32C for message checksums. 2020-04-22 02:56:12.787 INFO: initializing ssl context 2020-04-22 02:56:12.787 INFO: gcomm thread scheduling priority set to other:0 2020-04-22 02:56:12.787 WARN: Fail to access the file (./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 2020-04-22 02:56:12.787 INFO: Restoring primary-component from disk failed. Either node is booting for first time or re-booting after a graceful shutdown 2020-04-22 02:56:12.788 INFO: GMCast version 0 2020-04-22 02:56:12.789 INFO: (d36b253e, 'ssl://0.0.0.0:4444') listening at ssl://0.0.0.0:4444 2020-04-22 02:56:12.789 INFO: (d36b253e, 'ssl://0.0.0.0:4444') multicast: , ttl: 1 2020-04-22 02:56:12.789 INFO: EVS version 0 2020-04-22 02:56:12.789 INFO: gcomm: connecting to group 'cluster1-pxc', peer 'cluster1-pxc-2.cluster1-pxc:' 2020-04-22 02:56:12.797 INFO: SSL handshake successful, remote endpoint ssl://172.19.0.185:4567 local endpoint ssl://172.19.4.236:60754 cipher: ECDHE-RSA-AES256-GCM-SHA384 compression: none 2020-04-22 02:56:12.799 INFO: (d36b253e, 'ssl://0.0.0.0:4444') connection established to 65d71b03 ssl://172.19.0.185:4567 2020-04-22 02:56:12.799 INFO: (d36b253e, 'ssl://0.0.0.0:4444') turning message relay requesting on, nonlive peers: ssl://172.19.1.170:4567 ssl://172.19.2.44:4567 2020-04-22 02:56:13.016 INFO: SSL handshake successful, remote endpoint ssl://172.19.1.170:41248 local endpoint ssl://172.19.4.236:4444 cipher: ECDHE-RSA-AES256-GCM-SHA384 compression: none 2020-04-22 02:56:13.017 INFO: (d36b253e, 'ssl://0.0.0.0:4444') connection established to 56803d0f ssl://172.19.1.170:4567 2020-04-22 02:56:13.023 INFO: SSL handshake successful, remote endpoint ssl://172.19.2.44:38666 local endpoint ssl://172.19.4.236:4444 cipher: ECDHE-RSA-AES256-GCM-SHA384 compression: none 2020-04-22 02:56:13.024 INFO: SSL handshake successful, remote endpoint ssl://172.19.2.44:4567 local endpoint ssl://172.19.4.236:45086 cipher: ECDHE-RSA-AES256-GCM-SHA384 compression: none 2020-04-22 02:56:13.024 INFO: (d36b253e, 'ssl://0.0.0.0:4444') connection established to 4a935df7 ssl://172.19.2.44:4567 2020-04-22 02:56:13.024 INFO: (d36b253e, 'ssl://0.0.0.0:4444') connection established to 4a935df7 ssl://172.19.2.44:4567 2020-04-22 02:56:13.292 INFO: declaring 4a935df7 at ssl://172.19.2.44:4567 stable 2020-04-22 02:56:13.292 INFO: declaring 56803d0f at ssl://172.19.1.170:4567 stable 2020-04-22 02:56:13.292 INFO: declaring 65d71b03 at ssl://172.19.0.185:4567 stable 2020-04-22 02:56:13.293 INFO: Node 4a935df7 state primary 2020-04-22 02:56:13.294 INFO: Current view of cluster as seen by this node view (view_id(PRIM,4a935df7,6) memb { 4a935df7,0 56803d0f,0 65d71b03,0 d36b253e,0 } joined { } left { } partitioned { } ) 2020-04-22 02:56:13.294 INFO: Save the discovered primary-component to disk 2020-04-22 02:56:13.294 WARN: open file(./gvwstate.dat.tmp) failed(Permission denied) 2020-04-22 02:56:13.790 INFO: gcomm: connected 2020-04-22 02:56:13.790 INFO: Shifting CLOSED -> OPEN (TO: 0) 2020-04-22 02:56:13.790 INFO: New COMPONENT: primary = yes, bootstrap = no, my_idx = 3, memb_num = 4 2020-04-22 02:56:13.790 INFO: STATE EXCHANGE: Waiting for state UUID. 2020-04-22 02:56:13.790 INFO: STATE EXCHANGE: sent state msg: d3ba53e3-8444-11ea-a507-dfb53404e518 2020-04-22 02:56:13.790 INFO: STATE EXCHANGE: got state msg: d3ba53e3-8444-11ea-a507-dfb53404e518 from 0 (cluster1-pxc-0) 2020-04-22 02:56:13.790 INFO: STATE EXCHANGE: got state msg: d3ba53e3-8444-11ea-a507-dfb53404e518 from 1 (cluster1-pxc-1) 2020-04-22 02:56:13.790 INFO: STATE EXCHANGE: got state msg: d3ba53e3-8444-11ea-a507-dfb53404e518 from 2 (cluster1-pxc-2) 2020-04-22 02:56:13.792 INFO: STATE EXCHANGE: got state msg: d3ba53e3-8444-11ea-a507-dfb53404e518 from 3 (garb) 2020-04-22 02:56:13.792 INFO: Quorum results: version = 4, component = PRIMARY, conf_id = 4, members = 3/4 (primary/total), act_id = 17, last_appl. = -1, protocols = 0/9/3 (gcs/repl/appl), group UUID = ad79c07d-2579-11ea-b335-9347b0e3d60d 2020-04-22 02:56:13.792 INFO: Flow-control interval: [1048575, 1048575] 2020-04-22 02:56:13.792 INFO: Trying to continue unpaused monitor 2020-04-22 02:56:13.792 INFO: Shifting OPEN -> PRIMARY (TO: 17) 2020-04-22 02:56:13.792 INFO: Sending state transfer request: 'xtrabackup-v2:172.19.4.236:4444/xtrabackup_sst//1', size: 49 2020-04-22 02:56:13.793 INFO: Member 3.0 (garb) requested state transfer from 'cluster1-pxc-2'. Selected 2.0 (cluster1-pxc-2)(SYNCED) as donor. 2020-04-22 02:56:13.793 INFO: Shifting PRIMARY -> JOINER (TO: 17) 2020-04-22 02:56:13.793 INFO: Closing send monitor... 2020-04-22 02:56:13.793 INFO: Closed send monitor. 2020-04-22 02:56:13.793 INFO: gcomm: terminating thread 2020-04-22 02:56:13.793 INFO: gcomm: joining thread 2020-04-22 02:56:13.793 INFO: gcomm: closing backend 2020-04-22 02:56:13.794 INFO: 3.0 (garb): State transfer from 2.0 (cluster1-pxc-2) complete. 2020-04-22 02:56:13.794 INFO: SST leaving flow control 2020-04-22 02:56:13.794 INFO: Shifting JOINER -> JOINED (TO: 17) 2020-04-22 02:56:13.795 INFO: Current view of cluster as seen by this node view (view_id(NON_PRIM,4a935df7,6) memb { d36b253e,0 } joined { } left { } partitioned { 4a935df7,0 56803d0f,0 65d71b03,0 } ) 2020-04-22 02:56:13.795 INFO: Current view of cluster as seen by this node view ((empty)) 2020-04-22 02:56:13.796 INFO: gcomm: closed 2020-04-22 02:56:13.796 WARN: 0x14a1678 down context(s) not set 2020-04-22 02:56:13.796 WARN: Failed to send SYNC signal: -107 (Transport endpoint is not connected) 2020-04-22 02:56:13.796 INFO: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1 2020-04-22 02:56:13.796 INFO: Flow-control interval: [1048575, 1048575] 2020-04-22 02:56:13.796 INFO: Trying to continue unpaused monitor 2020-04-22 02:56:13.796 INFO: Received NON-PRIMARY. 2020-04-22 02:56:13.796 INFO: Shifting JOINED -> OPEN (TO: 17) 2020-04-22 02:56:13.796 INFO: Received self-leave message. 2020-04-22 02:56:13.796 INFO: Flow-control interval: [1048575, 1048575] 2020-04-22 02:56:13.796 INFO: Trying to continue unpaused monitor 2020-04-22 02:56:13.796 INFO: Received SELF-LEAVE. Closing connection. 2020-04-22 02:56:13.796 INFO: Shifting OPEN -> CLOSED (TO: 17) 2020-04-22 02:56:13.796 INFO: RECV thread exiting 0: Success 2020-04-22 02:56:13.796 INFO: recv_thread() joined. 2020-04-22 02:56:13.796 INFO: Closing replication queue. 2020-04-22 02:56:13.796 INFO: Closing slave action queue. 2020-04-22 02:56:13.796 WARN: Attempt to close a closed connection 2020-04-22 02:56:13.796 INFO: Exiting main loop 2020-04-22 02:56:13.796 INFO: Shifting CLOSED -> DESTROYED (TO: 17)

  • grep 'State transfer request failed' /tmp/garbd.log
  • grep 'WARN: Protocol violation. JOIN message sender ... (garb) is not in state transfer' /tmp/garbd.log
  • grep 'WARN: Rejecting JOIN message from ... (garb): new State Transfer required.' /tmp/garbd.log
  • socat -u openssl-listen:4444,reuseaddr,cert=/etc/mysql/ssl-internal/tls.crt,key=/etc/mysql/ssl-internal/tls.key,cafile=/etc/mysql/ssl-internal/ca.crt,verify=1,retry=30 stdio
  • xbcloud put --storage=s3 --parallel=10 --md5 --s3-bucket=andy-bakckup-s3 cluster1-2020-22-04-02:56:04-full 200422 02:56:16 xbcloud: Probe failed. Please check your credentials and endpoint settings.