[MDEV-32780] galera_as_slave_replay: assertion in the wsrep::transaction::before_rollback() Created: 2023-11-11  Updated: 2023-12-12

Status: In Testing
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.5.22
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Critical
Reporter: Julius Goryavsky Assignee: Ramesh Sivaraman
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Blocks
blocks MDEV-30172 Galera test case cleanup Stalled
Problem/Incident
is caused by MDEV-31413 Node has been dropped from the cluste... Closed
Relates
relates to MDEV-27806 Galera crash when "create a table as ... Closed
relates to MDEV-28378 galera.galera_as_slave_ctas fails wit... Stalled

 Description   

galera_as_slave_replay: test failed with assertion in the wsrep::transaction::before_rollback():

galera.galera_as_slave_replay 'innodb'   [ fail ]
        Test ended at 2023-11-10 21:20:04
 
CURRENT_TEST: galera.galera_as_slave_replay
mysqltest: At line 121: query 'let $wsrep_local_replays_new = `SELECT VARIABLE_VALUE FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_local_replays'`' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
SET SESSION wsrep_on = 0;
SET SESSION wsrep_on = 1;
SET GLOBAL debug_dbug = "";
SET DEBUG_SYNC = "now SIGNAL signal.wsrep_apply_cb";
connection node_2a;
SET GLOBAL wsrep_provider_options = 'dbug=';
SET GLOBAL wsrep_provider_options = 'signal=commit_monitor_master_enter_sync';
connection node_3;
SELECT COUNT(*) = 1 FROM t1 WHERE f2 = 'a';
COUNT(*) = 1
1
SELECT COUNT(*) = 1 FROM t1 WHERE f2 = 'c';
COUNT(*) = 1
1
SELECT * FROM t1;
f1	f2
1	a
3	c
connection node_2a;
set session wsrep_sync_wait=15;
 
More results from queries before failure can be found in /home/panda/mariadb-10.5/build/mysql-test/var/log/galera_as_slave_replay.log
 
 
Server [mysqld.2 - pid: 2167456, winpid: 2167456, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
$ /home/panda/mariadb-10.5/build/sql/mariadbd --defaults-group-suffix=.2 --defaults-file=/home/panda/mariadb-10.5/build/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 --core-file --loose-debug-sync-timeout=300
2023-11-10 21:19:40 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32190)
2023-11-10 21:19:40 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2023-11-10 21:19:40 0 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:16008' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members.
2023-11-10 21:19:40 0 [Note] Starting MariaDB 10.5.23-MariaDB-debug-log source revision 5deb8be746e988788ed6e5d91a935a02769bdd93 as process 2167457
2023-11-10 21:19:40 0 [Note] WSREP: wsrep_incoming_address = 127.0.0.1:16001
2023-11-10 21:19:40 0 [Note] WSREP: Server initial position: 00000000-0000-0000-0000-000000000000:-1
2023-11-10 21:19:40 0 [Note] WSREP: Loading provider /home/panda/galera/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
2023-11-10 21:19:40 0 [Note] WSREP: wsrep_load(): loading provider library '/home/panda/galera/libgalera_smm.so'
2023-11-10 21:19:40 0 [Note] WSREP: wsrep_load(): Galera 26.4.16(r63e9c25f) by Codership Oy <info@codership.com> loaded successfully.
2023-11-10 21:19:40 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
2023-11-10 21:19:40 0 [Warning] WSREP: Could not open state file for reading: '/home/panda/mariadb-10.5/build/mysql-test/var/mysqld.2/data//grastate.dat'
2023-11-10 21:19:40 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2023-11-10 21:19:40 0 [Note] WSREP: GCache DEBUG: opened preamble:
Version: 0
UUID: 00000000-0000-0000-0000-000000000000
Seqno: -1 - -1
Offset: -1
Synced: 0
2023-11-10 21:19:40 0 [Note] WSREP: Skipped GCache ring buffer recovery: could not determine history UUID.
2023-11-10 21:19:40 0 [Note] WSREP: Passing config to GCS: base_dir = /home/panda/mariadb-10.5/build/mysql-test/var/mysqld.2/data/; base_host = 127.0.0.1; base_port = 16006; 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 = PT30S; evs.install_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT10S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.debug = 0; gcache.dir = /home/panda/mariadb-10.5/build/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 = 10M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.fc_single_primary = no; gcs.max_packet_size = 645
2023-11-10 21:19:40 0 [Note] WSREP: SR storage init for: table
2023-11-10 21:19:40 0 [Note] WSREP: wsrep_start_replication
2023-11-10 21:19:40 0 [Note] WSREP: Start replication
2023-11-10 21:19:40 0 [Note] WSREP: Connecting with bootstrap option: 0
2023-11-10 21:19:40 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2023-11-10 21:19:40 0 [Note] WSREP: protonet asio version 0
2023-11-10 21:19:40 0 [Note] WSREP: Using CRC-32C for message checksums.
2023-11-10 21:19:40 0 [Note] WSREP: backend: asio
2023-11-10 21:19:40 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2023-11-10 21:19:40 0 [Note] WSREP: access file(/home/panda/mariadb-10.5/build/mysql-test/var/mysqld.2/data//gvwstate.dat) failed(No such file or directory)
2023-11-10 21:19:40 0 [Note] WSREP: restore pc from disk failed
2023-11-10 21:19:40 0 [Note] WSREP: GMCast version 0
2023-11-10 21:19:40 0 [Note] WSREP: (7a6129f4-81ad, 'tcp://0.0.0.0:16006') listening at tcp://0.0.0.0:16006
2023-11-10 21:19:40 0 [Note] WSREP: (7a6129f4-81ad, 'tcp://0.0.0.0:16006') multicast: , ttl: 1
2023-11-10 21:19:40 0 [Note] WSREP: EVS version 1
2023-11-10 21:19:40 0 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:16003'
2023-11-10 21:19:40 0 [Note] WSREP: (7a6129f4-81ad, 'tcp://0.0.0.0:16006') connection established to 799feaa1-a8c6 tcp://127.0.0.1:16003
2023-11-10 21:19:40 0 [Note] WSREP: (7a6129f4-81ad, 'tcp://0.0.0.0:16006') turning message relay requesting on, nonlive peers: 
2023-11-10 21:19:41 0 [Note] WSREP: EVS version upgrade 0 -> 1
2023-11-10 21:19:41 0 [Note] WSREP: declaring 799feaa1-a8c6 at tcp://127.0.0.1:16003 stable
2023-11-10 21:19:41 0 [Note] WSREP: PC protocol upgrade 0 -> 1
2023-11-10 21:19:41 0 [Note] WSREP: Node 799feaa1-a8c6 state prim
2023-11-10 21:19:41 0 [Note] WSREP: view(view_id(PRIM,799feaa1-a8c6,2) memb {
	799feaa1-a8c6,0
	7a6129f4-81ad,0
} joined {
} left {
} partitioned {
})
2023-11-10 21:19:41 0 [Note] WSREP: save pc into disk
2023-11-10 21:19:41 0 [Note] WSREP: gcomm: connected
2023-11-10 21:19:41 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2023-11-10 21:19:41 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2023-11-10 21:19:41 0 [Note] WSREP: Opened channel 'my_wsrep_cluster'
2023-11-10 21:19:41 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2023-11-10 21:19:41 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2023-11-10 21:19:41 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 7abed0c0-8006-11ee-9c3b-0e5b6532302b
2023-11-10 21:19:41 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7abed0c0-8006-11ee-9c3b-0e5b6532302b from 0 (panda)
2023-11-10 21:19:41 1 [Note] WSREP: wsrep system thread 1, 0x7f0da4000dc8 starting
2023-11-10 21:19:41 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7abed0c0-8006-11ee-9c3b-0e5b6532302b from 1 (panda)
2023-11-10 21:19:41 1 [Note] WSREP: Starting rollbacker thread 1
2023-11-10 21:19:41 2 [Note] WSREP: wsrep system thread 2, 0x7f0da8000dc8 starting
2023-11-10 21:19:41 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 = 79a568e4-8006-11ee-bee1-a6fa087265cf
2023-11-10 21:19:41 0 [Note] WSREP: Flow-control interval: [23, 23]
2023-11-10 21:19:41 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2)
2023-11-10 21:19:41 2 [Note] WSREP: Starting applier thread 2
2023-11-10 21:19:41 2 [Note] WSREP: ####### processing CC 2, local, ordered
2023-11-10 21:19:41 2 [Note] WSREP: Process first view: 79a568e4-8006-11ee-bee1-a6fa087265cf my uuid: 7a6129f4-8006-11ee-81ad-93233b85f30d
2023-11-10 21:19:41 2 [Note] WSREP: Server panda connected to cluster at position 79a568e4-8006-11ee-bee1-a6fa087265cf:2 with ID 7a6129f4-8006-11ee-81ad-93233b85f30d
2023-11-10 21:19:41 2 [Note] WSREP: server panda state change: disconnected -> connected
2023-11-10 21:19:41 2 [Note] WSREP: Server status change disconnected -> connected
2023-11-10 21:19:41 2 [Note] WSREP: Setting wsrep_ready to 0
2023-11-10 21:19:41 2 [Note] WSREP: wsrep_notify_status server not yet ready : wsrep_ready=0 status 3
2023-11-10 21:19:41 2 [Note] WSREP: ####### My UUID: 7a6129f4-8006-11ee-81ad-93233b85f30d
2023-11-10 21:19:41 2 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2023-11-10 21:19:41 0 [Note] WSREP: Service thread queue flushed.
2023-11-10 21:19:41 2 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2023-11-10 21:19:41 2 [Note] WSREP: State transfer required: 
	Group state: 79a568e4-8006-11ee-bee1-a6fa087265cf:2
	Local state: 00000000-0000-0000-0000-000000000000:-1
2023-11-10 21:19:41 2 [Note] WSREP: server panda state change: connected -> joiner
2023-11-10 21:19:41 2 [Note] WSREP: Server status change connected -> joiner
2023-11-10 21:19:41 2 [Note] WSREP: Setting wsrep_ready to 0
2023-11-10 21:19:41 2 [Note] WSREP: wsrep_notify_status server not yet ready : wsrep_ready=0 status 4
2023-11-10 21:19:41 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '127.0.0.1:16008' --datadir '/home/panda/mariadb-10.5/build/mysql-test/var/mysqld.2/data/' --defaults-file '/home/panda/mariadb-10.5/build/mysql-test/var/my.cnf' --defaults-group-suffix '.2' --parent 2167457 --progress 0 --binlog 'mysqld-bin' --binlog-index 'mysqld-bin.index' --mysqld-args --defaults-group-suffix=.2 --defaults-file=/home/panda/mariadb-10.5/build/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 --core-file --loose-debug-sync-timeout=300'
2023-11-10 21:19:41 0 [Note] WSREP: Joiner monitor thread started to monitor
WSREP_SST: [INFO] rsync SST started on joiner (20231110 21:19:41.675)
WSREP_SST: [INFO] Using stunnel for SSL encryption: CA: '/home/panda/mariadb-10.5/mysql-test/std_data/cacert.pem', CAPATH='', ssl-mode='VERIFY_CA' (20231110 21:19:41.785)
2023.11.10 21:19:41 LOG4[ui]: Insecure file permissions on /home/panda/mariadb-10.5/mysql-test/std_data/server-key.pem
2023-11-10 21:19:41 2 [Note] WSREP: Prepared SST request: rsync|localhost:aedc6bd4b1f47de6619bcc60fe3909a5@127.0.0.1:16008/rsync_sst
2023-11-10 21:19:41 2 [Note] WSREP: App waits SST: 1
2023-11-10 21:19:41 2 [Note] WSREP: ####### IST uuid:00000000-0000-0000-0000-000000000000 f: 0, l: 2, STRv: 3
2023-11-10 21:19:41 2 [Note] WSREP: IST receiver addr using tcp://127.0.0.1:16007
2023-11-10 21:19:41 2 [Note] WSREP: Prepared IST receiver for 0-2, listening at: tcp://127.0.0.1:16007
2023-11-10 21:19:41 0 [Note] WSREP: Member 1.0 (panda) requested state transfer from '*any*'. Selected 0.0 (panda)(SYNCED) as donor.
2023-11-10 21:19:41 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 2)
2023-11-10 21:19:41 2 [Note] WSREP: Requesting state transfer: success, donor: 0
2023-11-10 21:19:41 2 [Note] WSREP: Resetting GCache seqno map due to different histories.
2023-11-10 21:19:41 2 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:44 0 [Note] WSREP: (7a6129f4-81ad, 'tcp://0.0.0.0:16006') turning message relay requesting off
2023.11.10 21:19:44 LOG3[0]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:44 LOG3[1]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:44 LOG3[2]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[3]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[4]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[5]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[7]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[8]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[6]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023.11.10 21:19:45 LOG3[9]: SSL_read: ../ssl/record/rec_layer_s3.c:308: error:0A000126:SSL routines::unexpected eof while reading
2023-11-10 21:19:45 0 [Note] WSREP: 0.0 (panda): State transfer to 1.0 (panda) complete.
2023-11-10 21:19:45 0 [Note] WSREP: Member 0.0 (panda) synced with group.
WSREP_SST: [INFO] Extracting binlog files: (20231110 21:19:46.043)
mysqld-bin.000002
WSREP_SST: [INFO] Galera co-ords from recovery: 79a568e4-8006-11ee-bee1-a6fa087265cf:2 0 (20231110 21:19:46.093)
WSREP_SST: [INFO] rsync SST completed on joiner (20231110 21:19:46.096)
WSREP_SST: [INFO] Joiner cleanup: rsync PID=0, stunnel PID=2167611 (20231110 21:19:46.099)
WSREP_SST: [INFO] Joiner cleanup done. (20231110 21:19:46.632)
2023-11-10 21:19:46 3 [Note] WSREP: SST received
2023-11-10 21:19:46 3 [Note] WSREP: server panda state change: joiner -> initializing
2023-11-10 21:19:46 3 [Note] WSREP: Server status change joiner -> initializing
2023-11-10 21:19:46 3 [Note] WSREP: Setting wsrep_ready to 0
2023-11-10 21:19:46 3 [Note] WSREP: wsrep_notify_status server not yet ready : wsrep_ready=0 status 1
2023-11-10 21:19:46 0 [Note] Plugin 'partition' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'SEQUENCE' is disabled.
2023-11-10 21:19:46 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2023-11-10 21:19:46 0 [Note] InnoDB: Uses event mutexes
2023-11-10 21:19:46 0 [Note] InnoDB: Compressed tables use zlib 1.2.13
2023-11-10 21:19:46 0 [Note] InnoDB: Number of pools: 1
2023-11-10 21:19:46 0 [Note] InnoDB: Using SSE4.2 crc32 instructions
2023-11-10 21:19:46 0 [Note] InnoDB: Using Linux native AIO
2023-11-10 21:19:46 0 [Note] InnoDB: Initializing buffer pool, total size = 8388608, chunk size = 8388608
2023-11-10 21:19:46 0 [Note] InnoDB: Completed initialization of buffer pool
2023-11-10 21:19:46 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=55462,55462
2023-11-10 21:19:46 0 [Note] InnoDB: 128 rollback segments are active.
2023-11-10 21:19:46 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2023-11-10 21:19:46 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2023-11-10 21:19:46 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2023-11-10 21:19:46 0 [Note] InnoDB: 10.5.23 started; log sequence number 55474; transaction id 44
2023-11-10 21:19:46 0 [Note] InnoDB: Loading buffer pool(s) from /home/panda/mariadb-10.5/build/mysql-test/var/mysqld.2/data/ib_buffer_pool
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_CMP' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'FEEDBACK' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'user_variables' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
2023-11-10 21:19:46 0 [Note] Plugin 'unix_socket' is disabled.
2023-11-10 21:19:46 0 [Note] WSREP: wsrep_plugin_init()
2023-11-10 21:19:46 0 [Warning] /home/panda/mariadb-10.5/build/sql/mariadbd: unknown option '--loose-pam-debug'
2023-11-10 21:19:46 0 [Warning] /home/panda/mariadb-10.5/build/sql/mariadbd: unknown option '--loose-aria'
2023-11-10 21:19:46 0 [Note] Recovering after a crash using mysqld-bin
2023-11-10 21:19:46 0 [Note] Starting crash recovery...
2023-11-10 21:19:46 0 [Note] Crash recovery finished.
2023-11-10 21:19:46 0 [Note] InnoDB: Buffer pool(s) load completed at 231110 21:19:46
2023-11-10 21:19:46 0 [Note] WSREP: MYSQL_BIN_LOG::open(): Adding new xid_list_entry for mysqld-bin.000003 (1)
2023-11-10 21:19:46 0 [Note] Server socket created on IP: '127.0.0.1'.
2023-11-10 21:19:46 0 [Note] WSREP: Read WSREPXid from InnoDB:  79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:46 0 [Note] WSREP: wsrep_init_schema_and_SR (nil)
2023-11-10 21:19:46 5 [Note] WSREP: SQL: 236 CREATE TABLE IF NOT EXISTS mysql.wsrep_cluster(cluster_uuid CHAR(36) PRIMARY KEY,view_id BIGINT NOT NULL,view_seqno BIGINT NOT NULL,protocol_version INT NOT NULL,capabilities INT NOT NULL) ENGINE=InnoDB STATS_PERSISTENT=0 CHARSET=latin1 thd: 5
2023-11-10 21:19:46 5 [Note] WSREP: SQL: 237 CREATE TABLE IF NOT EXISTS mysql.wsrep_cluster_members(node_uuid CHAR(36) PRIMARY KEY,cluster_uuid CHAR(36) NOT NULL,node_name CHAR(32) NOT NULL,node_incoming_address VARCHAR(256) NOT NULL) ENGINE=InnoDB STATS_PERSISTENT=0 CHARSET=latin1 thd: 5
2023-11-10 21:19:46 5 [Note] WSREP: SQL: 233 CREATE TABLE IF NOT EXISTS mysql.wsrep_streaming_log(node_uuid CHAR(36), trx_id BIGINT, seqno BIGINT, flags INT NOT NULL, frag LONGBLOB NOT NULL, PRIMARY KEY (node_uuid, trx_id, seqno)) ENGINE=InnoDB STATS_PERSISTENT=0 CHARSET=latin1 thd: 5
2023-11-10 21:19:46 5 [Note] WSREP: SQL: 65 ALTER TABLE mysql.wsrep_cluster STATS_PERSISTENT=0 CHARSET=latin1 thd: 5
2023-11-10 21:19:46 5 [Note] WSREP: SQL: 73 ALTER TABLE mysql.wsrep_cluster_members STATS_PERSISTENT=0 CHARSET=latin1 thd: 5
2023-11-10 21:19:46 5 [Note] WSREP: SQL: 71 ALTER TABLE mysql.wsrep_streaming_log STATS_PERSISTENT=0 CHARSET=latin1 thd: 5
2023-11-10 21:19:46 0 [Note] WSREP: Server initialized
2023-11-10 21:19:46 0 [Note] WSREP: server panda state change: initializing -> initialized
2023-11-10 21:19:46 0 [Note] WSREP: Server status change initializing -> initialized
2023-11-10 21:19:46 0 [Note] WSREP: Setting wsrep_ready to 0
2023-11-10 21:19:46 0 [Note] WSREP: wsrep_notify_status server not yet ready : wsrep_ready=0 status 2
2023-11-10 21:19:46 0 [Note] WSREP: Startup creating 0 applier threads running 1
2023-11-10 21:19:46 0 [Note] Reading of all Master_info entries succeeded
2023-11-10 21:19:46 0 [Note] Added new Master_info '' to hash table
2023-11-10 21:19:46 0 [Note] /home/panda/mariadb-10.5/build/sql/mariadbd: ready for connections.
Version: '10.5.23-MariaDB-debug-log'  socket: '/home/panda/mariadb-10.5/build/mysql-test/var/tmp/mysqld.2.sock'  port: 16001  Source distribution
2023-11-10 21:19:46 8 [Note] WSREP: assigned new next trx id: 7
2023-11-10 21:19:46 8 [Note] WSREP: wsrep_after_statement for 8 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:46 8 [Note] WSREP: assigned new next trx id: 8
2023-11-10 21:19:46 3 [Note] WSREP: Read WSREPXid from InnoDB:  79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:46 3 [Note] WSREP: Recovered position from storage: 79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:46 3 [Note] WSREP: server panda state change: initialized -> joined
2023-11-10 21:19:46 3 [Note] WSREP: Server status change initialized -> joined
2023-11-10 21:19:46 3 [Note] WSREP: wsrep_notify_status server not yet ready : wsrep_ready=0 status 5
2023-11-10 21:19:46 3 [Note] WSREP: Restored cluster view:
  id: 79a568e4-8006-11ee-bee1-a6fa087265cf: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: 799feaa1-8006-11ee-a8c6-9faf3f89bd83, panda
	1: 7a6129f4-8006-11ee-81ad-93233b85f30d, panda
 
2023-11-10 21:19:46 3 [Note] WSREP: Recovered view from SST:
  id: 79a568e4-8006-11ee-bee1-a6fa087265cf: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: 799feaa1-8006-11ee-a8c6-9faf3f89bd83, panda
	1: 7a6129f4-8006-11ee-81ad-93233b85f30d, panda
 
2023-11-10 21:19:46 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2023-11-10 21:19:46 3 [Note] WSREP: No applier in Wsrep_server_service::log_view(), skipping write to wsrep_schema
2023-11-10 21:19:46 8 [Note] WSREP: wsrep_commit_empty for 8 client_state exec client_mode local trans_state executing sql SELECT VARIABLE_NAME, VARIABLE_VALUE
              FROM INFORMATION_SCHEMA.GLOBAL_STATUS
              WHERE VARIABLE_NAME = 'wsrep_ready'
2023-11-10 21:19:46 8 [Note] WSREP: wsrep_after_statement for 8 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:46 8 [Note] WSREP: wsrep_after_statement for 8 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:46 8 [Note] WSREP: assigned new next trx id: 9
2023-11-10 21:19:46 9 [Note] WSREP: Recovered cluster id 79a568e4-8006-11ee-bee1-a6fa087265cf
2023-11-10 21:19:46 3 [Note] WSREP: SST received: 79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:46 3 [Note] WSREP: SST succeeded for position 79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:46 0 [Note] WSREP: Joiner monitor thread ended with total time 5 sec
2023-11-10 21:19:46 2 [Note] WSREP: Installed new state from SST: 79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:47 2 [Note] WSREP: Cert. index preload up to 2
2023-11-10 21:19:47 0 [Note] WSREP: ####### IST applying starts with 3
2023-11-10 21:19:47 0 [Note] WSREP: ####### IST current seqno initialized to 2
2023-11-10 21:19:47 0 [Note] WSREP: Receiving IST...  0.0% (0/1 events) complete.
2023-11-10 21:19:47 0 [Note] WSREP: IST preload starting at 2
2023-11-10 21:19:47 0 [Note] WSREP: REPL Protocols: 10 (5)
2023-11-10 21:19:47 0 [Note] WSREP: Service thread queue flushed.
2023-11-10 21:19:47 0 [Note] WSREP: ####### Assign initial position for certification: 79a568e4-8006-11ee-bee1-a6fa087265cf:1, protocol version: 5
2023-11-10 21:19:47 0 [Note] WSREP: REPL Protocols: 10 (5)
2023-11-10 21:19:47 0 [Note] WSREP: ####### Adjusting cert position: 1 -> 2
2023-11-10 21:19:47 0 [Note] WSREP: Service thread queue flushed.
2023-11-10 21:19:47 0 [Note] WSREP: Lowest cert index boundary for CC from preload: 2
2023-11-10 21:19:47 0 [Note] WSREP: Min available from gcache for CC from preload: 2
2023-11-10 21:19:47 0 [Note] WSREP: Receiving IST...100.0% (1/1 events) complete.
2023-11-10 21:19:47 2 [Note] WSREP: IST received: 79a568e4-8006-11ee-bee1-a6fa087265cf:2
2023-11-10 21:19:47 2 [Note] WSREP: Lowest cert index boundary for CC from sst: 2
2023-11-10 21:19:47 2 [Note] WSREP: Min available from gcache for CC from sst: 2
2023-11-10 21:19:47 0 [Note] WSREP: 1.0 (panda): State transfer from 0.0 (panda) complete.
2023-11-10 21:19:47 0 [Note] WSREP: Shifting JOINER -> JOINED (TO: 2)
2023-11-10 21:19:47 0 [Note] WSREP: Processing event queue:... -nan% (0/0 events) complete.
2023-11-10 21:19:47 0 [Note] WSREP: Member 1.0 (panda) synced with group.
2023-11-10 21:19:47 0 [Note] WSREP: Processing event queue:...100.0% (1/1 events) complete.
2023-11-10 21:19:47 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2)
2023-11-10 21:19:47 2 [Note] WSREP: Server panda synced with group
2023-11-10 21:19:47 2 [Note] WSREP: server panda state change: joined -> synced
2023-11-10 21:19:47 2 [Note] WSREP: Server status change joined -> synced
2023-11-10 21:19:47 2 [Note] WSREP: Synchronized with group, ready for connections
2023-11-10 21:19:47 2 [Note] WSREP: Setting wsrep_ready to 1
2023-11-10 21:19:47 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2023-11-10 21:19:47 10 [Note] WSREP: assigned new next trx id: 10
2023-11-10 21:19:47 10 [Note] WSREP: wsrep_after_statement for 10 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 10 [Note] WSREP: assigned new next trx id: 11
2023-11-10 21:19:47 10 [Note] WSREP: wsrep_commit_empty for 10 client_state exec client_mode local trans_state executing sql SELECT VARIABLE_NAME, VARIABLE_VALUE
              FROM INFORMATION_SCHEMA.GLOBAL_STATUS
              WHERE VARIABLE_NAME = 'wsrep_ready'
2023-11-10 21:19:47 10 [Note] WSREP: wsrep_after_statement for 10 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 10 [Note] WSREP: wsrep_after_statement for 10 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 10 [Note] WSREP: assigned new next trx id: 12
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 13
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SHOW SLAVE STATUS
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 14
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT 'No such row' = 'No such row'
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 15
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql select count(*) from mysql.proc
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 16
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 17
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES     WHERE variable_name NOT IN ('timestamp')      AND variable_name not like "Last_IO_Err*"      AND variable_name != 'INNODB_IBUF_MAX_SIZE'      AND variable_name != 'INNODB_USE_NATIVE_AIO'      AND variable_name != 'INNODB_BUFFER_POOL_LOAD_AT_STARTUP'      AND variable_name not like 'GTID%POS'      AND variable_name != 'GTID_BINLOG_STATE'      AND variable_name != 'THREAD_POOL_SIZE'    ORDER BY variable_name
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 18
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.SCHEMATA ORDER BY BINARY SCHEMA_NAME
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 19
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.SCHEMATA     WHERE SCHEMA_NAME NOT IN ('mtr_wsrep_notify', 'wsrep_schema')     ORDER BY BINARY SCHEMA_NAME
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 20
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT table_name AS tables_in_test FROM INFORMATION_SCHEMA.TABLES     WHERE table_schema='test'
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 21
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT CONCAT(table_schema, '.', table_name) AS tables_in_mysql     FROM INFORMATION_SCHEMA.TABLES       WHERE table_schema='mysql'         ORDER BY tables_in_mysql
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 22
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT CONCAT(table_schema, '.', table_name) AS columns_in_mysql,   	 column_name, ordinal_position, column_default, is_nullable,          data_type, character_maximum_length, character_octet_length,          numeric_precision, numeric_scale, character_set_name,          collation_name, column_type, column_key, extra, column_comment     FROM INFORMATION_SCHEMA.COLUMNS       WHERE table_schema='mysql'         ORDER BY columns_in_mysql
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 23
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.EVENTS
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 24
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.TRIGGERS          WHERE TRIGGER_NAME NOT IN ('gs_insert', 'ts_insert')
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 25
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.ROUTINES
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 26
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SHOW STATUS LIKE 'slave_open_temp_tables'
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 27
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 28
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT * FROM INFORMATION_SCHEMA.PLUGINS
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 29
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql select * from information_schema.session_variables     where variable_name = 'debug_sync'
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 16
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 30
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql select @@datadir
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 31
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT COUNT(*)=1 FROM INFORMATION_SCHEMA.PLUGINS WHERE PLUGIN_NAME = 'wsrep' AND PLUGIN_STATUS='ACTIVE'
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 32
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT @@wsrep_on
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 33
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_commit_empty for 11 client_state exec client_mode local trans_state executing sql SELECT COUNT(*) FROM information_schema.innodb_trx WHERE trx_mysql_thread_id != 0
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: wsrep_after_statement for 11 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 11 [Note] WSREP: assigned new next trx id: 34
2023-11-10 21:19:47 12 [Note] WSREP: assigned new next trx id: 35
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql select count(*) from information_schema.system_variables where variable_name='have_sanitizer' and global_value like 'MSAN%'
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: assigned new next trx id: 36
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SELECT COUNT(*)=0 FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME = 'wsrep_on' AND VARIABLE_VALUE='ON'
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: assigned new next trx id: 37
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 8, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SHOW STATUS LIKE 'wsrep_ready'
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: assigned new next trx id: 38
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 8, thd->variables.wsrep_on= 1
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SHOW STATUS LIKE 'wsrep_ready'
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:47 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 13 [Note] WSREP: assigned new next trx id: 39
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_commit_empty for 13 client_state exec client_mode local trans_state executing sql SELECT VARIABLE_VALUE = 'ON' FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_ready'
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_after_statement for 13 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_after_statement for 13 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 13 [Note] WSREP: assigned new next trx id: 40
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_commit_empty for 13 client_state exec client_mode local trans_state executing sql select count(*) from information_schema.system_variables where variable_name='have_sanitizer' and global_value like 'MSAN%'
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_after_statement for 13 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 13 [Note] WSREP: wsrep_after_statement for 13 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 41
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SELECT VARIABLE_VALUE FROM INFORMATION_SCHEMA.GLOBAL_STATUS WHERE VARIABLE_NAME = 'wsrep_local_replays'
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 42
2023-11-10 21:19:49 12 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
2023-11-10 21:19:49 12 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='16002', master_log_file='', master_log_pos='4'.
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql CHANGE MASTER TO  MASTER_HOST='127.0.0.1', MASTER_USER='root', MASTER_PORT=16002
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 43
2023-11-10 21:19:49 14 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16002' in log '' at position 4
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql START SLAVE
2023-11-10 21:19:49 15 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './mysqld-relay-bin.000001' position: 4
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 14 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16002',replication started in log 'FIRST' at position 4
2023-11-10 21:19:49 15 [Note] WSREP: ready state reached
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next query and  trx id: 44
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: TOI Begin: CREATE TABLE t1 (f1 INTEGER PRIMARY KEY, f2 CHAR(1)) engine=innodb
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 45
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 46
2023-11-10 21:19:49 15 [Note] WSREP: avoiding binlog rotate due to TO isolation: 1
2023-11-10 21:19:49 15 [Note] WSREP: TO END: 3: CREATE TABLE t1 (f1 INTEGER PRIMARY KEY, f2 CHAR(1)) engine=innodb
2023-11-10 21:19:49 15 [Note] WSREP: Set WSREPXid for InnoDB:  79a568e4-8006-11ee-bee1-a6fa087265cf:3
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SELECT COUNT(*) = 2 FROM test.t1
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 15 [Note] WSREP: TO END: -1
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next query and  trx id: 47
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next trx id: 48
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_before_prepare: 1
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 49
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_prepare: 1
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_before_commit: 1, 4
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_ordered_commit: 1 4
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_commit: 1, 1, 4, 1
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state committed
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next query and  trx id: 50
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SELECT COUNT(*) = 2 FROM test.t1
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next trx id: 51
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_before_prepare: 1
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_prepare: 1
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_before_commit: 1, 5
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_ordered_commit: 1 5
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_commit: 1, 1, 5, 1
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state committed
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 52
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SELECT COUNT(*) = 2 FROM test.t1
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 53
2023-11-10 21:19:49 12 [Note] WSREP: refresh_provider_options: dbug=d,commit_monitor_master_enter_sync
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 54
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_commit_empty for 2 client_state exec client_mode high priority trans_state executing sql NULL
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next query and  trx id: 55
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: assigned new next query and  trx id: 56
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 57
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_commit_empty for 12 client_state exec client_mode local trans_state executing sql SELECT @@wsrep_on
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 58
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state executing
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_before_prepare: 1
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_prepare: 1
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_before_commit: 1, 7
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 63
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 64
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 2 [Note] WSREP: assigned new next trx id: 65
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 66
2023-11-10 21:19:49 12 [Note] WSREP: refresh_provider_options: dbug=
2023-11-10 21:19:49 2 [Note] WSREP: waiting for BF, trx order: 6 7
 
2023-11-10 21:19:49 2 [Note] WSREP: waiting for BF, trx order: 6 7
 
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 2 [Note] WSREP: cluster conflict due to high priority abort for threads:
2023-11-10 21:19:49 2 [Note] WSREP: Winning thread: 
   THD: 2, mode: high priority, state: exec, conflict: executing, seqno: 6
   SQL: INSERT INTO test.t1 VALUES (2, 'b')eNe
2023-11-10 21:19:49 2 [Note] WSREP: Victim thread: 
   THD: 15, mode: local, state: exec, conflict: committing, seqno: 7
   SQL: NULL
2023-11-10 21:19:49 2 [Note] WSREP: context: /home/panda/mariadb-10.5/storage/innobase/handler/ha_innodb.cc:18766
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_innobase_kill_one_trx: Aborter BF trx_id: 58 thread: 2 seqno: 6 client_state: exec client_mode: high priority trx_state executing query: INSERT INTO test.t1 VALUES (2, 'b')eNe
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_innobase_kill_one_trx: Victim normal trx_id: 57 thread: 15 seqno: 7 client_state: exec client_mode: local trx_state committing query: NULL
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_bf_abort BF aborter before
    thd: 2 thd_ptr: 0x7f0da8000dc8 client_mode: high priority client_state: exec trx_state: executing
    next_trx_id: 65 trx_id: 54 seqno: 6
    is_streaming: 0 fragments: 0
    sql_errno: 0 message: 
    command: 161 query: INSERT INTO test.t1 VALUES (2, 'b')eNe
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_bf_abort victim before
    thd: 15 thd_ptr: 0x7f0d98002ee8 client_mode: local client_state: exec trx_state: committing
    next_trx_id: 56 trx_id: 55 seqno: 7
    is_streaming: 0 fragments: 0
    sql_errno: 0 message: 
    command: 4 query: NULL
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_thd_bf_abort has failed, victim 15 will survive
2023-11-10 21:19:49 2 [Note] WSREP: waiting for BF, trx order: 6 7
 
2023-11-10 21:19:49 2 [Note] WSREP: waiting for BF, trx order: 6 7
 
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 67
2023-11-10 21:19:49 12 [Note] WSREP: refresh_provider_options: signal=commit_monitor_master_enter_sync
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_before_prepare: 1
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 68
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_after_statement for 12 client_state exec  client_mode local trans_state aborted
2023-11-10 21:19:49 12 [Note] WSREP: assigned new next trx id: 69
2023-11-10 21:19:49 12 [Note] WSREP: wsrep_sync_wait: thd->variables.wsrep_sync_wait= 15, mask= 1, thd->variables.wsrep_on= 1
2023-11-10 21:19:49 15 [Note] WSREP: SQL apply failed for MUST_REPLAY, res 1
2023-11-10 21:19:49 15 [Note] WSREP: apply_event_and_update_pos() result: 0
2023-11-10 21:19:49 15 [Note] WSREP: wsrep_after_statement for 15 client_state exec  client_mode local trans_state must_replay
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_after_prepare: 1
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_before_commit: 1, 6
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_ordered_commit: 1 6
2023-11-10 21:19:49 1 [Note] WSREP: wsrep_commit_empty for 1 client_state exec client_mode high priority trans_state replaying sql NULL
2023-11-10 21:19:49 1 [Note] WSREP: assigned new next trx id: 70
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_after_commit: 1, 1, 6, 0
2023-11-10 21:19:49 2 [Note] WSREP: wsrep_after_apply 2
2023-11-10 21:19:49 1 [Note] WSREP: assigned new next trx id: 71
2023-11-10 21:19:49 1 [ERROR] Slave SQL: Could not execute Write_rows_v1 event on table mysql.gtid_slave_pos; Duplicate entry '0-4' for key 'PRIMARY', Error_code: 1062; handler error HA_ERR_FOUND_DUPP_KEY; the event's master log FIRST, end_log_pos 199, Internal MariaDB error code: 1062
2023-11-10 21:19:49 1 [Warning] WSREP: Event 4 Write_rows_v1 apply failed: 121, seqno 7
2023-11-10 21:19:49 1 [Note] WSREP: Error buffer for thd 1 seqno 7, 60 bytes: ' Duplicate entry '0-4' for key 'PRIMARY', Error_code: 1062;'
mariadbd: /home/panda/mariadb-10.5/wsrep-lib/src/transaction.cpp:659: int wsrep::transaction::before_rollback(): Assertion `state() == s_executing || state() == s_preparing || state() == s_prepared || state() == s_must_abort || state() == s_aborting || state() == s_cert_failed || state() == s_must_replay' failed.
231110 21:19:49 [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.5.23-MariaDB-debug-log source revision: 5deb8be746e988788ed6e5d91a935a02769bdd93
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=7
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63769 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f0d98041458
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 = 0x7f0db8097518 thread_stack 0x49000
mysys/stacktrace.c:212(my_print_stacktrace)[0x56549edc7361]
sql/signal_handler.cc:241(handle_fatal_signal)[0x56549e43a0d9]
libc_sigaction.c:0(__restore_rt)[0x7f0dc726f520]
nptl/pthread_kill.c:44(__pthread_kill_implementation)[0x7f0dc72c39fc]
posix/raise.c:27(__GI_raise)[0x7f0dc726f476]
stdlib/abort.c:81(__GI_abort)[0x7f0dc72557f3]
intl/loadmsgcat.c:1177(_nl_load_domain)[0x7f0dc725571b]
/lib/x86_64-linux-gnu/libc.so.6(+0x39e96)[0x7f0dc7266e96]
src/transaction.cpp:668(wsrep::transaction::before_rollback())[0x56549efb8f4f]
src/client_state.cpp:412(wsrep::client_state::before_rollback())[0x56549ef96491]
sql/wsrep_trans_observer.h:431(wsrep_before_rollback(THD*, bool))[0x56549e43cbad]
sql/handler.cc:2097(ha_rollback_trans(THD*, bool))[0x56549e441b47]
sql/transaction.cc:372(trans_rollback(THD*))[0x56549e282250]
sql/wsrep_high_priority_service.cc:383(Wsrep_high_priority_service::rollback(wsrep::ws_handle const&, wsrep::ws_meta const&))[0x56549e8455bf]
src/server_state.cpp:342(apply_write_set(wsrep::server_state&, wsrep::high_priority_service&, wsrep::ws_handle const&, wsrep::ws_meta const&, wsrep::const_buffer const&))[0x56549efa8f45]
src/server_state.cpp:1129(wsrep::server_state::on_apply(wsrep::high_priority_service&, wsrep::ws_handle const&, wsrep::ws_meta const&, wsrep::const_buffer const&))[0x56549efacef6]
wsrep/high_priority_service.hpp:48(wsrep::high_priority_service::apply(wsrep::ws_handle const&, wsrep::ws_meta const&, wsrep::const_buffer const&))[0x56549efc794f]
src/wsrep_provider_v26.cpp:507((anonymous namespace)::apply_cb(void*, wsrep_ws_handle const*, unsigned int, wsrep_buf const*, wsrep_trx_meta const*, bool*))[0x56549efc4511]
src/trx_handle.cpp:396(galera::TrxHandleSlave::apply(void*, wsrep_cb_status (*)(void*, wsrep_ws_handle const*, unsigned int, wsrep_buf const*, wsrep_trx_meta const*, bool*), wsrep_trx_meta const&, bool&))[0x7f0dc2a3d651]
src/replicator_smm.cpp:1104(galera::ReplicatorSMM::replay_trx(galera::TrxHandleMaster&, galera::TrxHandleLock&, void*))[0x7f0dc2a4ad60]
src/wsrep_provider.cpp:339(galera_replay_trx)[0x7f0dc2a1cf67]
src/wsrep_provider_v26.cpp:984(wsrep::wsrep_provider_v26::replay(wsrep::ws_handle const&, wsrep::high_priority_service*))[0x56549efc63c5]
sql/wsrep_client_service.cc:297(Wsrep_client_service::replay())[0x56549e84192a]
src/transaction.cpp:2047(wsrep::transaction::replay(std::unique_lock<wsrep::mutex>&))[0x56549efbe492]
src/transaction.cpp:882(wsrep::transaction::after_statement(std::unique_lock<wsrep::mutex>&))[0x56549efb9a32]
src/client_state.cpp:266(wsrep::client_state::after_statement())[0x56549ef9584d]
sql/wsrep_trans_observer.h:470(wsrep_after_statement(THD*))[0x56549df71514]
sql/slave.cc:4499(exec_relay_log_event(THD*, Relay_log_info*, rpl_group_info*))[0x56549df803b0]
sql/slave.cc:5598(handle_slave_sql)[0x56549df83fca]
perfschema/pfs.cc:2203(pfs_spawn_thread)[0x56549e7baea0]
nptl/pthread_create.c:442(start_thread)[0x7f0dc72c1ac3]
x86_64/clone3.S:83(__clone3)[0x7f0dc7353a40]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0): (null)
Connection ID (thread ID): 1
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,not_null_range_scan=off
 
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.
 
We think the query pointer is invalid, but we will try to print it anyway. 
Query: 
 
Writing a core file...
Working directory at /home/panda/mariadb-10.5/build/mysql-test/var/mysqld.2/data
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        unlimited            unlimited            bytes     
Max resident set          unlimited            unlimited            bytes     
Max processes             63457                63457                processes 
Max open files            1024                 1024                 files     
Max locked memory         2094301184           2094301184           bytes     
Max address space         unlimited            unlimited            bytes     
Max file locks            unlimited            unlimited            locks     
Max pending signals       63457                63457                signals   
Max msgqueue size         819200               819200               bytes     
Max nice priority         0                    0                    
Max realtime priority     0                    0                    
Max realtime timeout      unlimited            unlimited            us        
Core pattern: |/usr/share/apport/apport -p%p -s%s -c%c -d%d -P%P -u%u -g%g -- %E



 Comments   
Comment by Jan Lindström [ 2023-11-20 ]

sysprg I could not reproduce this after bb-10.5-release was merged to 10.5. From git log I can't find revision 5deb8be used above. I think this is fixed after c3fdfbdbd that fixes replication of mysql.gtid_slave_pos table (MDEV-31413) mentioned in error log just before the crash.

Comment by Jan Lindström [ 2023-11-20 ]

Needs re-testing.

Comment by Jan Lindström [ 2023-11-21 ]

I think this is a problem as after ALTER TABLE mysql.gtid_slave_pos ENGINE=InnoDB (this is needed to make sure Galera cluster nodes can restart from correct position).

Comment by Jan Lindström [ 2023-11-21 ]

ramesh I think there is something wrong with CTAS, possible cases:

  • Normal galera cluster
  • Make sure ALTER TABLE mysql.gtid_slave_pos ENGINE=INNODB;
  • Galera as master to MariaDB slave
  • Galera as slave to MariaDB
    • CREATE TABLE t2 AS SELECT * FROM t1; – t1 empty table
    • CREATE TABLE t2 AS SELECT 1;
    • CREATE TABLE t2 AS SELECT * FROM t1; – t1 not empty
    • For all make sure GTIDs are consistent
Generated at Thu Feb 08 10:33:57 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.