[MDEV-27173] Galera crash with "Unknown writeset version: -1" while node recovers Created: 2021-12-06  Updated: 2022-09-30  Resolved: 2022-09-30

Status: Closed
Project: MariaDB Server
Component/s: Galera, Galera SST
Affects Version/s: 10.4.18
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Andras Marinescu Assignee: Jan Lindström (Inactive)
Resolution: Incomplete Votes: 0
Labels: None
Environment:

CentOS 7.8


Issue Links:
Relates
relates to MDEV-25025 SIGABRT in galera::WriteSetOut::gather Open

 Description   

We are experiencing random crashes when a galera node is trying to recover after a restart.
I have attached the logs for the crash bellow.
Unfortunately we have no steps to replicate as it happens randomly and very rare (once in a few weeks).

2021-12-04 23:08:29 0 [Note] InnoDB: Using Linux native AIO
2021-12-04 23:08:29 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2021-12-04 23:08:29 0 [Note] InnoDB: Uses event mutexes
2021-12-04 23:08:29 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2021-12-04 23:08:29 0 [Note] InnoDB: Number of pools: 1
2021-12-04 23:08:29 0 [Note] InnoDB: Using SSE2 crc32 instructions
2021-12-04 23:08:29 0 [Note] InnoDB: Initializing buffer pool, total size = 4G, instances = 4, chunk size = 128M
2021-12-04 23:08:29 0 [Note] InnoDB: Completed initialization of buffer pool
2021-12-04 23:08:30 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-12-04 23:08:31 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=697070416965
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856586 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856587 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856588 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856590 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856593 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856594 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856595 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: Transaction 645856596 was in the XA prepared state.
2021-12-04 23:08:31 0 [Note] InnoDB: 8 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo
2021-12-04 23:08:31 0 [Note] InnoDB: Trx id counter is 645856597
2021-12-04 23:08:31 0 [Note] InnoDB: Last binlog file '/mysql_path/mysql/binarylog/binarylog-bin.001020', position 1026029504
2021-12-04 23:08:31 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2021-12-04 23:08:31 0 [Note] InnoDB: Starting in background the rollback of recovered transactions
2021-12-04 23:08:31 0 [Note] InnoDB: Rollback of non-prepared transactions completed
2021-12-04 23:08:31 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2021-12-04 23:08:31 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2021-12-04 23:08:31 0 [Note] InnoDB: Setting file '/mysql_path/mysql/data/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-12-04 23:08:31 0 [Note] InnoDB: File '/mysql_path/mysql/data/ibtmp1' size is now 12 MB.
2021-12-04 23:08:31 0 [Note] InnoDB: Waiting for purge to start
2021-12-04 23:08:31 0 [Note] InnoDB: 10.4.18 started; log sequence number 697070416974; transaction id 645856598
2021-12-04 23:08:31 0 [Warning] InnoDB: Skipping buffer pool dump/restore during wsrep recovery.
2021-12-04 23:08:31 0 [Note] Using encryption key id 1 for temporary files
2021-12-04 23:08:31 0 [Note] Recovering after a crash using /mysql_path/mysql/binarylog/binarylog-bin
2021-12-04 23:08:35 0 [Note] Starting crash recovery...
2021-12-04 23:08:35 0 [Note] InnoDB: Starting recovery for XA transactions...
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856593 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856587 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856595 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856596 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856588 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856590 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856586 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction 645856594 in prepared state after recovery
2021-12-04 23:08:35 0 [Note] InnoDB: Transaction contains changes to 1 rows
2021-12-04 23:08:35 0 [Note] InnoDB: 8 transactions in prepared state after recovery
2021-12-04 23:08:35 0 [Note] Found 8 prepared transaction(s) in InnoDB
2021-12-04 23:08:35 0 [Warning] WSREP: Discovered discontinuity in recovered wsrep transaction XIDs. Truncating the recovery list to 0 entries
2021-12-04 23:08:35 0 [Note] WSREP: Last wsrep seqno to be recovered 71577924
2021-12-04 23:08:35 0 [Note] Crash recovery finished.
2021-12-04 23:08:35 0 [Note] Server socket created on IP: '0.0.0.0'.
2021-12-04 23:08:35 0 [Note] WSREP: Recovered position: 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:14 0 [Note] WSREP: Loading provider /usr/lib64/galera-4/libgalera_smm.so initial position: 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:14 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib64/galera-4/libgalera_smm.so'
2021-12-04 23:10:15 0 [Note] WSREP: wsrep_load(): Galera 26.4.8(r902dd26) by Codership Oy <info@codership.com> loaded successfully.
2021-12-04 23:10:15 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
2021-12-04 23:10:15 0 [Note] WSREP: Found saved state: 081ab320-121c-11ec-883e-abad2526041a:-1, safe_to_bootstrap: 0
2021-12-04 23:10:15 0 [Note] WSREP: GCache DEBUG: opened preamble:
Version: 2
UUID: 081ab320-121c-11ec-883e-abad2526041a
Seqno: -1 - -1
Offset: -1
Synced: 0
2021-12-04 23:10:15 0 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: 081ab320-121c-11ec-883e-abad2526041a, offset: -1
2021-12-04 23:10:15 0 [Note] WSREP: GCache::RingBuffer initial scan...  0.0% (         0/2147483672 bytes) complete.
2021-12-04 23:10:22 0 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (2147483672/2147483672 bytes) complete.
2021-12-04 23:10:22 0 [Note] WSREP: Recovering GCache ring buffer: found gapless sequence 70350498-71577933
2021-12-04 23:10:22 0 [Note] WSREP: GCache::RingBuffer unused buffers scan...  0.0% (         0/2146764128 bytes) complete.
2021-12-04 23:10:23 0 [Note] WSREP: GCache::RingBuffer unused buffers scan...100.0% (2146764128/2146764128 bytes) complete.
2021-12-04 23:10:23 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): found 0/1227436 locked buffers
2021-12-04 23:10:23 0 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): free space: 719520/2147483648
2021-12-04 23:10:23 0 [Note] WSREP: Passing config to GCS: base_dir = /mysql_path/mysql/; base_host = x.x.x.x; base_port = 4567; cert.log_conflicts = ON; 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 = /mysql_path/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 1G; gcache.recover = yes; gcache.size = 2G; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 0.99; gcs.fc_limit = 256; 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.c
2021-12-04 23:10:23 0 [Note] WSREP: Service thread queue flushed.
2021-12-04 23:10:23 0 [Note] WSREP: ####### Assign initial position for certification: 081ab320-121c-11ec-883e-abad2526041a:71577924, protocol version: -1
2021-12-04 23:10:23 0 [Note] WSREP: Start replication
2021-12-04 23:10:23 0 [Note] WSREP: Connecting with bootstrap option: 0
2021-12-04 23:10:23 0 [Note] WSREP: Setting GCS initial position to 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:23 0 [Note] WSREP: protonet asio version 0
2021-12-04 23:10:23 0 [Note] WSREP: Using CRC-32C for message checksums.
2021-12-04 23:10:23 0 [Note] WSREP: backend: asio
2021-12-04 23:10:23 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
2021-12-04 23:10:23 0 [Note] WSREP: restore pc from disk successfully
2021-12-04 23:10:23 0 [Note] WSREP: GMCast version 0
2021-12-04 23:10:23 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2021-12-04 23:10:23 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2021-12-04 23:10:23 0 [Note] WSREP: EVS version 1
2021-12-04 23:10:23 0 [Note] WSREP: gcomm: connecting to group 'GALERA_Cluster', peer 'x.x.x.x:,y.y.y.y:,z.z.z.z:'
2021-12-04 23:10:23 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://x.x.x.x:4567
2021-12-04 23:10:23 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') connection established to 3612d457-b5f0 tcp://z.z.z.z:4567
2021-12-04 23:10:23 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2021-12-04 23:10:23 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') connection established to db3807eb-835a tcp://y.y.y.y:4567
2021-12-04 23:10:24 0 [Note] WSREP: gcomm: connected
2021-12-04 23:10:24 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2021-12-04 23:10:24 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2021-12-04 23:10:24 0 [Note] WSREP: Opened channel 'GALERA_Cluster'
2021-12-04 23:10:24 1 [Note] WSREP: Starting rollbacker thread 1
2021-12-04 23:10:24 2 [Note] WSREP: Starting applier thread 2
2021-12-04 23:10:24 0 [Note] WSREP: EVS version upgrade 0 -> 1
2021-12-04 23:10:24 0 [Note] WSREP: declaring 3612d457-b5f0 at tcp://z.z.z.z:4567 stable
2021-12-04 23:10:24 0 [Note] WSREP: declaring db3807eb-835a at tcp://y.y.y.y:4567 stable
2021-12-04 23:10:24 0 [Note] WSREP: PC protocol upgrade 0 -> 1
2021-12-04 23:10:24 0 [Note] WSREP: Node 3612d457-b5f0 state prim
2021-12-04 23:10:24 0 [Note] WSREP: view(view_id(PRIM,3612d457-b5f0,104) memb {
        3612d457-b5f0,0
        d22e5726-a567,0
        db3807eb-835a,0
} joined {
} left {
} partitioned {
})
2021-12-04 23:10:24 0 [Note] WSREP: save pc into disk
2021-12-04 23:10:24 0 [Note] WSREP: clear restored view
2021-12-04 23:10:24 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 3
2021-12-04 23:10:24 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2021-12-04 23:10:24 0 [Note] WSREP: STATE EXCHANGE: sent state msg: faab6be5-554e-11ec-8160-9fc48c2b2616
2021-12-04 23:10:24 0 [Note] WSREP: STATE EXCHANGE: got state msg: faab6be5-554e-11ec-8160-9fc48c2b2616 from 1 (gnode1.internal)
2021-12-04 23:10:24 0 [Note] WSREP: STATE EXCHANGE: got state msg: faab6be5-554e-11ec-8160-9fc48c2b2616 from 2 (gnode2.internal)
2021-12-04 23:10:24 0 [Note] WSREP: STATE EXCHANGE: got state msg: faab6be5-554e-11ec-8160-9fc48c2b2616 from 0 (gnode3.internal)
2021-12-04 23:10:24 0 [Note] WSREP: Quorum results:
        version    = 6,
        component  = PRIMARY,
        conf_id    = 2,
        members    = 2/3 (joined/total),
        act_id     = 71580307,
        last_appl. = 71580297,
        protocols  = 2/10/4 (gcs/repl/appl),
        vote policy= 0,
        group UUID = 081ab320-121c-11ec-883e-abad2526041a
2021-12-04 23:10:24 0 [Note] WSREP: Flow-control interval: [439, 443]
2021-12-04 23:10:24 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 71580308)
2021-12-04 23:10:24 2 [Note] WSREP: ####### processing CC 71580308, local, ordered
2021-12-04 23:10:24 2 [Note] WSREP: Process first view: 081ab320-121c-11ec-883e-abad2526041a my uuid: d22e5726-154c-11ec-a567-ca7b2f1fa7eb
2021-12-04 23:10:24 2 [Note] WSREP: Server gnode1.internal connected to cluster at position 081ab320-121c-11ec-883e-abad2526041a:71580308 with ID d22e5726-154c-11ec-a567-ca7b2f1fa7eb
2021-12-04 23:10:24 2 [Note] WSREP: Server status change disconnected -> connected
2021-12-04 23:10:24 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-12-04 23:10:24 2 [Note] WSREP: ####### My UUID: d22e5726-154c-11ec-a567-ca7b2f1fa7eb
2021-12-04 23:10:24 2 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2021-12-04 23:10:24 0 [Note] WSREP: Service thread queue flushed.
2021-12-04 23:10:24 2 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2021-12-04 23:10:24 2 [Note] WSREP: State transfer required:
        Group state: 081ab320-121c-11ec-883e-abad2526041a:71580308
        Local state: 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:24 2 [Note] WSREP: Server status change connected -> joiner
2021-12-04 23:10:24 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-12-04 23:10:24 0 [Note] WSREP: Joiner monitor thread started to monitor
2021-12-04 23:10:24 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address 'x.x.x.x' --datadir '/mysql_path/mysql/' --parent '12973' --binlog '/mysql_path/mysql/binarylog/binarylog-bin' --mysqld-args --wsrep_start_position=081ab320-121c-11ec-883e-abad2526041a:71577924'
2021-12-04 23:10:24 2 [Note] WSREP: Prepared SST request: rsync|x.x.x.x:4444/rsync_sst
2021-12-04 23:10:24 2 [Note] WSREP: ####### IST uuid:081ab320-121c-11ec-883e-abad2526041a f: 71577925, l: 71580308, STRv: 3
2021-12-04 23:10:24 2 [Note] WSREP: IST receiver addr using tcp://x.x.x.x:4568
2021-12-04 23:10:24 2 [Note] WSREP: Prepared IST receiver for 71577925-71580308, listening at: tcp://x.x.x.x:4568
2021-12-04 23:10:25 0 [Note] WSREP: Member 1.0 (gnode1.internal) requested state transfer from '*any*'. Selected 2.0 (gnode2.internal)(SYNCED) as donor.
2021-12-04 23:10:25 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 71580317)
2021-12-04 23:10:25 2 [Note] WSREP: Requesting state transfer: success, donor: 2
2021-12-04 23:10:25 0 [Note] WSREP: 2.0 (gnode2.internal): State transfer to 1.0 (gnode1.internal) complete.
2021-12-04 23:10:25 0 [Note] WSREP: Member 2.0 (gnode2.internal) synced with group.
WSREP_SST: [INFO] Joiner cleanup. rsync PID: 13040 (20211204 23:10:26.010)
WSREP_SST: [INFO] Joiner cleanup done. (20211204 23:10:26.522)
2021-12-04 23:10:26 3 [Note] WSREP: SST received
2021-12-04 23:10:26 3 [Note] WSREP: Server status change joiner -> initializing
2021-12-04 23:10:26 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-12-04 23:10:26 0 [Note] InnoDB: Using Linux native AIO
2021-12-04 23:10:26 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2021-12-04 23:10:26 0 [Note] InnoDB: Uses event mutexes
2021-12-04 23:10:26 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2021-12-04 23:10:26 0 [Note] InnoDB: Number of pools: 1
2021-12-04 23:10:26 0 [Note] InnoDB: Using SSE2 crc32 instructions
2021-12-04 23:10:26 0 [Note] InnoDB: Initializing buffer pool, total size = 4G, instances = 4, chunk size = 128M
2021-12-04 23:10:26 0 [Note] InnoDB: Completed initialization of buffer pool
2021-12-04 23:10:26 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-12-04 23:10:27 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2021-12-04 23:10:27 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2021-12-04 23:10:27 0 [Note] InnoDB: Setting file '/mysql_path/mysql/data/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-12-04 23:10:27 0 [Note] InnoDB: File '/mysql_path/mysql/data/ibtmp1' size is now 12 MB.
2021-12-04 23:10:27 0 [Note] InnoDB: Waiting for purge to start
2021-12-04 23:10:27 0 [Note] InnoDB: 10.4.18 started; log sequence number 697070421289; transaction id 645856607
2021-12-04 23:10:27 0 [Note] InnoDB: Loading buffer pool(s) from /mysql_path/mysql/data/ib_buffer_pool
2021-12-04 23:10:27 0 [Note] Using encryption key id 1 for temporary files
2021-12-04 23:10:27 0 [Note] Server socket created on IP: '0.0.0.0'.
2021-12-04 23:10:27 0 [Warning] 'proxies_priv' entry '@% root@localhost.localdomain' ignored in --skip-name-resolve mode.
2021-12-04 23:10:27 0 [Note] WSREP: wsrep_init_schema_and_SR (nil)
2021-12-04 23:10:27 0 [Note] WSREP: Server initialized
2021-12-04 23:10:27 0 [Note] WSREP: Server status change initializing -> initialized
2021-12-04 23:10:27 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-12-04 23:10:27 3 [Note] WSREP: Server status change initialized -> joined
2021-12-04 23:10:27 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-12-04 23:10:27 3 [Note] WSREP: Recovered position from storage: 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:27 12 [Note] WSREP: Starting applier thread 12
2021-12-04 23:10:27 11 [Note] WSREP: Starting applier thread 11
2021-12-04 23:10:27 16 [Note] WSREP: Starting applier thread 16
2021-12-04 23:10:27 17 [Note] WSREP: Starting applier thread 17
2021-12-04 23:10:27 13 [Note] WSREP: Starting applier thread 13
2021-12-04 23:10:27 14 [Note] WSREP: Starting applier thread 14
2021-12-04 23:10:27 15 [Note] WSREP: Starting applier thread 15
2021-12-04 23:10:27 0 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.4.18-MariaDB-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
2021-12-04 23:10:27 3 [Note] WSREP: Recovered view from SST:
  id: 081ab320-121c-11ec-883e-abad2526041a:742
  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(1):
        0: 243e0615-1505-11ec-ac8b-764b020fb841, gnode1.internal
 
2021-12-04 23:10:27 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-12-04 23:10:27 20 [Note] WSREP: Recovered cluster id 081ab320-121c-11ec-883e-abad2526041a
2021-12-04 23:10:27 3 [Note] WSREP: SST received: 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:27 3 [Note] WSREP: SST succeeded for position 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:27 0 [Note] WSREP: Joiner monitor thread ended with total time 3 sec
2021-12-04 23:10:27 2 [Note] WSREP: Installed new state from SST: 081ab320-121c-11ec-883e-abad2526041a:71577924
2021-12-04 23:10:27 2 [Note] WSREP: Receiving IST: 2384 writesets, seqnos 71577925-71580308
2021-12-04 23:10:27 0 [Note] WSREP: ####### IST applying starts with 71577925
2021-12-04 23:10:27 0 [Note] WSREP: ####### IST current seqno initialized to 71577925
2021-12-04 23:10:27 0 [Note] WSREP: Receiving IST...  0.0% (   0/2384 events) complete.
2021-12-04 23:10:27 0 [Note] WSREP: Service thread queue flushed.
2021-12-04 23:10:27 0 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:71577925, protocol version: 5
2021-12-04 23:10:27 0 [Note] WSREP: (d22e5726-a567, 'tcp://0.0.0.0:4567') turning message relay requesting off
2021-12-04 23:10:27 22 [ERROR] WSREP: Unknown writeset version: -1
211204 23:10:27 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
 
Server version: 10.4.18-MariaDB-log
key_buffer_size=16777216
read_buffer_size=262144
max_used_connections=2
max_threads=3001
thread_count=17
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6980197 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f68b0000a88
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x7f6a4c092c90 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x556bf0a1c47e]
/usr/sbin/mysqld(handle_fatal_signal+0x30f)[0x556bf04aae8f]
2021-12-04 23:10:28 0 [Note] InnoDB: Buffer pool(s) load completed at 211204 23:10:28
/lib64/libpthread.so.0(+0xf630)[0x7f6af1967630]
/lib64/libc.so.6(gsignal+0x37)[0x7f6aefc37387]
:0(__GI_raise)[0x7f6aefc38a78]
src/write_set_ng.hpp:166(galera::WriteSetNG::Header::size(galera::WriteSetNG::Version))[0x7f6aec294c88]
src/write_set_ng.hpp:173(Header)[0x7f6aec295637]
src/trx_handle.hpp:992(galera::TrxHandleMaster::write_set_out())[0x7f6aec290e1a]
/usr/sbin/mysqld(_ZN5wsrep18wsrep_provider_v269enter_toiENS_9client_idERKSt6vectorINS_3keyESaIS3_EERKNS_12const_bufferERNS_7ws_metaEi+0x46f)[0x556bf0abed0f]
/usr/sbin/mysqld(_ZN5wsrep12client_state14poll_enter_toiERSt11unique_lockINS_5mutexEERKSt6vectorINS_3keyESaIS6_EERKNS_12const_bufferERNS_7ws_metaEiNSt6chrono10time_pointINSG_3_V212steady_clockENSG_8durationIlSt5ratioILl1ELl1000000000EEEEEERb+0x396)[0x556bf0a9e7a6]
/usr/sbin/mysqld(_ZN5wsrep12client_state15enter_toi_localERKSt6vectorINS_3keyESaIS2_EERKNS_12const_bufferENSt6chrono10time_pointINSA_3_V212steady_clockENSA_8durationIlSt5ratioILl1ELl1000000000EEEEEE+0x77)[0x556bf0a9ff57]
/usr/sbin/mysqld(_Z24wsrep_to_isolation_beginP3THDPKcS2_PK10TABLE_LISTP10Alter_infoPSt6vectorIN5wsrep3keyESaISA_EE+0x7b0)[0x556bf0412630]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x8a21)[0x556bf02a05c1]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x36d)[0x556bf02a0fed]
/usr/sbin/mysqld(+0x5ad5ec)[0x556bf018a5ec]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x30e2)[0x556bf02a4892]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x112)[0x556bf02a4e22]
/usr/sbin/mysqld(_Z11tp_callbackP13TP_connection+0x1df)[0x556bf047c83f]
/usr/sbin/mysqld(+0xa5d280)[0x556bf063a280]
pthread_create.c:0(start_thread)[0x7f6af195fea5]
/lib64/libc.so.6(clone+0x6d)[0x7f6aefcff9fd]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f68b00101d0): flush error logs
 
 
Connection ID (thread ID): 22
Status: NOT_KILLED
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=on,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on,split_materialized=on,condition_pushdown_for_subquery=on,rowid_filter=on,condition_pushdown_from_having=on
 
The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains
information that should help you find out what is causing the crash.
Writing a core file...
Working directory at /mysql_path/mysql
Resource Limits:
Limit                     Soft Limit           Hard Limit           Units
Max cpu time              unlimited            unlimited            seconds
Max file size             unlimited            unlimited            bytes
Max data size             unlimited            unlimited            bytes
Max stack size            8388608              unlimited            bytes
Max core file size        0                    unlimited            bytes
Max resident set          unlimited            unlimited            bytes
Max processes             63278                63278                processes
Max open files            16384                16384                files
Max locked memory         65536                65536                bytes
Max address space         unlimited            unlimited            bytes
Max file locks            unlimited            unlimited            locks
Max pending signals       63278                63278                signals
Max msgqueue size         819200               819200               bytes
Max nice priority         0                    0
Max realtime priority     0                    0
Max realtime timeout      unlimited            unlimited            us



 Comments   
Comment by Jan Lindström (Inactive) [ 2022-09-30 ]

I suggest to use more recent version of MariaDB and Galera library. If problem can be repeated with them, then please provide full error log, cluster configuration and full stack dump from all threads.

Generated at Thu Feb 08 09:50:53 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.