Details
-
Bug
-
Status: Closed (View Workflow)
-
Blocker
-
Resolution: Fixed
-
10.5.4, 10.5.2, 10.5.3, 10.5.5, 10.5.6, 10.5.7, 10.5.8, 10.5.9
-
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
-
-
- Closed
-
- is caused by
-
-
- Closed
-
- is duplicated by
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
MDEV-24705 add check that LSN of the last skipped log record equals to FIL_PAGE_LSN field
-
- Closed
-
-
-
- Closed
-
(1 relates to)
Activity
| Field | Original Value | New Value |
|---|---|---|
| Description |
I get this fault below, all from journal.
I am not in a position to conclude if this is a but, 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 but. 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. {code:java} 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. {code} |
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. {code:java} 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. {code} |
| Link |
This issue relates to |
| Fix Version/s | 10.5 [ 23123 ] | |
| Assignee | Marko Mäkelä [ marko ] | |
| Labels | need_feedback | |
| Priority | Minor [ 4 ] | Major [ 3 ] |
The failure is related to ROW_FORMAT=REDUNDANT tables, which ceased to be the default in MySQL 5.0.3. What had happened to the server before the first such failed crash recovery?
I had a crash before, I thought it was the same reason, it was yesterday, I will check more closely. After that crash I started MariaDB with
innodb_force_recovery = 1 |
, but let me check what happened before.
I updated from 10.5.8 to 10.5.9 on 24 Feb. 2021 12:39 pm.
I increased the max_open_files at some point because I saw the notes in the log in the last days, don't remember when exactly. I also increased the max_allowed_packet the last days, when I moved some files around and saw the warning in the log.
I got some warnings like this before the first crash:
Feb 28 09:23:04 social mariadbd[864708]: 2021-02-28 9:23:04 502983 [Warning] Aborted connection 502983 to db: 'ylms_friendica' user: 'root' host: 'localhost' (Got an error writing communication packets) |
Feb 28 10:23:19 social mariadbd[864708]: 2021-02-28 10:23:19 450847 [Warning] Aborted connection 450847 to db: 'ylms_friendica' user: 'ylms' host: 'localhost' (Got an error reading communication packets) |
Feb 28 15:59:47 social mariadbd[864708]: 2021-02-28 15:59:46 533631 [Warning] Aborted connection 533631 to db: 'ylms_friendica' user: 'root' host: 'localhost' (Got an error writing communication packets) |
Feb 28 20:45:01 social systemd[1]: mariadb.service: Main process exited, code=killed, status=9/KILL |
Feb 28 20:45:01 social systemd[1]: mariadb.service: Failed with result 'signal'. |
Feb 28 20:45:06 social systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1. |
Feb 28 20:45:06 social systemd[1]: Stopped MariaDB 10.5.9 database server. |
Feb 28 20:45:06 social systemd[1]: Starting MariaDB 10.5.9 database server... |
Feb 28 21:00:07 social systemd[1]: mariadb.service: start operation timed out. Terminating. |
Feb 28 21:15:07 social systemd[1]: mariadb.service: State 'stop-sigterm' timed out. Skipping SIGKILL. |
Was lazy then and rebooted the machine.
From that reboot to the next crash:
Feb 28 21:24:51 social systemd[1]: Starting MariaDB 10.5.9 database server... |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Note] /usr/bin/mariadbd (mysqld 10.5.9-MariaDB) starting as process 409 ... |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Warning] Could not increase number of max_open_files to more than 16384 (request: 32425) |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Warning] The parameter innodb_buffer_pool_instances is deprecated and has no effect. |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Note] InnoDB: Uses event mutexes |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Note] InnoDB: Number of pools: 1 |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Note] InnoDB: Using generic crc32 instructions |
Feb 28 21:24:51 social mariadbd[409]: 2021-02-28 21:24:51 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts) |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Using Linux native AIO |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Initializing buffer pool, total size = 17179869184, chunk size = 134217728 |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Completed initialization of buffer pool |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1915242122093,1915247067683 |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/cache.ibd' with space ID 77141, since the redo log references ./ylms_friendica/cache.ibd with space ID 77084. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/oembed.ibd' with space ID 77144, since the redo log references ./ylms_friendica/oembed.ibd with space ID 77087. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/parsed_url.ibd' with space ID 77145, since the redo log references ./ylms_friendica/parsed_url.ibd with space ID 77088. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/session.ibd' with space ID 77147, since the redo log references ./ylms_friendica/session.ibd with space ID 77090. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77136. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77137. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/auth_codes.ibd' with space ID 77140, since the redo log references ./ylms_friendica/auth_codes.ibd with space ID 77083. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/challenge.ibd' with space ID 77142, since the redo log references ./ylms_friendica/challenge.ibd with space ID 77085. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/locks.ibd' with space ID 77143, since the redo log references ./ylms_friendica/locks.ibd with space ID 77086. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/profile_check.ibd' with space ID 77146, since the redo log references ./ylms_friendica/profile_check.ibd with space ID 77089. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/tokens.ibd' with space ID 77148, since the redo log references ./ylms_friendica/tokens.ibd with space ID 77091. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77138. |
Feb 28 21:24:52 social mariadbd[409]: 2021-02-28 21:24:52 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77139. |
Feb 28 21:24:54 social mariadbd[409]: 2021-02-28 21:24:54 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77138. |
Feb 28 21:24:54 social mariadbd[409]: 2021-02-28 21:24:54 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77149. |
Feb 28 21:24:54 social mariadbd[409]: 2021-02-28 21:24:54 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77139. |
Feb 28 21:24:54 social mariadbd[409]: 2021-02-28 21:24:54 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77150. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77149. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77151. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77150. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77152. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77151. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77153. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77152. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77154. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77153. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77155. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77154. |
Feb 28 21:24:55 social mariadbd[409]: 2021-02-28 21:24:55 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77156. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77155. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77157. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77156. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77158. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77157. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77159. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77158. |
Feb 28 21:24:56 social mariadbd[409]: 2021-02-28 21:24:56 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77160. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77159. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77161. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77160. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77162. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77161. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77163. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77162. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77164. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77163. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77165. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77164. |
Feb 28 21:24:57 social mariadbd[409]: 2021-02-28 21:24:57 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77166. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77165. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77167. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77166. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77168. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77167. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77169. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77168. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77170. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77169. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77171. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77170. |
Feb 28 21:24:58 social mariadbd[409]: 2021-02-28 21:24:58 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77172. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77171. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77173. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77172. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77174. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77173. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77175. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77174. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77176. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77175. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77177. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77176. |
Feb 28 21:24:59 social mariadbd[409]: 2021-02-28 21:24:59 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77178. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77177. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77179. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77178. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77180. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77179. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77181. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77180. |
Feb 28 21:25:00 social mariadbd[409]: 2021-02-28 21:25:00 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77182. |
Feb 28 21:25:01 social mariadbd[409]: 2021-02-28 21:25:01 0 [Note] InnoDB: Ignoring data file './ylms_friendica/workerqueue.ibd' with space ID 77183, since the redo log references ./ylms_friendica/workerqueue.ibd with space ID 77181. |
Feb 28 21:25:01 social mariadbd[409]: 2021-02-28 21:25:01 0 [Note] InnoDB: Ignoring data file './ylms_friendica/process.ibd' with space ID 77184, since the redo log references ./ylms_friendica/process.ibd with space ID 77182. |
Feb 28 21:25:01 social mariadbd[409]: 2021-02-28 21:25:01 0 [Note] InnoDB: Starting final batch to recover 154483 pages from redo log. |
Feb 28 21:25:07 social mariadbd[409]: 2021-02-28 21:25:07 0 [Note] InnoDB: To recover: 71269 pages from log |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: Last binlog file './mysql-bin.000028', position 599081215 |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: 128 rollback segments are active. |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: Creating shared tablespace for temporary tables |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: 10.5.9 started; log sequence number 1916230170963; transaction id 4910077199 |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] Server socket created on IP: '127.0.0.1'. |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] Reading of all Master_info entries succeeded |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] Added new Master_info '' to hash table |
Feb 28 21:25:24 social mariadbd[409]: 2021-02-28 21:25:24 0 [Note] /usr/bin/mariadbd: ready for connections. |
Feb 28 21:25:24 social mariadbd[409]: Version: '10.5.9-MariaDB' socket: '/run/mysqld/mysqld.sock' port: 3306 Arch Linux |
Feb 28 21:25:24 social systemd[1]: Started MariaDB 10.5.9 database server. |
Feb 28 21:26:47 social mariadbd[409]: 2021-02-28 21:26:47 0 [Note] InnoDB: Buffer pool(s) load completed at 210228 21:26:47 |
Feb 28 21:39:41 social mariadbd[409]: 2021-02-28 21:39:41 2440 [Warning] Aborted connection 2440 to db: 'ylms_friendica' user: 'root' host: 'localhost' (Got an error writing communication packets) |
Mär 01 04:47:11 social mariadbd[409]: 2021-03-01 4:47:11 43351 [Warning] Aborted connection 43351 to db: 'ylms_friendica' user: 'root' host: 'localhost' (Got an error writing communication packets) |
Mär 01 09:26:03 social mariadbd[409]: 2021-03-01 9:26:03 9 [Warning] Aborted connection 9 to db: 'ylms_friendica' user: 'ylms' host: 'localhost' (Got an error reading communication packets) |
Mär 01 11:26:09 social mariadbd[409]: 2021-03-01 11:26:09 73467 [Warning] Aborted connection 73467 to db: 'ylms_friendica' user: 'root' host: 'localhost' (Got an error writing communication packets) |
Mär 01 12:45:19 social systemd[1]: mariadb.service: Main process exited, code=killed, status=9/KILL |
Mär 01 12:45:19 social systemd[1]: mariadb.service: Failed with result 'signal'. |
Mär 01 12:45:24 social systemd[1]: mariadb.service: Scheduled restart job, restart counter is at 1. |
Mär 01 12:45:24 social systemd[1]: Stopped MariaDB 10.5.9 database server. |
Was the database restored from a backup?
No.
Which MariaDB version had last been successfully used on the data directory?
I would say 10.5.8.
utzer, thank you. I wonder what caused the following, and which server version was running at that point:
Feb 28 20:45:01 social systemd[1]: mariadb.service: Main process exited, code=killed, status=9/KILL
|
Based on what you wrote, I would assume that it was already running 10.5.9 at that point. Still, what would have killed the process forcibly? Can you get more logs from the server somehow? Or enable core dumps, so that we could get stack traces for the next crash. Those stack traces might give some hint on what is going on.
I am afraid that it will now be hard to say what is the consequence of the corrupted page (which is the result of skipping some redo log records) and what is the original cause of the corruption. We cover crash recovery and backup in our internal tests, and there is no known problem in this area.
Finally, one thing that might explain this is faulty hardware. Have you checked sudo smartctl -a on your storage devices, and run sudo memtester to rule out problems in those areas?
As for the killed message I now found that this seems to be a system config problem, as it was out of memory on that VM.
Feb 28 20:44:56 social kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/mariadb.service,task=mariadbd,pid=864708,uid=974 |
Feb 28 20:44:56 social kernel: Out of memory: Killed process 864708 (mariadbd) total-vm:20868696kB, anon-rss:3813012kB, file-rss:0kB, shmem-rss:0kB, UID:974 pgtables:39276kB oom_score_adj:0 |
Feb 28 20:45:01 social kernel: oom_reaper: reaped process 864708 (mariadbd), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB |
Feb 28 20:45:01 social systemd[1]: mariadb.service: Main process exited, code=killed, status=9/KILL |
For the host I ran smartctl lately, for the vm I ran btrfs scrub yesterday and a check now (it is running and mounted, but there is no errors found in both).
Thank you, utzer (nice pseudonym, by the way). The reason for the crash has been explained, and this ticket will be covering the incorrect crash recovery, which will likely lead to corruption.
It is possible that the incorrect recovery was introduced by MDEV-21724 in MariaDB Server 10.5. I have asked for a more extensive test of ROW_FORMAT=REDUNDANT to be run, hoping that we will be able to repeat a similar failure. I would think that most of the time, our internal tests would be covering the recovery of the other page format (COMPACT or DYNAMIC).
| Link |
This issue relates to |
| Labels | need_feedback | corruption recovery |
I was able to achieve during RQG testing
|
|
|
... many times [Note] InnoDB: Ignoring data file ...
|
2021-03-05 7:09:13 0 [Note] InnoDB: Ignoring data file 'test/t5.ibd' with space ID 27, since the redo log references test/t5.ibd with space ID 23.
|
2021-03-05 7:09:16 0 [Note] InnoDB: Starting final batch to recover 763 pages from redo log.
|
2021-03-05 7:09:19 0 [ERROR] InnoDB: Not applying INSERT_HEAP_REDUNDANT due to corruption on [page id: space=26, page number=49]
|
2021-03-05 7:09:19 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
|
2021-03-05 7:09:19 0 [ERROR] InnoDB: Not applying DELETE_ROW_FORMAT_REDUNDANT due to corruption on [page id: space=26, page number=49]
|
2021-03-05 7:09:19 0 [ERROR] InnoDB: Set innodb_force_recovery=1 to ignore corruption.
|
2021-03-05 7:09:20 0 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[1473] with error Data structure corruption
|
[00] FATAL ERROR: 2021-03-05 07:09:20 mariabackup: innodb_init() returned 39 (Data structure corruption).
|
|
|
sdp:/home/mleich/RQG_O/storage/1614954603/MDEV-25031/dev/shm/vardir/1614954603/76/1_clone/rr
|
_RR_TRACE_DIR="." rr replay --mark-stdio (the first prepare)
|
_RR_TRACE_DIR="." rr replay --mark-stdio mariabackup-0 (the backup before it)
|
|
|
Archive:
|
sdp:/home/mleich/RQG_O/storage/1614954603/000934.tgz
|
|
|
Work flow:
|
1. Start the server and load some initial data
|
2. Two sessions run a DDL/DML mix
|
3. During 2. is ongoing
|
mariabackup --backup
|
Example: bin/mariabackup --host=127.0.0.1 --user=root --password='' --innodb-use-native-aio=0 --port=26100 --backup --datadir=/dev/shm/vardir/1614954603/76/1/data --target-dir=/dev/shm/vardir/1614954603/76/1_clone/data
|
Make a backup/copy of the data written by mariabackup --backup
|
in /home/mleich/RQG_O/storage/1614954603/MDEV-25031/dev/shm/vardir/1614954603/76/1/data_backup
|
mariabackup --prepare ... <---- I got the messages above at this step.
|
Example: mariabackup --host=127.0.0.1 --user=root --password='' --innodb-use-native-aio=0 --port=26104 --prepare --target-dir=/dev/shm/vardir/1614954603/76/1_clone/data
|
mariabackup --prepare ... again in that directory (users do not need to run a second prepare)
|
Start a server on the data there + check consistency
|
In most of the RQG tests all goes well.
|
|
|
origin/10.6 33cf577ad86f3a7dd6ff86fee4ecd9c535161f02 2021-03-05T14:26:14+02:00
|
The server claims to be 10.6.0.
|
|
|
RQG
|
====
|
git clone https://github.com/mleich1/rqg --branch experimental RQG
|
|
|
perl rqg.pl \
|
--grammar=conf/mariadb/table_stress_innodb_nocopy1.yy \
|
--gendata=conf_redundant/mariadb/table_stress.zz \
|
--gendata_sql=conf/mariadb/table_stress.sql \
|
--reporters=Mariabackup_linux \
|
--mysqld=--innodb_use_native_aio=1 \
|
--mysqld=--innodb_lock_schedule_algorithm=fcfs \
|
--mysqld=--loose-idle_write_transaction_timeout=0 \
|
--mysqld=--loose-idle_transaction_timeout=0 \
|
--mysqld=--loose-idle_readonly_transaction_timeout=0 \
|
--mysqld=--connect_timeout=60 \
|
--mysqld=--interactive_timeout=28800 \
|
--mysqld=--slave_net_timeout=60 \
|
--mysqld=--net_read_timeout=30 \
|
--mysqld=--net_write_timeout=60 \
|
--mysqld=--loose-table_lock_wait_timeout=50 \
|
--mysqld=--wait_timeout=28800 \
|
--mysqld=--lock-wait-timeout=86400 \
|
--mysqld=--innodb-lock-wait-timeout=50 \
|
--no-mask \
|
--queries=10000000 \
|
--seed=random \
|
--reporters=Backtrace \
|
--reporters=ErrorLog \
|
--reporters=Deadlock1 \
|
--validators=None \
|
--mysqld=--log_output=none \
|
--mysqld=--log-bin \
|
--mysqld=--log_bin_trust_function_creators=1 \
|
--mysqld=--loose-debug_assert_on_not_freed_memory=0 \
|
--engine=InnoDB \
|
--restart_timeout=240 \
|
--mysqld=--plugin-load-add=file_key_management.so \
|
--mysqld=--loose-file-key-management-filename=$RQG_HOME/conf_redundant/mariadb/encryption_keys.txt \
|
--duration=300 \
|
--mysqld=--loose-innodb_fatal_semaphore_wait_threshold=300 \
|
--mysqld=--loose-innodb-sync-debug \
|
--mysqld=--innodb_stats_persistent=on \
|
--mysqld=--innodb_adaptive_hash_index=off \
|
--mysqld=--loose-max-statement-time=30 \
|
--threads=2 \
|
--rr=Extended \
|
--mysqld=--innodb_page_size=4K \
|
--mysqld=--innodb-buffer-pool-size=5M \
|
--duration=300 \
|
--workdir=<local settings> \
|
--vardir=<local settings> \
|
--mtr-build-thread=<local settings> \
|
--basedir1=<local settings> \
|
--script_debug=_nix_
|
|
|
conf_redundant/mariadb/table_stress.zz
|
$tables = {
|
pk => [ 'int' ],
|
engines => [ 'InnoDB' ],
|
rows => [ 0, 1, 1000 ],
|
row_formats => [ 'REDUNDANT' ]
|
};
|
|
|
$fields = {
|
types => [ 'int' ],
|
indexes => [ undef ]
|
};
|
|
|
$data = {
|
numbers => [ 'digit' ]
|
};
|
I will try to simplify the test/increase the likelihood to replay the problem.
|
I realized that page 4 in the system tablespace is the root page of the change buffer B-tree (FSP_IBUF_TREE_ROOT_PAGE_NO). That is in the original InnoDB format. So, even if no tables are in ROW_FORMAT=REDUNDANT, this error is possible, when it affects the change buffer pages in the system tablespace.
| Status | Open [ 1 ] | In Progress [ 3 ] |
The rr replay trace that mleich posted shows an off-by-1 problem in page_cur_insert_rec_low():
(rr) p/x cur->rec[-extra_size]@extra_size
|
$14 = {0x80, 0x0, 0x0, 0x40, 0x43, 0x40, 0x80, 0x2c, 0x0, 0x2c, 0x0, 0x19,
|
0x0, 0x15, 0x0, 0x11, 0x0, 0xa, 0x0, 0x4, 0x0, 0x0, 0x18, 0x10, 0x7, 0x55}
|
(rr) p/x *insert_buf@extra_size
|
$15 = {0x3, 0x44, 0x83, 0x40, 0x43, 0x40, 0x80, 0x2c, 0x0, 0x2c, 0x0, 0x19,
|
0x0, 0x15, 0x0, 0x11, 0x0, 0xa, 0x0, 0x4, 0x0, 0x0, 0x20, 0x14, 0x0, 0x74}
|
The extra_size is actually referring to the record that we are about to insert, and not to the predecessor record cur->rec from which we are letting recovery copy a number of identical bytes. It turns out that the correct extra_size of cur->rec is 4 bytes shorter, and the first 4 bytes above actually belong to the preceding record. It happens so that the last of the 4 bytes matches insert_buf, and we will write an INSERT_HEAP_REDUNDANT record where the condition on pextra_size will be violated in page_apply_insert_redundant():
if (UNIV_UNLIKELY(hdr_c > extra_size || hdr_c > pextra_size)) |
goto corrupted; |
I think that we must simply make the recovery more tolerant and allow us to reuse data that resides before the preceding record. We are already doing the same in page_apply_insert_dynamic(). We must relax the above condition, but ensure that hdr_c is not referring to anything that is before the start of the payload area (which is something that we checked in page_cur_insert_rec_low() before writing the record):
const byte * const c_start= cur->rec - extra_size; |
if (c_start >= |
&block->frame[PAGE_OLD_SUPREMUM_END + REC_N_OLD_EXTRA_BYTES])
|
| Priority | Major [ 3 ] | Blocker [ 1 ] |
| Link |
This issue relates to |
| Link |
This issue is caused by |
| Affects Version/s | 10.5.8 [ 25023 ] | |
| Affects Version/s | 10.5.7 [ 25019 ] | |
| Affects Version/s | 10.5.6 [ 24508 ] | |
| Affects Version/s | 10.5.5 [ 24423 ] | |
| Affects Version/s | 10.5.3 [ 24263 ] | |
| Affects Version/s | 10.5.2 [ 24030 ] | |
| Affects Version/s | 10.5.4 [ 24264 ] | |
| Labels | corruption recovery | corruption recovery regression-10.5 |
While testing this, we found another crash recovery regression MDEV-25110, introduced in 10.5.7. That one could mostly affect Mariabackup and not normal crash recovery.
| issue.field.resolutiondate | 2021-03-11 12:40:25.0 | 2021-03-11 12:40:25.314 |
| Component/s | Backup [ 13902 ] | |
| Fix Version/s | 10.5.10 [ 25204 ] | |
| Fix Version/s | 10.5 [ 23123 ] | |
| Resolution | Fixed [ 1 ] | |
| Status | In Progress [ 3 ] | Closed [ 6 ] |
| Link |
This issue blocks |
| Link | This issue blocks MENT-1145 [ MENT-1145 ] |
| Link | This issue relates to TODO-2841 [ TODO-2841 ] |
| Link |
This issue relates to |
| Link |
This issue is duplicated by |
| Link |
This issue relates to |
| Workflow | MariaDB v3 [ 119673 ] | MariaDB v4 [ 158982 ] |
I have come across a crash with the same error message:
2022-05-23 10:12:14 0 [ERROR] InnoDB: Not applying INSERT_REUSE_DYNAMIC due to corruption on [page id: space=745895, page number=647870]
|
But unlike this bug that is trigger from the "page_apply_insert_redundant" function, the bug I observed follows the path of "page_apply_insert_dynamic" before the crash. For that reason, I will file a new JIRA for it.
| Zendesk Related Tickets | 158864 |
utzer, thank you. Yes, this looks like a bug: crash recovery would fail. We introduced a consistency check in
MDEV-24705to catch exactly this type of failure, but curiously no such message is present in the log.The failure is related to ROW_FORMAT=REDUNDANT tables, which ceased to be the default in MySQL 5.0.3. What had happened to the server before the first such failed crash recovery? Was the database restored from a backup? Which MariaDB version had last been successfully used on the data directory?