New node is re-download logs when it is restart

1 
##############
#
# add cluster Node (db2)
#
##############

2022-11-14 13:53:30 140020776741056 [Note] WSREP: Read nil XID from storage engines, skipping position init
2022-11-14 13:53:30 140020776741056 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera/libgalera_smm.so'
2022-11-14 13:53:30 140020776741056 [Note] WSREP: wsrep_load(): Galera 25.3.35(r545d0bf) by Codership Oy <in...@codership.com> loaded successfully.
2022-11-14 13:53:30 140020776741056 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Found saved state: er00347b-f5dd-23ec-8421-fb49bcft4928:53823515, safe_to_bootstrap: 0
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Passing config to GCS: base_dir = /home/db/; base_host = 192.168.0.2; 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 = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /home/db/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /home/db//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum =
2022-11-14 13:53:30 140020776741056 [Note] WSREP: GCache history reset: er00347b-f5dd-23ec-8421-fb49bcft4928:0 -> er00347b-f5dd-23ec-8421-fb49bcft4928:53823515
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Assign initial position for certification: 53823515, protocol version: -1
2022-11-14 13:53:30 140020776741056 [Note] WSREP: wsrep_sst_grab()
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Start replication
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Setting initial position to er00347b-f5dd-23ec-8421-fb49bcft4928:53823515
2022-11-14 13:53:30 140020776741056 [Note] WSREP: protonet asio version 0
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Using CRC-32C for message checksums.
2022-11-14 13:53:30 140020776741056 [Note] WSREP: backend: asio
2022-11-14 13:53:30 140020776741056 [Note] WSREP: gcomm thread scheduling priority set to other:0
2022-11-14 13:53:30 140020776741056 [Warning] WSREP: access file(/home/db//gvwstate.dat) failed(No such file or directory)
2022-11-14 13:53:30 140020776741056 [Note] WSREP: restore pc from disk failed
2022-11-14 13:53:30 140020776741056 [Note] WSREP: GMCast version 0
2022-11-14 13:53:30 140020776741056 [Note] WSREP: (48a11b19, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2022-11-14 13:53:30 140020776741056 [Note] WSREP: (48a11b19, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2022-11-14 13:53:30 140020776741056 [Note] WSREP: EVS version 0
2022-11-14 13:53:30 140020776741056 [Note] WSREP: gcomm: connecting to group 'galera_cluster', peer '192.168.0.1:,192.168.0.2:'
2022-11-14 13:53:30 140020776741056 [Note] WSREP: (48a11b19, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://192.168.0.2:4567
2022-11-14 13:53:30 140020776741056 [Note] WSREP: (48a11b19, 'tcp://0.0.0.0:4567') connection established to 6e2541ee tcp://192.168.0.1:4567
2022-11-14 13:53:30 140020776741056 [Note] WSREP: (48a11b19, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2022-11-14 13:53:30 140020776741056 [Note] WSREP: declaring 6e2541ee at tcp://192.168.0.1:4567 stable
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Node 6e2541ee state prim
2022-11-14 13:53:30 140020776741056 [Note] WSREP: view(view_id(PRIM,48a11b19,12) memb {
    48a11b19,0
    6e2541ee,0
} joined {
} left {
} partitioned {
})
2022-11-14 13:53:30 140020776741056 [Note] WSREP: save pc into disk
2022-11-14 13:53:30 140020776741056 [Note] WSREP: gcomm: connected
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Opened channel 'galera_cluster'
2022-11-14 13:53:30 140020421744384 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2022-11-14 13:53:30 140020776741056 [Note] WSREP: Waiting for SST to complete.
2022-11-14 13:53:30 140020421744384 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 69ed51f4-63d8-12df-bc73-ff000c998f01
2022-11-14 13:53:30 140020421744384 [Note] WSREP: STATE EXCHANGE: sent state msg: 69ed51f4-63d8-12df-bc73-ff000c998f01
2022-11-14 13:53:30 140020421744384 [Note] WSREP: STATE EXCHANGE: got state msg: 69ed51f4-63d8-12df-bc73-ff000c998f01 from 0 (db2)
2022-11-14 13:53:30 140020421744384 [Note] WSREP: STATE EXCHANGE: got state msg: 69ed51f4-63d8-12df-bc73-ff000c998f01 from 1 (db1)
2022-11-14 13:53:30 140020421744384 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 10,
    members    = 1/2 (joined/total),
    act_id     = 53823611,
    last_appl. = -1,
    protocols  = 0/7/3 (gcs/repl/appl),
    group UUID = er00347b-f5dd-23ec-8421-fb49bcft4928
2022-11-14 13:53:30 140020421744384 [Note] WSREP: Flow-control interval: [23, 23]
2022-11-14 13:53:30 140020421744384 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 53823611)
2022-11-14 13:53:30 140020637026048 [Note] WSREP: State transfer required:
    Group state: er00347b-f5dd-23ec-8421-fb49bcft4928:53823611
    Local state: er00347b-f5dd-23ec-8421-fb49bcft4928:53823515
2022-11-14 13:53:30 140020637026048 [Note] WSREP: REPL Protocols: 7 (3, 2)
2022-11-14 13:53:30 140020637026048 [Note] WSREP: New cluster view: global state: er00347b-f5dd-23ec-8421-fb49bcft4928:53823611, view# 11: Primary, number of nodes: 2, my index: 0, protocol version 3
2022-11-14 13:53:30 140020637026048 [Warning] WSREP: Gap in state sequence. Need state transfer.
2022-11-14 13:53:30 140020413351680 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '192.168.0.2' --datadir '/home/db/' --parent '35528' --binlog '/home/db/linkmine_binlog' --mysqld-args --basedir=/usr --wsrep_start_position=er00347b-f5dd-23ec-8421-fb49bcft4928:53823515'
WSREP_SST: [INFO] SSL configuration: CA='', CAPATH='', CERT='', KEY='', MODE='DISABLED', encrypt='0' (20221114 13:53:30.755)
WSREP_SST: [INFO] Moving '/home/db/innobackupex.prepare.log' to '/tmp/sst_log_archive/innobackupex.prepare.log.2022.11.14-13.53.31.019235477' (20221114 13:53:31.026)
WSREP_SST: [INFO] Moving '/home/db/innobackupex.move.log' to '/tmp/sst_log_archive/innobackupex.move.log.2022.11.14-13.53.31.019235477' (20221114 13:53:31.043)
WSREP_SST: [INFO] Streaming with xbstream (20221114 13:53:31.057)
WSREP_SST: [INFO] Using socat as streamer (20221114 13:53:31.061)
WSREP_SST: [INFO] Evaluating timeout -k 310 300 socat -u TCP-LISTEN:4444,reuseaddr stdio | '/usr//bin/xbstream' -x; RC=( ${PIPESTATUS[@]} ) (20221114 13:53:31.114)
2022-11-14 13:53:31 140020637026048 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2022-11-14 13:53:31 140020637026048 [Note] WSREP: Assign initial position for certification: 53823611, protocol version: 3
2022-11-14 13:53:31 140020670904064 [Note] WSREP: Service thread queue flushed.
2022-11-14 13:53:31 140020637026048 [Note] WSREP: IST receiver addr using tcp://192.168.0.2:4568
2022-11-14 13:53:31 140020637026048 [Warning] WSREP: Failed to prepare for incremental state transfer: Failed to open IST listener at tcp://192.168.0.2:4568', asio error 'bind: Cannot assign requested address': 99 (Cannot assign requested address)
     at /home/buildbot/buildbot/build/galera/src/ist.cpp:prepare():330. IST will be unavailable.
2022-11-14 13:53:31 140020421744384 [Note] WSREP: Member 0.0 (db2) requested state transfer from '*any*'. Selected 1.0 (db1)(SYNCED) as donor.
2022-11-14 13:53:31 140020421744384 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 53823611)
2022-11-14 13:53:31 140020637026048 [Note] WSREP: Requesting state transfer: success, donor: 1
2022-11-14 13:53:31 140020637026048 [Note] WSREP: GCache history reset: er00347b-f5dd-23ec-8421-fb49bcft4928:0 -> er00347b-f5dd-23ec-8421-fb49bcft4928:53823611
WSREP_SST: [INFO] Proceeding with SST (20221114 13:53:32.240)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | '/usr//bin/xbstream' -x; RC=( ${PIPESTATUS[@]} ) (20221114 13:53:32.241)
WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20221114 13:53:32.249)
2022-11-14 13:53:33 140020430137088 [Note] WSREP: (48a11b19, 'tcp://0.0.0.0:4567') turning message relay requesting off
removed ‘/home/host_home/db/linkmine_binlog.001290’
removed ‘/home/host_home/db/linkmine_binlog.index’



##############
#
# Donor (db1)
#
##############


221114 13:52:15 [Note] WSREP: (6e2541ee, 'tcp://0.0.0.0:4567') reconnecting to 1790218d (tcp://192.168.0.2:4567), attempt 30
221114 13:53:00 [Note] WSREP: (6e2541ee, 'tcp://0.0.0.0:4567') reconnecting to 1790218d (tcp://192.168.0.2:4567), attempt 60
221114 13:53:27 [Note] WSREP: (6e2541ee, 'tcp://0.0.0.0:4567') connection established to 48a11b19 tcp://192.168.0.2:4567
221114 13:53:27 [Note] WSREP: remote endpoint tcp://192.168.0.2:4567 changed identity 1790218d -> 48a11b19
221114 13:53:28 [Note] WSREP: declaring 48a11b19 at tcp://192.168.0.2:4567 stable
221114 13:53:28 [Note] WSREP: Node 6e2541ee state prim
221114 13:53:28 [Note] WSREP: view(view_id(PRIM,48a11b19,12) memb {
    48a11b19,0
    6e2541ee,0
} joined {
} left {
} partitioned {
})
221114 13:53:28 [Note] WSREP: save pc into disk
221114 13:53:28 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
221114 13:53:28 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
221114 13:53:28 [Note] WSREP: STATE EXCHANGE: sent state msg: 69ed51f4-63d8-12df-bc73-ff000c998f01
221114 13:53:28 [Note] WSREP: STATE EXCHANGE: got state msg: 69ed51f4-63d8-12df-bc73-ff000c998f01 from 0 (db2)
221114 13:53:28 [Note] WSREP: STATE EXCHANGE: got state msg: 69ed51f4-63d8-12df-bc73-ff000c998f01 from 1 (db1)
221114 13:53:28 [Note] WSREP: Quorum results:
    version    = 4,
    component  = PRIMARY,
    conf_id    = 10,
    members    = 1/2 (joined/total),
    act_id     = 53823611,
    last_appl. = 53823535,
    protocols  = 0/7/3 (gcs/repl/appl),
    group UUID = er00347b-f5dd-23ec-8421-fb49bcft4928
221114 13:53:28 [Note] WSREP: Flow-control interval: [23, 23]
221114 13:53:28 [Note] WSREP: New cluster view: global state: er00347b-f5dd-23ec-8421-fb49bcft4928:53823611, view# 11: Primary, number of nodes: 2, my index: 1, protocol version 3
221114 13:53:28 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
221114 13:53:28 [Note] WSREP: REPL Protocols: 7 (3, 2)
221114 13:53:28 [Note] WSREP: Assign initial position for certification: 53823611, protocol version: 3
221114 13:53:28 [Note] WSREP: Service thread queue flushed.
221114 13:53:28 [Note] WSREP: Member 0.0 (db2) requested state transfer from '*any*'. Selected 1.0 (db1)(SYNCED) as donor.
221114 13:53:28 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 53823611)
221114 13:53:28 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
221114 13:53:28 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.0.2:4444/xtrabackup_sst//-1' --socket '/var/lib/mysql/mysql.sock' --datadir '/home/db/' --defaults-file '/etc/my.cnf' --defaults-group-suffix ''  --binlog '/home/db/linkmine_binlog' --gtid 'er00347b-f5dd-23ec-8421-fb49bcft4928:53823611''
221114 13:53:28 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (20221114 13:53:29.839)
WSREP_SST: [INFO] Using socat as streamer (20221114 13:53:29.840)
WSREP_SST: [INFO] Using /tmp/tmp.gcoSsrmUVC as innobackupex temporary directory (20221114 13:53:29.846)
WSREP_SST: [INFO] Streaming GTID file before SST (20221114 13:53:29.849)
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio TCP:192.168.0.2:4444; RC=( ${PIPESTATUS[@]} ) (20221114 13:53:29.853)
WSREP_SST: [INFO] Sleeping before data transfer for SST (20221114 13:53:29.916)
221114 13:53:31 [Note] WSREP: (6e2541ee, 'tcp://0.0.0.0:4567') turning message relay requesting off
WSREP_SST: [INFO] Streaming the backup to joiner at 192.168.0.2 4444 (20221114 13:53:39.942)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf  --defaults-group=mysqld --no-version-check  $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:192.168.0.2:4444; RC=( ${PIPESTATUS[@]} ) (20221114 13:53:39.943)

It’s work fine at first. but remove data forder and re-download logs when New node is restart. How do i fix it?

Thanks for your time. Regards

1 Like
2

Hi seems IST is failing… do you have any other process listening on port 4568?

1 Like
3

Thank you for your interest.

4568 port is just use to IST
And New node is running on Docker container

  1. Donor (mysql Ver 15.1 Distrib 10.0.32-MariaDB, for Linux (x86_64) using readline 5.1)
  2. New node (mysql Ver 15.1 Distrib 10.2.44-MariaDB, for Linux (x86_64) using readline 5.1)

— New node status —

[root@localhost ~]# netstat -nap | grep 4568
tcp 0 0 0.0.0.0:4568 0.0.0.0:* LISTEN 4794/docker-proxy

— New node container run script —

docker run -itd --restart always
-p 30887:3306 -p 873:873
-p 4567:4567 -p 4567:4567/udp -p 4568:4568 -p 4444:4444
-p 8080-8085:8080-8085 -p 10001-10010:10001-10010 -p 10001-10010:10001-10010/udp
–name test_db -h test_db
-v share:/home/share
-v /etc/timezone:/etc/timezone -v /etc/localtime:/etc/localtime -v /sys/fs/cgroup:/sys/fs/cgroup:ro
–privileged test_db init

1 Like
4

I resorved it.
I change Docker option to --network host then it’s work.

1 Like