Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Won't Fix
-
10.4(EOL), 10.5
-
None
Description
mtr test mariabackup.mdev-14447 fails randomly in 10.5.1 tree with:
CURRENT_TEST: mariabackup.mdev-14447
|
sh: line 1: 21349 Aborted (core dumped) /home/my/maria-10.5/extr
|
a/mariabackup/mariabackup --prepare --verbose --apply-log-only --target-dir=/hom
|
e/my/maria-10.5/mysql-test/var/4/tmp/backup --incremental-dir=/home/my/maria-10.
|
5/mysql-test/var/4/tmp/backup_inc1 2>&1
|
mysqltest: At line 35: exec of '/home/my/maria-10.5/extra/mariabackup/mariabacku
|
p --prepare --verbose --apply-log-only --target-dir=/home/my/maria-10.5/mysql-te
|
st/var/4/tmp/backup --incremental-dir=/home/my/maria-10.5/mysql-test/var/4/tmp/b
|
ackup_inc1 2>&1' failed, error: 34304, status: 134, errno: 2
|
|
|
The result from queries just before the failure was:
|
call mtr.add_suppression("InnoDB: New log files created");
|
CREATE TABLE t(a varchar(40) PRIMARY KEY, b varchar(40), c varchar(40), d varchar(40), index(b,c,d)) ENGINE INNODB;
|
# Create full backup , modify table, then create incremental/differential backup
|
BEGIN;
|
INSERT INTO t select uuid(), uuid(), uuid(), uuid() from seq_1_to_100000;
|
COMMIT;
|
SELECT count(*) FROM t;
|
count(*)
|
100000
|
FOUND 1 /Checksum mismatch in datafile/ in backup.log
|
# Prepare full backup, apply incremental one
|
|
|
mariabackup: /my/maria-10.5/storage/innobase/log/log0recv.cc:2649: bool recv_parse_log_recs(lsn_t, store_t*, ulint, bool): Assertion `recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn' failed.
|
#3 0x00007fc00dae2160 in raise () from /lib64/libc.so.6
|
#4 0x00007fc00dae3741 in abort () from /lib64/libc.so.6
|
#5 0x00007fc00dada75a in __assert_fail_base () from /lib64/libc.so.6
|
#6 0x00007fc00dada7d2 in __assert_fail () from /lib64/libc.so.6
|
#7 0x000000000124cd9e in recv_parse_log_recs (checkpoint_lsn=34221332, store=0x7ffd40828884, available_mem=67371008, apply=true) at /my/maria-10.5/storage/innobase/log/log0recv.cc:2649
|
#8 0x000000000124df2a in recv_scan_log_recs (available_mem=67371008, store_to_hash=0x7ffd40828884, log_block=0x7fc009b21000 "", checkpoint_lsn=34221332, start_lsn=34221056, end_lsn=34286592, contiguous_lsn=0x7ffd40828a98, group_scanned_lsn=0x2628c98 <log_sys+664>) at /my/maria-10.5/storage/innobase/log/log0recv.cc:3110
|
#9 0x000000000124e4a5 in recv_group_scan_log_recs (checkpoint_lsn=34221332, contiguous_lsn=0x7ffd40828a98, last_phase=false) at /my/maria-10.5/storage/innobase/log/log0recv.cc:3198
|
#10 0x000000000124fb89 in recv_recovery_from_checkpoint_start (flush_lsn=64240) at /my/maria-10.5/storage/innobase/log/log0recv.cc:3507
|
#11 0x0000000001395450 in srv_start (create_new_db=false) at /my/maria-10.5/storage/innobase/srv/srv0start.cc:1743
|
#12 0x00000000007842a2 in innodb_init () at /my/maria-10.5/extra/mariabackup/xtrabackup.cc:1975
|
#13 0x000000000078e232 in xtrabackup_prepare_func (argv=0x3817150) at /my/maria-10.5/extra/mariabackup/xtrabackup.cc:5529
|
#14 0x0000000000790251 in main_low (argv=0x3817150) at /my/maria-10.5/extra/mariabackup/xtrabackup.cc:6318
|
#15 0x000000000078fa8e in main (argc=6, argv=0x7ffd40830208) at /my/maria-10.5/extra/mariabackup/xtrabackup.cc:6108
|
When trying to repeat, I also found this issue during shutdown
sql/signal_handler.cc:209(handle_fatal_signal)[0xbee896]
|
/lib64/libpthread.so.0(+0x12360)[0x7f2f68a3e360]
|
/lib64/libpthread.so.0(pthread_cond_wait+0x1fd)[0x7f2f68a3990d]
|
/usr/lib64/libstdc++.so.6(_ZNSt18condition_variable4waitERSt11unique_lockISt5mutexE+0xc)[0x7f2f672bfb4c]
|
tpool/task.cc:63(tpool::waitable_task::wait())[0x1478852]
|
srv/srv0srv.cc:2233(srv_shutdown_purge_tasks())[0x123710d]
|
srv/srv0srv.cc:2304(srv_purge_shutdown())[0x123758e]
|
srv/srv0start.cc:2296(innodb_preshutdown())[0x1240491]
|
sql/handler.cc:886(plugin_pre_shutdown(THD*, st_plugin_int**, void*))[0xbf3000]
|
sql/sql_plugin.cc:2452(plugin_foreach_with_mask(THD*, char (*)(THD*, st_plugin_int**, void*), int, unsigned int, void*))[0x8ce920]
|
sql/handler.cc:895(ha_pre_shutdown())[0xbf302c]
|
sql/mysqld.cc:5731(mysqld_main(int, char**))[0x774752]
|
Attachments
Issue Links
- relates to
-
-
- Closed
-
-
-
- Open
-
Activity
This may be duplicated by MDEV-29943. MariaDB Server 10.5.2 and later may be unaffected by this, because that was the first version to include the redo log rewrite MDEV-12353.
Also observed on 10.4:
10.4 a10a94b2
mariabackup.mdev-14447 w3 [ fail ]Test ended at 2020-01-31 07:44:04CURRENT_TEST: mariabackup.mdev-14447sh: line 1: 262394 Aborted /home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup --prepare --verbose --apply-log-only --target-dir=/home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup --incremental-dir=/home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1 2>&1mysqltest: At line 35: exec of '/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup --prepare --verbose --apply-log-only --target-dir=/home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup --incremental-dir=/home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1 2>&1' failed, error: 34304, status: 134, errno: 2Output from before failure:/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup based on MariaDB server 10.4.13-MariaDB Linux (x86_64)[00] 2020-01-31 07:44:01 incremental backup from 71201 is enabled.[00] 2020-01-31 07:44:01 cd to /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup/[00] 2020-01-31 07:44:01 This target seems to be already prepared.[00] 2020-01-31 07:44:01 mariabackup: using the following InnoDB configuration for recovery:[00] 2020-01-31 07:44:01 innodb_data_home_dir = .[00] 2020-01-31 07:44:01 innodb_data_file_path = ibdata_first:3M;ibdata_second:1M:autoextend[00] 2020-01-31 07:44:01 innodb_log_group_home_dir = /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1/[00] 2020-01-31 07:44:01 InnoDB: Using Linux native AIO[00] 2020-01-31 07:44:01 mariabackup: Generating a list of tablespaces[00] 2020-01-31 07:44:01 page size for /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//ibdata_second.delta is 16384 bytes[00] 2020-01-31 07:44:01 Applying /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//ibdata_second.delta to ./ibdata_second...[00] 2020-01-31 07:44:01 page size for /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//ibdata_first.delta is 16384 bytes[00] 2020-01-31 07:44:01 Applying /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//ibdata_first.delta to ./ibdata_first...[00] 2020-01-31 07:44:01 page size for /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//test/t.ibd.delta is 16384 bytes[00] 2020-01-31 07:44:01 Applying /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//test/t.ibd.delta to ./test/t.ibd...[00] 2020-01-31 07:44:01 page size for /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//mysql/transaction_registry.ibd.delta is 16384 bytes[00] 2020-01-31 07:44:01 Applying /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//mysql/transaction_registry.ibd.delta to ./mysql/transaction_registry.ibd...[00] 2020-01-31 07:44:01 page size for /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//mysql/innodb_table_stats.ibd.delta is 16384 bytes[00] 2020-01-31 07:44:01 Applying /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//mysql/innodb_table_stats.ibd.delta to ./mysql/innodb_table_stats.ibd...[00] 2020-01-31 07:44:01 page size for /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//mysql/innodb_index_stats.ibd.delta is 16384 bytes[00] 2020-01-31 07:44:01 Applying /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1//mysql/innodb_index_stats.ibd.delta to ./mysql/innodb_index_stats.ibd...[00] 2020-01-31 07:44:01 mariabackup: using the following InnoDB configuration for recovery:[00] 2020-01-31 07:44:01 innodb_data_home_dir = .[00] 2020-01-31 07:44:01 innodb_data_file_path = ibdata_first:3M;ibdata_second:1M:autoextend[00] 2020-01-31 07:44:01 innodb_log_group_home_dir = /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backup_inc1/[00] 2020-01-31 07:44:01 InnoDB: Using Linux native AIO[00] 2020-01-31 07:44:01 Starting InnoDB instance for recovery.[00] 2020-01-31 07:44:01 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)2020-01-31 7:44:02 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!2020-01-31 7:44:02 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins2020-01-31 7:44:02 0 [Note] InnoDB: Uses event mutexes2020-01-31 7:44:02 0 [Note] InnoDB: Compressed tables use zlib 1.2.72020-01-31 7:44:02 0 [Note] InnoDB: Number of pools: 12020-01-31 7:44:02 0 [Note] InnoDB: Using SSE2 crc32 instructions/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup: O_TMPFILE is not supported on /tmp (disabling future attempts)2020-01-31 7:44:02 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M2020-01-31 7:44:02 0 [Note] InnoDB: Completed initialization of buffer pool2020-01-31 7:44:02 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().2020-01-31 7:44:02 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=38532815MLOG_CHECKPOINT(37068128) read at 38532842MLOG_CHECKPOINT(37068128) reread at 38532815mariabackup: /home/elenst/src/10.4/storage/innobase/log/log0recv.cc:2788: bool recv_parse_log_recs(lsn_t, store_t*, ulint, bool): Assertion `recv_sys.mlog_checkpoint_lsn <= recv_sys.recovered_lsn' failed.200131 7:44:02 [ERROR] mysqld got signal 6 ;This could be because you hit a bug. It is also possible that this binaryor 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-bugsWe will try our best to scrape up some info that will hopefully helpdiagnose the problem, but since we have already crashed,something is definitely wrong and this may fail.Server version: 10.4.13-MariaDB-debugkey_buffer_size=0read_buffer_size=131072max_used_connections=0max_threads=1thread_count=0It is possible that mysqld could use up tokey_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 6033 K bytes of memoryHope that's ok; if not, decrease some variables in the equation.Thread pointer: 0x0Attempting backtrace. You can use the following information to find outwhere mysqld died. If you see no messages after this, something wentterribly wrong...stack_bottom = 0x0 thread_stack 0x49000/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup(my_print_stacktrace+0x40)[0x555c6aafd0c3]/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup(handle_fatal_signal+0x3a9)[0x555c6a26ee4f]sigaction.c:0(__restore_rt)[0x7fc483f6f5d0]:0(__GI_raise)[0x7fc482931207]:0(__GI_abort)[0x7fc4829328f8]:0(__assert_fail_base)[0x7fc48292a026]:0(__GI___assert_fail)[0x7fc48292a0d2]/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup(+0x11b1278)[0x555c6a796278]/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup(+0x11b239c)[0x555c6a79739c]log/log0recv.cc:2789(recv_parse_log_recs(unsigned long, store_t*, unsigned long, bool))[0x555c6a797932]log/log0recv.cc:3263(recv_scan_log_recs(unsigned long, store_t*, unsigned char const*, unsigned long, unsigned long, unsigned long, unsigned long*, unsigned long*))[0x555c6a798e94]log/log0recv.cc:3360(recv_group_scan_log_recs(unsigned long, unsigned long*, bool))[0x555c6a8de1a0]log/log0recv.cc:3660(recv_recovery_from_checkpoint_start(unsigned long))[0x555c69ce691f]srv/srv0start.cc:1871(srv_start(bool))[0x555c69cf0f9worker[3] > Restart - not startedmariabackup/xtrabackup.cc:1989(innodb_init())[0x555c69cf3166]mariabackup/xtrabackup.cc:5552(xtrabackup_prepare_func(char**))[0x555c69cf2973]/lib64/libc.so.6(__libc_start_main+0xf5)[0x7fc48291d3d5]/home/elenst/builds/10.4-a10a94b2-deb/bin/mariabackup(+0x6fcc89)[0x555c69ce1c89]The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html containsinformation that should help you find out what is causing the crash.Writing a core file...Working directory at /home/elenst/mtr_logs/var_10.4_a10a94b2_big/3/tmp/backupResource Limits:Limit Soft Limit Hard Limit UnitsMax cpu time unlimited unlimited secondsMax file size unlimited unlimited bytesMax data size unlimited unlimited bytesMax stack size 8388608 unlimited bytesMax core file size 0 unlimited bytesMax resident set unlimited unlimited bytesMax processes 4096 2315692 processesMax open files 1024 1024 filesMax locked memory 1073741824 1073741824 bytesMax address space unlimited unlimited bytesMax file locks unlimited unlimited locksMax pending signals 2315692 2315692 signalsMax msgqueue size 819200 819200 bytesMax nice priority 0 0Max realtime priority 0 0Max realtime timeout unlimited unlimited usCore pattern: core