[MDEV-26244] Galera test failure on galera_sst_mysqldump Created: 2021-07-26  Updated: 2021-07-27  Resolved: 2021-07-27

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

Type: Bug Priority: Major
Reporter: Jan Lindström (Inactive) Assignee: Alexey
Resolution: Cannot Reproduce Votes: 0
Labels: None


 Description   
  • Galera library 26.4.9

galera.galera_sst_mysqldump 'debug,innodb' [ fail ]
        Test ended at 2021-07-26 16:34:12
 
CURRENT_TEST: galera.galera_sst_mysqldump
 
 
Server [mysqld.2 - pid: 611488, winpid: 611488, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2021-07-26 16:33:31 0 [Warning] WSREP: option --wsrep-causal-reads is deprecated
2021-07-26 16:33:31 0 [Note] /home/jan/mysql/10.4e/sql/mysqld (mysqld 10.4.20-13-MariaDB-debug-log) starting as process 611489 ...
2021-07-26 16:33:31 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32190)
2021-07-26 16:33:31 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2021-07-26 16:33:31 0 [Note] WSREP: Loading provider /usr/lib/libgalera_enterprise_debug_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
2021-07-26 16:33:31 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/libgalera_enterprise_debug_smm.so'
2021-07-26 16:33:31 0 [Note] WSREP: wsrep_load(): Galera 26.4.8-1(r9ad04fba) by Codership Oy <info@codership.com> loaded successfully.
2021-07-26 16:33:31 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
2021-07-26 16:33:31 0 [Warning] WSREP: Could not open state file for reading: '/home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data//grastate.dat'
2021-07-26 16:33:31 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2021-07-26 16:33:31 0 [Note] WSREP: GCache DEBUG: opened preamble:
Version: 0
UUID: 00000000-0000-0000-0000-000000000000
Seqno: -1 - -1
Offset: -1
Synced: 0
2021-07-26 16:33:31 0 [Note] WSREP: Skipped GCache ring buffer recovery: could not determine history UUID.
2021-07-26 16:33:31 0 [Note] WSREP: Passing config to GCS: base_dir = /home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data/; base_host = 127.0.0.1; base_port = 16005; cert.log_conflicts = no; cert.optimistic_pa = yes; dbug = ; 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.debug = 0; gcache.dir = /home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data/; gcache.keep_pages_size = 0; gcache.keep_plaintext_size = 128M; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; gcache.size = 1; 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.
2021-07-26 16:33:31 0 [Note] WSREP: Start replication
2021-07-26 16:33:31 0 [Note] WSREP: Connecting with bootstrap option: 0
2021-07-26 16:33:31 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2021-07-26 16:33:31 0 [Note] WSREP: protonet asio version 0
2021-07-26 16:33:31 0 [Note] WSREP: Using CRC-32C for message checksums.
2021-07-26 16:33:31 0 [Note] WSREP: backend: asio
2021-07-26 16:33:31 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2021-07-26 16:33:31 0 [Warning] WSREP: access file(/home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data//gvwstate.dat) failed(No such file or directory)
2021-07-26 16:33:31 0 [Note] WSREP: restore pc from disk failed
2021-07-26 16:33:31 0 [Note] WSREP: GMCast version 0
2021-07-26 16:33:31 0 [Note] WSREP: (11604f8b-bc1d, 'tcp://0.0.0.0:16005') listening at tcp://0.0.0.0:16005
2021-07-26 16:33:31 0 [Note] WSREP: (11604f8b-bc1d, 'tcp://0.0.0.0:16005') multicast: , ttl: 1
2021-07-26 16:33:31 0 [Note] WSREP: EVS version 1
2021-07-26 16:33:31 0 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:16002'
2021-07-26 16:33:31 0 [Note] WSREP: (11604f8b-bc1d, 'tcp://0.0.0.0:16005') connection established to 110b06a5-a5aa tcp://127.0.0.1:16002
2021-07-26 16:33:31 0 [Note] WSREP: (11604f8b-bc1d, 'tcp://0.0.0.0:16005') turning message relay requesting on, nonlive peers: 
2021-07-26 16:33:31 0 [Note] WSREP: EVS version upgrade 0 -> 1
2021-07-26 16:33:31 0 [Note] WSREP: declaring 110b06a5-a5aa at tcp://127.0.0.1:16002 stable
2021-07-26 16:33:31 0 [Note] WSREP: PC protocol upgrade 0 -> 1
2021-07-26 16:33:31 0 [Note] WSREP: Node 110b06a5-a5aa state prim
2021-07-26 16:33:31 0 [Note] WSREP: view(view_id(PRIM,110b06a5-a5aa,2) memb {
	110b06a5-a5aa,0
	11604f8b-bc1d,0
} joined {
} left {
} partitioned {
})
2021-07-26 16:33:31 0 [Note] WSREP: save pc into disk
2021-07-26 16:33:32 0 [Note] WSREP: gcomm: connected
2021-07-26 16:33:32 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2021-07-26 16:33:32 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2021-07-26 16:33:32 0 [Note] WSREP: Opened channel 'my_wsrep_cluster'
2021-07-26 16:33:32 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2021-07-26 16:33:32 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2021-07-26 16:33:32 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 11af8f96-ee16-11eb-8947-22bf837c6ef4
2021-07-26 16:33:32 0 [Note] WSREP: STATE EXCHANGE: got state msg: 11af8f96-ee16-11eb-8947-22bf837c6ef4 from 0 (jan-HP-ZBook-15u-G5)
2021-07-26 16:33:32 0 [Note] WSREP: STATE EXCHANGE: got state msg: 11af8f96-ee16-11eb-8947-22bf837c6ef4 from 1 (jan-HP-ZBook-15u-G5)
2021-07-26 16:33:32 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 = 110c04f4-ee16-11eb-9d8c-ab837787d450
2021-07-26 16:33:32 1 [Note] WSREP: Starting rollbacker thread 1
2021-07-26 16:33:32 0 [Note] WSREP: Created page /home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data/galera.page.000000 of size 134217696 bytes
2021-07-26 16:33:32 2 [Note] WSREP: Starting applier thread 2
2021-07-26 16:33:32 0 [Note] WSREP: Flow-control interval: [23, 23]
2021-07-26 16:33:32 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2)
2021-07-26 16:33:32 2 [Note] WSREP: ####### processing CC 2, local, ordered
2021-07-26 16:33:32 2 [Note] WSREP: Process first view: 110c04f4-ee16-11eb-9d8c-ab837787d450 my uuid: 11604f8b-ee16-11eb-bc1d-fb61760fa8ae
2021-07-26 16:33:32 2 [Note] WSREP: Server jan-HP-ZBook-15u-G5 connected to cluster at position 110c04f4-ee16-11eb-9d8c-ab837787d450:2 with ID 11604f8b-ee16-11eb-bc1d-fb61760fa8ae
2021-07-26 16:33:32 2 [Note] WSREP: Server status change disconnected -> connected
2021-07-26 16:33:32 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:32 2 [Note] WSREP: ####### My UUID: 11604f8b-ee16-11eb-bc1d-fb61760fa8ae
2021-07-26 16:33:32 2 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2021-07-26 16:33:32 0 [Note] WSREP: Service thread queue flushed.
2021-07-26 16:33:32 2 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2021-07-26 16:33:32 2 [Note] WSREP: State transfer required: 
	Group state: 110c04f4-ee16-11eb-9d8c-ab837787d450:2
	Local state: 00000000-0000-0000-0000-000000000000:-1
2021-07-26 16:33:32 2 [Note] WSREP: Server status change connected -> joiner
2021-07-26 16:33:32 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:32 0 [Note] WSREP: Joiner monitor thread started to monitor
2021-07-26 16:33:32 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '127.0.0.2:16007' --datadir '/home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data/' --defaults-file '/home/jan/mysql/10.4e/mysql-test/var/my.cnf' --defaults-group-suffix '.2' --parent '611489' --binlog-index 'mysqld-bin.index' --mysqld-args --defaults-group-suffix=.2 --defaults-file=/home/jan/mysql/10.4e/mysql-test/var/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --enable-gdb --core-file --loose-debug-sync-timeout=300'
2021-07-26 16:33:32 2 [Note] WSREP: Prepared SST request: rsync|127.0.0.2:16007/rsync_sst
2021-07-26 16:33:32 2 [Note] WSREP: App waits SST: 1
2021-07-26 16:33:32 2 [Note] WSREP: ####### IST uuid:00000000-0000-0000-0000-000000000000 f: 0, l: 2, STRv: 3
2021-07-26 16:33:32 2 [Note] WSREP: IST receiver addr using tcp://127.0.0.1:16006
2021-07-26 16:33:32 2 [Note] WSREP: Prepared IST receiver for 0-2, listening at: tcp://127.0.0.1:16006
2021-07-26 16:33:32 0 [Note] WSREP: Member 1.0 (jan-HP-ZBook-15u-G5) requested state transfer from '*any*'. Selected 0.0 (jan-HP-ZBook-15u-G5)(SYNCED) as donor.
2021-07-26 16:33:32 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 2)
2021-07-26 16:33:32 2 [Note] WSREP: Requesting state transfer: success, donor: 0
2021-07-26 16:33:32 2 [Note] WSREP: Resetting GCache seqno map due to different histories.
2021-07-26 16:33:32 2 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 110c04f4-ee16-11eb-9d8c-ab837787d450:2
2021-07-26 16:33:33 0 [Note] WSREP: 0.0 (jan-HP-ZBook-15u-G5): State transfer to 1.0 (jan-HP-ZBook-15u-G5) complete.
2021-07-26 16:33:33 0 [Note] WSREP: Member 0.0 (jan-HP-ZBook-15u-G5) synced with group.
WSREP_SST: [INFO] Joiner cleanup. rsync PID: 611549 (20210726 16:33:33.641)
WSREP_SST: [INFO] Joiner cleanup done. (20210726 16:33:34.162)
2021-07-26 16:33:34 3 [Note] WSREP: SST received
2021-07-26 16:33:34 3 [Note] WSREP: Server status change joiner -> initializing
2021-07-26 16:33:34 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:34 0 [Note] Plugin 'partition' is disabled.
2021-07-26 16:33:34 0 [Note] InnoDB: Using Linux native AIO
2021-07-26 16:33:34 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2021-07-26 16:33:34 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2021-07-26 16:33:34 0 [Note] InnoDB: Uses event mutexes
2021-07-26 16:33:34 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2021-07-26 16:33:34 0 [Note] InnoDB: Number of pools: 1
2021-07-26 16:33:34 0 [Note] InnoDB: Using SSE2 crc32 instructions
2021-07-26 16:33:34 0 [Note] mysqld: O_TMPFILE is not supported on /home/jan/mysql/10.4e/mysql-test/var/tmp/mysqld.2 (disabling future attempts)
2021-07-26 16:33:34 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
2021-07-26 16:33:34 0 [Note] InnoDB: Completed initialization of buffer pool
2021-07-26 16:33:34 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-07-26 16:33:34 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=64940
2021-07-26 16:33:34 0 [Note] InnoDB: Starting final batch to recover 18 pages from redo log.
2021-07-26 16:33:34 0 [Note] WSREP: (11604f8b-bc1d, 'tcp://0.0.0.0:16005') turning message relay requesting off
2021-07-26 16:33:34 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2021-07-26 16:33:34 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2021-07-26 16:33:34 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-07-26 16:33:34 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2021-07-26 16:33:34 0 [Note] InnoDB: Waiting for purge to start
2021-07-26 16:33:34 0 [Note] InnoDB: 10.4.20 started; log sequence number 74328; transaction id 38
2021-07-26 16:33:34 0 [Note] InnoDB: Loading buffer pool(s) from /home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data/ib_buffer_pool
2021-07-26 16:33:34 0 [Note] Plugin 'SEQUENCE' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_CMP' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2021-07-26 16:33:34 0 [Note] InnoDB: Buffer pool(s) load completed at 210726 16:33:34
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'FEEDBACK' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'user_variables' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2021-07-26 16:33:34 0 [Note] Plugin 'unix_socket' is disabled.
2021-07-26 16:33:34 0 [Warning] /home/jan/mysql/10.4e/sql/mysqld: unknown option '--loose-pam-debug'
2021-07-26 16:33:34 0 [Warning] /home/jan/mysql/10.4e/sql/mysqld: unknown option '--loose-aria'
2021-07-26 16:33:34 0 [Note] Server socket created on IP: '127.0.0.1'.
2021-07-26 16:33:34 0 [Note] WSREP: wsrep_init_schema_and_SR (nil)
2021-07-26 16:33:34 0 [Note] WSREP: Server initialized
2021-07-26 16:33:34 0 [Note] WSREP: Server status change initializing -> initialized
2021-07-26 16:33:34 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:34 3 [Note] WSREP: Server status change initialized -> joined
2021-07-26 16:33:34 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:34 0 [Note] Reading of all Master_info entries succeeded
2021-07-26 16:33:34 0 [Note] Added new Master_info '' to hash table
2021-07-26 16:33:34 0 [Note] /home/jan/mysql/10.4e/sql/mysqld: ready for connections.
Version: '10.4.20-13-MariaDB-debug-log'  socket: '/home/jan/mysql/10.4e/mysql-test/var/tmp/mysqld.2.sock'  port: 16001  Source distribution
2021-07-26 16:33:34 3 [Note] WSREP: Recovered position from storage: 110c04f4-ee16-11eb-9d8c-ab837787d450:2
2021-07-26 16:33:34 3 [Note] WSREP: Recovered view from SST:
  id: 110c04f4-ee16-11eb-9d8c-ab837787d450: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: 110b06a5-ee16-11eb-a5aa-bed8a359e65c, jan-HP-ZBook-15u-G5
	1: 11604f8b-ee16-11eb-bc1d-fb61760fa8ae, jan-HP-ZBook-15u-G5
 
2021-07-26 16:33:34 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:34 12 [Note] WSREP: Recovered cluster id 110c04f4-ee16-11eb-9d8c-ab837787d450
2021-07-26 16:33:34 3 [Note] WSREP: SST received: 110c04f4-ee16-11eb-9d8c-ab837787d450:2
2021-07-26 16:33:34 3 [Note] WSREP: SST succeeded for position 110c04f4-ee16-11eb-9d8c-ab837787d450:2
2021-07-26 16:33:34 2 [Note] WSREP: Installed new state from SST: 110c04f4-ee16-11eb-9d8c-ab837787d450:2
2021-07-26 16:33:34 0 [Note] WSREP: Joiner monitor thread ended with total time 2 sec
2021-07-26 16:33:34 2 [Note] WSREP: Cert. index preload up to 2
2021-07-26 16:33:34 0 [Note] WSREP: ####### IST applying starts with 3
2021-07-26 16:33:34 0 [Note] WSREP: ####### IST current seqno initialized to 2
2021-07-26 16:33:34 0 [Note] WSREP: Receiving IST...  0.0% (0/1 events) complete.
2021-07-26 16:33:34 0 [Note] WSREP: IST preload starting at 2
2021-07-26 16:33:34 0 [Note] WSREP: REPL Protocols: 10 (5)
2021-07-26 16:33:34 0 [Note] WSREP: Service thread queue flushed.
2021-07-26 16:33:34 0 [Note] WSREP: ####### Assign initial position for certification: 110c04f4-ee16-11eb-9d8c-ab837787d450:1, protocol version: 5
2021-07-26 16:33:34 0 [Note] WSREP: REPL Protocols: 10 (5)
2021-07-26 16:33:34 0 [Note] WSREP: ####### Adjusting cert position: 1 -> 2
2021-07-26 16:33:34 0 [Note] WSREP: Service thread queue flushed.
2021-07-26 16:33:34 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 2
2021-07-26 16:33:34 0 [Note] WSREP: Min available from gcache for CC from preload: 2
2021-07-26 16:33:34 0 [Note] WSREP: Receiving IST...100.0% (1/1 events) complete.
2021-07-26 16:33:34 2 [Note] WSREP: IST received: 110c04f4-ee16-11eb-9d8c-ab837787d450:2
2021-07-26 16:33:34 2 [Note] WSREP: Lowest cert index boundary for CC from sst: 2
2021-07-26 16:33:34 2 [Note] WSREP: Min available from gcache for CC from sst: 2
2021-07-26 16:33:34 0 [Note] WSREP: 1.0 (jan-HP-ZBook-15u-G5): State transfer from 0.0 (jan-HP-ZBook-15u-G5) complete.
2021-07-26 16:33:34 0 [Note] WSREP: Shifting JOINER -> JOINED (TO: 2)
2021-07-26 16:33:34 0 [Note] WSREP: Member 1.0 (jan-HP-ZBook-15u-G5) synced with group.
2021-07-26 16:33:34 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2)
2021-07-26 16:33:34 2 [Note] WSREP: Server jan-HP-ZBook-15u-G5 synced with group
2021-07-26 16:33:34 2 [Note] WSREP: Server status change joined -> synced
2021-07-26 16:33:34 2 [Note] WSREP: Synchronized with group, ready for connections
2021-07-26 16:33:34 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:37 15 [Note] WSREP: Stop replication by 15
2021-07-26 16:33:37 15 [Note] WSREP: Server status change synced -> disconnecting
2021-07-26 16:33:37 15 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:37 15 [Note] WSREP: Closing send monitor...
2021-07-26 16:33:37 15 [Note] WSREP: Closed send monitor.
2021-07-26 16:33:37 15 [Note] WSREP: gcomm: terminating thread
2021-07-26 16:33:37 15 [Note] WSREP: gcomm: joining thread
2021-07-26 16:33:37 15 [Note] WSREP: gcomm: closing backend
2021-07-26 16:33:38 15 [Note] WSREP: view(view_id(NON_PRIM,110b06a5-a5aa,2) memb {
	11604f8b-bc1d,0
} joined {
} left {
} partitioned {
	110b06a5-a5aa,0
})
2021-07-26 16:33:38 15 [Note] WSREP: PC protocol downgrade 1 -> 0
2021-07-26 16:33:38 15 [Note] WSREP: view((empty))
2021-07-26 16:33:38 15 [Note] WSREP: gcomm: closed
2021-07-26 16:33:38 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2021-07-26 16:33:38 0 [Note] WSREP: Flow-control interval: [16, 16]
2021-07-26 16:33:38 0 [Note] WSREP: Received NON-PRIMARY.
2021-07-26 16:33:38 0 [Note] WSREP: Shifting SYNCED -> OPEN (TO: 7)
2021-07-26 16:33:38 0 [Note] WSREP: New SELF-LEAVE.
2021-07-26 16:33:38 0 [Note] WSREP: Flow-control interval: [0, 0]
2021-07-26 16:33:38 0 [Note] WSREP: Received SELF-LEAVE. Closing connection.
2021-07-26 16:33:38 0 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 7)
2021-07-26 16:33:38 0 [Note] WSREP: RECV thread exiting 0: Success
2021-07-26 16:33:38 2 [Note] WSREP: ================================================
View:
  id: 110c04f4-ee16-11eb-9d8c-ab837787d450:7
  status: non-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: 11604f8b-ee16-11eb-bc1d-fb61760fa8ae, jan-HP-ZBook-15u-G5
=================================================
2021-07-26 16:33:38 15 [Note] WSREP: recv_thread() joined.
2021-07-26 16:33:38 2 [Note] WSREP: Non-primary view
2021-07-26 16:33:38 15 [Note] WSREP: Closing replication queue.
2021-07-26 16:33:38 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:38 15 [Note] WSREP: Closing slave action queue.
2021-07-26 16:33:38 2 [Note] WSREP: ================================================
View:
  id: 110c04f4-ee16-11eb-9d8c-ab837787d450:7
  status: non-primary
  protocol_version: 4
  capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
  final: yes
  own_index: -1
  members(0):
=================================================
2021-07-26 16:33:38 2 [Note] WSREP: Non-primary view
2021-07-26 16:33:38 2 [Note] WSREP: Server status change disconnecting -> disconnected
2021-07-26 16:33:38 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:38 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:38 2 [Note] WSREP: Applier thread exiting ret: 0 thd: 2
2021-07-26 16:33:38 1 [Note] WSREP: rollbacker thread exiting 1
2021-07-26 16:33:38 2 [Warning] Aborted connection 2 to db: 'unconnected' user: 'unauthenticated' host: '' (This connection closed normally without authentication)
2021-07-26 16:33:38 1 [Warning] Aborted connection 1 to db: 'unconnected' user: 'unauthenticated' host: '' (This connection closed normally without authentication)
2021-07-26 16:33:40 15 [Note] WSREP: Stop replication by 15
2021-07-26 16:33:40 15 [Note] WSREP: Start replication
2021-07-26 16:33:40 15 [Note] WSREP: Connecting with bootstrap option: 0
2021-07-26 16:33:40 15 [Note] WSREP: Setting GCS initial position to 110c04f4-ee16-11eb-9d8c-ab837787d450:7
2021-07-26 16:33:40 15 [Note] WSREP: protonet asio version 0
2021-07-26 16:33:40 15 [Note] WSREP: Using CRC-32C for message checksums.
2021-07-26 16:33:40 15 [Note] WSREP: backend: asio
2021-07-26 16:33:40 15 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2021-07-26 16:33:40 15 [Warning] WSREP: access file(/home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data//gvwstate.dat) failed(No such file or directory)
2021-07-26 16:33:40 15 [Note] WSREP: restore pc from disk failed
2021-07-26 16:33:40 15 [Note] WSREP: GMCast version 0
2021-07-26 16:33:40 15 [Note] WSREP: (169d15ca-8931, 'tcp://0.0.0.0:16005') listening at tcp://0.0.0.0:16005
2021-07-26 16:33:40 15 [Note] WSREP: (169d15ca-8931, 'tcp://0.0.0.0:16005') multicast: , ttl: 1
2021-07-26 16:33:40 15 [Note] WSREP: EVS version 1
2021-07-26 16:33:40 15 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:16002'
2021-07-26 16:33:40 15 [Note] WSREP: (169d15ca-8931, 'tcp://0.0.0.0:16005') connection established to 110b06a5-a5aa tcp://127.0.0.1:16002
2021-07-26 16:33:40 15 [Note] WSREP: (169d15ca-8931, 'tcp://0.0.0.0:16005') turning message relay requesting on, nonlive peers: 
2021-07-26 16:33:40 15 [Note] WSREP: EVS version upgrade 0 -> 1
2021-07-26 16:33:40 15 [Note] WSREP: declaring 110b06a5-a5aa at tcp://127.0.0.1:16002 stable
2021-07-26 16:33:40 15 [Note] WSREP: PC protocol upgrade 0 -> 1
2021-07-26 16:33:40 15 [Note] WSREP: Node 110b06a5-a5aa state prim
2021-07-26 16:33:40 15 [Note] WSREP: view(view_id(PRIM,110b06a5-a5aa,4) memb {
	110b06a5-a5aa,0
	169d15ca-8931,0
} joined {
} left {
} partitioned {
})
2021-07-26 16:33:40 15 [Note] WSREP: save pc into disk
2021-07-26 16:33:41 15 [Note] WSREP: gcomm: connected
2021-07-26 16:33:41 15 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2021-07-26 16:33:41 15 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 7)
2021-07-26 16:33:41 15 [Note] WSREP: Opened channel 'my_wsrep_cluster'
2021-07-26 16:33:41 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2021-07-26 16:33:41 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2021-07-26 16:33:41 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 16ecb01c-ee16-11eb-999c-a2cc07c8e4ee
2021-07-26 16:33:41 0 [Note] WSREP: STATE EXCHANGE: got state msg: 16ecb01c-ee16-11eb-999c-a2cc07c8e4ee from 0 (jan-HP-ZBook-15u-G5)
2021-07-26 16:33:41 0 [Note] WSREP: STATE EXCHANGE: got state msg: 16ecb01c-ee16-11eb-999c-a2cc07c8e4ee from 1 (jan-HP-ZBook-15u-G5)
2021-07-26 16:33:41 0 [Note] WSREP: Quorum results:
	version    = 6,
	component  = PRIMARY,
	conf_id    = 3,
	members    = 1/2 (joined/total),
	act_id     = 9,
	last_appl. = 0,
	protocols  = 2/10/4 (gcs/repl/appl),
	vote policy= 0,
	group UUID = 110c04f4-ee16-11eb-9d8c-ab837787d450
2021-07-26 16:33:41 16 [Note] WSREP: Starting rollbacker thread 16
2021-07-26 16:33:41 0 [Note] WSREP: Flow-control interval: [23, 23]
2021-07-26 16:33:41 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 10)
2021-07-26 16:33:41 17 [Note] WSREP: Starting applier thread 17
2021-07-26 16:33:41 17 [Note] WSREP: ####### processing CC 10, local, ordered
2021-07-26 16:33:41 17 [Note] WSREP: Process first view: 110c04f4-ee16-11eb-9d8c-ab837787d450 my uuid: 169d15ca-ee16-11eb-8931-d21ae40b4c15
2021-07-26 16:33:41 17 [Note] WSREP: Server jan-HP-ZBook-15u-G5 connected to cluster at position 110c04f4-ee16-11eb-9d8c-ab837787d450:10 with ID 169d15ca-ee16-11eb-8931-d21ae40b4c15
2021-07-26 16:33:41 17 [Note] WSREP: Server status change disconnected -> connected
2021-07-26 16:33:41 17 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:41 17 [Note] WSREP: ####### My UUID: 169d15ca-ee16-11eb-8931-d21ae40b4c15
2021-07-26 16:33:41 17 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2021-07-26 16:33:41 0 [Note] WSREP: Service thread queue flushed.
2021-07-26 16:33:41 17 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2021-07-26 16:33:41 17 [Note] WSREP: State transfer required: 
	Group state: 110c04f4-ee16-11eb-9d8c-ab837787d450:10
	Local state: 110c04f4-ee16-11eb-9d8c-ab837787d450:7
2021-07-26 16:33:41 17 [Note] WSREP: Server status change connected -> joiner
2021-07-26 16:33:41 17 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:33:41 17 [Note] WSREP: Prepared SST request: mysqldump|127.0.0.1:16001
2021-07-26 16:33:41 17 [Note] WSREP: App waits SST: 1
2021-07-26 16:33:41 17 [Note] WSREP: ####### IST uuid:110c04f4-ee16-11eb-9d8c-ab837787d450 f: 8, l: 10, STRv: 3
2021-07-26 16:33:41 0 [Note] WSREP: Joiner monitor thread started to monitor
2021-07-26 16:33:41 17 [Note] WSREP: IST receiver addr using tcp://127.0.0.1:16006
2021-07-26 16:33:41 17 [Note] WSREP: Prepared IST receiver for 8-10, listening at: tcp://127.0.0.1:16006
2021-07-26 16:33:41 0 [Note] WSREP: Member 1.0 (jan-HP-ZBook-15u-G5) requested state transfer from '*any*'. Selected 0.0 (jan-HP-ZBook-15u-G5)(SYNCED) as donor.
2021-07-26 16:33:41 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 10)
2021-07-26 16:33:41 17 [Note] WSREP: Requesting state transfer: success, donor: 0
2021-07-26 16:33:43 0 [Note] WSREP: (169d15ca-8931, 'tcp://0.0.0.0:16005') turning message relay requesting off
2021-07-26 16:34:11 25 [Note] WSREP: SST setting local position to 110c04f4-ee16-11eb-9d8c-ab837787d450:7 current 00000000-0000-0000-0000-000000000000:-1
2021-07-26 16:34:11 25 [Note] WSREP: SST received
2021-07-26 16:34:11 25 [Note] WSREP: Server status change joiner -> joined
2021-07-26 16:34:11 25 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:34:11 25 [Note] WSREP: Recovered position from storage: 110c04f4-ee16-11eb-9d8c-ab837787d450:7
2021-07-26 16:34:11 25 [Note] WSREP: Recovered view from SST:
  id: 110c04f4-ee16-11eb-9d8c-ab837787d450: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: 110b06a5-ee16-11eb-a5aa-bed8a359e65c, jan-HP-ZBook-15u-G5
	1: 11604f8b-ee16-11eb-bc1d-fb61760fa8ae, jan-HP-ZBook-15u-G5
 
2021-07-26 16:34:11 25 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-26 16:34:11 26 [Note] WSREP: Recovered cluster id 110c04f4-ee16-11eb-9d8c-ab837787d450
2021-07-26 16:34:11 25 [Note] WSREP: SST received: 110c04f4-ee16-11eb-9d8c-ab837787d450:7
2021-07-26 16:34:11 25 [Note] WSREP: SST succeeded for position 110c04f4-ee16-11eb-9d8c-ab837787d450:7
2021-07-26 16:34:11 25 [Note] WSREP: wsrep_start_position set to '110c04f4-ee16-11eb-9d8c-ab837787d450:7'
2021-07-26 16:34:11 0 [Note] WSREP: Joiner monitor thread ended with total time 30 sec
2021-07-26 16:34:11 17 [Note] WSREP: Installed new state from SST: 110c04f4-ee16-11eb-9d8c-ab837787d450:7
2021-07-26 16:34:11 0 [Note] WSREP: 0.0 (jan-HP-ZBook-15u-G5): State transfer to 1.0 (jan-HP-ZBook-15u-G5) complete.
2021-07-26 16:34:11 0 [Note] WSREP: Member 0.0 (jan-HP-ZBook-15u-G5) synced with group.
2021-07-26 16:34:11 17 [Note] WSREP: Receiving IST: 3 writesets, seqnos 8-10
2021-07-26 16:34:11 0 [Note] WSREP: ####### IST applying starts with 8
2021-07-26 16:34:11 0 [Note] WSREP: ####### IST current seqno initialized to 3
2021-07-26 16:34:11 0 [Note] WSREP: Receiving IST...  0.0% (0/8 events) complete.
2021-07-26 16:34:11 0 [Note] WSREP: IST preload starting at 3
2021-07-26 16:34:11 0 [Note] WSREP: Service thread queue flushed.
2021-07-26 16:34:11 0 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:2, protocol version: 5
mysqld: /home/jan/mysql/galera-es/gcache/src/gcache_page_store.cpp:569: void gcache::PageStore::repossess(gcache::BufferHeader*, const void*): Assertion `p.freed_' failed.
210726 16:34:11 [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.20-13-MariaDB-debug
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=8
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63656 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0
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 = 0x0 thread_stack 0x49000
mysys/stacktrace.c:174(my_print_stacktrace)[0x558483de7b93]
sql/signal_handler.cc:222(handle_fatal_signal)[0x55848351ec51]
sigaction.c:0(__restore_rt)[0x7f9463be51f0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0xcb)[0x7f946369afbb]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x116)[0x7f9463680864]
/lib/x86_64-linux-gnu/libc.so.6(+0x26749)[0x7f9463680749]
/lib/x86_64-linux-gnu/libc.so.6(+0x383d6)[0x7f94636923d6]
src/gcache_page_store.cpp:571(gcache::PageStore::repossess(gcache::BufferHeader*, void const*))[0x7f945e531fc7]
src/GCache_seqno.cpp:323(gcache::GCache::seqno_get_ptr(long, long&))[0x7f945e528160]
src/ist_proto.hpp:663(galera::ist::Proto::recv_ordered(gu::AsioSocket&, std::pair<gcs_action, bool>&))[0x7f945e407ac5]
src/ist.cpp:382(galera::ist::Receiver::run())[0x7f945e3ffa85]
src/ist.cpp:156(run_receiver_thread)[0x7f945e3fe62b]
nptl/pthread_create.c:474(start_thread)[0x7f9463bda450]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x43)[0x7f9463771d53]
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 /home/jan/mysql/10.4e/mysql-test/var/mysqld.2/data
Resource Limits:
Fatal signal 11 while backtracing



 Comments   
Comment by Jan Lindström (Inactive) [ 2021-07-27 ]

I used incorrect Galera library accidentally.

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