Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Not a Bug
-
10.5
-
None
Description
(This was originally filed as https://jira.mariadb.org/browse/MDEV-24162, but mistakenly marked as duplicate of MDEV-23672, which it is not)
While trying to join an existing Galera cluster of two MariaDB 10.1.48 nodes with a fresh install of MariaDB 10.5.8, the maria-backup part runs fine but once all files have been transferred and the mariadbd tries to start it fails on:
tammi 12 20:20:51 mariadbd[63031]: WSREP_SST: [INFO] Evaluating /usr//bin/mariabackup --move-back --no-version-check --move-back --force-non-empty-directories --target-dir=${DATA} &> /var/lib/mysql//mariabackup.move.log (20210112 20:20:51.467)
|
tammi 12 20:20:51 mariadbd[63031]: WSREP_SST: [INFO] Move successful, removing /var/lib/mysql//.sst (20210112 20:20:51.742)
|
tammi 12 20:20:51 mariadbd[63031]: WSREP_SST: [INFO] Galera co-ords from recovery: 7f74fdea-cda3-11e9-ae2f-ab188b9a01f2:339777552 (20210112 20:20:51.752)
|
tammi 12 20:20:51 mariadbd[63031]: WSREP_SST: [INFO] Total time on joiner: 0 seconds (20210112 20:20:51.756)
|
tammi 12 20:20:51 mariadbd[63031]: WSREP_SST: [INFO] Removing the sst_in_progress file (20210112 20:20:51.759)
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 3 [Note] WSREP: SST received
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 3 [Note] WSREP: Server status change joiner -> initializing
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 3 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Uses event mutexes
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Number of pools: 1
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Using Linux native AIO
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Initializing buffer pool, total size = 2147483648, chunk size = 134217728
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Completed initialization of buffer pool
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 100663296 bytes
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
|
tammi 12 20:20:51 mariadbd[63031]: 2021-01-12 20:20:51 0 [Note] InnoDB: New log file created, LSN=1586283788623
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0 [Note] InnoDB: 128 rollback segments are active.
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0 [Note] InnoDB: Creating sys_virtual system tables.
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0 [Note] InnoDB: 10.5.9 started; log sequence number 0; transaction id 8247886884634323262
|
tammi 12 20:20:52 mariadbd[63031]: 2021-01-12 20:20:52 0x7fd1737fe700 InnoDB: Assertion failure in file /build/mariadb-10.5-onlwrq/mariadb-10.5-10.5.9+maria~bionic~ubuntu18.04.1~1610445096.8de233af815.10.5/storage/innobase/include/fut0lst.h line 127
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: Failing assertion: addr.page == FIL_NULL || addr.boffset >= FIL_PAGE_DATA
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: We intentionally generate a memory trap.
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: If you get repeated assertion failures or crashes, even
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: immediately after the mysqld startup, there may be
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: corruption in the InnoDB tablespace. Please refer to
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
|
tammi 12 20:20:52 mariadbd[63031]: InnoDB: about forcing recovery.
|
tammi 12 20:20:52 mariadbd[63031]: 210112 20:20:52 [ERROR] mysqld got signal 6 ;
|
Because the daemon is managed by systemd, it automatically tries to restart. The second start fails on a slightly different error:
tammi 12 20:21:03 sh[6248]: 2021-01-12 20:21:00 0 [ERROR] InnoDB: Page [page id: space=0, page number=975] log sequence number 1587610736226 is in the future! Current system log sequence number 1586283836448.
|
tammi 12 20:21:03 sh[6248]: 2021-01-12 20:21:00 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
|
tammi 12 20:21:03 sh[6248]: 2021-01-12 20:21:00 0 [ERROR] InnoDB: Page [page id: space=0, page number=977] log sequence number 1586526112239 is in the future! Current system log sequence number 1586283836448.
|
tammi 12 20:21:03 sh[6248]: 2021-01-12 20:21:00 0 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
|
tammi 12 20:21:03 sh[6248]: 2021-01-12 20:21:00 0x7f3eeaf0d800 InnoDB: Assertion failure in file /build/mariadb-10.5-onlwrq/mariadb-10.5-10.5.9+maria~bionic~ubuntu18.04.1~1610445096.8de233af815.10.5/storage/innobase/dict/dict0load.cc line 1816
|
tammi 12 20:21:03 sh[6248]: InnoDB: Failing assertion: btr_pcur_is_on_user_rec(&pcur)
|
Any further restarts repeat this latter error.
Full journald output from both runs attached.
I have also produced core dumps of both crashes and they are attached.
In first process 63031 there is:
#10 0x0000559d3cbdb3fe in ut_dbg_assertion_failed (expr=expr@entry=0x559d3d712a10 "addr.page == FIL_NULL || addr.boffset >= FIL_PAGE_DATA", file=file@entry=0x559d3d712980 "/build/mariadb-10.5-onlwrq/mariadb-10.5-10.5.9+maria~bionic~ubuntu18.04.1~1610445096.8de233af815.10.5/storage/innobase/include/fut0lst.h", line=line@entry=127) at ./storage/innobase/ut/ut0dbg.cc:60
|
No locals.
|
#11 0x0000559d3d2f7756 in flst_read_addr (faddr=<optimized out>) at ./storage/innobase/include/fut0lst.h:127
|
addr = <optimized out>
|
addr = <optimized out>
|
#12 flst_get_prev_addr (node=<optimized out>) at ./storage/innobase/include/fut0lst.h:153
|
No locals.
|
#13 trx_purge_rseg_get_next_history_log (n_pages_handled=n_pages_handled@entry=0x7fd1737fdc78) at ./storage/innobase/trx/trx0purge.cc:856
|
prev_log_addr = <optimized out>
|
trx_no = <optimized out>
|
mtr = {m_last = 0x0, m_last_offset = 0, m_log_mode = 0, m_modifications = 0, m_made_dirty = 0, m_inside_ibuf = 0, m_trim_pages = 0, m_memo = {m_heap = 0x0, m_list = {<ilist<mtr_buf_t::block_t, void>> = {sentinel_ = {next = 0x7fd1737fd278, prev = 0x7fd1737fd278}}, size_ = 1}, m_size = 16, m_first_block = {<ilist_node<void>> = {next = 0x7fd1737fd258, prev = 0x7fd1737fd258}, m_data = "\000l\000\004\322\177\000\000\001", '\000' <repeats 490 times>, m_used = 16}}, m_log = {m_heap = 0x0, m_list = {<ilist<mtr_buf_t::block_t, void>> = {sentinel_ = {next = 0x7fd1737fd4a8, prev = 0x7fd1737fd4a8}}, size_ = 1}, m_size = 0, m_first_block = {<ilist_node<void>> = {next = 0x7fd1737fd488, prev = 0x7fd1737fd488}, m_data = '\000' <repeats 496 times>..., m_used = 0}}, m_user_space = 0x0, m_commit_lsn = 0, m_freed_space = 0x0, m_freed_pages = 0x0}
|
undo_page = <optimized out>
|
log_hdr = <optimized out>
|
empty = <optimized out>
|
purge = <optimized out>
|
The second process has:
#6 0x000055a9f78373fe in ut_dbg_assertion_failed (expr=expr@entry=0x55a9f83a20e8 "btr_pcur_is_on_user_rec(&pcur)", file=file@entry=0x55a9f83a1848 "/build/mariadb-10.5-onlwrq/mariadb-10.5-10.5.9+maria~bionic~ubuntu18.04.1~1610445096.8de233af815.10.5/storage/innobase/dict/dict0load.cc", line=line@entry=1816) at ./storage/innobase/ut/ut0dbg.cc:60
|
No locals.
|
#7 0x000055a9f800d623 in dict_load_columns (heap=0x55a9fc21f518, table=0x55a9fc20f480) at ./storage/innobase/dict/dict0load.cc:1816
|
err_msg = <optimized out>
|
name = 0x0
|
nth_v_col = 18446744073709551615
|
sys_columns = <optimized out>
|
The failure happened originally on 10.5.8. I created new builds based on latest 10.5 HEAD with debug symbols etc to ensure that this bug is in fact not fixed in git yet, but exists and if 10.5.9 was released today, it would still fail like this. The attached README.txt includes notes on how I created the debug build with symbols and installed it etc procedure.
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-
-
-
- Closed
-