Details
Description
This bug is also being tracked in the FreeBSD Bugzilla: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=256112
I created fresh FreeBSD VMs with fresh installs of MariaDB 10.6.3
I started the first node with "mysqld_safe --wsrep-new-cluster" and tried to have the second node connect.
No data was changed on either node, just trying to get them to communicate.
The first node remains in the "sync" state the entire time, never entering the "donor" state.
The second node starts rsync, and is stuck listening for a connection indefinitely.
Using the default configs for FreeBSD, with default bind-address commented out, and then this cnf file added on both nodes:
[galera]
|
wsrep_on=ON
|
wsrep_provider = /usr/local/lib/libgalera_smm.so
|
wsrep_provider_options = "gmcast.segment=202;pc.weight=1"
|
wsrep_cluster_name = "testdb"
|
wsrep_cluster_address = "gcomm://192.168.20.132,192.168.20.122"
|
wsrep_sst_method = rsync
|
|
[mysqld]
|
binlog_format=ROW
|
bind-address=0.0.0.0
|
On the first node (donor):
2021-07-07 4:44:25 0 [Note] WSREP: Loading provider /usr/local/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
|
2021-07-07 4:44:25 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/local/lib/libgalera_smm.so'
|
2021-07-07 4:44:25 0 [Note] WSREP: wsrep_load(): Galera 4.6(rrelease_26.4.6) by Codership Oy <info@codership.com> loaded successfully.
|
2021-07-07 4:44:25 0 [Note] WSREP: CRC-32C: using hardware acceleration.
|
2021-07-07 4:44:25 0 [Note] WSREP: Found saved state: 4e704a59-dedc-11eb-a825-dfcedc24af98:-1, safe_to_bootstrap: 1
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: opened preamble:
|
Version: 2
|
UUID: 4e704a59-dedc-11eb-a825-dfcedc24af98
|
Seqno: -1 - -1
|
Offset: -1
|
Synced: 0
|
2021-07-07 4:44:25 0 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: 4e704a59-dedc-11eb-a825-dfcedc24af98, offset: -1
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer initial scan... 0.0% ( 0/134217752 bytes) complete.
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete.
|
2021-07-07 4:44:25 0 [Note] WSREP: Recovering GCache ring buffer: found gapless sequence 1-4
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer unused buffers scan... 0.0% ( 0/1264 bytes) complete.
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer unused buffers scan...100.0% (1264/1264 bytes) complete.
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): found 3/7 locked buffers
|
2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): free space: 134217016/134217728
|
2021-07-07 4:44:25 0 [Note] WSREP: Passing config to GCS: base_dir = /var/db/mysql/; base_host = 192.168.20.132; 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 = /var/db/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; 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 = 202; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum
|
2021-07-07 4:44:25 0 [Note] WSREP: Start replication
|
2021-07-07 4:44:25 0 [Note] WSREP: Connecting with bootstrap option: 1
|
2021-07-07 4:44:25 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
|
2021-07-07 4:44:25 0 [Note] WSREP: protonet asio version 0
|
2021-07-07 4:44:25 0 [Note] WSREP: Using CRC-32C for message checksums.
|
2021-07-07 4:44:25 0 [Note] WSREP: backend: asio
|
2021-07-07 4:44:25 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
|
2021-07-07 4:44:25 0 [Note] WSREP: restore pc from disk successfully
|
2021-07-07 4:44:25 0 [Note] WSREP: GMCast version 0
|
2021-07-07 4:44:25 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
|
2021-07-07 4:44:25 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
|
2021-07-07 4:44:25 0 [Note] WSREP: EVS version 1
|
2021-07-07 4:44:25 0 [Note] WSREP: gcomm: bootstrapping new group 'testdb'
|
2021-07-07 4:44:25 0 [Note] WSREP: start_prim is enabled, turn off pc_recovery
|
2021-07-07 4:44:25 0 [Note] WSREP: EVS version upgrade 0 -> 1
|
2021-07-07 4:44:25 0 [Note] WSREP: PC protocol upgrade 0 -> 1
|
2021-07-07 4:44:25 0 [Note] WSREP: Node dff40154-8099 state prim
|
2021-07-07 4:44:25 0 [Note] WSREP: view(view_id(PRIM,dff40154-8099,3) memb {
|
dff40154-8099,202
|
} joined {
|
} left {
|
} partitioned {
|
})
|
2021-07-07 4:44:25 0 [Note] WSREP: save pc into disk
|
2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr without UUID: tcp://192.168.20.122:4567
|
2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr proto entry 0x42435460
|
2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr without UUID: tcp://192.168.20.132:4567
|
2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr proto entry 0x42435540
|
2021-07-07 4:44:25 0 [Note] WSREP: clear restored view
|
2021-07-07 4:44:25 0 [Note] WSREP: gcomm: connected
|
2021-07-07 4:44:25 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
|
2021-07-07 4:44:25 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
|
2021-07-07 4:44:25 0 [Note] WSREP: Opened channel 'testdb'
|
2021-07-07 4:44:25 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
|
2021-07-07 4:44:25 0 [Note] WSREP: Starting new group from scratch: 01bbfaaf-dede-11eb-b363-16edbc96f9c8
|
2021-07-07 4:44:25 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 01bc0065-dede-11eb-85ce-9a71a683bc8e
|
2021-07-07 4:44:25 1 [Note] WSREP: Starting applier thread 1
|
2021-07-07 4:44:25 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 01bc0065-dede-11eb-85ce-9a71a683bc8e
|
2021-07-07 4:44:25 0 [Note] WSREP: STATE EXCHANGE: got state msg: 01bc0065-dede-11eb-85ce-9a71a683bc8e from 0 (arm-galera-10-6-2)
|
2021-07-07 4:44:25 0 [Note] WSREP: Quorum results:
|
version = 6,
|
component = PRIMARY,
|
conf_id = 0,
|
members = 1/1 (joined/total),
|
act_id = 0,
|
last_appl. = 0,
|
protocols = 2/10/4 (gcs/repl/appl),
|
vote policy= 0,
|
group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8
|
2021-07-07 4:44:25 0 [Note] WSREP: Flow-control interval: [16, 16]
|
2021-07-07 4:44:25 0 [Note] WSREP: Restored state OPEN -> JOINED (1)
|
2021-07-07 4:44:25 0 [Note] WSREP: Member 0.202 (arm-galera-10-6-2) synced with group.
|
2021-07-07 4:44:25 2 [Note] WSREP: Starting rollbacker thread 2
|
2021-07-07 4:44:25 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 1)
|
2021-07-07 4:44:25 1 [Note] WSREP: ####### processing CC 1, local, ordered
|
2021-07-07 4:44:25 1 [Note] WSREP: Process first view: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 my uuid: dff40154-dedd-11eb-8099-3206581b79af
|
2021-07-07 4:44:25 1 [Note] WSREP: Server arm-galera-10-6-2 connected to cluster at position 01bbfaaf-dede-11eb-b363-16edbc96f9c8:1 with ID dff40154-dedd-11eb-8099-3206581b79af
|
2021-07-07 4:44:25 1 [Note] WSREP: Server status change disconnected -> connected
|
2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:44:25 1 [Note] WSREP: ####### My UUID: dff40154-dedd-11eb-8099-3206581b79af
|
2021-07-07 4:44:25 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: no
|
2021-07-07 4:44:25 0 [Note] WSREP: Service thread queue flushed.
|
2021-07-07 4:44:25 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
|
2021-07-07 4:44:25 1 [Note] WSREP: REPL Protocols: 10 (5)
|
2021-07-07 4:44:25 1 [Note] WSREP: ####### Adjusting cert position: -1 -> 1
|
2021-07-07 4:44:25 0 [Note] WSREP: Service thread queue flushed.
|
2021-07-07 4:44:25 1 [Note] WSREP: GCache history reset: 4e704a59-dedc-11eb-a825-dfcedc24af98:4 -> 01bbfaaf-dede-11eb-b363-16edbc96f9c8:0
|
2021-07-07 4:44:25 1 [Note] WSREP: GCache DEBUG: RingBuffer::seqno_reset(): discarded 712 bytes
|
2021-07-07 4:44:25 1 [Note] WSREP: GCache DEBUG: RingBuffer::seqno_reset(): found 0/1 locked buffers
|
2021-07-07 4:44:25 1 [Note] WSREP: ================================================
|
View:
|
id: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:1
|
status: primary
|
protocol_version: 4
|
capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
|
final: no
|
own_index: 0
|
members(1):
|
0: dff40154-dedd-11eb-8099-3206581b79af, arm-galera-10-6-2
|
=================================================
|
2021-07-07 4:44:25 1 [Note] WSREP: Server status change connected -> joiner
|
2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:44:25 1 [Note] WSREP: Server status change joiner -> initializing
|
2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:44:25 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
|
2021-07-07 4:44:25 0 [Note] InnoDB: Number of pools: 1
|
2021-07-07 4:44:25 0 [Note] InnoDB: Using generic crc32 instructions
|
2021-07-07 4:44:25 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728
|
2021-07-07 4:44:25 0 [Note] InnoDB: Completed initialization of buffer pool
|
2021-07-07 4:44:25 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=78394,78394
|
2021-07-07 4:44:25 0 [Note] InnoDB: Starting final batch to recover 4 pages from redo log.
|
2021-07-07 4:44:25 0 [Note] InnoDB: 128 rollback segments are active.
|
2021-07-07 4:44:25 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
|
2021-07-07 4:44:25 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2021-07-07 4:44:25 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2021-07-07 4:44:25 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2021-07-07 4:44:25 0 [Note] InnoDB: 10.6.3 started; log sequence number 82877; transaction id 77
|
2021-07-07 4:44:25 0 [Note] InnoDB: Loading buffer pool(s) from /var/db/mysql/ib_buffer_pool
|
2021-07-07 4:44:25 0 [Note] Plugin 'FEEDBACK' is disabled.
|
2021-07-07 4:44:25 0 [Note] Recovering after a crash using tc.log
|
2021-07-07 4:44:25 0 [Note] Starting table crash recovery...
|
2021-07-07 4:44:25 0 [Note] Crash table recovery finished.
|
2021-07-07 4:44:25 0 [Note] InnoDB: Buffer pool(s) load completed at 210707 4:44:25
|
2021-07-07 4:44:25 0 [Note] Server socket created on IP: '0.0.0.0'.
|
2021-07-07 4:44:25 0 [Note] WSREP: wsrep_init_schema_and_SR 0x0
|
2021-07-07 4:44:25 0 [Note] WSREP: Server initialized
|
2021-07-07 4:44:25 0 [Note] WSREP: Server status change initializing -> initialized
|
2021-07-07 4:44:25 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:44:25 1 [Note] WSREP: Bootstrapping a new cluster, setting initial position to 00000000-0000-0000-0000-000000000000:-1
|
2021-07-07 4:44:26 4 [Note] WSREP: Recovered cluster id 4e704a59-dedc-11eb-a825-dfcedc24af98
|
2021-07-07 4:44:26 1 [Note] WSREP: Server status change initialized -> joined
|
2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:44:26 0 [Note] /usr/local/libexec/mariadbd: ready for connections.
|
Version: '10.6.3-MariaDB' socket: '/var/run/mysql/mysql.sock' port: 3306 FreeBSD Ports
|
2021-07-07 4:44:26 1 [Note] WSREP: Lowest cert index boundary for CC from group: 1
|
2021-07-07 4:44:26 1 [Note] WSREP: Min available from gcache for CC from group: 1
|
2021-07-07 4:44:26 1 [Note] WSREP: Server arm-galera-10-6-2 synced with group
|
2021-07-07 4:44:26 1 [Note] WSREP: Server status change joined -> synced
|
2021-07-07 4:44:26 1 [Note] WSREP: Synchronized with group, ready for connections
|
2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:45:08 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') connection established to 1b87f978-a60b tcp://192.168.20.122:4567
|
2021-07-07 4:45:08 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
|
2021-07-07 4:45:09 0 [Note] WSREP: declaring 1b87f978-a60b at tcp://192.168.20.122:4567 stable
|
2021-07-07 4:45:09 0 [Note] WSREP: Node dff40154-8099 state prim
|
2021-07-07 4:45:09 0 [Note] WSREP: view(view_id(PRIM,1b87f978-a60b,4) memb {
|
1b87f978-a60b,202
|
dff40154-8099,202
|
} joined {
|
} left {
|
} partitioned {
|
})
|
2021-07-07 4:45:09 0 [Note] WSREP: save pc into disk
|
2021-07-07 4:45:09 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
|
2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
|
2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 1c291b89-dede-11eb-9bde-0648d8449482
|
2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 0 (arm-galera-10-6-1)
|
2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 1 (arm-galera-10-6-2)
|
2021-07-07 4:45:09 0 [Note] WSREP: Quorum results:
|
version = 6,
|
component = PRIMARY,
|
conf_id = 1,
|
members = 1/2 (joined/total),
|
act_id = 1,
|
last_appl. = 0,
|
protocols = 2/10/4 (gcs/repl/appl),
|
vote policy= 0,
|
group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8
|
2021-07-07 4:45:09 0 [Note] WSREP: Flow-control interval: [23, 23]
|
2021-07-07 4:45:09 1 [Note] WSREP: ####### processing CC 2, local, ordered
|
2021-07-07 4:45:09 1 [Note] WSREP: ####### My UUID: dff40154-dedd-11eb-8099-3206581b79af
|
2021-07-07 4:45:09 1 [Note] WSREP: Skipping cert index reset
|
2021-07-07 4:45:09 1 [Note] WSREP: REPL Protocols: 10 (5)
|
2021-07-07 4:45:09 1 [Note] WSREP: ####### Adjusting cert position: 1 -> 2
|
2021-07-07 4:45:09 0 [Note] WSREP: Service thread queue flushed.
|
2021-07-07 4:45:09 1 [Note] WSREP: ================================================
|
View:
|
id: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2
|
status: primary
|
protocol_version: 4
|
capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
|
final: no
|
own_index: 1
|
members(2):
|
0: 1b87f978-dede-11eb-a60b-b74d48a2b703, arm-galera-10-6-1
|
1: dff40154-dedd-11eb-8099-3206581b79af, arm-galera-10-6-2
|
=================================================
|
2021-07-07 4:45:09 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:45:09 1 [Note] WSREP: Lowest cert index boundary for CC from group: 2
|
2021-07-07 4:45:09 1 [Note] WSREP: Min available from gcache for CC from group: 1
|
2021-07-07 4:45:11 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') turning message relay requesting off
|
On the second node (joiner):
2021-07-07 4:45:08 0 [Note] WSREP: Loading provider /usr/local/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
|
2021-07-07 4:45:08 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/local/lib/libgalera_smm.so'
|
2021-07-07 4:45:09 0 [Note] WSREP: wsrep_load(): Galera 4.6(rrelease_26.4.6) by Codership Oy <info@codership.com> loaded successfully.
|
2021-07-07 4:45:09 0 [Note] WSREP: CRC-32C: using hardware acceleration.
|
2021-07-07 4:45:09 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
|
2021-07-07 4:45:09 0 [Note] WSREP: GCache DEBUG: opened preamble:
|
Version: 2
|
UUID: 00000000-0000-0000-0000-000000000000
|
Seqno: -1 - -1
|
Offset: -1
|
Synced: 0
|
2021-07-07 4:45:09 0 [Note] WSREP: Skipped GCache ring buffer recovery: could not determine history UUID.
|
2021-07-07 4:45:09 0 [Note] WSREP: Passing config to GCS: base_dir = /var/db/mysql/; base_host = 192.168.20.122; 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 = /var/db/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; 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 = 202; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum
|
2021-07-07 4:45:09 0 [Note] WSREP: Start replication
|
2021-07-07 4:45:09 0 [Note] WSREP: Connecting with bootstrap option: 0
|
2021-07-07 4:45:09 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
|
2021-07-07 4:45:09 0 [Note] WSREP: protonet asio version 0
|
2021-07-07 4:45:09 0 [Note] WSREP: Using CRC-32C for message checksums.
|
2021-07-07 4:45:09 0 [Note] WSREP: backend: asio
|
2021-07-07 4:45:09 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
|
2021-07-07 4:45:09 0 [Warning] WSREP: access file(/var/db/mysql//gvwstate.dat) failed(No such file or directory)
|
2021-07-07 4:45:09 0 [Note] WSREP: restore pc from disk failed
|
2021-07-07 4:45:09 0 [Note] WSREP: GMCast version 0
|
2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
|
2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
|
2021-07-07 4:45:09 0 [Note] WSREP: EVS version 1
|
2021-07-07 4:45:09 0 [Note] WSREP: gcomm: connecting to group 'testdb', peer '192.168.20.132:,192.168.20.122:'
|
2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://192.168.20.122:4567
|
2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') connection established to dff40154-8099 tcp://192.168.20.132:4567
|
2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
|
2021-07-07 4:45:09 0 [Note] WSREP: EVS version upgrade 0 -> 1
|
2021-07-07 4:45:09 0 [Note] WSREP: declaring dff40154-8099 at tcp://192.168.20.132:4567 stable
|
2021-07-07 4:45:09 0 [Note] WSREP: PC protocol upgrade 0 -> 1
|
2021-07-07 4:45:09 0 [Note] WSREP: Node dff40154-8099 state prim
|
2021-07-07 4:45:09 0 [Note] WSREP: view(view_id(PRIM,1b87f978-a60b,4) memb {
|
1b87f978-a60b,202
|
dff40154-8099,202
|
} joined {
|
} left {
|
} partitioned {
|
})
|
2021-07-07 4:45:09 0 [Note] WSREP: save pc into disk
|
2021-07-07 4:45:10 0 [Note] WSREP: gcomm: connected
|
2021-07-07 4:45:10 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
|
2021-07-07 4:45:10 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
|
2021-07-07 4:45:10 0 [Note] WSREP: Opened channel 'testdb'
|
2021-07-07 4:45:10 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
|
2021-07-07 4:45:10 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 1c291b89-dede-11eb-9bde-0648d8449482
|
2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 1c291b89-dede-11eb-9bde-0648d8449482
|
2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 0 (arm-galera-10-6-1)
|
2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 1 (arm-galera-10-6-2)
|
2021-07-07 4:45:10 0 [Note] WSREP: Quorum results:
|
version = 6,
|
component = PRIMARY,
|
conf_id = 1,
|
members = 1/2 (joined/total),
|
act_id = 1,
|
last_appl. = 0,
|
protocols = 2/10/4 (gcs/repl/appl),
|
vote policy= 0,
|
group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8
|
2021-07-07 4:45:10 0 [Note] WSREP: Flow-control interval: [23, 23]
|
2021-07-07 4:45:10 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2)
|
2021-07-07 4:45:10 2 [Note] WSREP: Starting rollbacker thread 2
|
2021-07-07 4:45:10 1 [Note] WSREP: Starting applier thread 1
|
2021-07-07 4:45:10 1 [Note] WSREP: ####### processing CC 2, local, ordered
|
2021-07-07 4:45:10 1 [Note] WSREP: Process first view: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 my uuid: 1b87f978-dede-11eb-a60b-b74d48a2b703
|
2021-07-07 4:45:10 1 [Note] WSREP: Server arm-galera-10-6-1 connected to cluster at position 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 with ID 1b87f978-dede-11eb-a60b-b74d48a2b703
|
2021-07-07 4:45:10 1 [Note] WSREP: Server status change disconnected -> connected
|
2021-07-07 4:45:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:45:10 1 [Note] WSREP: ####### My UUID: 1b87f978-dede-11eb-a60b-b74d48a2b703
|
2021-07-07 4:45:10 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
|
2021-07-07 4:45:10 0 [Note] WSREP: Service thread queue flushed.
|
2021-07-07 4:45:10 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
|
2021-07-07 4:45:10 1 [Note] WSREP: State transfer required:
|
Group state: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2
|
Local state: 00000000-0000-0000-0000-000000000000:-1
|
2021-07-07 4:45:10 1 [Note] WSREP: Server status change connected -> joiner
|
2021-07-07 4:45:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-07-07 4:45:10 0 [Note] WSREP: Joiner monitor thread started to monitor
|
2021-07-07 4:45:10 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '192.168.20.122' --datadir '/var/db/mysql/' --defaults-extra-file '/usr/local/etc/mysql/my.cnf' --parent '989' --mysqld-args --defaults-extra-file=/usr/local/etc/mysql/my.cnf --basedir=/usr/local --datadir=/var/db/mysql --plugin-dir=/usr/local/lib/mysql/plugin --log-error=/var/log/mysql/mysqld.err --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --port=3306'
|
2021-07-07 4:45:12 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') turning message relay requesting off
|
Attachments
Issue Links
- relates to
-
MDEV-10432 Remove bash/lsof dependencies from scripts
-
- Closed
-
Activity
Field | Original Value | New Value |
---|---|---|
Assignee | Julius Goryavsky [ sysprg ] |
Description |
This bug is also being tracked in the FreeBSD Bugzilla: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=256112
I created fresh FreeBSD VMs with fresh installs of MariaDB 10.6.3 I started the first node with "mysqld_safe --wsrep-new-cluster" and tried to have the second node connect. No data was changed on either node, just trying to get them to communicate. The first node remains in the "sync" state the entire time, never entering the "doror" state. The second node starts rsync, and is stuck listening for a connection indefinitely. Using the default configs for FreeBSD, with default bind-address commented out, and then this cnf file added on both nodes: {noformat} [galera] wsrep_on=ON wsrep_provider = /usr/local/lib/libgalera_smm.so wsrep_provider_options = "gmcast.segment=202;pc.weight=1" wsrep_cluster_name = "testdb" wsrep_cluster_address = "gcomm://192.168.20.132,192.168.20.122" wsrep_sst_method = rsync [mysqld] binlog_format=ROW bind-address=0.0.0.0 {noformat} On the first node (donor): {noformat} 2021-07-07 4:44:25 0 [Note] WSREP: Loading provider /usr/local/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/local/lib/libgalera_smm.so' 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_load(): Galera 4.6(rrelease_26.4.6) by Codership Oy <info@codership.com> loaded successfully. 2021-07-07 4:44:25 0 [Note] WSREP: CRC-32C: using hardware acceleration. 2021-07-07 4:44:25 0 [Note] WSREP: Found saved state: 4e704a59-dedc-11eb-a825-dfcedc24af98:-1, safe_to_bootstrap: 1 2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: opened preamble: Version: 2 UUID: 4e704a59-dedc-11eb-a825-dfcedc24af98 Seqno: -1 - -1 Offset: -1 Synced: 0 2021-07-07 4:44:25 0 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: 4e704a59-dedc-11eb-a825-dfcedc24af98, offset: -1 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer initial scan... 0.0% ( 0/134217752 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: Recovering GCache ring buffer: found gapless sequence 1-4 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer unused buffers scan... 0.0% ( 0/1264 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer unused buffers scan...100.0% (1264/1264 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): found 3/7 locked buffers 2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): free space: 134217016/134217728 2021-07-07 4:44:25 0 [Note] WSREP: Passing config to GCS: base_dir = /var/db/mysql/; base_host = 192.168.20.132; 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 = /var/db/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; 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 = 202; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum 2021-07-07 4:44:25 0 [Note] WSREP: Start replication 2021-07-07 4:44:25 0 [Note] WSREP: Connecting with bootstrap option: 1 2021-07-07 4:44:25 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:44:25 0 [Note] WSREP: protonet asio version 0 2021-07-07 4:44:25 0 [Note] WSREP: Using CRC-32C for message checksums. 2021-07-07 4:44:25 0 [Note] WSREP: backend: asio 2021-07-07 4:44:25 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 2021-07-07 4:44:25 0 [Note] WSREP: restore pc from disk successfully 2021-07-07 4:44:25 0 [Note] WSREP: GMCast version 0 2021-07-07 4:44:25 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567 2021-07-07 4:44:25 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') multicast: , ttl: 1 2021-07-07 4:44:25 0 [Note] WSREP: EVS version 1 2021-07-07 4:44:25 0 [Note] WSREP: gcomm: bootstrapping new group 'testdb' 2021-07-07 4:44:25 0 [Note] WSREP: start_prim is enabled, turn off pc_recovery 2021-07-07 4:44:25 0 [Note] WSREP: EVS version upgrade 0 -> 1 2021-07-07 4:44:25 0 [Note] WSREP: PC protocol upgrade 0 -> 1 2021-07-07 4:44:25 0 [Note] WSREP: Node dff40154-8099 state prim 2021-07-07 4:44:25 0 [Note] WSREP: view(view_id(PRIM,dff40154-8099,3) memb { dff40154-8099,202 } joined { } left { } partitioned { }) 2021-07-07 4:44:25 0 [Note] WSREP: save pc into disk 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr without UUID: tcp://192.168.20.122:4567 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr proto entry 0x42435460 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr without UUID: tcp://192.168.20.132:4567 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr proto entry 0x42435540 2021-07-07 4:44:25 0 [Note] WSREP: clear restored view 2021-07-07 4:44:25 0 [Note] WSREP: gcomm: connected 2021-07-07 4:44:25 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636 2021-07-07 4:44:25 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2021-07-07 4:44:25 0 [Note] WSREP: Opened channel 'testdb' 2021-07-07 4:44:25 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1 2021-07-07 4:44:25 0 [Note] WSREP: Starting new group from scratch: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:44:25 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 01bc0065-dede-11eb-85ce-9a71a683bc8e 2021-07-07 4:44:25 1 [Note] WSREP: Starting applier thread 1 2021-07-07 4:44:25 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 01bc0065-dede-11eb-85ce-9a71a683bc8e 2021-07-07 4:44:25 0 [Note] WSREP: STATE EXCHANGE: got state msg: 01bc0065-dede-11eb-85ce-9a71a683bc8e from 0 (arm-galera-10-6-2) 2021-07-07 4:44:25 0 [Note] WSREP: Quorum results: version = 6, component = PRIMARY, conf_id = 0, members = 1/1 (joined/total), act_id = 0, last_appl. = 0, protocols = 2/10/4 (gcs/repl/appl), vote policy= 0, group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:44:25 0 [Note] WSREP: Flow-control interval: [16, 16] 2021-07-07 4:44:25 0 [Note] WSREP: Restored state OPEN -> JOINED (1) 2021-07-07 4:44:25 0 [Note] WSREP: Member 0.202 (arm-galera-10-6-2) synced with group. 2021-07-07 4:44:25 2 [Note] WSREP: Starting rollbacker thread 2 2021-07-07 4:44:25 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 1) 2021-07-07 4:44:25 1 [Note] WSREP: ####### processing CC 1, local, ordered 2021-07-07 4:44:25 1 [Note] WSREP: Process first view: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 my uuid: dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:44:25 1 [Note] WSREP: Server arm-galera-10-6-2 connected to cluster at position 01bbfaaf-dede-11eb-b363-16edbc96f9c8:1 with ID dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:44:25 1 [Note] WSREP: Server status change disconnected -> connected 2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 1 [Note] WSREP: ####### My UUID: dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:44:25 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: no 2021-07-07 4:44:25 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:44:25 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1 2021-07-07 4:44:25 1 [Note] WSREP: REPL Protocols: 10 (5) 2021-07-07 4:44:25 1 [Note] WSREP: ####### Adjusting cert position: -1 -> 1 2021-07-07 4:44:25 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:44:25 1 [Note] WSREP: GCache history reset: 4e704a59-dedc-11eb-a825-dfcedc24af98:4 -> 01bbfaaf-dede-11eb-b363-16edbc96f9c8:0 2021-07-07 4:44:25 1 [Note] WSREP: GCache DEBUG: RingBuffer::seqno_reset(): discarded 712 bytes 2021-07-07 4:44:25 1 [Note] WSREP: GCache DEBUG: RingBuffer::seqno_reset(): found 0/1 locked buffers 2021-07-07 4:44:25 1 [Note] WSREP: ================================================ View: id: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:1 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final: no own_index: 0 members(1): 0: dff40154-dedd-11eb-8099-3206581b79af, arm-galera-10-6-2 ================================================= 2021-07-07 4:44:25 1 [Note] WSREP: Server status change connected -> joiner 2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 1 [Note] WSREP: Server status change joiner -> initializing 2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2021-07-07 4:44:25 0 [Note] InnoDB: Number of pools: 1 2021-07-07 4:44:25 0 [Note] InnoDB: Using generic crc32 instructions 2021-07-07 4:44:25 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728 2021-07-07 4:44:25 0 [Note] InnoDB: Completed initialization of buffer pool 2021-07-07 4:44:25 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=78394,78394 2021-07-07 4:44:25 0 [Note] InnoDB: Starting final batch to recover 4 pages from redo log. 2021-07-07 4:44:25 0 [Note] InnoDB: 128 rollback segments are active. 2021-07-07 4:44:25 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1" 2021-07-07 4:44:25 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2021-07-07 4:44:25 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2021-07-07 4:44:25 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2021-07-07 4:44:25 0 [Note] InnoDB: 10.6.3 started; log sequence number 82877; transaction id 77 2021-07-07 4:44:25 0 [Note] InnoDB: Loading buffer pool(s) from /var/db/mysql/ib_buffer_pool 2021-07-07 4:44:25 0 [Note] Plugin 'FEEDBACK' is disabled. 2021-07-07 4:44:25 0 [Note] Recovering after a crash using tc.log 2021-07-07 4:44:25 0 [Note] Starting table crash recovery... 2021-07-07 4:44:25 0 [Note] Crash table recovery finished. 2021-07-07 4:44:25 0 [Note] InnoDB: Buffer pool(s) load completed at 210707 4:44:25 2021-07-07 4:44:25 0 [Note] Server socket created on IP: '0.0.0.0'. 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_init_schema_and_SR 0x0 2021-07-07 4:44:25 0 [Note] WSREP: Server initialized 2021-07-07 4:44:25 0 [Note] WSREP: Server status change initializing -> initialized 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 1 [Note] WSREP: Bootstrapping a new cluster, setting initial position to 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:44:26 4 [Note] WSREP: Recovered cluster id 4e704a59-dedc-11eb-a825-dfcedc24af98 2021-07-07 4:44:26 1 [Note] WSREP: Server status change initialized -> joined 2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:26 0 [Note] /usr/local/libexec/mariadbd: ready for connections. Version: '10.6.3-MariaDB' socket: '/var/run/mysql/mysql.sock' port: 3306 FreeBSD Ports 2021-07-07 4:44:26 1 [Note] WSREP: Lowest cert index boundary for CC from group: 1 2021-07-07 4:44:26 1 [Note] WSREP: Min available from gcache for CC from group: 1 2021-07-07 4:44:26 1 [Note] WSREP: Server arm-galera-10-6-2 synced with group 2021-07-07 4:44:26 1 [Note] WSREP: Server status change joined -> synced 2021-07-07 4:44:26 1 [Note] WSREP: Synchronized with group, ready for connections 2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:08 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') connection established to 1b87f978-a60b tcp://192.168.20.122:4567 2021-07-07 4:45:08 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 2021-07-07 4:45:09 0 [Note] WSREP: declaring 1b87f978-a60b at tcp://192.168.20.122:4567 stable 2021-07-07 4:45:09 0 [Note] WSREP: Node dff40154-8099 state prim 2021-07-07 4:45:09 0 [Note] WSREP: view(view_id(PRIM,1b87f978-a60b,4) memb { 1b87f978-a60b,202 dff40154-8099,202 } joined { } left { } partitioned { }) 2021-07-07 4:45:09 0 [Note] WSREP: save pc into disk 2021-07-07 4:45:09 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID. 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 1c291b89-dede-11eb-9bde-0648d8449482 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 0 (arm-galera-10-6-1) 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 1 (arm-galera-10-6-2) 2021-07-07 4:45:09 0 [Note] WSREP: Quorum results: version = 6, component = PRIMARY, conf_id = 1, members = 1/2 (joined/total), act_id = 1, last_appl. = 0, protocols = 2/10/4 (gcs/repl/appl), vote policy= 0, group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:45:09 0 [Note] WSREP: Flow-control interval: [23, 23] 2021-07-07 4:45:09 1 [Note] WSREP: ####### processing CC 2, local, ordered 2021-07-07 4:45:09 1 [Note] WSREP: ####### My UUID: dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:45:09 1 [Note] WSREP: Skipping cert index reset 2021-07-07 4:45:09 1 [Note] WSREP: REPL Protocols: 10 (5) 2021-07-07 4:45:09 1 [Note] WSREP: ####### Adjusting cert position: 1 -> 2 2021-07-07 4:45:09 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:45:09 1 [Note] WSREP: ================================================ View: id: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final: no own_index: 1 members(2): 0: 1b87f978-dede-11eb-a60b-b74d48a2b703, arm-galera-10-6-1 1: dff40154-dedd-11eb-8099-3206581b79af, arm-galera-10-6-2 ================================================= 2021-07-07 4:45:09 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:09 1 [Note] WSREP: Lowest cert index boundary for CC from group: 2 2021-07-07 4:45:09 1 [Note] WSREP: Min available from gcache for CC from group: 1 2021-07-07 4:45:11 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') turning message relay requesting off {noformat} On the second node (joiner): {noformat} 2021-07-07 4:45:08 0 [Note] WSREP: Loading provider /usr/local/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:45:08 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/local/lib/libgalera_smm.so' 2021-07-07 4:45:09 0 [Note] WSREP: wsrep_load(): Galera 4.6(rrelease_26.4.6) by Codership Oy <info@codership.com> loaded successfully. 2021-07-07 4:45:09 0 [Note] WSREP: CRC-32C: using hardware acceleration. 2021-07-07 4:45:09 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1 2021-07-07 4:45:09 0 [Note] WSREP: GCache DEBUG: opened preamble: Version: 2 UUID: 00000000-0000-0000-0000-000000000000 Seqno: -1 - -1 Offset: -1 Synced: 0 2021-07-07 4:45:09 0 [Note] WSREP: Skipped GCache ring buffer recovery: could not determine history UUID. 2021-07-07 4:45:09 0 [Note] WSREP: Passing config to GCS: base_dir = /var/db/mysql/; base_host = 192.168.20.122; 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 = /var/db/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; 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 = 202; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum 2021-07-07 4:45:09 0 [Note] WSREP: Start replication 2021-07-07 4:45:09 0 [Note] WSREP: Connecting with bootstrap option: 0 2021-07-07 4:45:09 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:45:09 0 [Note] WSREP: protonet asio version 0 2021-07-07 4:45:09 0 [Note] WSREP: Using CRC-32C for message checksums. 2021-07-07 4:45:09 0 [Note] WSREP: backend: asio 2021-07-07 4:45:09 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 2021-07-07 4:45:09 0 [Warning] WSREP: access file(/var/db/mysql//gvwstate.dat) failed(No such file or directory) 2021-07-07 4:45:09 0 [Note] WSREP: restore pc from disk failed 2021-07-07 4:45:09 0 [Note] WSREP: GMCast version 0 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') multicast: , ttl: 1 2021-07-07 4:45:09 0 [Note] WSREP: EVS version 1 2021-07-07 4:45:09 0 [Note] WSREP: gcomm: connecting to group 'testdb', peer '192.168.20.132:,192.168.20.122:' 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://192.168.20.122:4567 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') connection established to dff40154-8099 tcp://192.168.20.132:4567 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 2021-07-07 4:45:09 0 [Note] WSREP: EVS version upgrade 0 -> 1 2021-07-07 4:45:09 0 [Note] WSREP: declaring dff40154-8099 at tcp://192.168.20.132:4567 stable 2021-07-07 4:45:09 0 [Note] WSREP: PC protocol upgrade 0 -> 1 2021-07-07 4:45:09 0 [Note] WSREP: Node dff40154-8099 state prim 2021-07-07 4:45:09 0 [Note] WSREP: view(view_id(PRIM,1b87f978-a60b,4) memb { 1b87f978-a60b,202 dff40154-8099,202 } joined { } left { } partitioned { }) 2021-07-07 4:45:09 0 [Note] WSREP: save pc into disk 2021-07-07 4:45:10 0 [Note] WSREP: gcomm: connected 2021-07-07 4:45:10 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636 2021-07-07 4:45:10 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2021-07-07 4:45:10 0 [Note] WSREP: Opened channel 'testdb' 2021-07-07 4:45:10 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2 2021-07-07 4:45:10 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 1c291b89-dede-11eb-9bde-0648d8449482 2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 1c291b89-dede-11eb-9bde-0648d8449482 2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 0 (arm-galera-10-6-1) 2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 1 (arm-galera-10-6-2) 2021-07-07 4:45:10 0 [Note] WSREP: Quorum results: version = 6, component = PRIMARY, conf_id = 1, members = 1/2 (joined/total), act_id = 1, last_appl. = 0, protocols = 2/10/4 (gcs/repl/appl), vote policy= 0, group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:45:10 0 [Note] WSREP: Flow-control interval: [23, 23] 2021-07-07 4:45:10 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2) 2021-07-07 4:45:10 2 [Note] WSREP: Starting rollbacker thread 2 2021-07-07 4:45:10 1 [Note] WSREP: Starting applier thread 1 2021-07-07 4:45:10 1 [Note] WSREP: ####### processing CC 2, local, ordered 2021-07-07 4:45:10 1 [Note] WSREP: Process first view: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 my uuid: 1b87f978-dede-11eb-a60b-b74d48a2b703 2021-07-07 4:45:10 1 [Note] WSREP: Server arm-galera-10-6-1 connected to cluster at position 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 with ID 1b87f978-dede-11eb-a60b-b74d48a2b703 2021-07-07 4:45:10 1 [Note] WSREP: Server status change disconnected -> connected 2021-07-07 4:45:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:10 1 [Note] WSREP: ####### My UUID: 1b87f978-dede-11eb-a60b-b74d48a2b703 2021-07-07 4:45:10 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes 2021-07-07 4:45:10 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:45:10 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1 2021-07-07 4:45:10 1 [Note] WSREP: State transfer required: Group state: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 Local state: 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:45:10 1 [Note] WSREP: Server status change connected -> joiner 2021-07-07 4:45:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:10 0 [Note] WSREP: Joiner monitor thread started to monitor 2021-07-07 4:45:10 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '192.168.20.122' --datadir '/var/db/mysql/' --defaults-extra-file '/usr/local/etc/mysql/my.cnf' --parent '989' --mysqld-args --defaults-extra-file=/usr/local/etc/mysql/my.cnf --basedir=/usr/local --datadir=/var/db/mysql --plugin-dir=/usr/local/lib/mysql/plugin --log-error=/var/log/mysql/mysqld.err --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --port=3306' 2021-07-07 4:45:12 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') turning message relay requesting off {noformat} |
This bug is also being tracked in the FreeBSD Bugzilla: https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=256112
I created fresh FreeBSD VMs with fresh installs of MariaDB 10.6.3 I started the first node with "mysqld_safe --wsrep-new-cluster" and tried to have the second node connect. No data was changed on either node, just trying to get them to communicate. The first node remains in the "sync" state the entire time, never entering the "donor" state. The second node starts rsync, and is stuck listening for a connection indefinitely. Using the default configs for FreeBSD, with default bind-address commented out, and then this cnf file added on both nodes: {noformat} [galera] wsrep_on=ON wsrep_provider = /usr/local/lib/libgalera_smm.so wsrep_provider_options = "gmcast.segment=202;pc.weight=1" wsrep_cluster_name = "testdb" wsrep_cluster_address = "gcomm://192.168.20.132,192.168.20.122" wsrep_sst_method = rsync [mysqld] binlog_format=ROW bind-address=0.0.0.0 {noformat} On the first node (donor): {noformat} 2021-07-07 4:44:25 0 [Note] WSREP: Loading provider /usr/local/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/local/lib/libgalera_smm.so' 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_load(): Galera 4.6(rrelease_26.4.6) by Codership Oy <info@codership.com> loaded successfully. 2021-07-07 4:44:25 0 [Note] WSREP: CRC-32C: using hardware acceleration. 2021-07-07 4:44:25 0 [Note] WSREP: Found saved state: 4e704a59-dedc-11eb-a825-dfcedc24af98:-1, safe_to_bootstrap: 1 2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: opened preamble: Version: 2 UUID: 4e704a59-dedc-11eb-a825-dfcedc24af98 Seqno: -1 - -1 Offset: -1 Synced: 0 2021-07-07 4:44:25 0 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: 4e704a59-dedc-11eb-a825-dfcedc24af98, offset: -1 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer initial scan... 0.0% ( 0/134217752 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: Recovering GCache ring buffer: found gapless sequence 1-4 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer unused buffers scan... 0.0% ( 0/1264 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: GCache::RingBuffer unused buffers scan...100.0% (1264/1264 bytes) complete. 2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): found 3/7 locked buffers 2021-07-07 4:44:25 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): free space: 134217016/134217728 2021-07-07 4:44:25 0 [Note] WSREP: Passing config to GCS: base_dir = /var/db/mysql/; base_host = 192.168.20.132; 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 = /var/db/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; 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 = 202; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum 2021-07-07 4:44:25 0 [Note] WSREP: Start replication 2021-07-07 4:44:25 0 [Note] WSREP: Connecting with bootstrap option: 1 2021-07-07 4:44:25 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:44:25 0 [Note] WSREP: protonet asio version 0 2021-07-07 4:44:25 0 [Note] WSREP: Using CRC-32C for message checksums. 2021-07-07 4:44:25 0 [Note] WSREP: backend: asio 2021-07-07 4:44:25 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 2021-07-07 4:44:25 0 [Note] WSREP: restore pc from disk successfully 2021-07-07 4:44:25 0 [Note] WSREP: GMCast version 0 2021-07-07 4:44:25 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567 2021-07-07 4:44:25 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') multicast: , ttl: 1 2021-07-07 4:44:25 0 [Note] WSREP: EVS version 1 2021-07-07 4:44:25 0 [Note] WSREP: gcomm: bootstrapping new group 'testdb' 2021-07-07 4:44:25 0 [Note] WSREP: start_prim is enabled, turn off pc_recovery 2021-07-07 4:44:25 0 [Note] WSREP: EVS version upgrade 0 -> 1 2021-07-07 4:44:25 0 [Note] WSREP: PC protocol upgrade 0 -> 1 2021-07-07 4:44:25 0 [Note] WSREP: Node dff40154-8099 state prim 2021-07-07 4:44:25 0 [Note] WSREP: view(view_id(PRIM,dff40154-8099,3) memb { dff40154-8099,202 } joined { } left { } partitioned { }) 2021-07-07 4:44:25 0 [Note] WSREP: save pc into disk 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr without UUID: tcp://192.168.20.122:4567 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr proto entry 0x42435460 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr without UUID: tcp://192.168.20.132:4567 2021-07-07 4:44:25 0 [Note] WSREP: discarding pending addr proto entry 0x42435540 2021-07-07 4:44:25 0 [Note] WSREP: clear restored view 2021-07-07 4:44:25 0 [Note] WSREP: gcomm: connected 2021-07-07 4:44:25 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636 2021-07-07 4:44:25 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2021-07-07 4:44:25 0 [Note] WSREP: Opened channel 'testdb' 2021-07-07 4:44:25 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1 2021-07-07 4:44:25 0 [Note] WSREP: Starting new group from scratch: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:44:25 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 01bc0065-dede-11eb-85ce-9a71a683bc8e 2021-07-07 4:44:25 1 [Note] WSREP: Starting applier thread 1 2021-07-07 4:44:25 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 01bc0065-dede-11eb-85ce-9a71a683bc8e 2021-07-07 4:44:25 0 [Note] WSREP: STATE EXCHANGE: got state msg: 01bc0065-dede-11eb-85ce-9a71a683bc8e from 0 (arm-galera-10-6-2) 2021-07-07 4:44:25 0 [Note] WSREP: Quorum results: version = 6, component = PRIMARY, conf_id = 0, members = 1/1 (joined/total), act_id = 0, last_appl. = 0, protocols = 2/10/4 (gcs/repl/appl), vote policy= 0, group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:44:25 0 [Note] WSREP: Flow-control interval: [16, 16] 2021-07-07 4:44:25 0 [Note] WSREP: Restored state OPEN -> JOINED (1) 2021-07-07 4:44:25 0 [Note] WSREP: Member 0.202 (arm-galera-10-6-2) synced with group. 2021-07-07 4:44:25 2 [Note] WSREP: Starting rollbacker thread 2 2021-07-07 4:44:25 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 1) 2021-07-07 4:44:25 1 [Note] WSREP: ####### processing CC 1, local, ordered 2021-07-07 4:44:25 1 [Note] WSREP: Process first view: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 my uuid: dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:44:25 1 [Note] WSREP: Server arm-galera-10-6-2 connected to cluster at position 01bbfaaf-dede-11eb-b363-16edbc96f9c8:1 with ID dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:44:25 1 [Note] WSREP: Server status change disconnected -> connected 2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 1 [Note] WSREP: ####### My UUID: dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:44:25 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: no 2021-07-07 4:44:25 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:44:25 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1 2021-07-07 4:44:25 1 [Note] WSREP: REPL Protocols: 10 (5) 2021-07-07 4:44:25 1 [Note] WSREP: ####### Adjusting cert position: -1 -> 1 2021-07-07 4:44:25 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:44:25 1 [Note] WSREP: GCache history reset: 4e704a59-dedc-11eb-a825-dfcedc24af98:4 -> 01bbfaaf-dede-11eb-b363-16edbc96f9c8:0 2021-07-07 4:44:25 1 [Note] WSREP: GCache DEBUG: RingBuffer::seqno_reset(): discarded 712 bytes 2021-07-07 4:44:25 1 [Note] WSREP: GCache DEBUG: RingBuffer::seqno_reset(): found 0/1 locked buffers 2021-07-07 4:44:25 1 [Note] WSREP: ================================================ View: id: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:1 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final: no own_index: 0 members(1): 0: dff40154-dedd-11eb-8099-3206581b79af, arm-galera-10-6-2 ================================================= 2021-07-07 4:44:25 1 [Note] WSREP: Server status change connected -> joiner 2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 1 [Note] WSREP: Server status change joiner -> initializing 2021-07-07 4:44:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2021-07-07 4:44:25 0 [Note] InnoDB: Number of pools: 1 2021-07-07 4:44:25 0 [Note] InnoDB: Using generic crc32 instructions 2021-07-07 4:44:25 0 [Note] InnoDB: Initializing buffer pool, total size = 134217728, chunk size = 134217728 2021-07-07 4:44:25 0 [Note] InnoDB: Completed initialization of buffer pool 2021-07-07 4:44:25 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=78394,78394 2021-07-07 4:44:25 0 [Note] InnoDB: Starting final batch to recover 4 pages from redo log. 2021-07-07 4:44:25 0 [Note] InnoDB: 128 rollback segments are active. 2021-07-07 4:44:25 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1" 2021-07-07 4:44:25 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2021-07-07 4:44:25 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2021-07-07 4:44:25 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2021-07-07 4:44:25 0 [Note] InnoDB: 10.6.3 started; log sequence number 82877; transaction id 77 2021-07-07 4:44:25 0 [Note] InnoDB: Loading buffer pool(s) from /var/db/mysql/ib_buffer_pool 2021-07-07 4:44:25 0 [Note] Plugin 'FEEDBACK' is disabled. 2021-07-07 4:44:25 0 [Note] Recovering after a crash using tc.log 2021-07-07 4:44:25 0 [Note] Starting table crash recovery... 2021-07-07 4:44:25 0 [Note] Crash table recovery finished. 2021-07-07 4:44:25 0 [Note] InnoDB: Buffer pool(s) load completed at 210707 4:44:25 2021-07-07 4:44:25 0 [Note] Server socket created on IP: '0.0.0.0'. 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_init_schema_and_SR 0x0 2021-07-07 4:44:25 0 [Note] WSREP: Server initialized 2021-07-07 4:44:25 0 [Note] WSREP: Server status change initializing -> initialized 2021-07-07 4:44:25 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:25 1 [Note] WSREP: Bootstrapping a new cluster, setting initial position to 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:44:26 4 [Note] WSREP: Recovered cluster id 4e704a59-dedc-11eb-a825-dfcedc24af98 2021-07-07 4:44:26 1 [Note] WSREP: Server status change initialized -> joined 2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:44:26 0 [Note] /usr/local/libexec/mariadbd: ready for connections. Version: '10.6.3-MariaDB' socket: '/var/run/mysql/mysql.sock' port: 3306 FreeBSD Ports 2021-07-07 4:44:26 1 [Note] WSREP: Lowest cert index boundary for CC from group: 1 2021-07-07 4:44:26 1 [Note] WSREP: Min available from gcache for CC from group: 1 2021-07-07 4:44:26 1 [Note] WSREP: Server arm-galera-10-6-2 synced with group 2021-07-07 4:44:26 1 [Note] WSREP: Server status change joined -> synced 2021-07-07 4:44:26 1 [Note] WSREP: Synchronized with group, ready for connections 2021-07-07 4:44:26 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:08 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') connection established to 1b87f978-a60b tcp://192.168.20.122:4567 2021-07-07 4:45:08 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 2021-07-07 4:45:09 0 [Note] WSREP: declaring 1b87f978-a60b at tcp://192.168.20.122:4567 stable 2021-07-07 4:45:09 0 [Note] WSREP: Node dff40154-8099 state prim 2021-07-07 4:45:09 0 [Note] WSREP: view(view_id(PRIM,1b87f978-a60b,4) memb { 1b87f978-a60b,202 dff40154-8099,202 } joined { } left { } partitioned { }) 2021-07-07 4:45:09 0 [Note] WSREP: save pc into disk 2021-07-07 4:45:09 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID. 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 1c291b89-dede-11eb-9bde-0648d8449482 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 0 (arm-galera-10-6-1) 2021-07-07 4:45:09 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 1 (arm-galera-10-6-2) 2021-07-07 4:45:09 0 [Note] WSREP: Quorum results: version = 6, component = PRIMARY, conf_id = 1, members = 1/2 (joined/total), act_id = 1, last_appl. = 0, protocols = 2/10/4 (gcs/repl/appl), vote policy= 0, group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:45:09 0 [Note] WSREP: Flow-control interval: [23, 23] 2021-07-07 4:45:09 1 [Note] WSREP: ####### processing CC 2, local, ordered 2021-07-07 4:45:09 1 [Note] WSREP: ####### My UUID: dff40154-dedd-11eb-8099-3206581b79af 2021-07-07 4:45:09 1 [Note] WSREP: Skipping cert index reset 2021-07-07 4:45:09 1 [Note] WSREP: REPL Protocols: 10 (5) 2021-07-07 4:45:09 1 [Note] WSREP: ####### Adjusting cert position: 1 -> 2 2021-07-07 4:45:09 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:45:09 1 [Note] WSREP: ================================================ View: id: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 status: primary protocol_version: 4 capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO final: no own_index: 1 members(2): 0: 1b87f978-dede-11eb-a60b-b74d48a2b703, arm-galera-10-6-1 1: dff40154-dedd-11eb-8099-3206581b79af, arm-galera-10-6-2 ================================================= 2021-07-07 4:45:09 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:09 1 [Note] WSREP: Lowest cert index boundary for CC from group: 2 2021-07-07 4:45:09 1 [Note] WSREP: Min available from gcache for CC from group: 1 2021-07-07 4:45:11 0 [Note] WSREP: (dff40154-8099, 'tcp://0.0.0.0:4567') turning message relay requesting off {noformat} On the second node (joiner): {noformat} 2021-07-07 4:45:08 0 [Note] WSREP: Loading provider /usr/local/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:45:08 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/local/lib/libgalera_smm.so' 2021-07-07 4:45:09 0 [Note] WSREP: wsrep_load(): Galera 4.6(rrelease_26.4.6) by Codership Oy <info@codership.com> loaded successfully. 2021-07-07 4:45:09 0 [Note] WSREP: CRC-32C: using hardware acceleration. 2021-07-07 4:45:09 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1 2021-07-07 4:45:09 0 [Note] WSREP: GCache DEBUG: opened preamble: Version: 2 UUID: 00000000-0000-0000-0000-000000000000 Seqno: -1 - -1 Offset: -1 Synced: 0 2021-07-07 4:45:09 0 [Note] WSREP: Skipped GCache ring buffer recovery: could not determine history UUID. 2021-07-07 4:45:09 0 [Note] WSREP: Passing config to GCS: base_dir = /var/db/mysql/; base_host = 192.168.20.122; 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 = /var/db/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; 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 = 202; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum 2021-07-07 4:45:09 0 [Note] WSREP: Start replication 2021-07-07 4:45:09 0 [Note] WSREP: Connecting with bootstrap option: 0 2021-07-07 4:45:09 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:45:09 0 [Note] WSREP: protonet asio version 0 2021-07-07 4:45:09 0 [Note] WSREP: Using CRC-32C for message checksums. 2021-07-07 4:45:09 0 [Note] WSREP: backend: asio 2021-07-07 4:45:09 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 2021-07-07 4:45:09 0 [Warning] WSREP: access file(/var/db/mysql//gvwstate.dat) failed(No such file or directory) 2021-07-07 4:45:09 0 [Note] WSREP: restore pc from disk failed 2021-07-07 4:45:09 0 [Note] WSREP: GMCast version 0 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') multicast: , ttl: 1 2021-07-07 4:45:09 0 [Note] WSREP: EVS version 1 2021-07-07 4:45:09 0 [Note] WSREP: gcomm: connecting to group 'testdb', peer '192.168.20.132:,192.168.20.122:' 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://192.168.20.122:4567 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') connection established to dff40154-8099 tcp://192.168.20.132:4567 2021-07-07 4:45:09 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 2021-07-07 4:45:09 0 [Note] WSREP: EVS version upgrade 0 -> 1 2021-07-07 4:45:09 0 [Note] WSREP: declaring dff40154-8099 at tcp://192.168.20.132:4567 stable 2021-07-07 4:45:09 0 [Note] WSREP: PC protocol upgrade 0 -> 1 2021-07-07 4:45:09 0 [Note] WSREP: Node dff40154-8099 state prim 2021-07-07 4:45:09 0 [Note] WSREP: view(view_id(PRIM,1b87f978-a60b,4) memb { 1b87f978-a60b,202 dff40154-8099,202 } joined { } left { } partitioned { }) 2021-07-07 4:45:09 0 [Note] WSREP: save pc into disk 2021-07-07 4:45:10 0 [Note] WSREP: gcomm: connected 2021-07-07 4:45:10 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636 2021-07-07 4:45:10 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0) 2021-07-07 4:45:10 0 [Note] WSREP: Opened channel 'testdb' 2021-07-07 4:45:10 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2 2021-07-07 4:45:10 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 1c291b89-dede-11eb-9bde-0648d8449482 2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 1c291b89-dede-11eb-9bde-0648d8449482 2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 0 (arm-galera-10-6-1) 2021-07-07 4:45:10 0 [Note] WSREP: STATE EXCHANGE: got state msg: 1c291b89-dede-11eb-9bde-0648d8449482 from 1 (arm-galera-10-6-2) 2021-07-07 4:45:10 0 [Note] WSREP: Quorum results: version = 6, component = PRIMARY, conf_id = 1, members = 1/2 (joined/total), act_id = 1, last_appl. = 0, protocols = 2/10/4 (gcs/repl/appl), vote policy= 0, group UUID = 01bbfaaf-dede-11eb-b363-16edbc96f9c8 2021-07-07 4:45:10 0 [Note] WSREP: Flow-control interval: [23, 23] 2021-07-07 4:45:10 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2) 2021-07-07 4:45:10 2 [Note] WSREP: Starting rollbacker thread 2 2021-07-07 4:45:10 1 [Note] WSREP: Starting applier thread 1 2021-07-07 4:45:10 1 [Note] WSREP: ####### processing CC 2, local, ordered 2021-07-07 4:45:10 1 [Note] WSREP: Process first view: 01bbfaaf-dede-11eb-b363-16edbc96f9c8 my uuid: 1b87f978-dede-11eb-a60b-b74d48a2b703 2021-07-07 4:45:10 1 [Note] WSREP: Server arm-galera-10-6-1 connected to cluster at position 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 with ID 1b87f978-dede-11eb-a60b-b74d48a2b703 2021-07-07 4:45:10 1 [Note] WSREP: Server status change disconnected -> connected 2021-07-07 4:45:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:10 1 [Note] WSREP: ####### My UUID: 1b87f978-dede-11eb-a60b-b74d48a2b703 2021-07-07 4:45:10 1 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes 2021-07-07 4:45:10 0 [Note] WSREP: Service thread queue flushed. 2021-07-07 4:45:10 1 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1 2021-07-07 4:45:10 1 [Note] WSREP: State transfer required: Group state: 01bbfaaf-dede-11eb-b363-16edbc96f9c8:2 Local state: 00000000-0000-0000-0000-000000000000:-1 2021-07-07 4:45:10 1 [Note] WSREP: Server status change connected -> joiner 2021-07-07 4:45:10 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification. 2021-07-07 4:45:10 0 [Note] WSREP: Joiner monitor thread started to monitor 2021-07-07 4:45:10 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '192.168.20.122' --datadir '/var/db/mysql/' --defaults-extra-file '/usr/local/etc/mysql/my.cnf' --parent '989' --mysqld-args --defaults-extra-file=/usr/local/etc/mysql/my.cnf --basedir=/usr/local --datadir=/var/db/mysql --plugin-dir=/usr/local/lib/mysql/plugin --log-error=/var/log/mysql/mysqld.err --pid-file=/var/run/mysql/mysqld.pid --socket=/var/run/mysql/mysql.sock --port=3306' 2021-07-07 4:45:12 0 [Note] WSREP: (1b87f978-a60b, 'tcp://0.0.0.0:4567') turning message relay requesting off {noformat} |
Priority | Major [ 3 ] | Critical [ 2 ] |
Priority | Critical [ 2 ] | Major [ 3 ] |
Link |
This issue relates to |
Attachment | wsrep_sst_rsync_freebsd.diff [ 58545 ] |
Fix Version/s | 10.2 [ 14601 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Fix Version/s | 10.4 [ 22408 ] | |
Fix Version/s | 10.5 [ 23123 ] | |
Fix Version/s | 10.6 [ 24028 ] | |
Fix Version/s | 10.7 [ 24805 ] |
Status | Open [ 1 ] | In Progress [ 3 ] |
Assignee | Julius Goryavsky [ sysprg ] | Jan Lindström [ jplindst ] |
Status | In Progress [ 3 ] | In Review [ 10002 ] |
Assignee | Jan Lindström [ jplindst ] | Julius Goryavsky [ sysprg ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Affects Version/s | 10.2 [ 14601 ] | |
Affects Version/s | 10.3 [ 22126 ] | |
Affects Version/s | 10.4 [ 22408 ] | |
Affects Version/s | 10.5 [ 23123 ] | |
Affects Version/s | 10.7 [ 24805 ] |
issue.field.resolutiondate | 2021-08-16 09:10:27.0 | 2021-08-16 09:10:27.936 |
Fix Version/s | 10.2.41 [ 26032 ] | |
Fix Version/s | 10.3.32 [ 26029 ] | |
Fix Version/s | 10.4.22 [ 26031 ] | |
Fix Version/s | 10.5.13 [ 26026 ] | |
Fix Version/s | 10.6.5 [ 26034 ] | |
Fix Version/s | 10.7.0 [ 26072 ] | |
Fix Version/s | 10.2 [ 14601 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Fix Version/s | 10.4 [ 22408 ] | |
Fix Version/s | 10.5 [ 23123 ] | |
Fix Version/s | 10.6 [ 24028 ] | |
Fix Version/s | 10.7 [ 24805 ] | |
Resolution | Fixed [ 1 ] | |
Status | Stalled [ 10000 ] | Closed [ 6 ] |
Summary | Galera WSREP SST broken on 10.6 under FreeBSD | Galera WSREP SST broken under FreeBSD |
Workflow | MariaDB v3 [ 123300 ] | MariaDB v4 [ 159488 ] |
Since this has sat idle for a month, I decided to delve further into this myself. Log files were certainly unhelpful in this one.
Turns out that the non-"lsof" path in the rsync sst script is once again broken. This has been something that has broken countless times over the year, and would be very much appreciated if there was actually a unit test for non-lsof users, or make it a hard requirement that this is no longer supported.
For reference:
MDEV-10432