[MDEV-25031] Not applying INSERT_REUSE_REDUNDANT due to corruption on page - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Blocker
Resolution: Fixed
Affects Version/s: 10.5.4, 10.5.2, 10.5.3, 10.5.5, 10.5.6, 10.5.7, 10.5.8, 10.5.9
Fix Version/s: 10.5.10
Component/s: Backup, Storage Engine - InnoDB
Labels:
Environment:
Arch Linux, current updates installed: Linux 5.10.19-1-lts #1 SMP Fri, 26 Feb 2021

Description

I get this fault below, from the journal. I am not in a position to conclude if this is a bug, but it happens repeatedly and if there is a small chance it is a bug I would like to submit the fault here to have someone exclude it is a bug. Sorry to bother your with this. I am thankful for any effort taken and also for any tip what to look into specifically.

I did check the filesystem, but there was no fault there, as far as I can see.

Mär 02 12:26:40 social systemd[1]: mariadb.service: Main process exited, code=killed, status=9/KILL

Mär 02 12:26:40 social systemd[1]: mariadb.service: Failed with result 'signal'.

Mär 02 12:26:45 social systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1.

Mär 02 12:26:45 social systemd[1]: Stopped MariaDB 10.5.9 database server.

Mär 02 12:26:45 social systemd[1]: Starting MariaDB 10.5.9 database server...

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] /usr/bin/mariadbd (mysqld 10.5.9-MariaDB) starting as process 319571 ...

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Warning] Could not increase number of max_open_files to more than 16384 (request: 32425)

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] InnoDB: Uses event mutexes

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] InnoDB: Compressed tables use zlib 1.2.11

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] InnoDB: Number of pools: 1

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] InnoDB: Using generic crc32 instructions

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] InnoDB: Using Linux native AIO

Mär 02 12:26:46 social mariadbd[319571]: 2021-03-02 12:26:46 0 [Note] InnoDB: Initializing buffer pool, total size = 17179869184, chunk size = 134217728

Mär 02 12:26:47 social mariadbd[319571]: 2021-03-02 12:26:47 0 [Note] InnoDB: Completed initialization of buffer pool

Mär 02 12:26:47 social mariadbd[319571]: 2021-03-02 12:26:47 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

Mär 02 12:26:47 social mariadbd[319571]: 2021-03-02 12:26:47 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1950138044187,1950909387225

Mär 02 12:27:02 social mariadbd[319571]: 2021-03-02 12:27:02 0 [Note] InnoDB: Read redo log up to LSN=1951723032064

Mär 02 12:27:02 social mariadbd[319571]: 2021-03-02 12:27:02 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77357.

Mär 02 12:27:02 social mariadbd[319571]: 2021-03-02 12:27:02 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77356.

Mär 02 12:27:06 social mariadbd[319571]: 2021-03-02 12:27:06 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77362.

Mär 02 12:27:06 social mariadbd[319571]: 2021-03-02 12:27:06 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77363.

Mär 02 12:27:07 social mariadbd[319571]: 2021-03-02 12:27:07 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77362.

Mär 02 12:27:07 social mariadbd[319571]: 2021-03-02 12:27:07 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77364.

Mär 02 12:27:07 social mariadbd[319571]: 2021-03-02 12:27:07 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77363.

Mär 02 12:27:07 social mariadbd[319571]: 2021-03-02 12:27:07 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77365.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77364.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77366.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77365.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77367.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77366.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77368.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77367.

Mär 02 12:27:08 social mariadbd[319571]: 2021-03-02 12:27:08 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77369.

Mär 02 12:27:09 social mariadbd[319571]: 2021-03-02 12:27:09 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77368.

Mär 02 12:27:09 social mariadbd[319571]: 2021-03-02 12:27:09 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77370.

Mär 02 12:27:09 social mariadbd[319571]: 2021-03-02 12:27:09 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77369.

Mär 02 12:27:09 social mariadbd[319571]: 2021-03-02 12:27:09 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77371.

Mär 02 12:27:10 social mariadbd[319571]: 2021-03-02 12:27:10 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77370.

Mär 02 12:27:10 social mariadbd[319571]: 2021-03-02 12:27:10 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77372.

Mär 02 12:27:10 social mariadbd[319571]: 2021-03-02 12:27:10 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77371.

Mär 02 12:27:10 social mariadbd[319571]: 2021-03-02 12:27:10 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77373.

Mär 02 12:27:11 social mariadbd[319571]: 2021-03-02 12:27:11 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77374, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77372.

Mär 02 12:27:11 social mariadbd[319571]: 2021-03-02 12:27:11 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77375, since the redo log references ./ylms_friendica/process.ibd with space ID 77373.

Mär 02 12:27:12 social mariadbd[319571]: 2021-03-02 12:27:12 0 [ERROR] InnoDB: Not applying INSERT_REUSE_REDUNDANT due to corruption on [page id: space=0, page number=4]

Mär 02 12:27:12 social mariadbd[319571]: 2021-03-02 12:27:12 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.

Mär 02 12:27:12 social mariadbd[319571]: 2021-03-02 12:27:12 0 [ERROR] [FATAL] InnoDB: Trying to read 16384 bytes at 13844040843264 outside the bounds of the file: ./ibdata1

Mär 02 12:27:12 social mariadbd[319571]: 210302 12:27:12 [ERROR] mysqld got signal 6 ;

Mär 02 12:27:12 social mariadbd[319571]: This could be because you hit a bug. It is also possible that this binary

Mär 02 12:27:12 social mariadbd[319571]: or one of the libraries it was linked against is corrupt, improperly built,

Mär 02 12:27:12 social mariadbd[319571]: or misconfigured. This error can also be caused by malfunctioning hardware.

Mär 02 12:27:12 social mariadbd[319571]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs

Mär 02 12:27:12 social mariadbd[319571]: We will try our best to scrape up some info that will hopefully help

Mär 02 12:27:12 social mariadbd[319571]: diagnose the problem, but since we have already crashed,

Mär 02 12:27:12 social mariadbd[319571]: something is definitely wrong and this may fail.

Mär 02 12:27:12 social mariadbd[319571]: Server version: 10.5.9-MariaDB

Mär 02 12:27:12 social mariadbd[319571]: key_buffer_size=134217728

Mär 02 12:27:12 social mariadbd[319571]: read_buffer_size=131072

Mär 02 12:27:12 social mariadbd[319571]: max_used_connections=0

Mär 02 12:27:12 social mariadbd[319571]: max_threads=388

Mär 02 12:27:12 social mariadbd[319571]: thread_count=0

Mär 02 12:27:12 social mariadbd[319571]: It is possible that mysqld could use up to

Mär 02 12:27:12 social mariadbd[319571]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 985198 K  bytes of memory

Mär 02 12:27:12 social mariadbd[319571]: Hope that's ok; if not, decrease some variables in the equation.

Mär 02 12:27:12 social mariadbd[319571]: Thread pointer: 0x0

Mär 02 12:27:12 social mariadbd[319571]: Attempting backtrace. You can use the following information to find out

Mär 02 12:27:12 social mariadbd[319571]: where mysqld died. If you see no messages after this, something went

Mär 02 12:27:12 social mariadbd[319571]: terribly wrong...

Mär 02 12:27:12 social mariadbd[319571]: stack_bottom = 0x0 thread_stack 0x49000

Mär 02 12:27:12 social mariadbd[319571]: ??:0(my_print_stacktrace)[0x55ba2dc07ebf]

Mär 02 12:27:12 social mariadbd[319571]: ??:0(handle_fatal_signal)[0x55ba2d6eb650]

Mär 02 12:27:12 social mariadbd[319571]: sigaction.c:0(__restore_rt)[0x7f9a2aae4960]

Mär 02 12:27:13 social mariadbd[319571]: :0(__GI_raise)[0x7f9a2a5fbef5]

Mär 02 12:27:13 social mariadbd[319571]: :0(__GI_abort)[0x7f9a2a5e5862]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x55ba2d3ca9da]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x55ba2d3de0c5]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x55ba2d3de10c]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(std::unique_lock<std::mutex>::unlock())[0x55ba2db27131]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(std::unique_lock<std::mutex>::unlock())[0x55ba2db28385]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(std::unique_lock<std::mutex>::unlock())[0x55ba2db17401]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(std::unique_lock<std::mutex>::unlock())[0x55ba2dadedd1]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(std::unique_lock<std::mutex>::unlock())[0x55ba2dad51cc]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(std::unique_lock<std::mutex>::unlock())[0x55ba2dadb6d0]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(Wsrep_server_service::log_dummy_write_set(wsrep::client_state&, wsrep::ws_meta const&))[0x55ba2d3c3e1d]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(wsrep_notify_status(wsrep::server_state::state, wsrep::view const*))[0x55ba2d9f192a]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(ha_initialize_handlerton(st_plugin_int*))[0x55ba2d6ee193]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(sys_var_pluginvar::sys_var_pluginvar(sys_var_chain*, char const*, st_plugin_int*, st_mysql_sys_var*))[0x55ba2d5018dd]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(plugin_init(int*, char**, int))[0x55ba2d502a04]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(unireg_abort)[0x55ba2d42c89a]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(mysqld_main(int, char**))[0x55ba2d432725]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(__libc_start_main)[0x7f9a2a5e6b25]

Mär 02 12:27:13 social mariadbd[319571]: ??:0(_start)[0x55ba2d4266fe]

Mär 02 12:27:13 social mariadbd[319571]: The manual page at https://mariadb.com/kb/en/how-to-produce-a-full-stack-trace-for-mysqld/ contains

Mär 02 12:27:13 social mariadbd[319571]: information that should help you find out what is causing the crash.

Mär 02 12:27:13 social mariadbd[319571]: Writing a core file...

Mär 02 12:27:13 social mariadbd[319571]: Working directory at /var/lib/mysql

Mär 02 12:27:13 social mariadbd[319571]: Resource Limits:

Mär 02 12:27:13 social mariadbd[319571]: Limit                     Soft Limit           Hard Limit           Units

Mär 02 12:27:13 social mariadbd[319571]: Max cpu time              unlimited            unlimited            seconds

Mär 02 12:27:13 social mariadbd[319571]: Max file size             unlimited            unlimited            bytes

Mär 02 12:27:13 social mariadbd[319571]: Max data size             unlimited            unlimited            bytes

Mär 02 12:27:13 social mariadbd[319571]: Max stack size            8388608              unlimited            bytes

Mär 02 12:27:13 social mariadbd[319571]: Max core file size        unlimited            unlimited            bytes

Mär 02 12:27:13 social mariadbd[319571]: Max resident set          unlimited            unlimited            bytes

Mär 02 12:27:13 social mariadbd[319571]: Max processes             79997                79997                processes

Mär 02 12:27:13 social mariadbd[319571]: Max open files            16384                16384                files

Mär 02 12:27:13 social mariadbd[319571]: Max locked memory         65536                65536                bytes

Mär 02 12:27:13 social mariadbd[319571]: Max address space         unlimited            unlimited            bytes

Mär 02 12:27:13 social mariadbd[319571]: Max file locks            unlimited            unlimited            locks

Mär 02 12:27:13 social mariadbd[319571]: Max pending signals       79997                79997                signals

Mär 02 12:27:13 social mariadbd[319571]: Max msgqueue size         819200               819200               bytes

Mär 02 12:27:13 social mariadbd[319571]: Max nice priority         0                    0

Mär 02 12:27:13 social mariadbd[319571]: Max realtime priority     0                    0

Mär 02 12:27:13 social mariadbd[319571]: Max realtime timeout      unlimited            unlimited            us

Mär 02 12:27:13 social mariadbd[319571]: Core pattern: |/usr/lib/systemd/systemd-coredump %P %u %g %s %t %c %h

Mär 02 12:27:15 social systemd[1]: mariadb.service: Main process exited, code=dumped, status=6/ABRT

Mär 02 12:27:15 social systemd[1]: mariadb.service: Failed with result 'core-dump'.

Mär 02 12:27:15 social systemd[1]: Failed to start MariaDB 10.5.9 database server.

Attachments

Issue Links

blocks

MDEV-24197 Prepare step of backup failing on large backup

Closed

is caused by

MDEV-21724 Optimize page_cur_insert_rec_low() redo logging

Closed

is duplicated by

MDEV-25569 Restore crashed due to Data structure corruption

Closed

relates to

MDEV-24197 Prepare step of backup failing on large backup

Closed

MDEV-24705 add check that LSN of the last skipped log record equals to FIL_PAGE_LSN field

Closed

MDEV-25745 InnoDB recovery fails with [ERROR] InnoDB: Not applying INSERT_REUSE_REDUNDANT due to corruption

Closed

(1 relates to)

Activity

Transition	Time In Source Status	Execution Times

Marko Mäkelä made transition - 2021-03-09 09:55

Open

In Progress

6d 21h 36m

Marko Mäkelä made transition - 2021-03-11 12:40

In Progress

Closed

2d 2h 44m

People

Assignee:: Marko Mäkelä

Reporter:: Ben Utzer

Votes:: 0 Vote for this issue

Watchers:: 6 Start watching this issue

Dates

Created:: 2021-03-02 12:19

Updated:: 2024-07-07 21:44

Resolved:: 2021-03-11 12:40

Git Integration

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

MariaDB Server