[MDEV-21420] Galera test failure on galera.mysql-wsrep#33 Created: 2020-01-03  Updated: 2020-10-06  Resolved: 2020-07-07

Status: Closed
Project: MariaDB Server
Component/s: Galera, Tests
Affects Version/s: 10.4.12
Fix Version/s: 10.4.16

Type: Bug Priority: Critical
Reporter: Stepan Patryshev (Inactive) Assignee: Stepan Patryshev (Inactive)
Resolution: Cannot Reproduce Votes: 0
Labels: None
Environment:

TestTarball_2 debian-9/10; CentOS Linux release 7.6.1810 (Core).


Attachments: Zip Archive 191230_CS_local_SSD.zip     Zip Archive 200102_local_SSD.zip     Text File 200102_local_SSD_stdout.log     Text File 20200103.3_ttb2_deb10.txt    
Issue Links:
Relates

 Description   

galera.mysql-wsrep#33 sporadically failed on Azure and on local suite non-debug runs. It failed also on local run of CS 10.4.12-MariaDB-debug ffc0a08 (Server logs).

Azure:
stdout.log:

10.4.11-5-MariaDB 0b7cd76, Debian-10

2020-01-03T14:48:30.9113989Z galera.mysql-wsrep#33 'innodb'           w1 [ fail ]  Found warnings/errors in server log file!
2020-01-03T14:48:30.9115309Z         Test ended at 2020-01-03 14:48:30
2020-01-03T14:48:30.9115665Z line
2020-01-03T14:48:30.9116192Z 2020-01-03 14:48:23 0 [Warning] WSREP: No re-merged primary component found.
2020-01-03T14:48:30.9116788Z 2020-01-03 14:48:23 0 [Warning] WSREP: No bootstrapped primary component found.
2020-01-03T14:48:30.9117507Z 2020-01-03 14:48:23 0 [ERROR] WSREP: gcs/src/gcs_state_msg.cpp:gcs_state_msg_get_quorum():947: Failed to establish quorum.
2020-01-03T14:48:30.9118219Z ^ Found warnings in /var/tmp/mtr/1/log/mysqld.2.err
2020-01-03T14:48:30.9118454Z ok

Local run:

10.4.11-5-MariaDB e844a75. CentOS 7

200102 10:21:31 +3.975 galera.mysql-wsrep#33 'innodb'           w4 [ fail ]
        Test ended at 2020-01-02 10:21:31
 
CURRENT_TEST: galera.mysql-wsrep#33
 
 
Server [mysqld.2 - pid: 30174, winpid: 30174, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2020-01-02 10:21:17 0 [Warning] WSREP: option --wsrep-causal-reads is deprecated
2020-01-02 10:21:17 0 [Note] /home/stepan/ment/10.4/sql/mysqld (mysqld 10.4.11-5-MariaDB-log) starting as process 30176 ...
2020-01-02 10:21:17 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4186)
2020-01-02 10:21:17 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
2020-01-02 10:21:17 0 [Note] WSREP: Loading provider /usr/lib/libgalera_enterprise_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
wsrep loader: [INFO] wsrep_load(): loading provider library '/usr/lib/libgalera_enterprise_smm.so'
wsrep loader: [INFO] wsrep_load(): Galera 26.4.4(r4702) by Codership Oy <info@codership.com> loaded successfully.
2020-01-02 10:21:17 0 [Note] WSREP: CRC-32C: using hardware acceleration.
2020-01-02 10:21:17 0 [Warning] WSREP: Could not open state file for reading: '/home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data//grastate.dat'
2020-01-02 10:21:17 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2020-01-02 10:21:17 0 [Note] WSREP: GCache DEBUG: opened preamble:
Version: 0
UUID: 00000000-0000-0000-0000-000000000000
Seqno: -1 - -1
Offset: -1
Synced: 0
2020-01-02 10:21:17 0 [Note] WSREP: Skipped GCache ring buffer recovery: could not determine history UUID.
2020-01-02 10:21:17 0 [Note] WSREP: Passing config to GCS: base_dir = /home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data/; base_host = 127.0.0.1; base_port = 16065; cert.log_conflicts = no; cert.optimistic_pa = yes; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /home/stepan/ment/10.4/mysql-test/var/4/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 = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit 
2020-01-02 10:21:17 0 [Note] WSREP: Start replication
2020-01-02 10:21:17 0 [Note] WSREP: Connecting with bootstrap option: 0
2020-01-02 10:21:17 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2020-01-02 10:21:17 0 [Note] WSREP: protonet asio version 0
2020-01-02 10:21:17 0 [Note] WSREP: Using CRC-32C for message checksums.
2020-01-02 10:21:17 0 [Note] WSREP: backend: asio
2020-01-02 10:21:17 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2020-01-02 10:21:17 0 [Warning] WSREP: access file(/home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data//gvwstate.dat) failed(No such file or directory)
2020-01-02 10:21:17 0 [Note] WSREP: restore pc from disk failed
2020-01-02 10:21:17 0 [Note] WSREP: GMCast version 0
2020-01-02 10:21:17 0 [Note] WSREP: (d97fdf2b, 'tcp://0.0.0.0:16065') listening at tcp://0.0.0.0:16065
2020-01-02 10:21:17 0 [Note] WSREP: (d97fdf2b, 'tcp://0.0.0.0:16065') multicast: , ttl: 1
2020-01-02 10:21:17 0 [Note] WSREP: EVS version 1
2020-01-02 10:21:17 0 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:16062'
2020-01-02 10:21:17 0 [Note] WSREP: (d97fdf2b, 'tcp://0.0.0.0:16065') connection established to d93d095f tcp://127.0.0.1:16062
2020-01-02 10:21:17 0 [Note] WSREP: (d97fdf2b, 'tcp://0.0.0.0:16065') turning message relay requesting on, nonlive peers: 
2020-01-02 10:21:18 0 [Note] WSREP: EVS version upgrade 0 -> 1
2020-01-02 10:21:18 0 [Note] WSREP: declaring d93d095f at tcp://127.0.0.1:16062 stable
2020-01-02 10:21:18 0 [Note] WSREP: PC protocol upgrade 0 -> 1
2020-01-02 10:21:18 0 [Note] WSREP: Node d93d095f state prim
2020-01-02 10:21:18 0 [Note] WSREP: view(view_id(PRIM,d93d095f,2) memb {
	d93d095f,0
	d97fdf2b,0
} joined {
} left {
} partitioned {
})
2020-01-02 10:21:18 0 [Note] WSREP: save pc into disk
2020-01-02 10:21:18 0 [Note] WSREP: gcomm: connected
2020-01-02 10:21:18 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2020-01-02 10:21:18 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2020-01-02 10:21:18 0 [Note] WSREP: Opened channel 'my_wsrep_cluster'
2020-01-02 10:21:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2020-01-02 10:21:18 1 [Note] WSREP: Starting rollbacker thread 1
2020-01-02 10:21:18 2 [Note] WSREP: Starting applier thread 2
2020-01-02 10:21:18 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2020-01-02 10:21:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: d9d13e1a-2d38-11ea-b4e3-174b911882dd
2020-01-02 10:21:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: d9d13e1a-2d38-11ea-b4e3-174b911882dd from 0 (cnt7glr11.localdomain)
2020-01-02 10:21:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: d9d13e1a-2d38-11ea-b4e3-174b911882dd from 1 (cnt7glr11.localdomain)
2020-01-02 10:21:18 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 = d93f97a6-2d38-11ea-8061-6a768212d23d
2020-01-02 10:21:18 0 [Note] WSREP: Flow-control interval: [23, 23]
2020-01-02 10:21:18 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 2)
2020-01-02 10:21:18 2 [Note] WSREP: ####### processing CC 2, local, ordered
2020-01-02 10:21:18 2 [Note] WSREP: REPL Protocols: 10 (5, 3)
2020-01-02 10:21:18 2 [Note] WSREP: ####### My UUID: d97fdf2b-2d38-11ea-9acd-22e5b7d6446b
2020-01-02 10:21:18 2 [Note] WSREP: Server cnt7glr11.localdomain connected to cluster at position d93f97a6-2d38-11ea-8061-6a768212d23d:2 with ID d97fdf2b-2d38-11ea-9acd-22e5b7d6446b
2020-01-02 10:21:18 2 [Note] WSREP: Server status change disconnected -> connected
2020-01-02 10:21:18 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:18 2 [Note] WSREP: State transfer required: 
	Group state: d93f97a6-2d38-11ea-8061-6a768212d23d:2
	Local state: 00000000-0000-0000-0000-000000000000:-1
2020-01-02 10:21:18 2 [Note] WSREP: Server status change connected -> joiner
2020-01-02 10:21:18 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:18 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'joiner' --address '127.0.0.2:16067' --datadir '/home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data/' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.2' --parent '30176' --binlog-index 'mysqld-bin.index' --mysqld-args --defaults-group-suffix=.2 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300'
2020-01-02 10:21:18 2 [Note] WSREP: Prepared SST request: rsync|127.0.0.2:16067/rsync_sst
2020-01-02 10:21:18 2 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2020-01-02 10:21:18 0 [Note] WSREP: Service thread queue flushed.
2020-01-02 10:21:18 2 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: 5
2020-01-02 10:21:18 2 [Note] WSREP: ####### IST uuid:00000000-0000-0000-0000-000000000000 f: 0, l: 2, STRv: 3
2020-01-02 10:21:18 2 [Note] WSREP: IST receiver addr using tcp://127.0.0.1:16066
2020-01-02 10:21:18 2 [Note] WSREP: Prepared IST receiver for 0-2, listening at: tcp://127.0.0.1:16066
2020-01-02 10:21:18 0 [Note] WSREP: Member 1.0 (cnt7glr11.localdomain) requested state transfer from '*any*'. Selected 0.0 (cnt7glr11.localdomain)(SYNCED) as donor.
2020-01-02 10:21:18 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 2)
2020-01-02 10:21:18 2 [Note] WSREP: Requesting state transfer: success, donor: 0
2020-01-02 10:21:18 2 [Note] WSREP: Resetting GCache seqno map due to different histories.
2020-01-02 10:21:18 2 [Note] WSREP: GCache history reset: old(00000000-0000-0000-0000-000000000000:0 -> d93f97a6-2d38-11ea-8061-6a768212d23d:2
2020-01-02 10:21:20 0 [Note] WSREP: 0.0 (cnt7glr11.localdomain): State transfer to 1.0 (cnt7glr11.localdomain) complete.
2020-01-02 10:21:20 0 [Note] WSREP: Member 0.0 (cnt7glr11.localdomain) synced with group.
2020-01-02 10:21:20 0 [Note] WSREP: (d97fdf2b, 'tcp://0.0.0.0:16065') turning message relay requesting off
WSREP_SST: [INFO] Joiner cleanup. rsync PID: 30256 (20200102 10:21:21.048)
WSREP_SST: [INFO] Joiner cleanup done. (20200102 10:21:21.557)
2020-01-02 10:21:21 3 [Note] WSREP: SST received
2020-01-02 10:21:21 3 [Note] WSREP: Server status change joiner -> initializing
2020-01-02 10:21:21 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:21 0 [Note] Plugin 'partition' is disabled.
2020-01-02 10:21:21 0 [Note] InnoDB: Using Linux native AIO
2020-01-02 10:21:21 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-01-02 10:21:21 0 [Note] InnoDB: Uses event mutexes
2020-01-02 10:21:21 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2020-01-02 10:21:21 0 [Note] InnoDB: Number of pools: 1
2020-01-02 10:21:21 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-01-02 10:21:21 0 [Note] mysqld: O_TMPFILE is not supported on /home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.2 (disabling future attempts)
2020-01-02 10:21:21 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
2020-01-02 10:21:21 0 [Note] InnoDB: Completed initialization of buffer pool
2020-01-02 10:21:21 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-01-02 10:21:21 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=64353
2020-01-02 10:21:21 0 [Note] InnoDB: Starting final batch to recover 18 pages from redo log.
2020-01-02 10:21:21 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-01-02 10:21:21 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-01-02 10:21:21 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-01-02 10:21:21 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-01-02 10:21:21 0 [Note] InnoDB: Waiting for purge to start
2020-01-02 10:21:21 0 [Note] InnoDB: 10.4.11 started; log sequence number 74900; transaction id 40
2020-01-02 10:21:21 0 [Note] InnoDB: Loading buffer pool(s) from /home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data/ib_buffer_pool
2020-01-02 10:21:21 0 [Note] Plugin 'SEQUENCE' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_CMP' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2020-01-02 10:21:21 0 [Note] InnoDB: Buffer pool(s) load completed at 200102 10:21:21
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'FEEDBACK' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'user_variables' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2020-01-02 10:21:21 0 [Note] Plugin 'unix_socket' is disabled.
2020-01-02 10:21:21 0 [Warning] /home/stepan/ment/10.4/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
2020-01-02 10:21:21 0 [Warning] /home/stepan/ment/10.4/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
2020-01-02 10:21:21 0 [Warning] /home/stepan/ment/10.4/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
2020-01-02 10:21:21 0 [Warning] /home/stepan/ment/10.4/sql/mysqld: unknown option '--loose-pam-debug'
2020-01-02 10:21:21 0 [Warning] /home/stepan/ment/10.4/sql/mysqld: unknown option '--loose-aria'
2020-01-02 10:21:21 0 [Warning] /home/stepan/ment/10.4/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
2020-01-02 10:21:21 0 [Note] Server socket created on IP: '127.0.0.1'.
2020-01-02 10:21:21 0 [Note] WSREP: wsrep_init_schema_and_SR (nil)
2020-01-02 10:21:21 0 [Note] WSREP: Server initialized
2020-01-02 10:21:21 0 [Note] WSREP: Server status change initializing -> initialized
2020-01-02 10:21:21 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:21 3 [Note] WSREP: Server status change initialized -> joined
2020-01-02 10:21:21 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:21 3 [Note] WSREP: Recovered position from storage: d93f97a6-2d38-11ea-8061-6a768212d23d:2
2020-01-02 10:21:21 3 [Note] WSREP: Recovered view from SST:
  id: d93f97a6-2d38-11ea-8061-6a768212d23d: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: d93d095f-2d38-11ea-a831-4355147a9bdc, cnt7glr11.localdomain
	1: d97fdf2b-2d38-11ea-9acd-22e5b7d6446b, cnt7glr11.localdomain
 
2020-01-02 10:21:21 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:21 11 [Note] WSREP: Recovered cluster id d93f97a6-2d38-11ea-8061-6a768212d23d
2020-01-02 10:21:21 0 [Note] Reading of all Master_info entries succeeded
2020-01-02 10:21:21 0 [Note] Added new Master_info '' to hash table
2020-01-02 10:21:21 0 [Note] /home/stepan/ment/10.4/sql/mysqld: ready for connections.
Version: '10.4.11-5-MariaDB-log'  socket: '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.2.sock'  port: 16061  Source distribution
2020-01-02 10:21:21 3 [Note] WSREP: SST received: d93f97a6-2d38-11ea-8061-6a768212d23d:2
2020-01-02 10:21:21 2 [Note] WSREP: Installed new state from SST: d93f97a6-2d38-11ea-8061-6a768212d23d:2
2020-01-02 10:21:21 2 [Note] WSREP: Cert. index preload up to 2
2020-01-02 10:21:21 0 [Note] WSREP: ####### IST applying starts with 3
2020-01-02 10:21:21 0 [Note] WSREP: ####### IST current seqno initialized to 2
2020-01-02 10:21:21 0 [Note] WSREP: Receiving IST...  0.0% (0/1 events) complete.
2020-01-02 10:21:21 0 [Note] WSREP: IST preload starting at 2
2020-01-02 10:21:21 0 [Note] WSREP: REPL Protocols: 10 (5, 3)
2020-01-02 10:21:21 0 [Note] WSREP: Service thread queue flushed.
2020-01-02 10:21:21 0 [Note] WSREP: ####### Assign initial position for certification: d93f97a6-2d38-11ea-8061-6a768212d23d:1, protocol version: 5
2020-01-02 10:21:21 0 [Note] WSREP: REPL Protocols: 10 (5, 3)
2020-01-02 10:21:21 0 [Note] WSREP: ####### Adjusting cert position: 1 -> 2
2020-01-02 10:21:21 0 [Note] WSREP: Service thread queue flushed.
2020-01-02 10:21:21 0 [Note] WSREP: Lowest cert indnex boundary for CC from preload: 2
2020-01-02 10:21:21 0 [Note] WSREP: Min available from gcache for CC from preload: 2
2020-01-02 10:21:21 0 [Note] WSREP: Receiving IST...100.0% (1/1 events) complete.
2020-01-02 10:21:21 2 [Note] WSREP: IST received: d93f97a6-2d38-11ea-8061-6a768212d23d:2
2020-01-02 10:21:21 2 [Note] WSREP: Lowest cert indnex boundary for CC from group: 2
2020-01-02 10:21:21 2 [Note] WSREP: Min available from gcache for CC from group: 2
2020-01-02 10:21:21 0 [Note] WSREP: 1.0 (cnt7glr11.localdomain): State transfer from 0.0 (cnt7glr11.localdomain) complete.
2020-01-02 10:21:21 0 [Note] WSREP: Shifting JOINER -> JOINED (TO: 2)
2020-01-02 10:21:21 0 [Note] WSREP: Member 1.0 (cnt7glr11.localdomain) synced with group.
2020-01-02 10:21:21 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2)
2020-01-02 10:21:21 2 [Note] WSREP: Server cnt7glr11.localdomain synced with group
2020-01-02 10:21:21 2 [Note] WSREP: Server status change joined -> synced
2020-01-02 10:21:21 2 [Note] WSREP: Synchronized with group, ready for connections
2020-01-02 10:21:21 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:24 16 [Note] WSREP: Stop replication by 16
2020-01-02 10:21:24 16 [Note] WSREP: Server status change synced -> disconnecting
2020-01-02 10:21:24 16 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:25 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:25 2 [Note] WSREP: Server status change disconnecting -> disconnected
2020-01-02 10:21:25 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:25 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:25 2 [Note] WSREP: Applier thread exiting ret: 0 thd: 2
2020-01-02 10:21:25 2 [Warning] Aborted connection 2 to db: 'unconnected' user: 'unauthenticated' host: '' (This connection closed normally without authentication)
2020-01-02 10:21:25 1 [Note] WSREP: rollbacker thread exiting 1
2020-01-02 10:21:25 1 [Warning] Aborted connection 1 to db: 'unconnected' user: 'unauthenticated' host: '' (This connection closed normally without authentication)
wsrep loader: [INFO] wsrep_load(): loading provider library 'none'
2020-01-02 10:21:26 16 [Note] WSREP: Stop replication by 16
2020-01-02 10:21:26 16 [Note] WSREP: Loading provider /usr/lib/libgalera_enterprise_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
wsrep loader: [INFO] wsrep_load(): loading provider library '/usr/lib/libgalera_enterprise_smm.so'
wsrep loader: [INFO] wsrep_load(): Galera 26.4.4(r4702) by Codership Oy <info@codership.com> loaded successfully.
2020-01-02 10:21:26 16 [Note] WSREP: CRC-32C: using hardware acceleration.
2020-01-02 10:21:26 16 [Note] WSREP: Found saved state: d93f97a6-2d38-11ea-8061-6a768212d23d:7, safe_to_bootstrap: 0
2020-01-02 10:21:26 16 [Note] WSREP: GCache DEBUG: opened preamble:
Version: 2
UUID: d93f97a6-2d38-11ea-8061-6a768212d23d
Seqno: 2 - 7
Offset: 1280
Synced: 1
2020-01-02 10:21:26 16 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: d93f97a6-2d38-11ea-8061-6a768212d23d, offset: 1280
2020-01-02 10:21:26 16 [Note] WSREP: GCache::RingBuffer initial scan...  0.0% (        0/134217752 bytes) complete.
2020-01-02 10:21:26 16 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete.
2020-01-02 10:21:26 16 [Note] WSREP: Recovering GCache ring buffer: found gapless sequence 2-7
2020-01-02 10:21:26 16 [Note] WSREP: GCache::RingBuffer unused buffers scan...  0.0% (   0/3728 bytes) complete.
2020-01-02 10:21:26 16 [Note] WSREP: GCache::RingBuffer unused buffers scan...100.0% (3728/3728 bytes) complete.
2020-01-02 10:21:26 16 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): found 0/6 locked buffers
2020-01-02 10:21:26 16 [Note] WSREP: GCache DEBUG: RingBuffer::recover(): used space: 3728/134217728
2020-01-02 10:21:26 16 [Note] WSREP: Passing config to GCS: base_dir = /home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data/; base_host = 127.0.0.1; base_port = 16065; cert.log_conflicts = no; cert.optimistic_pa = yes; debug = no; evs.auto_evict = 0; evs.causal_keepalive_period = PT1S; evs.debug_log_mask = 0x1; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.info_log_mask = 0; evs.install_timeout = PT7.5S; evs.join_retrans_period = PT1S; evs.keepalive_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.use_aggregate = true; evs.user_send_window = 2; evs.version = 1; evs.view_forget_timeout = P1D; gcache.dir = /home/stepan/ment/10.4/mysql-test/var/4/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 = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gc
2020-01-02 10:21:26 0 [Note] WSREP: Service thread queue flushed.
2020-01-02 10:21:26 16 [Note] WSREP: ####### Assign initial position for certification: d93f97a6-2d38-11ea-8061-6a768212d23d:7, protocol version: -1
2020-01-02 10:21:26 16 [Note] WSREP: Stop replication by 16
2020-01-02 10:21:26 16 [Note] WSREP: Start replication
2020-01-02 10:21:26 16 [Note] WSREP: Connecting with bootstrap option: 0
2020-01-02 10:21:26 16 [Note] WSREP: Setting GCS initial position to d93f97a6-2d38-11ea-8061-6a768212d23d:7
2020-01-02 10:21:26 16 [Note] WSREP: protonet asio version 0
2020-01-02 10:21:26 16 [Note] WSREP: Using CRC-32C for message checksums.
2020-01-02 10:21:26 16 [Note] WSREP: backend: asio
2020-01-02 10:21:26 16 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2020-01-02 10:21:26 16 [Warning] WSREP: access file(/home/stepan/ment/10.4/mysql-test/var/4/mysqld.2/data//gvwstate.dat) failed(No such file or directory)
2020-01-02 10:21:26 16 [Note] WSREP: restore pc from disk failed
2020-01-02 10:21:26 16 [Note] WSREP: GMCast version 0
2020-01-02 10:21:26 16 [Note] WSREP: (de6ea9a8, 'tcp://0.0.0.0:16065') listening at tcp://0.0.0.0:16065
2020-01-02 10:21:26 16 [Note] WSREP: (de6ea9a8, 'tcp://0.0.0.0:16065') multicast: , ttl: 1
2020-01-02 10:21:26 16 [Note] WSREP: EVS version 1
2020-01-02 10:21:26 16 [Note] WSREP: gcomm: connecting to group 'my_wsrep_cluster', peer '127.0.0.1:16062'
2020-01-02 10:21:26 16 [Note] WSREP: (de6ea9a8, 'tcp://0.0.0.0:16065') connection established to d93d095f tcp://127.0.0.1:16062
2020-01-02 10:21:26 16 [Note] WSREP: (de6ea9a8, 'tcp://0.0.0.0:16065') turning message relay requesting on, nonlive peers: 
2020-01-02 10:21:26 16 [Note] WSREP: EVS version upgrade 0 -> 1
2020-01-02 10:21:26 16 [Note] WSREP: declaring d93d095f at tcp://127.0.0.1:16062 stable
2020-01-02 10:21:26 16 [Note] WSREP: PC protocol upgrade 0 -> 1
2020-01-02 10:21:26 16 [Note] WSREP: Node d93d095f state prim
2020-01-02 10:21:26 16 [Note] WSREP: view(view_id(PRIM,d93d095f,4) memb {
	d93d095f,0
	de6ea9a8,0
} joined {
} left {
} partitioned {
})
2020-01-02 10:21:26 16 [Note] WSREP: save pc into disk
2020-01-02 10:21:27 16 [Note] WSREP: gcomm: connected
2020-01-02 10:21:27 16 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2020-01-02 10:21:27 16 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2020-01-02 10:21:27 16 [Note] WSREP: Opened channel 'my_wsrep_cluster'
2020-01-02 10:21:27 17 [Note] WSREP: Starting rollbacker thread 17
2020-01-02 10:21:27 18 [Note] WSREP: Starting applier thread 18
2020-01-02 10:21:27 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2020-01-02 10:21:27 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2020-01-02 10:21:27 0 [Note] WSREP: STATE EXCHANGE: sent state msg: debbc6f4-2d38-11ea-adda-eface141faee
2020-01-02 10:21:27 0 [Note] WSREP: STATE EXCHANGE: got state msg: debbc6f4-2d38-11ea-adda-eface141faee from 0 (cnt7glr11.localdomain)
2020-01-02 10:21:27 0 [Note] WSREP: STATE EXCHANGE: got state msg: debbc6f4-2d38-11ea-adda-eface141faee from 1 (cnt7glr11.localdomain)
2020-01-02 10:21:27 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 = d93f97a6-2d38-11ea-8061-6a768212d23d
2020-01-02 10:21:27 0 [Note] WSREP: Flow-control interval: [23, 23]
2020-01-02 10:21:27 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 10)
2020-01-02 10:21:27 18 [Note] WSREP: ####### processing CC 10, local, ordered
2020-01-02 10:21:27 18 [Note] WSREP: REPL Protocols: 10 (5, 3)
2020-01-02 10:21:27 18 [Note] WSREP: ####### My UUID: de6ea9a8-2d38-11ea-8381-3a4d9984ff9a
2020-01-02 10:21:27 18 [Note] WSREP: Server cnt7glr11.localdomain connected to cluster at position d93f97a6-2d38-11ea-8061-6a768212d23d:10 with ID de6ea9a8-2d38-11ea-8381-3a4d9984ff9a
2020-01-02 10:21:27 18 [Note] WSREP: Server status change disconnected -> connected
2020-01-02 10:21:27 18 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:27 18 [Note] WSREP: State transfer required: 
	Group state: d93f97a6-2d38-11ea-8061-6a768212d23d:10
	Local state: d93f97a6-2d38-11ea-8061-6a768212d23d:7
2020-01-02 10:21:27 18 [Note] WSREP: Server status change connected -> joiner
2020-01-02 10:21:27 18 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:27 18 [Note] WSREP: Prepared SST request: mysqldump|127.0.0.1:16061
2020-01-02 10:21:27 18 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2020-01-02 10:21:27 0 [Note] WSREP: Service thread queue flushed.
2020-01-02 10:21:27 18 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: 5
2020-01-02 10:21:27 18 [Note] WSREP: ####### IST uuid:d93f97a6-2d38-11ea-8061-6a768212d23d f: 8, l: 10, STRv: 3
2020-01-02 10:21:27 18 [Note] WSREP: IST receiver addr using tcp://127.0.0.1:16066
2020-01-02 10:21:27 18 [Note] WSREP: Prepared IST receiver for 8-10, listening at: tcp://127.0.0.1:16066
2020-01-02 10:21:27 0 [Note] WSREP: Member 1.0 (cnt7glr11.localdomain) requested state transfer from '*any*'. Selected 0.0 (cnt7glr11.localdomain)(SYNCED) as donor.
2020-01-02 10:21:27 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 10)
2020-01-02 10:21:27 18 [Note] WSREP: Requesting state transfer: success, donor: 0
2020-01-02 10:21:29 0 [Note] WSREP: (de6ea9a8, 'tcp://0.0.0.0:16065') turning message relay requesting off
2020-01-02 10:21:30 0 [Warning] WSREP: 0.0 (cnt7glr11.localdomain): State transfer to 1.0 (cnt7glr11.localdomain) failed: -1 (Operation not permitted)
2020-01-02 10:21:30 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():1178: Will never receive state. Need to abort.
2020-01-02 10:21:30 0 [Note] WSREP: gcomm: terminating thread
2020-01-02 10:21:30 0 [Note] WSREP: gcomm: joining thread
2020-01-02 10:21:30 0 [Note] WSREP: gcomm: closing backend
2020-01-02 10:21:31 0 [Note] WSREP: view(view_id(NON_PRIM,d93d095f,4) memb {
	de6ea9a8,0
} joined {
} left {
} partitioned {
	d93d095f,0
})
2020-01-02 10:21:31 0 [Note] WSREP: PC protocol downgrade 1 -> 0
2020-01-02 10:21:31 0 [Note] WSREP: view((empty))
2020-01-02 10:21:31 0 [Note] WSREP: gcomm: closed
2020-01-02 10:21:31 0 [Note] WSREP: /home/stepan/ment/10.4/sql/mysqld: Terminated.
----------SERVER LOG END-------------
mysqltest failed but provided no output
The result from queries just before the failure was:
< snip >
INSERT INTO t1 VALUES ('node1_committed_during');
INSERT INTO t1 VALUES ('node1_committed_during');
INSERT INTO t1 VALUES ('node1_committed_during');
COMMIT;
START TRANSACTION;
INSERT INTO t1 VALUES ('node1_to_be_committed_after');
INSERT INTO t1 VALUES ('node1_to_be_committed_after');
INSERT INTO t1 VALUES ('node1_to_be_committed_after');
INSERT INTO t1 VALUES ('node1_to_be_committed_after');
INSERT INTO t1 VALUES ('node1_to_be_committed_after');
connect node_1a_galera_st_disconnect_slave, 127.0.0.1, root, , test, $NODE_MYPORT_1;
SET AUTOCOMMIT=OFF;
START TRANSACTION;
INSERT INTO t1 VALUES ('node1_to_be_rollbacked_after');
INSERT INTO t1 VALUES ('node1_to_be_rollbacked_after');
INSERT INTO t1 VALUES ('node1_to_be_rollbacked_after');
INSERT INTO t1 VALUES ('node1_to_be_rollbacked_after');
INSERT INTO t1 VALUES ('node1_to_be_rollbacked_after');
connection node_2;
Loading wsrep provider ...
 
 
 
 - saving '/home/stepan/ment/10.4/mysql-test/var/4/log/galera.mysql-wsrep#33-innodb/' to '/home/stepan/ment/10.4/mysql-test/var/log/galera.mysql-wsrep#33-innodb/'
***Warnings generated in error logs during shutdown after running tests: galera.mysql-wsrep#33
 
2020-01-02 10:21:27 1 [ERROR] WSREP: Process completed with error: wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300: 1 (Operation not permitted)
2020-01-02 10:21:27 1 [ERROR] WSREP: Try 1/3: 'wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --innworker[3] 200102 10:22:08 +874.294 mysql-test-run: WARNING: Process [mysqld.5 - pid: 2654, winpid: 2654, exit: 256] died after mysql-test-run waited 0.1 seconds for /home/stepan/ment/10.4/mysql-test/var/3/run/mysqld.5.pid to be created.
odb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --wsrep-on=ON --core-file --loose-debug-sync-timeout=300' failed: 1 (Operation not permitted)
2020-01-02 10:21:28 1 [ERROR] WSREP: Process completed with error: wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300: 1 (Operation not permitted)
2020-01-02 10:21:28 1 [ERROR] WSREP: Try 2/3: 'wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300' failed: 1 (Operation not permitted)
2020-01-02 10:21:29 1 [ERROR] WSREP: Process completed with error: wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300: 1 (Operation not permitted)
2020-01-02 10:21:29 1 [ERROR] WSREP: Try 3/3: 'wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300' failed: 1 (Operation not permitted)
2020-01-02 10:21:30 1 [Warning] WSREP: SST start failed
2020-01-02 10:21:30 1 [ERROR] WSREP: SST bypass failed: 1
2020-01-02 10:21:30 1 [ERROR] WSREP: Failed to bypass SST
2020-01-02 10:21:30 0 [Warning] WSREP: 0.0 (cnt7glr11.localdomain): State transfer to 1.0 (cnt7glr11.localdomain) failed: -1 (Operation not permitted)
2020-01-02 10:21:30 0 [Warning] WSREP: 0.0 (cnt7glr11.localdomain): State transfer to 1.0 (cnt7glr11.localdomain) failed: -1 (Operation not permitted)
2020-01-02 10:21:30 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():1178: Will never receive state. Need to abort.

Server logs from local run.



 Comments   
Comment by Stepan Patryshev (Inactive) [ 2020-01-08 ]

Increased the priority since it fails on Azure.

Comment by Alexey [ 2020-06-20 ]

@Julien, this issue does not seem to be related to Galera, but rather to mariadb client code or configuration... Wsrep/SST code has no reference to /etc/my.cnf.d at least I could not find any.

^G/home/stepan/ment/10.4/scripts/../client/mysql: Can't read dir of '/etc/my.cnf.d' (Errcode: 2 "No such file or directory")
Fatal error in defaults handling. Program aborted
^G/home/stepan/ment/10.4/scripts/../client/mysql: Can't read dir of '/etc/my.cnf.d' (Errcode: 2 "No such file or directory")
Fatal error in defaults handling. Program aborted
2020-01-02 10:21:29 1 [ERROR] WSREP: Process completed with error: wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300: 1 (Operation not permitted)
2020-01-02 10:21:29 1 [ERROR] WSREP: Try 3/3: 'wsrep_sst_mysqldump --address '127.0.0.1:16061' --port '16061' --local-port '16060' --socket '/home/stepan/ment/10.4/mysql-test/var/tmp/4/mysqld.1.sock' --defaults-file '/home/stepan/ment/10.4/mysql-test/var/4/my.cnf' --defaults-group-suffix '.1' --gtid 'd93f97a6-2d38-11ea-8061-6a768212d23d:7' --gtid-domain-id '0' --bypass --mysqld-args --defaults-group-suffix=.1 --defaults-file=/home/stepan/ment/10.4/mysql-test/var/4/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 --wsrep-on=ON --core-file --loose-debug-sync-timeout=300' failed: 1 (Operation not permitted)
2020-01-02 10:21:29 0 [Note] WSREP: (d93d095f, 'tcp://0.0.0.0:16062') turning message relay requesting off
2020-01-02 10:21:30 1 [Note] WSREP: SST sending failed: -1
2020-01-02 10:21:30 1 [Note] WSREP: Server status change donor -> joined
2020-01-02 10:21:30 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:30 1 [Warning] WSREP: SST start failed
2020-01-02 10:21:30 1 [Note] WSREP: Server status change joined -> synced
2020-01-02 10:21:30 1 [Note] WSREP: Synchronized with group, ready for connections
2020-01-02 10:21:30 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2020-01-02 10:21:30 1 [ERROR] WSREP: SST bypass failed: 1
2020-01-02 10:21:30 1 [ERROR] WSREP: Failed to bypass SST
2020-01-02 10:21:30 0 [Warning] WSREP: 0.0 (cnt7glr11.localdomain): State transfer to 1.0 (cnt7glr11.localdomain) failed: -1 (Operation not permitted)

Comment by Stepan Patryshev (Inactive) [ 2020-07-06 ]

I have created MENT-858 for galera.mysql-wsrep#33 failures on 10.2/10.3 ES with another error: Can't start server: port 16101 already in use.

Comment by Stepan Patryshev (Inactive) [ 2020-07-07 ]

Closing since it does not fail on CI on 10.4 CS.
See MENT-858 for failures on 10.2/10.3 ES.

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