[MDEV-26079] Terminate called after throwing an instance of 'wsrep::runtime_error' when sst_donor_node=... was added by mistake instead of wsrep_sst_donor=... Created: 2021-07-02  Updated: 2023-10-10

Status: Stalled
Project: MariaDB Server
Component/s: Galera SST
Affects Version/s: 10.4.19, 10.5.11
Fix Version/s: 10.4

Type: Bug Priority: Major
Reporter: Valerii Kravchuk Assignee: Julius Goryavsky
Resolution: Unresolved Votes: 1
Labels: None


 Description   

This was a result of a simple mistake, unknown variable added to the .cnf file:

...
WSREP_SST: [INFO] Waiting for SST streaming to complete! (20210702 10:28:35.583)
2021-07-02 10:28:36 0 [Note] WSREP: (7d0fe405-a751, 'ssl://0.0.0.0:4567') turning message relay requesting off
2021-07-02 12:07:01 0 [Note] WSREP: 3.10 (node2): State transfer to 2.10 (node1) complete.
2021-07-02 12:07:01 0 [Note] WSREP: Member 3.10 (node2) synced with group.
WSREP_SST: [INFO] Preparing the backup at /mnt/ephemeral/mysql//.sst (20210702 12:07:01.265)
WSREP_SST: [INFO] Evaluating /usr/bin/mariabackup --prepare --no-version-check $INNOEXTRA --target-dir=${DATA} --mysqld-args $WSREP_SST_OPT_MYSQLD &> /mnt/ephemeral/mysql//mariabackup.prepare.log (20210702 12:07:01.266)
WSREP_SST: [INFO] Moving the backup to /mnt/ephemeral/mysql/ (20210702 12:10:51.688)
WSREP_SST: [INFO] Evaluating /usr/bin/mariabackup --move-back --no-version-check --move-back --force-non-empty-directories --target-dir=${DATA} &> /mnt/ephemeral/mysql//mariabackup.move.log (20210702 12:10:51.690)
WSREP_SST: [INFO] Move successful, removing /mnt/ephemeral/mysql//.sst (20210702 12:10:57.664)
WSREP_SST: [INFO] Galera co-ords from recovery: c5fa34ac-decf-11ea-8a0b-cb555e1e5dba:2755838490 (20210702 12:10:57.735)
WSREP_SST: [INFO] Total time on joiner: 0 seconds (20210702 12:10:57.737)
WSREP_SST: [INFO] Removing the sst_in_progress file (20210702 12:10:57.739)
2021-07-02 12:10:57 0 [Warning] WSREP: Did not find domain ID from SST script output 'c5fa34ac-decf-11ea-8a0b-cb555e1e5dba:2755838490'. Domain ID must be set manually to keep binlog consistent
2021-07-02 12:10:57 3 [Note] WSREP: SST received
2021-07-02 12:10:57 3 [Note] WSREP: Server status change joiner -> initializing
2021-07-02 12:10:57 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2021-07-02 12:10:57 0 [Note] InnoDB: Using Linux native AIO
2021-07-02 12:10:57 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2021-07-02 12:10:57 0 [Note] InnoDB: Uses event mutexes
2021-07-02 12:10:57 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2021-07-02 12:10:57 0 [Note] InnoDB: Number of pools: 1
2021-07-02 12:10:57 0 [Note] InnoDB: Using SSE2 crc32 instructions
2021-07-02 12:10:57 0 [Note] InnoDB: Initializing buffer pool, total size = 32G, instances = 16, chunk size = 128M
2021-07-02 12:10:58 0 [Note] InnoDB: Completed initialization of buffer pool
2021-07-02 12:10:59 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2021-07-02 12:10:59 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 4294967296 bytes
2021-07-02 12:10:59 0 [Note] InnoDB: Setting log file ./ib_logfile1 size to 4294967296 bytes
2021-07-02 12:10:59 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2021-07-02 12:10:59 0 [Note] InnoDB: New log files created, LSN=20361560444134
2021-07-02 12:11:02 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2021-07-02 12:11:02 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2021-07-02 12:11:02 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2021-07-02 12:11:02 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2021-07-02 12:11:02 0 [Note] InnoDB: Waiting for purge to start
2021-07-02 12:11:02 0 [Note] InnoDB: 10.4.19 started; log sequence number 20361560444428; transaction id 41751313723
2021-07-02 12:11:02 0 [Note] InnoDB: Loading buffer pool(s) from /mnt/ephemeral/mysql/ib_buffer_pool
2021-07-02 12:11:02 0 [Note] Plugin 'FEEDBACK' is disabled.
2021-07-02 12:11:02 0 [ERROR] /usr/sbin/mysqld: unknown variable 'sst_donor_node=node2,'
2021-07-02 12:11:02 0 [ERROR] Aborting
terminate called after throwing an instance of 'wsrep::runtime_error'
 what(): State wait was interrupted
210702 12:11:02 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.
 
Server version: 10.4.19-MariaDB-log
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=0
max_threads=352
thread_count=9
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 905724 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f0538000aa8
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 = 0x7f05509c3ab0 thread_stack 0x49000
mysys/stacktrace.c:175(my_print_stacktrace)[0x55fab7dee40e]
sql/signal_handler.cc:222(handle_fatal_signal)[0x55fab787746f]
/lib64/libpthread.so.0(+0xf630)[0x7f155ccf5630]
/lib64/libc.so.6(gsignal+0x37)[0x7f155c140387]
:0(__GI_raise)[0x7f155c141a78]
/lib64/libstdc++.so.6(_ZN9__gnu_cxx27__verbose_terminate_handlerEv+0x165)[0x7f155c83aa95]
/lib64/libstdc++.so.6(+0x5ea06)[0x7f155c838a06]
/lib64/libstdc++.so.6(+0x5ea33)[0x7f155c838a33]
/lib64/libstdc++.so.6(+0x5ec53)[0x7f155c838c53]
/usr/sbin/mysqld(_ZNK5wsrep12server_state16wait_until_stateERSt11unique_lockINS_5mutexEENS0_5stateE+0x104)[0x55fab7e77cb4]
/usr/sbin/mysqld(_ZN5wsrep12server_state12sst_receivedERNS_14client_serviceEi+0x94c)[0x55fab7e80b0c]
/usr/sbin/mysqld(+0x83eaf8)[0x55fab77e1af8]
/usr/sbin/mysqld(+0x83f24e)[0x55fab77e224e]
pthread_create.c:0(start_thread)[0x7f155ccedea5]
/lib64/libc.so.6(clone+0x6d)[0x7f155c2089fd]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x0): (null)
Connection ID (thread ID): 3
Status: NOT_KILLED

Crashing hard after SST completed is both unexpected and wasted some notable time. This should be treated in a more graceful way.



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

2021-07-02 12:11:02 0 [ERROR] /usr/sbin/mysqld: unknown variable 'sst_donor_node=db-rt2,'
2021-07-02 12:11:02 0 [ERROR] Aborting
terminate called after throwing an instance of 'wsrep::runtime_error'
what(): State wait was interrupted
210702 12:11:02 [ERROR] mysqld got signal 6 ;

Comment by Valerii Kravchuk [ 2022-02-03 ]

Another case recently:

...
2022-02-03  7:43:31 3 [Note] WSREP: SST received
2022-02-03  7:43:31 3 [Note] WSREP: Server status change joiner -> initializing
2022-02-03  7:43:31 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2022-02-03  7:43:31 0 [Note] InnoDB: Uses event mutexes
2022-02-03  7:43:31 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2022-02-03  7:43:31 0 [Note] InnoDB: Number of pools: 1
2022-02-03  7:43:31 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
2022-02-03  7:43:31 0 [Note] mariadbd: O_TMPFILE is not supported on /var/lib/mysqltmp (disabling future attempts)
2022-02-03  7:43:31 0 [Note] InnoDB: Using Linux native AIO
2022-02-03  7:43:31 0 [Note] InnoDB: Initializing buffer pool, total size = 17179869184, chunk size = 134217728
2022-02-03  7:43:32 0 [Note] InnoDB: Completed initialization of buffer pool
2022-02-03  7:43:32 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 4294967296 bytes
2022-02-03  7:43:32 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2022-02-03  7:43:32 0 [Note] InnoDB: New log file created, LSN=8739015341366
2022-02-03  7:43:32 0 [Note] InnoDB: 128 rollback segments are active.
2022-02-03  7:43:32 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2022-02-03  7:43:32 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2022-02-03  7:43:32 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2022-02-03  7:43:32 0 [Note] InnoDB: 10.5.11 started; log sequence number 0; transaction id 2216973451
2022-02-03  7:43:32 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2022-02-03  7:43:32 0 [Note] Plugin 'FEEDBACK' is disabled.
2022-02-03  7:43:32 0 [ERROR] /usr/sbin/mariadbd: unknown variable 'sst-log-archive=1'
2022-02-03  7:43:32 0 [ERROR] Aborting
terminate called after throwing an instance of 'wsrep::runtime_error'
  what():  State wait was interrupted
220203  7:43:32 [ERROR] mysqld got signal 6 ;
...

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