Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-22810

mariabackup does not honor open_files_limit from option during backup prepare

Details

    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.

      Attachments

        Activity

          Mariabackup has "open_files_limit" option, but it is applied only for backup(see xb_set_max_open_files(), see also my_set_max_open_files()). So, yes, we need to process it properly on --prepare.

          vlad.lesin Vladislav Lesin added a comment - Mariabackup has "open_files_limit" option, but it is applied only for backup(see xb_set_max_open_files(), see also my_set_max_open_files()). So, yes, we need to process it properly on --prepare.

          People

            vlad.lesin Vladislav Lesin
            prupert Pim Rupert
            Votes:
            1 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

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