Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.2(EOL), 10.3(EOL), 10.4(EOL), 10.5, 10.6
-
CentOS 7 x86_64
Description
While manually running "mariabackup --innobackupex --apply-log <path>" on a streamed mariabackup we encounter "Too many open files" errors after a while.
The backup contains 70000 tables. The open_files_limit is set to 409600 via option files in /etc/my.cnf.d/* for both [mysqld] and [mariabackup]. This should be absolutely sufficient for mariabackup.
```
[mysqld]
open_files_limit=409600
(...)
[mariabackup]
open_files_limit=409600
```
Fulll log (until errors start to appear):
```
200605 10:09:46 innobackupex: Starting the apply-log operation
IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints "completed OK!".
--innobackupex based on MariaDB server 10.4.13-MariaDB Linux (x86_64)
[00] 2020-06-05 10:09:46 cd to /mnt/ephemeral/mysql/
[00] 2020-06-05 10:09:48 This target seems to be not prepared yet.
[00] 2020-06-05 10:09:48 mariabackup: using the following InnoDB configuration for recovery:
[00] 2020-06-05 10:09:48 innodb_data_home_dir = .
[00] 2020-06-05 10:09:48 innodb_data_file_path = ibdata1:12M:autoextend
[00] 2020-06-05 10:09:48 innodb_log_group_home_dir = .
[00] 2020-06-05 10:09:48 InnoDB: Using Linux native AIO
[00] 2020-06-05 10:09:48 Starting InnoDB instance for recovery.
[00] 2020-06-05 10:09:48 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2020-06-05 10:09:48 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-06-05 10:09:48 0 [Note] InnoDB: Uses event mutexes
2020-06-05 10:09:48 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
2020-06-05 10:09:48 0 [Note] InnoDB: Number of pools: 1
2020-06-05 10:09:48 0 [Note] InnoDB: Using SSE2 crc32 instructions
2020-06-05 10:09:48 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2020-06-05 10:09:48 0 [Note] InnoDB: Completed initialization of buffer pool
2020-06-05 10:09:48 0 [Note] InnoDB: page_cleaner coordinator priority: -20
2020-06-05 10:09:48 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=13480598526559
2020-06-05 10:10:03 0 [Note] InnoDB: Read redo log up to LSN=13480817081344
2020-06-05 10:10:18 0 [Note] InnoDB: Read redo log up to LSN=13481701358592
2020-06-05 10:10:33 0 [Note] InnoDB: Read redo log up to LSN=13482990844928
2020-06-05 10:10:48 0 [Note] InnoDB: Read redo log up to LSN=13484115966976
2020-06-05 10:11:03 0 [Note] InnoDB: Read redo log up to LSN=13485129677824
2020-06-05 10:11:18 0 [Note] InnoDB: Read redo log up to LSN=13486234483712
2020-06-05 10:11:33 0 [Note] InnoDB: Read redo log up to LSN=13487609297920
2020-06-05 10:11:48 0 [Note] InnoDB: Read redo log up to LSN=13489064852480
2020-06-05 10:12:03 0 [Note] InnoDB: Read redo log up to LSN=13490413452288
2020-06-05 10:12:18 0 [Note] InnoDB: Read redo log up to LSN=13491307166720
2020-06-05 10:12:33 0 [Note] InnoDB: Read redo log up to LSN=13491964230656
2020-06-05 10:12:48 0 [Note] InnoDB: Read redo log up to LSN=13492832123904
2020-06-05 10:13:03 0 [Note] InnoDB: Read redo log up to LSN=13493708405760
2020-06-05 10:13:14 0 [Note] InnoDB: Starting a batch to recover 10041 pages from redo log.
2020-06-05 10:13:15 0 [Note] InnoDB: Starting a batch to recover 10280 pages from redo log.
2020-06-05 10:13:16 0 [Note] InnoDB: Starting a batch to recover 9760 pages from redo log.
2020-06-05 10:13:17 0 [Note] InnoDB: Starting a batch to recover 10485 pages from redo log.
2020-06-05 10:13:17 0 [Note] InnoDB: Starting a batch to recover 11897 pages from redo log.
2020-06-05 10:13:18 0 [Note] InnoDB: To recover: 4129 pages from log
2020-06-05 10:13:19 0 [Note] InnoDB: Starting a batch to recover 9880 pages from redo log.
2020-06-05 10:13:20 0 [Note] InnoDB: Starting a batch to recover 9860 pages from redo log.
2020-06-05 10:13:21 0 [Note] InnoDB: Starting a batch to recover 10216 pages from redo log.
2020-06-05 10:13:22 0 [Note] InnoDB: Starting a batch to recover 11249 pages from redo log.
2020-06-05 10:13:23 0 [Note] InnoDB: Starting a batch to recover 9204 pages from redo log.
2020-06-05 10:13:24 0 [Note] InnoDB: Starting a batch to recover 9572 pages from redo log.
2020-06-05 10:13:24 0 [ERROR] InnoDB: Operating system error number 24 in a file operation.
2020-06-05 10:13:24 0 [ERROR] InnoDB: Error number 24 means 'Too many open files'
2020-06-05 10:13:24 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
2020-06-05 10:13:24 0 [ERROR] InnoDB: File DATABASE/TABLE.ibd: 'open' returned OS error 224.
2020-06-05 10:13:24 0 [ERROR] InnoDB: Operating system error number 24 in a file operation.
2020-06-05 10:13:24 0 [ERROR] InnoDB: Error number 24 means 'Too many open files'
2020-06-05 10:13:24 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
2020-06-05 10:13:24 0 [Warning] InnoDB: Cannot open 'DATABASE/TABLE.ibd'. Have you deleted .ibd files under a running mysqld server?
2020-06-05 10:13:24 0 [ERROR] InnoDB: Operating system error number 24 in a file operation.
2020-06-05 10:13:24 0 [ERROR] InnoDB: Error number 24 means 'Too many open files'
2020-06-05 10:13:24 0 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
2020-06-05 10:13:24 0 [ERROR] InnoDB: File DATABASE/TABLE.ibd: 'open' returned OS error 224.
2020-06-05 10:13:24 0 [ERROR] InnoDB: Operating system error number 24 in a file operation.
```
When manually raising the "ulimit -n 409600" on the shell before running the command there are no errors. Thus, it appears that the option file is not honored by mariabackup.