[MDEV-19060] mariabackup does not detect open files limit, creates corrupt backups Created: 2019-03-27  Updated: 2023-07-28  Resolved: 2019-03-27

Status: Closed
Project: MariaDB Server
Component/s: mariabackup
Affects Version/s: 10.1.38
Fix Version/s: 10.1.39

Type: Bug Priority: Major
Reporter: Rick Pizzi Assignee: Vladislav Vaintroub
Resolution: Fixed Votes: 2
Labels: None

Issue Links:
Relates
relates to MDEV-21935 Mariabackup file limits set incorrectly. Open
relates to MDEV-22081 mariabackup crashes on exceeding open... Open

 Description   

mariabackup is not able to detect if the operating file system open files limit (ulimit -n) is not sufficient to open all tables.

The resulting backup is corrupt, as any table that couldn't be opened due to max open files limit being reached, is not saved into the backup.

The worst part of this is the fact that the tool prints "completed OK" at the end and exits with a zero error status (success). So, backup seems successful but it's actually corrupted and unusable!

Xtrabackup properly detects the open files limit being reached and aborts.

190327 08:52:11 Connecting to MySQL server host: localhost, user: root, password: set, port: not set, socket: not set
Using server version 10.1.38-MariaDB
mariabackup based on MariaDB server 10.1.38-MariaDB Linux (x86_64)
mariabackup: uses posix_fadvise().
mariabackup: cd to /var/lib/mysql/
mariabackup: open files limit requested 2000000, set to 1024
mariabackup: using the following InnoDB configuration:
mariabackup:   innodb_data_home_dir =
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = ./
mariabackup:   innodb_log_files_in_group = 2
mariabackup:   innodb_log_file_size = 1073741824
mariabackup: using O_DIRECT
190327 08:52:13 >> log scanned up to (4685244185786)
mariabackup: Generating a list of tablespaces
190327 08:52:14 >> log scanned up to (4685244194434)
190327 08:52:15 >> log scanned up to (4685244199407)
2019-03-27 08:52:15 7f69f3dfe900  InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
InnoDB: Error: could not open single-table tablespace file ./schema/ref_component.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
InnoDB: To fix the problem and start mysqld:
InnoDB: 1) If there is a permission problem in the file and mysqld cannot
InnoDB: open the file, you should modify the permissions.
InnoDB: 2) If the table is not needed, or you can restore it from a backup,
InnoDB: then you can remove the .ibd file, and InnoDB will do a normal
InnoDB: crash recovery and ignore that table.
InnoDB: 3) If the file system or the disk is broken, and you cannot remove
InnoDB: the .ibd file, you can set innodb_force_recovery > 0 in my.cnf
InnoDB: and force InnoDB to continue crash recovery here.
2019-03-27 08:52:15 7f69f3dfe900  InnoDB: Operating system error number 24 in a file operation.
InnoDB: Error number 24 means 'Too many open files'.
InnoDB: Some operating system error numbers are described at
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
InnoDB: Error: could not open single-table tablespace file ./schema/event.ibd
InnoDB: We do not continue the crash recovery, because the table may become
InnoDB: corrupt if we cannot apply the log records in the InnoDB log to it.
 
[ ... ]
 
mariabackup: Starting 4 threads for parallel data files transfer
190327 08:52:15 [04] Streaming ./schema/audit_log.ibd
190327 08:52:15 [03] Streaming ./schema/QRTZ_BLOB_TRIGGERS.ibd
190327 08:52:15 [01] Streaming ibdata1
190327 08:52:15 [02] Streaming ./schema/QRTZ_TRIGGERS.ibd
190327 08:52:15 [03]        ...done
190327 08:52:15 [04]        ...done
 
[ ... ]
 
190327 09:09:43 [01] Streaming ./performance_schema/db.opt to <STDOUT>
190327 09:09:43 [01]        ...done
190327 09:09:43 Finished backing up non-InnoDB tables and files
190327 09:09:43 [01] Streaming aria_log_control to <STDOUT>
190327 09:09:44 [01]        ...done
190327 09:09:44 [01] Streaming aria_log.00000001 to <STDOUT>
190327 09:09:44 [01]        ...done
190327 09:09:44 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
mariabackup: The latest check point (for incremental): '4685309388527'
mariabackup: Stopping log copying thread.
.190327 09:09:44 >> log scanned up to (4685564855228)
 
190327 09:09:44 Executing UNLOCK TABLES
190327 09:09:44 All tables unlocked
190327 09:09:44 [00] Streaming ib_buffer_pool to <STDOUT>
190327 09:09:44 [00]        ...done
190327 09:09:44 Backup created in directory '/mysql_backup/2019-03-27/mariabackup/'
190327 09:09:44 [00] Streaming backup-my.cnf
190327 09:09:44 [00]        ...done
190327 09:09:44 [00] Streaming xtrabackup_info
190327 09:09:44 [00]        ...done
mariabackup: Transaction log of lsn (4685125800268) to (4685564855228) was copied.
190327 09:09:44 completed OK!



 Comments   
Comment by Vladislav Vaintroub [ 2019-03-27 ]

documented in https://mariadb.com/kb/en/library/mariabackup-overview/#too-many-open-files

Comment by Rick Pizzi [ 2019-03-27 ]

Documenting is cool but it's different from fixing...
The tool should abort when it detects this problem. Xtrabackup does it since the beginning.
It's a 10 minutes fix. Please

Comment by Vladislav Vaintroub [ 2019-03-27 ]

we will fix and document the fix. The bug was not closed, was it? a comment is there because julien.fritsch asked for workaround documentation

Comment by Rick Pizzi [ 2019-03-27 ]

Thanks!!

Comment by Vova Moroz [ 2023-07-28 ]

Still being reproduced on 10.4.26

Generated at Thu Feb 08 08:48:46 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.