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

mariabackup does not honor open_files_limit from option during backup prepare

    XMLWordPrintable

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

          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.