[MDEV-33922] InnoDB undo log tablespace file corruption - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Incomplete
Affects Version/s: 10.11.7, 10.11.8
Fix Version/s: N/A
Component/s: Storage Engine - InnoDB
Labels:
- innodb
Environment:
CloudLinux release 7.9 (Boris Yegorov)
CloudLinux release 8.9 (Anatoly Levchenko)

Description

Hello, we've had 15 separate MariaDB instances in the past 4 months run into an issue where the MariaDB server suddenly crashes, with an indication of a corrupted undo tablespace file, and starts to crash loop until it's begun with innodb_force_recovery=1 to ignore the corrupted page, as is described in the error logs. All of the servers are using `innodb_undo_tablespaces=3`in `my.cnf`.

We can't find a reliable way to reproduce the issue. We initially thought it was brought over during 10.6 -> 10.11 upgrades, but the most recent case is a month-old server that started with 10.11.7. If there's anything else you need to help debug the issue, we'll be happy to provide it.

Apr 16 07:44:58 host1339 mysqld[173461]: 2024-04-16  7:44:58 1447973524 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: .//undo003

Apr 16 07:44:58 host1339 mysqld[173461]: 2024-04-16  7:44:58 1447973524 [ERROR] InnoDB: File './/undo003' is corrupted

Apr 16 07:44:58 host1339 mysqld[173461]: 2024-04-16 07:44:58 0x7f7f9013f700  InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011-10.11.7/mariadb-10.11.7/storage/innobase/trx/trx0purge.cc line 268

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: Failing assertion: undo_page

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: We intentionally generate a memory trap.

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: If you get repeated assertion failures or crashes, even

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: immediately after the mariadbd startup, there may be

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: corruption in the InnoDB tablespace. Please refer to

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: about forcing recovery.

Apr 16 07:44:58 host1339 mysqld[173461]: 240416  7:44:58 [ERROR] mysqld got signal 6 ;

Apr 16 07:44:58 host1339 mysqld[173461]: Sorry, we probably made a mistake, and this is a bug.

Apr 16 07:44:58 host1339 mysqld[173461]: Your assistance in bug reporting will enable us to fix this for the next release.

Apr 16 07:44:58 host1339 mysqld[173461]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Apr 16 07:44:58 host1339 mysqld[173461]: We will try our best to scrape up some info that will hopefully help

Apr 16 07:44:58 host1339 mysqld[173461]: diagnose the problem, but since we have already crashed,

Apr 16 07:44:58 host1339 mysqld[173461]: something is definitely wrong and this may fail.

Apr 16 07:44:58 host1339 mysqld[173461]: Server version: 10.11.7-MariaDB-cll-lve source revision: 87e13722a95af5d9378d990caf48cb6874439347

Apr 16 07:44:58 host1339 mysqld[173461]: key_buffer_size=2147483648

Apr 16 07:44:58 host1339 mysqld[173461]: read_buffer_size=4194304

Apr 16 07:44:58 host1339 mysqld[173461]: max_used_connections=1205

Apr 16 07:44:58 host1339 mysqld[173461]: max_threads=2002

Apr 16 07:44:58 host1339 mysqld[173461]: thread_count=320

Apr 16 07:44:58 host1339 mysqld[173461]: It is possible that mysqld could use up to

Apr 16 07:44:58 host1339 mysqld[173461]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551172 K  bytes of memory

Apr 16 07:44:58 host1339 mysqld[173461]: Hope that's ok; if not, decrease some variables in the equation.

Apr 16 07:44:58 host1339 mysqld[173461]: Thread pointer: 0x7f81165dbc58

Apr 16 07:44:58 host1339 mysqld[173461]: Attempting backtrace. You can use the following information to find out

Apr 16 07:44:58 host1339 mysqld[173461]: where mysqld died. If you see no messages after this, something went

Apr 16 07:44:58 host1339 mysqld[173461]: terribly wrong...

Apr 16 07:44:58 host1339 mysqld[173461]: stack_bottom = 0x7f7f9013d358 thread_stack 0x49000

Apr 16 07:44:58 host1339 mysqld[173461]: 2024-04-16 07:44:58 0x7f7a770c0700  InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011-10.11.7/mariadb-10.11.7/storage/innobase/buf/buf0lru.cc line 281

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: Failing assertion: !block->page.in_file()

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: We intentionally generate a memory trap.

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: If you get repeated assertion failures or crashes, even

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: immediately after the mariadbd startup, there may be

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: corruption in the InnoDB tablespace. Please refer to

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/

Apr 16 07:44:58 host1339 mysqld[173461]: InnoDB: about forcing recovery.

Apr 16 07:45:05 host1339 systemd-coredump[2183663]: Process 173461 (mysqld) of user 991 dumped core.

...

Apr 16 08:02:23 host1339 mysqld[2811986]: 2024-04-16  8:02:23 0 [ERROR] InnoDB: Corrupted page identifier at 3543005337948; set innodb_force_recovery=1 to ignore the record.

Apr 16 08:02:23 host1339 mysqld[2811986]: 2024-04-16  8:02:23 0 [Note] InnoDB: End of log at LSN=3543005337948

Apr 16 08:02:23 host1339 mysqld[2811986]: 2024-04-16  8:02:23 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error

Attachments

Issue Links

relates to

MDEV-33189 Server crash after reading outside of bounds on ibdata1 , file corrupted, no auto-recovery

Closed

MDEV-34233 InnoDB crashes due to corrupted ibdata1 (Assertion failure in innodb.undo_page)

Closed

MDEV-34453 Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: ./ibdata1

Closed

Activity

Ascending order - Click to sort in descending order

Arnas Klova created issue - 2024-04-17 06:54

Marko Mäkelä added a comment - 2024-04-24 05:12

The failing assertion is something that I intentionally left there when in ~~MDEV-13542~~ I was fixing other crashes on accessing corrupted pages:

  /* This function is invoked during transaction commit, which is not

  allowed to fail. If we get a corrupted undo header, we will crash here. */

  ut_a(undo_page);

Finding the root causes of corruption is very challenging, unless there is a script that allows the corruption to be reproduced with some reasonable probability. In our internal testing we catch and fix cases, mostly thanks to ~~MDEV-18976~~ and https://rr-project.org. Since the latest quarterly releases, some potential race conditions in the buffer pool were fixed as well. If you have a staging environment where you can run tests, I would suggest that you download the currently latest 10.11 development snapshot from https://ci.mariadb.org/45877/ and test if the situation has improved. The scheduled quarterly releases should be out soon, but I can’t give an exact date, because MySQL 8.0.37 (containing some security fixes that might be applicable to MariaDB) has not been released yet.

Marko Mäkelä added a comment - 2024-04-24 05:12 The failing assertion is something that I intentionally left there when in MDEV-13542 I was fixing other crashes on accessing corrupted pages: /* This function is invoked during transaction commit, which is not allowed to fail. If we get a corrupted undo header, we will crash here. */ ut_a(undo_page); Finding the root causes of corruption is very challenging, unless there is a script that allows the corruption to be reproduced with some reasonable probability. In our internal testing we catch and fix cases, mostly thanks to MDEV-18976 and https://rr-project.org . Since the latest quarterly releases, some potential race conditions in the buffer pool were fixed as well. If you have a staging environment where you can run tests, I would suggest that you download the currently latest 10.11 development snapshot from https://ci.mariadb.org/45877/ and test if the situation has improved. The scheduled quarterly releases should be out soon, but I can’t give an exact date, because MySQL 8.0.37 (containing some security fixes that might be applicable to MariaDB) has not been released yet.

Felix Huettner added a comment - 2024-04-30 08:24 - edited

We today saw probably the same issue in 11.0.5.
We run this from the docker image docker.io/bitnami/mariadb-galera:11.0.5-debian-12-r6

2024-04-30  7:06:14 257295 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: .//undo003

2024-04-30  7:06:14 257295 [ERROR] InnoDB: File './/undo003' is corrupted

2024-04-30 07:06:14 0x7f52a250b6c0  InnoDB: Assertion failure in file /bitnami/blacksmith-sandox/mariadb-galera-11.0.5/storage/innobase/trx/trx0undo.cc line 1440

InnoDB: Failing assertion: rollback

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.

240430  7:06:14 [ERROR] mysqld got signal 6 ;

Sorry, we probably made a mistake, and this is a bug.

Your assistance in bug reporting will enable us to fix this for the next release.

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: 11.0.5-MariaDB-log source revision: 6ef0b2ee5f9e03ea672eda219987b7991697d708

key_buffer_size=33554432

read_buffer_size=131072

max_used_connections=1160

max_threads=2002

thread_count=871

It is possible that mysqld could use up to

key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4442584 K  bytes of memory

Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x7f54001696e8

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 = 0x7f52a250ad78 thread_stack 0x49000

2024-04-30 07:06:15 0x7f5610c616c0  InnoDB: Assertion failure in file /bitnami/blacksmith-sandox/mariadb-galera-11.0.5/storage/innobase/buf/buf0lru.cc line 281

InnoDB: Failing assertion: !block->page.in_file()

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.

Felix Huettner added a comment - 2024-04-30 08:24 - edited We today saw probably the same issue in 11.0.5. We run this from the docker image docker.io/bitnami/mariadb-galera:11.0.5-debian-12-r6 2024-04-30 7:06:14 257295 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: .//undo003 2024-04-30 7:06:14 257295 [ERROR] InnoDB: File './/undo003' is corrupted 2024-04-30 07:06:14 0x7f52a250b6c0 InnoDB: Assertion failure in file /bitnami/blacksmith-sandox/mariadb-galera-11.0.5/storage/innobase/trx/trx0undo.cc line 1440 InnoDB: Failing assertion: rollback 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. 240430 7:06:14 [ERROR] mysqld got signal 6 ; Sorry, we probably made a mistake, and this is a bug. Your assistance in bug reporting will enable us to fix this for the next release. 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: 11.0.5-MariaDB-log source revision: 6ef0b2ee5f9e03ea672eda219987b7991697d708 key_buffer_size=33554432 read_buffer_size=131072 max_used_connections=1160 max_threads=2002 thread_count=871 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4442584 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. Thread pointer: 0x7f54001696e8 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 = 0x7f52a250ad78 thread_stack 0x49000 2024-04-30 07:06:15 0x7f5610c616c0 InnoDB: Assertion failure in file /bitnami/blacksmith-sandox/mariadb-galera-11.0.5/storage/innobase/buf/buf0lru.cc line 281 InnoDB: Failing assertion: !block->page.in_file() 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.

Marko Mäkelä added a comment - 2024-05-24 11:25

felix.huettner@mail.schwarz, yes, that assertion should fail on XA PREPARE when the undo log is corrupted.

Marko Mäkelä added a comment - 2024-05-24 11:25 felix.huettner@mail.schwarz , yes, that assertion should fail on XA PREPARE when the undo log is corrupted.

Marko Mäkelä made changes - 2024-05-24 11:41

Field	Original Value	New Value
Link		This issue relates to ~~MDEV-34233~~ [ ~~MDEV-34233~~ ]

Daniel Black made changes - 2024-06-26 01:50

Link

This issue relates to ~~MDEV-34453~~ [ ~~MDEV-34453~~ ]

Marko Mäkelä made changes - 2024-06-28 12:38

Link

This issue relates to ~~MDEV-33189~~ [ ~~MDEV-33189~~ ]

Arnas Klova added a comment - 2024-07-15 16:01

Hello, unfortunately, 10.11.8 did not fix the undo log corruption issue.
In addition to this issue ,there appears to be a problem: undo logs can corrupt to a point where MariaDB server won't start until you use innodb_force_recovery=6 and dump, recreate datadir and reimport databases.
It's surprisingly common. With an over thousand server fleet, this type of incident occurs at least twice a week. This happened with 10.11.7 too.

Jul 12 15:52:48 host mysqld[17809]: 2024-07-12 15:52:48 11763250 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: .//undo001

Jul 12 15:52:48 host mysqld[17809]: 2024-07-12 15:52:48 11763250 [ERROR] InnoDB: File './/undo001' is corrupted

Jul 12 15:52:48 host mysqld[17809]: 2024-07-12 15:52:48 0x7f32d2dd6700  InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011-10.11.8/mariadb-10.11.8/storage/innobase/trx/trx0purge.cc line 190

Jul 12 15:52:48 host mysqld[17809]: InnoDB: Failing assertion: undo_page

...

Jul 12 15:52:48 host mysqld[17809]: Server version: 10.11.8-MariaDB-cll-lve source revision: 3a069644682e336e445039e48baae9693f9a08ee

...

Jul 12 15:52:50 host mysqld[17809]: 2024-07-12 15:52:50 11763303 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: .//undo001

Jul 12 15:52:50 host mysqld[17809]: 2024-07-12 15:52:50 11763303 [ERROR] [FATAL] InnoDB: Unknown error Required history data has been deleted

...

Jul 12 15:55:53 host mysqld[32216]: 2024-07-12 15:55:53 0 [ERROR] InnoDB: Corrupted page identifier at 142446661109158; set innodb_force_recovery=1 to ignore the record.

Jul 12 15:55:53 host mysqld[32216]: 2024-07-12 15:55:53 0 [Note] InnoDB: End of log at LSN=142446661109158

...

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Note] InnoDB: At LSN: 142446607401689: unable to open file ./user_KTxyj/#sql-ib3058332.ibd for tablespace 3058323

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158

Jul 12 16:28:43 host mysqld[31901]: 2024-07-12 16:28:43 0 [Note] InnoDB: End of log at LSN=142446661287136

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: !!! innodb_force_recovery is set to 6 !!!

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Started in read only mode

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Compressed tables use zlib 1.2.7

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Number of transaction pools: 1

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Disabling background log and ibuf IO write threads.

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Using Linux native AIO

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Initializing buffer pool, total size = 9.805GiB, chunk size = 156.875MiB

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Completed initialization of buffer pool

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: innodb_force_recovery=6 skips redo log apply

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Warning] InnoDB: Retry attempts for writing partial data failed.

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [ERROR] InnoDB: Write to file ./ibdata1 failed at offset 1048576, 16384 bytes should have been written, only 0 were written. Operating system error number 9. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor'

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/

Jul 12 17:02:35 host mysqld[28827]: 2024-07-12 17:02:35 0 [ERROR] InnoDB: Failed to upgrade the double write buffer

In the following example `host2`also starts with the undo log file suddenly getting corrupted, crashing right after. It then identifies `Corrupted page identifier at 102609070806801; set innodb_force_recovery=1 to ignore the record.` However, using innodb_force_recovery=1 didn't start the server; it hanged for 5 minutes until systemd auto-restart kicked in. This looped until innodb_force_recovery=6 was used, and databases were dumped and reimported after remaking datadir.
We have kept the the datadir for that server for investigation purposes.

Jul 12 08:48:30 host2 mysqld[48685]: 2024-07-12  8:48:30 16996196 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: .//undo003

Jul 12 08:48:30 host2 mysqld[48685]: 2024-07-12  8:48:30 16996196 [ERROR] InnoDB: File './/undo003' is corrupted

Jul 12 08:48:30 host2 mysqld[48685]: 2024-07-12 08:48:30 0x7fe22f940700  InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011-10.11.8/mariadb-10.11.8/storage/innobase/trx/trx0purge.cc line 190

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: Failing assertion: undo_page

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: We intentionally generate a memory trap.

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: Submit a detailed bug report to https://jira.mariadb.org/

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: If you get repeated assertion failures or crashes, even

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: immediately after the mariadbd startup, there may be

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: corruption in the InnoDB tablespace. Please refer to

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/

Jul 12 08:48:30 host2 mysqld[48685]: InnoDB: about forcing recovery.

Jul 12 08:48:30 host2 mysqld[48685]: 240712  8:48:30 [ERROR] mysqld got signal 6 ;

Jul 12 08:48:30 host2 mysqld[48685]: Sorry, we probably made a mistake, and this is a bug.

Jul 12 08:48:30 host2 mysqld[48685]: Your assistance in bug reporting will enable us to fix this for the next release.

Jul 12 08:48:30 host2 mysqld[48685]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Jul 12 08:48:30 host2 mysqld[48685]: We will try our best to scrape up some info that will hopefully help

Jul 12 08:48:30 host2 mysqld[48685]: diagnose the problem, but since we have already crashed,

Jul 12 08:48:30 host2 mysqld[48685]: something is definitely wrong and this may fail.

Jul 12 08:48:30 host2 mysqld[48685]: Server version: 10.11.8-MariaDB-cll-lve source revision: 3a069644682e336e445039e48baae9693f9a08ee

Jul 12 08:48:30 host2 mysqld[48685]: key_buffer_size=2147483648

Jul 12 08:48:30 host2 mysqld[48685]: read_buffer_size=4194304

Jul 12 08:48:30 host2 mysqld[48685]: max_used_connections=262

Jul 12 08:48:30 host2 mysqld[48685]: max_threads=2002

Jul 12 08:48:30 host2 mysqld[48685]: thread_count=262

Jul 12 08:48:30 host2 mysqld[48685]: It is possible that mysqld could use up to

Jul 12 08:48:30 host2 mysqld[48685]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551187 K  bytes of memory

Jul 12 08:48:30 host2 mysqld[48685]: Hope that's ok; if not, decrease some variables in the equation.

Jul 12 08:48:30 host2 mysqld[48685]: Thread pointer: 0x7fde6c412018

Jul 12 08:48:30 host2 mysqld[48685]: Attempting backtrace. You can use the following information to find out

Jul 12 08:48:30 host2 mysqld[48685]: where mysqld died. If you see no messages after this, something went

Jul 12 08:48:30 host2 mysqld[48685]: terribly wrong...

Jul 12 08:48:30 host2 mysqld[48685]: stack_bottom = 0x7fe22f93fc00 thread_stack 0x49000

Jul 12 08:48:37 host2 mysqld[48685]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55b824a2e93e]

Jul 12 08:48:42 host2 mysqld[48685]: /usr/sbin/mysqld(handle_fatal_signal+0x2f7)[0x55b824498ba7]

Jul 12 08:48:47 host2 mysqld[48685]: sigaction.c:0(__restore_rt)[0x7fe25d20c630]

Jul 12 08:48:49 host2 mysqld[48685]: /lib64/libc.so.6(gsignal+0x37)[0x7fe25b48b387]

Jul 12 08:48:49 host2 mysqld[48685]: /lib64/libc.so.6(abort+0x148)[0x7fe25b48ca78]

Jul 12 08:48:54 host2 mysqld[48685]: 2024-07-12 08:48:54 0x7fe23645f700  InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011-10.11.8/mariadb-10.11.8/storage/innobase/buf/buf0lru.cc line 281

Jul 12 08:48:54 host2 mysqld[48685]: InnoDB: Failing assertion: !block->page.in_file()

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] Starting MariaDB 10.11.8-MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 38070

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] mysqld: Aria engine: starting recovery

Jul 12 08:52:23 host2 mysqld[38070]: tables to flush: 3 2 1 0

Jul 12 08:52:23 host2 mysqld[38070]: (0.0 seconds);

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] mysqld: Aria engine: recovery done

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Compressed tables use zlib 1.2.7

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Number of transaction pools: 1

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Using Linux native AIO

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Initializing buffer pool, total size = 9.805GiB, chunk size = 156.875MiB

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Completed initialization of buffer pool

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Buffered log writes (block size=512 bytes)

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer

Jul 12 08:52:23 host2 mysqld[38070]: 2024-07-12  8:52:23 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=102608836230414

Jul 12 08:52:24 host2 mysqld[38070]: 2024-07-12  8:52:24 0 [ERROR] InnoDB: Corrupted page identifier at 102609070806801; set innodb_force_recovery=1 to ignore the record.

Jul 12 08:52:24 host2 mysqld[38070]: 2024-07-12  8:52:24 0 [Note] InnoDB: End of log at LSN=102609070806801

Jul 12 08:52:24 host2 mysqld[38070]: 2024-07-12  8:52:24 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error

Jul 12 08:52:24 host2 mysqld[38070]: 2024-07-12  8:52:24 0 [Note] InnoDB: Starting shutdown...

Jul 12 08:52:24 host2 mysqld[38070]: 2024-07-12  8:52:24 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] Starting MariaDB 10.11.8-MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 4950

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: !!! innodb_force_recovery is set to 1 !!!

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Compressed tables use zlib 1.2.7

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Number of transaction pools: 1

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Using Linux native AIO

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Initializing buffer pool, total size = 9.805GiB, chunk size = 156.875MiB

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Completed initialization of buffer pool

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Buffered log writes (block size=512 bytes)

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=102608836230414

Jul 12 08:53:09 host2 mysqld[4950]: 2024-07-12  8:53:09 0 [Note] InnoDB: At LSN: 102608936674584: unable to open file ./u999477289_tovKC/#sql-ib2913140.ibd for tablespace 2912698

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801

Jul 12 08:53:10 host2 mysqld[4950]: 2024-07-12  8:53:10 0 [Note] InnoDB: End of log at LSN=102609071027522

Jul 12 08:58:57 host2 mysqld[8105]: 2024-07-12  8:58:57 0 [Note] libgovernor.so found

Jul 12 08:58:57 host2 mysqld[8105]: 2024-07-12  8:58:57 0 [Note] All governors functions found too

Jul 12 08:58:57 host2 mysqld[8105]: 2024-07-12  8:58:57 0 [Note] Governor connected

Jul 12 08:58:57 host2 mysqld[8105]: 2024-07-12  8:58:57 0 [Note] All governors lve functions found too

Jul 12 08:58:57 host2 mysqld[8105]: 2024-07-12  8:58:57 0 [Warning] Could not increase number of max_open_files to more than 1048576 (request: 8194079)

Jul 12 08:58:57 host2 mysqld[8105]: 2024-07-12  8:58:57 0 [Note] Starting MariaDB 10.11.8-MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 8105

In third example, a different error showed up, which also required full recovery:

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT(184417878318711) at 184417878318711

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [ERROR] InnoDB: Log scan aborted at LSN 184417878318711

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [Note] InnoDB: Starting shutdown...

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [Note] Plugin 'FEEDBACK' is disabled.

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [Warning] 'innodb-log-write-ahead-size' was removed. It does nothing now and exists only for compatibility with old my.cnf files.

Jul  9 22:42:51 host3 mariadbd[3158236]: 2024-07-09 22:42:51 0 [ERROR] Unknown/unsupported storage engine: InnoDB

...

Jul  9 22:51:56 host3 mariadbd[3493264]: 2024-07-09 22:51:56 0 [Note] Starting MariaDB 10.11.8-MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 3493264o

...

Jul  9 22:59:46 host3 mariadbd[3760705]: 2024-07-09 22:59:46 0 [Note] InnoDB: !!! innodb_force_recovery is set to 6 !!!

Jul  9 23:04:37 host3 mariadbd[3760705]: 2024-07-09 23:04:37 25215 [Warning] InnoDB: A transaction id in a record of table `user_pBg07`.`wpstg0_posts` is newer than the system-wide maximum.

Jul  9 23:04:37 host3 mariadbd[3760705]: 2024-07-09 23:04:37 25215 [ERROR] InnoDB: We detected index corruption in an InnoDB type table. You have to dump + drop + reimport the table or, in a case of widespread corruption, dump all InnoDB tables and recreate the whole tablespace. If the mariadbd server crashes after the startup or when you dump the tables. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.

...

Thanks

Arnas Klova added a comment - 2024-07-15 16:01 Hello, unfortunately, 10.11.8 did not fix the undo log corruption issue. In addition to this issue ,there appears to be a problem: undo logs can corrupt to a point where MariaDB server won't start until you use innodb_force_recovery=6 and dump, recreate datadir and reimport databases. It's surprisingly common. With an over thousand server fleet, this type of incident occurs at least twice a week. This happened with 10.11.7 too. Jul 12 15 : 52 : 48 host mysqld[ 17809 ]: 2024 - 07 - 12 15 : 52 : 48 11763250 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: . //undo001 Jul 12 15 : 52 : 48 host mysqld[ 17809 ]: 2024 - 07 - 12 15 : 52 : 48 11763250 [ERROR] InnoDB: File './/undo001' is corrupted Jul 12 15 : 52 : 48 host mysqld[ 17809 ]: 2024 - 07 - 12 15 : 52 : 48 0x7f32d2dd6700 InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011- 10.11 . 8 /mariadb- 10.11 . 8 /storage/innobase/trx/trx0purge.cc line 190 Jul 12 15 : 52 : 48 host mysqld[ 17809 ]: InnoDB: Failing assertion: undo_page ... Jul 12 15 : 52 : 48 host mysqld[ 17809 ]: Server version: 10.11 . 8 -MariaDB-cll-lve source revision: 3a069644682e336e445039e48baae9693f9a08ee ... Jul 12 15 : 52 : 50 host mysqld[ 17809 ]: 2024 - 07 - 12 15 : 52 : 50 11763303 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: . //undo001 Jul 12 15 : 52 : 50 host mysqld[ 17809 ]: 2024 - 07 - 12 15 : 52 : 50 11763303 [ERROR] [FATAL] InnoDB: Unknown error Required history data has been deleted ... Jul 12 15 : 55 : 53 host mysqld[ 32216 ]: 2024 - 07 - 12 15 : 55 : 53 0 [ERROR] InnoDB: Corrupted page identifier at 142446661109158 ; set innodb_force_recovery= 1 to ignore the record. Jul 12 15 : 55 : 53 host mysqld[ 32216 ]: 2024 - 07 - 12 15 : 55 : 53 0 [Note] InnoDB: End of log at LSN= 142446661109158 ... Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Note] InnoDB: At LSN: 142446607401689 : unable to open file ./user_KTxyj/#sql-ib3058332.ibd for tablespace 3058323 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring malformed log record at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 142446661109158 Jul 12 16 : 28 : 43 host mysqld[ 31901 ]: 2024 - 07 - 12 16 : 28 : 43 0 [Note] InnoDB: End of log at LSN= 142446661287136 Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: !!! innodb_force_recovery is set to 6 !!! Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Started in read only mode Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Compressed tables use zlib 1.2 . 7 Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Number of transaction pools: 1 Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Disabling background log and ibuf IO write threads. Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Using Linux native AIO Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Initializing buffer pool, total size = 9 .805GiB, chunk size = 156 .875MiB Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Completed initialization of buffer pool Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: innodb_force_recovery= 6 skips redo log apply Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Warning] InnoDB: Retry attempts for writing partial data failed. Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [ERROR] InnoDB: Write to file ./ibdata1 failed at offset 1048576 , 16384 bytes should have been written, only 0 were written. Operating system error number 9 . Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded. Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor' Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [Note] InnoDB: Some operating system error numbers are described at https: //mariadb.com/kb/en/library/operating-system-error-codes/ Jul 12 17 : 02 : 35 host mysqld[ 28827 ]: 2024 - 07 - 12 17 : 02 : 35 0 [ERROR] InnoDB: Failed to upgrade the double write buffer In the following example `host2`also starts with the undo log file suddenly getting corrupted, crashing right after. It then identifies `Corrupted page identifier at 102609070806801; set innodb_force_recovery=1 to ignore the record.` However, using innodb_force_recovery=1 didn't start the server; it hanged for 5 minutes until systemd auto-restart kicked in. This looped until innodb_force_recovery=6 was used, and databases were dumped and reimported after remaking datadir. We have kept the the datadir for that server for investigation purposes. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: 2024 - 07 - 12 8 : 48 : 30 16996196 [ERROR] InnoDB: Trying to read 16384 bytes at 70368744161280 outside the bounds of the file: . //undo003 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: 2024 - 07 - 12 8 : 48 : 30 16996196 [ERROR] InnoDB: File './/undo003' is corrupted Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: 2024 - 07 - 12 08 : 48 : 30 0x7fe22f940700 InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011- 10.11 . 8 /mariadb- 10.11 . 8 /storage/innobase/trx/trx0purge.cc line 190 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: Failing assertion: undo_page Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: We intentionally generate a memory trap. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: Submit a detailed bug report to https: //jira.mariadb.org/ Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: If you get repeated assertion failures or crashes, even Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: immediately after the mariadbd startup, there may be Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: corruption in the InnoDB tablespace. Please refer to Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: https: //mariadb.com/kb/en/library/innodb-recovery-modes/ Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: InnoDB: about forcing recovery. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: 240712 8 : 48 : 30 [ERROR] mysqld got signal 6 ; Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: Sorry, we probably made a mistake, and this is a bug. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: Your assistance in bug reporting will enable us to fix this for the next release. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: To report this bug, see https: //mariadb.com/kb/en/reporting-bugs Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: We will try our best to scrape up some info that will hopefully help Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: diagnose the problem, but since we have already crashed, Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: something is definitely wrong and this may fail. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: Server version: 10.11 . 8 -MariaDB-cll-lve source revision: 3a069644682e336e445039e48baae9693f9a08ee Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: key_buffer_size= 2147483648 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: read_buffer_size= 4194304 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: max_used_connections= 262 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: max_threads= 2002 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: thread_count= 262 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: It is possible that mysqld could use up to Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 18551187 K bytes of memory Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: Hope that's ok; if not, decrease some variables in the equation. Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: Thread pointer: 0x7fde6c412018 Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: Attempting backtrace. You can use the following information to find out Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: where mysqld died. If you see no messages after this , something went Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: terribly wrong... Jul 12 08 : 48 : 30 host2 mysqld[ 48685 ]: stack_bottom = 0x7fe22f93fc00 thread_stack 0x49000 Jul 12 08 : 48 : 37 host2 mysqld[ 48685 ]: /usr/sbin/mysqld(my_print_stacktrace+ 0x2e )[ 0x55b824a2e93e ] Jul 12 08 : 48 : 42 host2 mysqld[ 48685 ]: /usr/sbin/mysqld(handle_fatal_signal+ 0x2f7 )[ 0x55b824498ba7 ] Jul 12 08 : 48 : 47 host2 mysqld[ 48685 ]: sigaction.c: 0 (__restore_rt)[ 0x7fe25d20c630 ] Jul 12 08 : 48 : 49 host2 mysqld[ 48685 ]: /lib64/libc.so. 6 (gsignal+ 0x37 )[ 0x7fe25b48b387 ] Jul 12 08 : 48 : 49 host2 mysqld[ 48685 ]: /lib64/libc.so. 6 (abort+ 0x148 )[ 0x7fe25b48ca78 ] Jul 12 08 : 48 : 54 host2 mysqld[ 48685 ]: 2024 - 07 - 12 08 : 48 : 54 0x7fe23645f700 InnoDB: Assertion failure in file /builddir/build/BUILD/cl-MariaDB1011- 10.11 . 8 /mariadb- 10.11 . 8 /storage/innobase/buf/buf0lru.cc line 281 Jul 12 08 : 48 : 54 host2 mysqld[ 48685 ]: InnoDB: Failing assertion: !block->page.in_file() Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] Starting MariaDB 10.11 . 8 -MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 38070 Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] mysqld: Aria engine: starting recovery Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: tables to flush: 3 2 1 0 Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: ( 0.0 seconds); Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] mysqld: Aria engine: recovery done Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Compressed tables use zlib 1.2 . 7 Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Number of transaction pools: 1 Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Using Linux native AIO Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Initializing buffer pool, total size = 9 .805GiB, chunk size = 156 .875MiB Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Completed initialization of buffer pool Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Buffered log writes (block size= 512 bytes) Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer Jul 12 08 : 52 : 23 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 23 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN= 102608836230414 Jul 12 08 : 52 : 24 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 24 0 [ERROR] InnoDB: Corrupted page identifier at 102609070806801 ; set innodb_force_recovery= 1 to ignore the record. Jul 12 08 : 52 : 24 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 24 0 [Note] InnoDB: End of log at LSN= 102609070806801 Jul 12 08 : 52 : 24 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 24 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error Jul 12 08 : 52 : 24 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 24 0 [Note] InnoDB: Starting shutdown... Jul 12 08 : 52 : 24 host2 mysqld[ 38070 ]: 2024 - 07 - 12 8 : 52 : 24 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] Starting MariaDB 10.11 . 8 -MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 4950 Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: !!! innodb_force_recovery is set to 1 !!! Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Compressed tables use zlib 1.2 . 7 Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Number of transaction pools: 1 Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Using Linux native AIO Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Initializing buffer pool, total size = 9 .805GiB, chunk size = 156 .875MiB Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Completed initialization of buffer pool Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Buffered log writes (block size= 512 bytes) Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Resetting space id's in the doublewrite buffer Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN= 102608836230414 Jul 12 08 : 53 : 09 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 09 0 [Note] InnoDB: At LSN: 102608936674584 : unable to open file ./u999477289_tovKC/#sql-ib2913140.ibd for tablespace 2912698 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring malformed log record at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Warning] InnoDB: Ignoring corrupted page identifier at LSN 102609070806801 Jul 12 08 : 53 : 10 host2 mysqld[ 4950 ]: 2024 - 07 - 12 8 : 53 : 10 0 [Note] InnoDB: End of log at LSN= 102609071027522 Jul 12 08 : 58 : 57 host2 mysqld[ 8105 ]: 2024 - 07 - 12 8 : 58 : 57 0 [Note] libgovernor.so found Jul 12 08 : 58 : 57 host2 mysqld[ 8105 ]: 2024 - 07 - 12 8 : 58 : 57 0 [Note] All governors functions found too Jul 12 08 : 58 : 57 host2 mysqld[ 8105 ]: 2024 - 07 - 12 8 : 58 : 57 0 [Note] Governor connected Jul 12 08 : 58 : 57 host2 mysqld[ 8105 ]: 2024 - 07 - 12 8 : 58 : 57 0 [Note] All governors lve functions found too Jul 12 08 : 58 : 57 host2 mysqld[ 8105 ]: 2024 - 07 - 12 8 : 58 : 57 0 [Warning] Could not increase number of max_open_files to more than 1048576 (request: 8194079 ) Jul 12 08 : 58 : 57 host2 mysqld[ 8105 ]: 2024 - 07 - 12 8 : 58 : 57 0 [Note] Starting MariaDB 10.11 . 8 -MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 8105 In third example, a different error showed up, which also required full recovery: Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT( 184417878318711 ) at 184417878318711 Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [ERROR] InnoDB: Log scan aborted at LSN 184417878318711 Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [Note] InnoDB: Starting shutdown... Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [Note] Plugin 'FEEDBACK' is disabled. Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [Warning] 'innodb-log-write-ahead-size' was removed. It does nothing now and exists only for compatibility with old my.cnf files. Jul 9 22 : 42 : 51 host3 mariadbd[ 3158236 ]: 2024 - 07 - 09 22 : 42 : 51 0 [ERROR] Unknown/unsupported storage engine: InnoDB ... Jul 9 22 : 51 : 56 host3 mariadbd[ 3493264 ]: 2024 - 07 - 09 22 : 51 : 56 0 [Note] Starting MariaDB 10.11 . 8 -MariaDB-cll-lve source revision 3a069644682e336e445039e48baae9693f9a08ee as process 3493264o ... Jul 9 22 : 59 : 46 host3 mariadbd[ 3760705 ]: 2024 - 07 - 09 22 : 59 : 46 0 [Note] InnoDB: !!! innodb_force_recovery is set to 6 !!! Jul 9 23 : 04 : 37 host3 mariadbd[ 3760705 ]: 2024 - 07 - 09 23 : 04 : 37 25215 [Warning] InnoDB: A transaction id in a record of table `user_pBg07`.`wpstg0_posts` is newer than the system-wide maximum. Jul 9 23 : 04 : 37 host3 mariadbd[ 3760705 ]: 2024 - 07 - 09 23 : 04 : 37 25215 [ERROR] InnoDB: We detected index corruption in an InnoDB type table. You have to dump + drop + reimport the table or, in a case of widespread corruption, dump all InnoDB tables and recreate the whole tablespace. If the mariadbd server crashes after the startup or when you dump the tables. Please refer to https: //mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery. ... Thanks

Arnas Klova made changes - 2024-07-26 06:48

Affects Version/s

10.11.8 [ 29630 ]

Marko Mäkelä added a comment - 2024-11-26 06:50

Hi! Is this reproducible with the recently released MariaDB Server 10.11.10, which includes a fix of ~~MDEV-34453~~?

Marko Mäkelä added a comment - 2024-11-26 06:50 Hi! Is this reproducible with the recently released MariaDB Server 10.11.10, which includes a fix of MDEV-34453 ?

Marko Mäkelä made changes - 2024-11-26 06:50

Status

Open [ 1 ]

Needs Feedback [ 10501 ]

Julien Fritsch made changes - 2024-12-30 08:00

Fix Version/s		N/A [ 14700 ]
Resolution		Incomplete [ 4 ]
Status	Needs Feedback [ 10501 ]	Closed [ 6 ]

People

Assignee:: Unassigned

Reporter:: Arnas Klova

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 2024-04-17 06:54

Updated:: 2024-12-30 08:00

Resolved:: 2024-12-30 08:00

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.