Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.2.0, 10.3.0, 10.4.0, 10.5.0, 10.6.0, 10.5.15, 10.6.7, 10.5
-
None
Description
Hi, all MariaDB developers.
My team recently performed a successful MariaDB server upgrade, from 10.0.17 to 10.6.7.
The upgrade procedures is alike:
- Prepare MariaDB 10.0.17 backup(previously it was backed up by xtrabackup 2.2.9)
xtrabackup 2.2.9 backup data was totally good.
dbchecksum for ibdata1 was totally good. - Copy prepared backup data into another VM.
- Upgrade MariaDB to 10.6.7 (mysql_update was utilized) in that VM.
After a successful upgrade, we can verify that MariaDB 10.6.7 was good about the prepared data, no error log, business level sanity check was totally fine.
We haven't done CHECK TABLE because we set innodb_file_per_table=1 in my.cnf, ibdata1 should mostly be undo tablespace data(occupied around 200G in size), so I though running CHECK TABLE won't help either.
But when I run MariaDB 10.6.7 innodbchecksum for the ibdata1, it'll report page1 error. All data upgraded from 10.0.17 to 10.6.7 will report corruption.
The command I executed for backup the upgraded databased:
mariabackup --defaults-file=/etc/mysql/my.cnf --socket=/tmp/my.sock --user=xxxxx --password=xxxxxxxx --slave-info --backup --log-innodb-page-corruption --target-dir /tmp/tstempYF2mY9/prep_2022.02.24_093401.414814
Logs
(P.S. corrupt page content was excluded intentionally, it contain some sensitive data, if you need that, I may need to do some data redaction)
[01] 2022-02-24 09:34:01 Copying ibdata1 to /tmp/tstempYF2mY9/prep_2022.02.24_093401.414814/ibdata1
|
|
|
[01] 2022-02-24 09:40:52 Database page corruption detected at page 3994534, retrying...
|
|
|
[01] 2022-02-24 09:40:52 Database page corruption detected at page 3994534, retrying...
|
|
|
[01] 2022-02-24 09:40:52 Database page corruption detected at page 3994534, retrying...
|
|
|
[01] 2022-02-24 09:40:52 Database page corruption detected at page 3994534, retrying...
|
|
|
[01] 2022-02-24 09:40:54 Error: failed to read page after 10 retries. File ibdata1 seems to be corrupted. WARNING!!! The corruption is ignored due to log-innodb-page-corruption option, the backup can contain corrupted data.
|
|
|
2022-02-24 09:40:54 0x7f6663fff700 InnoDB: Assertion failure in file /home/buildbot/buildbot/build/extra/mariabackup/xtrabackup.cc line 804
|
|
|
InnoDB: Failing assertion: p
|
|
|
InnoDB: We intentionally generate a memory trap.
|
|
|
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
|
|
|
InnoDB: If you get repeated assertion failures or crashes, even
|
|
|
InnoDB: immediately after the mariadbd startup, there may be
|
|
|
InnoDB: corruption in the InnoDB tablespace. Please refer to
|
|
|
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
|
|
|
InnoDB: about forcing recovery.
|
|
|
220224 9:40:54 [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.6.7-MariaDB
|
|
|
key_buffer_size=0
|
|
|
read_buffer_size=131072
|
|
|
max_used_connections=0
|
|
|
max_threads=1
|
|
|
thread_count=0
|
|
|
It is possible that mysqld could use up to
|
|
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6133 K bytes of memory
|
|
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
|
Thread pointer: 0x0
|
|
|
Attempting backtrace. You can use the following information to find out
|
|
|
where mysqld died. If you see no messages after this, something went
|
|
|
terribly wrong...
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274318)
|
|
|
stack_bottom = 0x0 thread_stack 0x49000
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274318)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274318)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274318)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274318)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274318)
|
|
|
addr2line: 'mariabackup': No such file
|
|
|
Printing to addr2line failed
|
|
|
mariabackup(my_print_stacktrace+0x2e)[0x55b01b984b7e]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442274971)
|
|
|
mariabackup(handle_fatal_signal+0x307)[0x55b01b3b6ef7]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442275535)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
sigaction.c:0(__restore_rt)[0x7f666d7d35f0]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
:0(__GI_raise)[0x7f666cc1f337]
|
|
|
:0(__GI_abort)[0x7f666cc20a28]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
addr2line: 'mariabackup': No such file
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276086)
|
|
|
mariabackup(+0x6b3275)[0x55b01afd2275]
|
|
|
mariabackup(+0x6ff34a)[0x55b01b01e34a]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276829)
|
|
|
mariabackup(_ZN14CorruptedPages16add_page_no_lockEPKcmjb+0x10a)[0x55b01b02b1aa]
|
|
|
mariabackup(_ZN14CorruptedPages8add_pageEPKcmj+0x37)[0x55b01b02b247]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276829)
|
|
|
mariabackup(_Z15xb_fil_cur_readP12xb_fil_cur_tR14CorruptedPages+0x307)[0x55b01b0397a7]
|
|
|
mariabackup(+0x708b35)[0x55b01b027b35]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276829)
|
|
|
mariabackup(+0x708dcc)[0x55b01b027dcc]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442276829)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442277491)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442278246)
|
|
|
??:0(std::this_thread::__sleep_for(std::chrono::duration<long, std::ratio<1l, 1l> >, std::chrono::duration<long, std::ratio<1l, 1000000000l> >))[0x7f666d36e070]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442278898)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442278898)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442279634)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442279634)
|
|
|
pthread_create.c:0(start_thread)[0x7f666d7cbe65]
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442279634)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442280417)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442280417)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442280417)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442280417)
|
|
|
??:0(__clone)[0x7f666cce788d]
|
|
|
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.
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442280417)
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442280417)
|
|
|
Writing a core file...
|
|
|
Working directory at /nutstore/mysql/db4
|
|
|
[00] 2022-02-24 09:40:54 >> log scanned up to (46654442281016)
|
|
|
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 0 unlimited bytes
|
|
|
Max resident set unlimited unlimited bytes
|
|
|
Max processes 4096 1030594 processes
|
|
|
Max open files 1024 4096 files
|
|
|
Max locked memory 65536 65536 bytes
|
|
|
Max address space unlimited unlimited bytes
|
|
|
Max file locks unlimited unlimited locks
|
|
|
Max pending signals 1030594 1030594 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: core
|
Since I add the --log-innodb-page-corruption cli option, I expect page corruption will be logged but not to halt the backup procedure, and after data preparing, the page corruption will be gone, since it happened in unallocated system table space?(need confirmation)
Attachments
Issue Links
- is caused by
-
MDEV-19534 Make innodb_checksum_algorithm=full_crc32 by default, and remove innodb_checksums
-
- Closed
-
- relates to
-
-
- Closed
-
-
-
- Closed
-
Activity
Which values of innodb_checksum_algorithm have you used in the past?
We haven't set innodb_checksum_algorithm explicitly, according to https://mariadb.com/kb/en/innodb-system-variables/#innodb_checksum_algorithm, it should be innodb_checksum_algorithm=innodb in MariaDB 10.0.x
I tested the other page dump again. It is necessary to add one all-zero page before that page, so that page size will be correctly detected as 16384 bytes.
Such a 32768-byte file would be accepted by the 10.2, 10.3, and 10.4 versions of innochecksum by default, but no longer by the 10.5 version.
Each of those older-version innochecksum will reject the file when invoked as follows:
innochecksum -C crc32 sparse.bin
|
The 10.5 innochecksum would accept the file when invoked as follows:
innochecksum -C innodb sparse.bin
|
Starting with 10.5, the non-strict innodb_checksum_algorithm=crc32 validation is rejecting this page that appears to use innodb_checksum_algorithm=innodb.
The implementation of MDEV-19534 included the following change:
diff --git a/storage/innobase/buf/buf0checksum.cc b/storage/innobase/buf/buf0checksum.cc
|
index c5ad0cfb657..2fb97f3b137 100644
|
--- a/storage/innobase/buf/buf0checksum.cc
|
+++ b/storage/innobase/buf/buf0checksum.cc
|
@@ -33,11 +33,8 @@ Created Aug 11, 2011 Vasil Dimov
|
#include "srv0srv.h"
|
#endif /* !UNIV_INNOCHECKSUM */
|
|
-/** the macro MYSQL_SYSVAR_ENUM() requires "long unsigned int" and if we
|
-use srv_checksum_algorithm_t here then we get a compiler error:
|
-ha_innodb.cc:12251: error: cannot convert 'srv_checksum_algorithm_t*' to
|
- 'long unsigned int*' in initialization */
|
-ulong srv_checksum_algorithm = SRV_CHECKSUM_ALGORITHM_INNODB;
|
+/** the value of innodb_checksum_algorithm */
|
+ulong srv_checksum_algorithm;
|
|
/** Calculate the CRC32 checksum of a page. The value is stored to the page
|
when it is written to a file and also checked for a match when reading from |
Due to this change, buf_page_is_corrupted() in innochecksum would invoke buf_calc_page_crc32(). Coincidentally, buf_calc_page_crc32() will return crc32=687675747 for this page, and that value happens to be the value of checksum_field2. Therefore, the following check will wrongly determine that the page is corrupted:
if (crc32_inited |
&& ((checksum_field1 == crc32
|
&& checksum_field2 != crc32)
|
|| (checksum_field1 != crc32
|
&& checksum_field2 == crc32))) {
|
return true; |
}
|
I can repeat the wrong outcome also in the 10.4 innochecksum when applying the above patch.
The wrong claim of corrupted page in mariadb-backup --backup should be due to the same problem, but I have no easy way to check it.
The incorrect page validation should affect any MariaDB Server version since 10.0. After testing a fix on 10.4 and 10.5, I posted a fix for 10.2, so that this can be fixed in the last scheduled release before end-of-life.
@marko, thank you very much!
Although we solved this glitch by utilizing the mydumper to dump the whole db concurrently, and then load the db into MariaDB 10.6.