[MDEV-21222] mariabackup.incremental_backup failed with memory allocation failure Created: 2019-09-25  Updated: 2021-05-10  Resolved: 2021-05-10

Status: Closed
Project: MariaDB Server
Component/s: mariabackup, Tests
Affects Version/s: 10.2, 10.3
Fix Version/s: 10.2.33, 10.3.24, 10.4.14, 10.5.5, 10.6.0

Type: Bug Priority: Major
Reporter: Alexey Bychko (Inactive) Assignee: Vladislav Lesin
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Relates
relates to MDEV-21323 mariabackup crash Closed

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/20355

10.2 3fb0fe40

 
mariabackup.incremental_backup '64k,innodb' w4 [ fail ]
 
        Test ended at 2019-11-30 03:48:21
 
 
 
CURRENT_TEST: mariabackup.incremental_backup
 
[00] 2019-11-30 03:48:21 Connecting to MySQL server host: localhost, user: root, password: set, port: 16020, socket: /mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/tmp/4/mysqld.1.sock
 
[00] 2019-11-30 03:48:21 Using server version 10.2.30-MariaDB-debug-log
 
/mnt/buildbot/build/mariadb-10.2.30/extra/mariabackup/mariabackup based on MariaDB server 10.2.30-MariaDB Linux (i686)
 
[00] 2019-11-30 03:48:21 incremental backup from 6078476 is enabled.
 
[00] 2019-11-30 03:48:21 uses posix_fadvise().
 
[00] 2019-11-30 03:48:21 cd to /mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/4/mysqld.1/data/
 
[00] 2019-11-30 03:48:21 open files limit requested 1024, set to 1024
 
[00] 2019-11-30 03:48:21 InnoDB: The page size of the database is set to 65536.
 
[00] 2019-11-30 03:48:21 mariabackup: using the following InnoDB configuration:
 
[00] 2019-11-30 03:48:21 innodb_data_home_dir = 
[00] 2019-11-30 03:48:21 innodb_data_file_path = ibdata1:12M:autoextend
 
[00] 2019-11-30 03:48:21 innodb_log_group_home_dir = ./
 
[00] 2019-11-30 03:48:21 InnoDB: Using Linux native AIO
 
2019-11-30  3:48:21 3069069248 [Note] InnoDB: Number of pools: 1
 
[00] 2019-11-30 03:48:21 mariabackup: Generating a list of tablespaces
 
2019-11-30  3:48:21 3069069248 [Warning] InnoDB: Allocated tablespace ID 5 for test/t, old maximum was 0
 
[00] 2019-11-30 03:48:21 >> log scanned up to (6083805)
 
[00] 2019-11-30 03:48:21 mariabackup: Starting 2 threads for parallel data files transfer
 
2019-11-30  3:48:21 3041913664 [ERROR] InnoDB: mmap(1073741824 bytes) failed; errno 12
 
[02] 2019-11-30 03:48:21 Can't allocate 1073741824 bytes
 
[02] 2019-11-30 03:48:21 mariabackup: error: failed to initialize page write filter.
 
[01] 2019-11-30 03:48:21 Copying ibdata1 to /mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/4/tmp/backup_inc1/ibdata1.delta
 
[02] 2019-11-30 03:48:21 mariabackup: xtrabackup_copy_datafile() failed.
 
[00] FATAL ERROR: 2019-11-30 03:48:21 failed to copy datafile.
 
mysqltest: At line 53: exec of '/mnt/buildbot/build/mariadb-10.2.30/extra/mariabackup/mariabackup --defaults-file=/mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/4/my.cnf --backup --parallel=2 --ftwrl-wait-timeout=5 --ftwrl-wait-threshold=300 --ftwrl-wait-query-type=all --target-dir=/mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/4/tmp/backup_inc1 --incremental-basedir=/mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/4/tmp/backup' failed, error: 256, status: 1, errno: 11
 
Output from before failure:
 
i
 
1
 
2
 
 
 
 
 
 
 
The result from queries just before the failure was:
 
< snip >
 
connect  con1,localhost,root,,;
 
SET GLOBAL innodb_flush_log_at_trx_commit = 1;
 
INSERT INTO t VALUES(1);
 
# Create full backup , modify table, then create incremental/differential backup
 
BEGIN;
 
INSERT INTO t VALUES(0);
 
DELETE FROM t WHERE i=0;
 
connection default;
 
COMMIT;
 
# Generate enough aria log records to increase area log file size
 
SELECT * FROM t;
 
i
 
1
 
2



 Comments   
Comment by Julien Fritsch [ 2019-10-24 ]

This looks to be fixed, no? abychko

Comment by Julien Fritsch [ 2019-10-25 ]

vlad.lesin is that fixed ?

Comment by Marko Mäkelä [ 2019-12-10 ]

Here is a recent failure: http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/20473

10.2 fd1979bc9a535735ed3f3a7dbb67d09568dd8417

 
mariabackup.incremental_backup '64k,innodb' w3 [ fail ]
 
        Test ended at 2019-12-08 18:50:53
 
 
 
CURRENT_TEST: mariabackup.incremental_backup
 
[00] 2019-12-08 18:50:53 Connecting to MySQL server host: localhost, user: root, password: set, port: 16060, socket: /mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/tmp/3/mysqld.1.sock
 
[00] 2019-12-08 18:50:53 Using server version 10.2.30-MariaDB-debug-log
 
/mnt/buildbot/build/mariadb-10.2.30/extra/mariabackup/mariabackup based on MariaDB server 10.2.30-MariaDB Linux (i686)
 
[00] 2019-12-08 18:50:53 incremental backup from 6082702 is enabled.
 
[00] 2019-12-08 18:50:53 uses posix_fadvise().
 
[00] 2019-12-08 18:50:53 cd to /mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/3/mysqld.1/data/
 
[00] 2019-12-08 18:50:53 open files limit requested 1024, set to 1024
 
[00] 2019-12-08 18:50:53 InnoDB: The page size of the database is set to 65536.
 
[00] 2019-12-08 18:50:53 mariabackup: using the following InnoDB configuration:
 
[00] 2019-12-08 18:50:53 innodb_data_home_dir = 
[00] 2019-12-08 18:50:53 innodb_data_file_path = ibdata1:12M:autoextend
 
[00] 2019-12-08 18:50:53 innodb_log_group_home_dir = ./
 
[00] 2019-12-08 18:50:53 InnoDB: Using Linux native AIO
 
2019-12-08 18:50:53 3068708800 [Note] InnoDB: Number of pools: 1
 
[00] 2019-12-08 18:50:53 mariabackup: Generating a list of tablespaces
 
2019-12-08 18:50:53 3068708800 [Warning] InnoDB: Allocated tablespace ID 5 for test/t, old maximum was 0
 
[00] 2019-12-08 18:50:53 >> log scanned up to (6084326)
 
[00] 2019-12-08 18:50:53 mariabackup: Starting 2 threads for parallel data files transfer
 
2019-12-08 18:50:53 3049945920 [ERROR] InnoDB: mmap(1073741824 bytes) failed; errno 12
 
[01] 2019-12-08 18:50:53 Can't allocate 1073741824 bytes
 
[02] 2019-12-08 18:50:53 Copying ./test/t.ibd to /mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/3/tmp/backup_inc1/test/t.ibd.delta
 
[01] 2019-12-08 18:50:53 mariabackup: error: failed to initialize page write filter.
 
[01] 2019-12-08 18:50:53 mariabackup: xtrabackup_copy_datafile() failed.
 
[00] FATAL ERROR: 2019-12-08 18:50:53 failed to copy datafile.
 
mysqltest: At line 53: exec of '/mnt/buildbot/build/mariadb-10.2.30/extra/mariabackup/mariabackup --defaults-file=/mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/3/my.cnf --backup --parallel=2 --ftwrl-wait-timeout=5 --ftwrl-wait-threshold=300 --ftwrl-wait-query-type=all --target-dir=/mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/3/tmp/backup_inc1 --incremental-basedir=/mnt/buildbot/build/mariadb-10.2.30/mysql-test/var/3/tmp/backup' failed, error: 256, status: 1, errno: 11

A mmap() request of 1GiB in a 32-bit address space seems a little steep to me.

Comment by Marko Mäkelä [ 2019-12-22 ]

Here is a recent occurence on 10.5 (failing to allocate 1GiB):

10.5 7e10e80b8faab51139588a985a684df960ab81b9

 
[02] 2019-12-21 14:37:13 Copying ibdata1 to /mnt/buildbot/build/mariadb-10.5.1/mysql-test/var/4/tmp/backup_inc1/ibdata1.delta
 
2019-12-21 14:37:13 0 [ERROR] InnoDB: mmap(1073741824 bytes) failed; errno 12

http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/20622/steps/mtr_ps/logs/stdio

Comment by Sergei Golubchik [ 2020-03-13 ]

I've disabled the 64k test variant on the 32bit architectire. vlad.lesin feel free to either close this issue or to remove my change and fix the issue differently.

Comment by Vladislav Lesin [ 2021-05-10 ]

The issue is in incremental write filter initialization code:

static my_bool                                                                                                                    
wf_incremental_init(xb_write_filt_ctxt_t *ctxt, char *dst_name,                 
                    xb_fil_cur_t *cursor, CorruptedPages *corrupted_pages)      
{                                                                                                                                 
        char                            meta_name[FN_REFLEN];                   
        xb_wf_incremental_ctxt_t        *cp =                                   
                &(ctxt->wf_incremental_ctxt);                                   
                                                                                                                                  
        ctxt->cursor = cursor;                                                  
                                                                                                                                  
        /* allocate buffer for incremental backup (4096 pages) */               
        cp->delta_buf_size = (cursor->page_size.physical() / 4)                 
                * cursor->page_size.physical();                                 
        cp->delta_buf = (unsigned char *)os_mem_alloc_large(&cp->delta_buf_size);
 
...
 
}

The possible fix would be in decreasing delta buffer size for debug build. But as the issue takes place only for 32-bit architecture, disabling 64k test for it looks good to me.

Generated at Thu Feb 08 09:05:30 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.