Vladislav Vaintroub added a comment - 2017-09-16 07:00 Could you attach your test case please

Marko Mäkelä added a comment - 2017-09-18 05:18 Sorry, I forgot to mention the test case name. It is in the buildbot log: mariabackup.apply-log-only-incr

Andrii Nikitin (Inactive) added a comment - 2017-09-20 04:41 I can reliably see the crash by increasing incremental backup volume in apply-log-only-incr , see attached apply-log-only-incr1.test a@UBINTI:~/env1$ m1-10.1/build/mysql-test/mtr apply-log-only-incr1 --mem Logging: /home/a/env1/_depot/m-branch/10.1/mysql-test/mysql-test-run.pl apply-log-only-incr1 --mem vardir: /home/a/env1/m1-10.1/build/mysql-test/var Checking leftover processes... Removing old var directory... Creating var directory '/home/a/env1/m1-10.1/build/mysql-test/var'... - symlinking 'var' to '/dev/shm/var_auto_Xi2X' Checking supported features... MariaDB Version 10.1.27-MariaDB - SSL connections supported Sphinx 'indexer' binary not found, sphinx suite will be skipped Collecting tests... Installing system database...   ==============================================================================   TEST RESULT TIME (ms) or COMMENT --------------------------------------------------------------------------   worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019 call mtr.add_suppression("InnoDB: New log files created"); CREATE TABLE t(a INT UNSIGNED PRIMARY KEY, b varchar(40)) ENGINE INNODB; start transaction; NOT FOUND /Rollback of trx with id/ in current_test # expect NOT FOUND mariabackup.apply-log-only-incr1 'innodb_plugin' [ fail ] Test ended at 2017-09-20 06:40:16   CURRENT_TEST: mariabackup.apply-log-only-incr1 /home/a/env1/m1-10.1/build/extra/mariabackup/mariabackup based on MariaDB server 10.1.27-MariaDB Linux (x86_64) incremental backup from 1629454 is enabled. xtrabackup: cd to /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup/ xtrabackup: This target seems to be already prepared with --apply-log-only. xtrabackup: xtrabackup_logfile detected: size=2818048, start_lsn=(87443196) xtrabackup: using the following InnoDB configuration for recovery: xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend xtrabackup: innodb_log_group_home_dir = /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1/ xtrabackup: innodb_log_files_in_group = 1 xtrabackup: innodb_log_file_size = 2818048 xtrabackup: Generating a list of tablespaces xtrabackup: page size for /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//ibdata1.delta is 16384 bytes 2017-09-20 6:40:15 140401058917312 [Warning] InnoDB: Failed to set O_DIRECT on file /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//ibdata1.delta: OPEN: Invalid argument, continuing anyway. O_DIRECT is known to result in 'Invalid argument' on Linux on tmpfs, see MySQL Bug#26662. Applying /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//ibdata1.delta to ./ibdata1... xtrabackup: page size for /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//test/t.ibd.delta is 16384 bytes Applying /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//test/t.ibd.delta to ./test/t.ibd... xtrabackup: page size for /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//mysql/innodb_index_stats.ibd.delta is 16384 bytes Applying /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//mysql/innodb_index_stats.ibd.delta to ./mysql/innodb_index_stats.ibd... xtrabackup: page size for /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//mysql/innodb_table_stats.ibd.delta is 16384 bytes Applying /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1//mysql/innodb_table_stats.ibd.delta to ./mysql/innodb_table_stats.ibd... xtrabackup: using the following InnoDB configuration for recovery: xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend xtrabackup: innodb_log_group_home_dir = /home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1/ xtrabackup: innodb_log_files_in_group = 1 xtrabackup: innodb_log_file_size = 2818048 xtrabackup: Starting InnoDB instance for recovery. xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter) 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Using mutexes to ref count buffer pool pages 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: The InnoDB memory heap is disabled 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Compressed tables use zlib 1.2.11 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Using SSE crc32 instructions 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Initializing buffer pool, size = 100.0M 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Completed initialization of buffer pool 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Highest supported file format is Barracuda. 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Starting crash recovery from checkpoint LSN=87443196 2017-09-20 6:40:15 140401058917312 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer... 2017-09-20 6:40:15 140401058917312 [ERROR] InnoDB: Trying to access page number 16 in space 0 space name ./ibdata1, which is outside the tablespace bounds. Byte offset 0, len 16384 i/o type 10.Please check that the configuration matches the InnoDB system tablespace location (ibdata files) 2017-09-20 06:40:15 7fb1ab3e2bc0 InnoDB: Assertion failure in thread 140401058917312 in file ha_innodb.cc line 21973 InnoDB: We intentionally generate a memory trap. InnoDB: Submit a detailed bug report to http://bugs.mysql.com. InnoDB: If you get repeated assertion failures or crashes, even InnoDB: immediately after the mysqld startup, there may be InnoDB: corruption in the InnoDB tablespace. Please refer to InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html InnoDB: about forcing recovery. 170920 6:40:15 [ERROR] mysqld got signal 6 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware.   To report this bug, see https://mariadb.com/kb/en/reporting-bugs   We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail.   Server version: 10.1.27-MariaDB key_buffer_size=0 read_buffer_size=131072 max_used_connections=0 max_threads=1 thread_count=0 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 5311 K bytes of memory Hope that's ok; if not, decrease some variables in the equation.   Thread pointer: 0x0 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 0x0 thread_stack 0x48400 /home/a/env1/m1-10.1/build/extra/mariabackup/mariabackup(my_print_stacktrace+0x29)[0x55e7fb0b53b9] /home/a/env1/m1-10.1/build/extra/mariabackup/mariabackup(handle_fatal_signal+0x3ad)[0x55e7facf60fd] /lib/x86_64-linux-gnu/libpthread.so.0(+0x11670)[0x7fb1aafdb670] mysys/stacktrace.c:268(my_print_stacktrace)[0x7fb1a946977f] sql/signal_handler.cc:168(handle_fatal_signal)[0x7fb1a946b37a] handler/ha_innodb.cc:21973(ib_logf(ib_log_level_t, char const*, ...))[0x55e7faf58f26] fil/fil0fil.cc:6114(fil_report_invalid_page_access)[0x55e7faf146c8] buf/buf0rea.cc:250(buf_read_page_low(dberr_t*, bool, unsigned long, unsigned long, unsigned long, unsigned long, long, unsigned long, trx_t*))[0x55e7faee4511] buf/buf0rea.cc:512(buf_read_page(unsigned long, unsigned long, unsigned long, trx_t*))[0x55e7faee56c6] buf/buf0buf.cc:3075(buf_page_get_gen(unsigned long, unsigned long, unsigned long, unsigned long, buf_block_t*, unsigned long, char const*, unsigned long, mtr_t*, dberr_t*))[0x55e7faec95a5] include/trx0undo.ic:174(trx_undo_page_get)[0x55e7fb040d47] trx/trx0rseg.cc:214(trx_rseg_mem_create(unsigned long, unsigned long, unsigned long, unsigned long, ib_bh_t*, mtr_t*))[0x55e7fb034b3d] trx/trx0rseg.cc:292(trx_rseg_create_instance)[0x55e7fb0353cc] trx/trx0sys.cc:673(trx_sys_init_at_db_start())[0x55e7fb03695e] srv/srv0start.cc:2654(innobase_start_or_create_for_mysql())[0x55e7fb020393] mariabackup/xtrabackup.cc:1738(innodb_init())[0x55e7faa7c5d7] mariabackup/xtrabackup.cc:5790(xtrabackup_prepare_func)[0x55e7faa67cf5] /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)[0x7fb1a94543f1] /home/a/env1/m1-10.1/build/extra/mariabackup/mariabackup(_start+0x2a)[0x55e7faa7b07a] The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash. Aborted (core dumped) mysqltest: At line 38: exec of '/home/a/env1/m1-10.1/build/extra/mariabackup/mariabackup --prepare --apply-log-only --target-dir=/home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup --incremental-dir=/home/a/env1/m1-10.1/build/mysql-test/var/tmp/backup_inc1 ' failed, error: 34304, status: 134, errno: 2 Output from before failure: # expect NOT FOUND   - saving '/home/a/env1/m1-10.1/build/mysql-test/var/log/mariabackup.apply-log-only-incr1-innodb_plugin/' to '/home/a/env1/m1-10.1/build/mysql-test/var/log/mariabackup.apply-log-only-incr1-innodb_plugin/' -------------------------------------------------------------------------- The servers were restarted 0 times Spent 0.000 of 53 seconds executing testcases   Failure: Failed 1/1 tests, 0.00% were successful.   Failing test(s): mariabackup.apply-log-only-incr1   The log files in var/log may give you some hint of what went wrong.   If you want to report this error, please read first the documentation at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html   mysql-test-run: *** ERROR: there were failing test cases

Marko Mäkelä added a comment - 2017-09-20 08:44 I think that to fix this, the following should be done: If the .delta files ignore the all-zero tail of .ibd files, we can still determine the desired file size by looking at the FSP_SIZE field in page 0. Simply, when applying .delta file to page 0, also extend the file to the size indicated by FSP_SIZE. No change to the .delta file format is needed. Test also with --skip-innodb-changed-pages in 10.1, because in 10.2 that option does not exist yet. After applying each .delta file, delete that .delta file. This is just the safe and sane thing to do, and will fix MDEV-13310 in 10.2.