[MDEV-14192] mariabackup.incremental_backup failed in buildbot with Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0 Created: 2017-10-29  Updated: 2020-10-06  Resolved: 2019-06-19

Status: Closed
Project: MariaDB Server
Component/s: Backup, Storage Engine - InnoDB, Tests
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: 10.2.25, 10.3.16, 10.4.6

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Vladislav Lesin
Resolution: Fixed Votes: 0
Labels: affects-tests

Issue Links:
Duplicate
is duplicated by MDEV-15277 mariabackup.xb_file_key_management fa... Closed
Relates
relates to MDEV-18038 Assertion failure in innodb.undo_trun... Closed
relates to MDEV-18653 mariabackup.unencrypted_page_compress... Open

 Description   

mariabackup.incremental_backup '4k,innodb' w4 [ fail ]
        Test ended at 2017-10-02 08:02:18
 
CURRENT_TEST: mariabackup.incremental_backup
171002 08:02:10 Connecting to MySQL server host: localhost, user: root, password: set, port: 16060, socket: D:/winx64-debug/build/mysql-test/var/tmp/4/mysqld.1.sock
Using server version 10.2.10-MariaDB-debug-log
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.10-MariaDB Win64 (AMD64) 
incremental backup from 735814 is enabled.
xtrabackup: cd to D:\winx64-debug\build\mysql-test\var\4\mysqld.1\data\
xtrabackup: open files limit requested 1024, set to 0
InnoDB: The universal page size of the database is set to 4096.
xtrabackup: using the following InnoDB configuration:
xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup:   innodb_log_group_home_dir = .\
2017-10-02  8:02:10 6580 [Note] InnoDB: Number of pools: 1
171002 08:02:10 >> log scanned up to (742992)
xtrabackup: Generating a list of tablespaces
2017-10-02  8:02:10 6580 [Warning] InnoDB: Allocated tablespace ID 2 for mysql/innodb_index_stats, old maximum was 0
171002 08:02:10 [01] Copying .\ibdata1 to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\ibdata1.delta
171002 08:02:10 [01]        ...done
171002 08:02:10 [01] Copying .\mysql\innodb_index_stats.ibd to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\innodb_index_stats.ibd.delta
171002 08:02:10 [01]        ...done
171002 08:02:10 [01] Copying .\mysql\innodb_table_stats.ibd to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\innodb_table_stats.ibd.delta
171002 08:02:10 [01]        ...done
171002 08:02:10 [01] Copying .\test\t.ibd to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\test\t.ibd.delta
171002 08:02:10 [01]        ...done
171002 08:02:11 Waiting 5 seconds for queries running longer than 300 seconds to finish
171002 08:02:11 Executing FLUSH TABLES WITH READ LOCK...
171002 08:02:11 Starting to backup non-InnoDB tables and files
171002 08:02:11 [01] Copying .\mtr\db.opt to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\db.opt
171002 08:02:11 [01]        ...done
171002 08:02:11 >> log scanned up to (743019)
171002 08:02:11 [01] Copying .\mtr\global_suppressions.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\global_suppressions.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\global_suppressions.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\global_suppressions.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\global_suppressions.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\global_suppressions.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\global_suppressions.TRG to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\global_suppressions.TRG
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\gs_insert.TRN to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\gs_insert.TRN
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\test_suppressions.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\test_suppressions.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\test_suppressions.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\test_suppressions.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\test_suppressions.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\test_suppressions.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\test_suppressions.TRG to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\test_suppressions.TRG
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mtr\ts_insert.TRN to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mtr\ts_insert.TRN
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\columns_priv.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\columns_priv.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\columns_priv.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\columns_priv.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\columns_priv.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\columns_priv.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\column_stats.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\column_stats.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\column_stats.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\column_stats.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\column_stats.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\column_stats.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\db.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\db.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\db.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\db.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\db.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\db.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\event.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\event.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\event.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\event.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\event.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\event.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\func.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\func.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\func.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\func.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\func.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\func.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\general_log.CSM to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\general_log.CSM
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\general_log.CSV to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\general_log.CSV
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\general_log.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\general_log.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\gtid_slave_pos.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\gtid_slave_pos.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\gtid_slave_pos.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\gtid_slave_pos.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\gtid_slave_pos.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\gtid_slave_pos.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_category.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_category.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_category.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_category.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_category.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_category.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_keyword.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_keyword.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_keyword.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_keyword.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_keyword.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_keyword.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_relation.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_relation.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_relation.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_relation.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_relation.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_relation.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_topic.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_topic.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_topic.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_topic.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\help_topic.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\help_topic.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\host.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\host.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\host.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\host.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\host.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\host.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\index_stats.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\index_stats.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\index_stats.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\index_stats.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\index_stats.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\index_stats.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\innodb_index_stats.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\innodb_index_stats.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\innodb_table_stats.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\innodb_table_stats.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\plugin.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\plugin.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\plugin.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\plugin.MYD
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\plugin.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\plugin.MYI
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\proc.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\proc.frm
171002 08:02:11 [01]        ...done
171002 08:02:11 [01] Copying .\mysql\proc.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\proc.MYD
171002 08:02:11 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\proc.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\proc.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\procs_priv.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\procs_priv.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\procs_priv.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\procs_priv.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\procs_priv.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\procs_priv.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\proxies_priv.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\proxies_priv.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\proxies_priv.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\proxies_priv.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\proxies_priv.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\proxies_priv.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\roles_mapping.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\roles_mapping.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\roles_mapping.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\roles_mapping.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\roles_mapping.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\roles_mapping.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\servers.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\servers.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\servers.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\servers.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\servers.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\servers.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\slow_log.CSM to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\slow_log.CSM
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\slow_log.CSV to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\slow_log.CSV
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\slow_log.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\slow_log.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\tables_priv.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\tables_priv.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\tables_priv.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\tables_priv.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\tables_priv.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\tables_priv.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\table_stats.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\table_stats.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\table_stats.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\table_stats.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\table_stats.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\table_stats.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_leap_second.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_leap_second.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_leap_second.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_leap_second.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_leap_second.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_leap_second.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_name.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_name.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_name.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_name.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_name.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_name.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_transition.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_transition.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_transition.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_transition.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_transition.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_transition.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_transition_type.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_transition_type.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_transition_type.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_transition_type.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\time_zone_transition_type.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\time_zone_transition_type.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\user.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\user.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\user.MYD to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\user.MYD
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\mysql\user.MYI to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\mysql\user.MYI
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\performance_schema\db.opt to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\performance_schema\db.opt
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying .\test\t.frm to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\test\t.frm
171002 08:02:12 [01]        ...done
171002 08:02:12 Finished backing up non-InnoDB tables and files
171002 08:02:12 [01] Copying aria_log.00000001 to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\aria_log.00000001
171002 08:02:12 [01]        ...done
171002 08:02:12 [01] Copying aria_log_control to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\aria_log_control
171002 08:02:12 [01]        ...done
171002 08:02:12 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
xtrabackup: The latest check point (for incremental): '735814'
xtrabackup: Stopping log copying thread.
 
171002 08:02:12 >> log scanned up to (743019)
171002 08:02:12 Executing UNLOCK TABLES
171002 08:02:12 All tables unlocked
171002 08:02:12 [00] Copying ib_buffer_pool to D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\ib_buffer_pool
171002 08:02:12 [00]        ...done
171002 08:02:12 Backup created in directory 'D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\'
171002 08:02:12 [00] Writing backup-my.cnf
171002 08:02:12 [00]        ...done
171002 08:02:12 [00] Writing xtrabackup_info
171002 08:02:12 [00]        ...done
xtrabackup: Redo log (from LSN 735814 to 743019) was copied.
171002 08:02:12 completed OK!
mysqltest: At line 21: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe --prepare --target-dir=D:/winx64-debug/build/mysql-test/var/4/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.10-MariaDB Win64 (AMD64) 
xtrabackup: cd to D:/winx64-debug/build/mysql-test/var/4/tmp/backup/
xtrabackup: This target seems to be not prepared yet.
InnoDB: The universal page size of the database is set to 4096.
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 = .
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)

2017-10-02  8:02:12 1760 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-10-02  8:02:12 1760 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2017-10-02  8:02:12 1760 [Note] InnoDB: Uses event mutexes
2017-10-02  8:02:12 1760 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-10-02  8:02:12 1760 [Note] InnoDB: Number of pools: 1
2017-10-02  8:02:12 1760 [Note] InnoDB: Using generic crc32 instructions
2017-10-02  8:02:12 1760 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2017-10-02  8:02:12 1760 [Note] InnoDB: Completed initialization of buffer pool
2017-10-02  8:02:12 1760 [Note] InnoDB: Highest supported file format is Barracuda.
2017-10-02 08:02:12 0x6e0  InnoDB: Assertion failure in file D:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 5406
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
171002  8:02:12 [ERROR] mysqld got exception 0x80000003 ;
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.2.10-MariaDB-debug
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 = 4976 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:488]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5406]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:681]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2934]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3193]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2219]
mariabackup.exe!innodb_init()[xtrabackup.cc:1646]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:4810]
mariabackup.exe!main_low()[xtrabackup.cc:5490]
mariabackup.exe!main()[xtrabackup.cc:5287]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:259]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
 
 
 
The result from queries just before the failure was:
call mtr.add_suppression("InnoDB: New log files created");
CREATE TABLE t(i INT) ENGINE INNODB;
INSERT INTO t VALUES(1);
# Create full backup , modify table, then create incremental/differential backup
INSERT INTO t VALUES(2);
SELECT * FROM t;
i
1
2
# Prepare full backup, apply incremental one
 
 - saving 'D:/winx64-debug/build/mysql-test/var/4/log/mariabackup.incremental_backup-4k,innodb/' to 'D:/winx64-debug/build/mysql-test/var/log/mariabackup.incremental_backup-4k,innodb/'
 
Retrying test mariabackup.incremental_backup, attempt(2/3)...



 Comments   
Comment by Marko Mäkelä [ 2017-11-01 ]

Another 10.2 failure: mariabackup.apply-log-only-incr

CURRENT_TEST: mariabackup.apply-log-only-incr
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.11-MariaDB Win64 (AMD64) 
incremental backup from 1633737 is enabled.
mariabackup: cd to D:\winx64-debug\build\mysql-test\var\4\tmp\backup\
mariabackup: This target seems to be already prepared.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\
mariabackup: Generating a list of tablespaces
mariabackup: page size for D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\ibdata1.delta is 16384 bytes
Applying D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\ibdata1.delta to .\ibdata1...
mariabackup: page size for D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\mysql\innodb_index_stats.ibd.delta is 16384 bytes
Applying D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\mysql\innodb_index_stats.ibd.delta to .\mysql\innodb_index_stats.ibd...
mariabackup: page size for D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\mysql\innodb_table_stats.ibd.delta is 16384 bytes
Applying D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\mysql\innodb_table_stats.ibd.delta to .\mysql\innodb_table_stats.ibd...
mariabackup: page size for D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\test\t.ibd.delta is 16384 bytes
Applying D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\\test\t.ibd.delta to .\test\t.ibd...
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = D:\winx64-debug\build\mysql-test\var\4\tmp\backup_inc1\
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2017-11-01  8:44:55 324 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-11-01  8:44:55 324 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2017-11-01  8:44:55 324 [Note] InnoDB: Uses event mutexes
2017-11-01  8:44:55 324 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-11-01  8:44:55 324 [Note] InnoDB: Number of pools: 1
2017-11-01  8:44:55 324 [Note] InnoDB: Using generic crc32 instructions
2017-11-01  8:44:55 324 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2017-11-01  8:44:56 324 [Note] InnoDB: Completed initialization of buffer pool
2017-11-01  8:44:56 324 [Note] InnoDB: Highest supported file format is Barracuda.
2017-11-01 08:44:56 0x144  InnoDB: Assertion failure in file D:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 5243
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
171101  8:44:56 [ERROR] mysqld got exception 0x80000003 ;
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.2.11-MariaDB-debug
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 = 4979 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:488]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5243]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:652]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2903]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3164]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2243]
mariabackup.exe!innodb_init()[xtrabackup.cc:1653]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:4820]
mariabackup.exe!main_low()[xtrabackup.cc:5499]
mariabackup.exe!main()[xtrabackup.cc:5296]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
mysqltest: At line 40: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe --prepare --apply-log-only --target-dir=D:/winx64-debug/build/mysql-test/var/4/tmp/backup --incremental-dir=D:/winx64-debug/build/mysql-test/var/4/tmp/backup_inc1 ' failed, error: 255, status: 255, errno: 2
Output from before failure:
# expect NOT FOUND
 
 
 
The result from queries just before the failure was:
call mtr.add_suppression("InnoDB: New log files created");
CREATE TABLE t(a INT UNSIGNED PRIMARY KEY) ENGINE INNODB;
INSERT INTO t VALUES(0);
COMMIT;
start transaction;
NOT FOUND /Rollback of trx with id/ in current_test
# expect NOT FOUND

Comment by Marko Mäkelä [ 2017-11-01 ]

Correct me if I am wrong, but it looks like this could be caused if source_offset in log_group_read_log_seg() is not a multiple of 512:

	source_offset = log_group_calc_lsn_offset(start_lsn, group);

How could that happen? Let us look at the last statement in that function:

	return(log_group_calc_real_offset(offset, group));

And that function definition:

UNIV_INLINE
lsn_t
log_group_calc_real_offset(
/*=======================*/
	lsn_t			offset,	/*!< in: size offset within the
					log group */
	const log_group_t*	group)	/*!< in: log group */
{
	/* The lsn parameters are updated while holding both the mutexes
	and it is ok to have either of them while reading */
	ut_ad(log_mutex_own() || log_write_mutex_own());
 
	return(offset + LOG_FILE_HDR_SIZE
	       * (1 + offset / (group->file_size - LOG_FILE_HDR_SIZE)));
}

LOG_FILE_HDR_SIZE is an integer multiple of 512 bytes. Therefore, log_group_calc_real_offset() can only return an unaligned offset if the passed offset was not aligned.

Maybe the bug is that when recv_group_scan_log_recs() is scanning the redo log, and it previously detected the end of the log at some end_lsn in the middle of a block, it is re-reading from the wrong offset?

diff --git a/storage/innobase/log/log0recv.cc b/storage/innobase/log/log0recv.cc
index 0a6679be721..2d707820f4a 100644
--- a/storage/innobase/log/log0recv.cc
+++ b/storage/innobase/log/log0recv.cc
@@ -622,6 +622,8 @@ log_group_read_log_seg(
 	lsn_t	source_offset;
 
 	ut_ad(log_mutex_own());
+	ut_ad(!(start_lsn % OS_FILE_LOG_BLOCK_SIZE));
+	ut_ad(!(end_lsn % OS_FILE_LOG_BLOCK_SIZE));
 
 loop:
 	source_offset = log_group_calc_lsn_offset(start_lsn, group);
@@ -2899,7 +2901,8 @@ recv_group_scan_log_recs(
 			recv_apply_hashed_log_recs(false);
 		}
 
-		start_lsn = end_lsn;
+		start_lsn = ut_uint64_align_down(end_lsn,
+						 OS_FILE_LOG_BLOCK_SIZE);
 		end_lsn = log_group_read_log_seg(
 			log_sys->buf, group, start_lsn,
 			start_lsn + RECV_SCAN_SIZE);

However, it is not clear to me how could have an end_lsn that is not a multiple of OS_FILE_LOG_BLOCK_SIZE here.
wlad, can you please try to repeat the failure of --suite=mariabackup on Windows, and then retry with the above patch applied?

Comment by Elena Stepanova [ 2017-11-23 ]

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/6152/steps/test/logs/stdio

mariabackup.apply-log-only 'innodb'      w3 [ fail ]
        Test ended at 2017-11-07 21:47:32
 
CURRENT_TEST: mariabackup.apply-log-only
D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.11-MariaDB Win32 (AMD64) 
mariabackup: cd to D:\win32-debug\build\mysql-test\var\3\tmp\backup\
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2017-11-07 21:47:29 3144 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-11-07 21:47:29 3144 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2017-11-07 21:47:29 3144 [Note] InnoDB: Uses event mutexes
2017-11-07 21:47:29 3144 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-11-07 21:47:29 3144 [Note] InnoDB: Number of pools: 1
2017-11-07 21:47:29 3144 [Note] InnoDB: Using generic crc32 instructions
2017-11-07 21:47:29 3144 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2017-11-07 21:47:29 3144 [Note] InnoDB: Completed initialization of buffer pool
2017-11-07 21:47:30 3144 [Note] InnoDB: Highest supported file format is Barracuda.
2017-11-07 21:47:30 0xc48  InnoDB: Assertion failure in file D:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 5238
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
171107 21:47:30 [ERROR] mysqld got exception 0x80000003 ;
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.2.11-MariaDB-debug
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 = 4178 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:488]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5238]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:652]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2903]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3161]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2244]
mariabackup.exe!innodb_init()[xtrabackup.cc:1653]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:4820]
mariabackup.exe!main_low()[xtrabackup.cc:5499]
mariabackup.exe!main()[xtrabackup.cc:5296]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
mysqltest: At line 14: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe --prepare --apply-log-only --target-dir=D:/win32-debug/build/mysql-test/var/3/tmp/backup ' failed, error: 255, status: 255, errno: 2
Output from before failure:
 
 
 
The result from queries just before the failure was:
call mtr.add_suppression("InnoDB: New log files created");
CREATE TABLE t(a varchar(60)) ENGINE INNODB;
start transaction;
INSERT INTO t VALUES(1);

Comment by Elena Stepanova [ 2017-11-27 ]

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/6387/steps/test/logs/stdio

mariabackup.xbstream '8k,innodb'         w2 [ fail ]
        Test ended at 2017-11-24 16:12:00
 
CURRENT_TEST: mariabackup.xbstream
mysqltest: At line 17: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe --prepare --target-dir=D:/win32-debug/build/mysql-test/var/2/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.11-MariaDB Win32 (AMD64) 
mariabackup: cd to D:/win32-debug/build/mysql-test/var/2/tmp/backup/
mariabackup: This target seems to be not prepared yet.
InnoDB: The universal page size of the database is set to 8192.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2017-11-24 16:11:52 7300 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-11-24 16:11:52 7300 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2017-11-24 16:11:52 7300 [Note] InnoDB: Uses event mutexes
2017-11-24 16:11:52 7300 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-11-24 16:11:52 7300 [Note] InnoDB: Number of pools: 1
2017-11-24 16:11:52 7300 [Note] InnoDB: Using SSE2 crc32 instructions
2017-11-24 16:11:52 7300 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2017-11-24 16:11:52 7300 [Note] InnoDB: Completed initialization of buffer pool
2017-11-24 16:11:52 7300 [Note] InnoDB: Highest supported file format is Barracuda.
2017-11-24 16:11:52 0x1c84  InnoDB: Assertion failure in file D:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 5264
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
171124 16:11:53 [ERROR] mysqld got exception 0x80000003 ;
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.2.11-MariaDB-debug
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 = 4191 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:488]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5264]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:654]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2906]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3164]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2241]
mariabackup.exe!innodb_init()[xtrabackup.cc:1653]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:4817]
mariabackup.exe!main_low()[xtrabackup.cc:5496]
mariabackup.exe!main()[xtrabackup.cc:5293]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.

Comment by Alice Sherepa [ 2017-11-30 ]

http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/6254/steps/test/logs/stdio

mariabackup.incremental_encrypted '16k,innodb' w3 [ fail ]
        Test ended at 2017-11-29 17:46:20
 
CURRENT_TEST: mariabackup.incremental_encrypted
mysqltest: At line 29: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe --prepare --target-dir=D:/winx64-debug/build/mysql-test/var/3/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.12-MariaDB Win64 (AMD64) 
mariabackup: cd to D:/winx64-debug/build/mysql-test/var/3/tmp/backup/
Loading encryption plugin
	 Encryption plugin parameter :  '--debug_key_management_version=2'
	 Encryption plugin parameter :  '--prepare'
	 Encryption plugin parameter :  '--target-dir=D:/winx64-debug/build/mysql-test/var/3/tmp/backup'
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2017-11-29 17:46:15 8864 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-11-29 17:46:15 8864 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2017-11-29 17:46:15 8864 [Note] InnoDB: Uses event mutexes
2017-11-29 17:46:15 8864 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-11-29 17:46:15 8864 [Note] InnoDB: Number of pools: 1
2017-11-29 17:46:15 8864 [Note] InnoDB: Using SSE2 crc32 instructions
2017-11-29 17:46:15 8864 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2017-11-29 17:46:15 8864 [Note] InnoDB: Completed initialization of buffer pool
2017-11-29 17:46:15 8864 [Note] InnoDB: Highest supported file format is Barracuda.
2017-11-29 17:46:15 0x22a0  InnoDB: Assertion failure in file D:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 5264
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
171129 17:46:15 [ERROR] mysqld got exception 0x80000003 ;
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.2.12-MariaDB-debug
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 = 4993 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:488]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5264]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:654]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2906]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3167]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2241]
mariabackup.exe!innodb_init()[xtrabackup.cc:1653]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:4817]
mariabackup.exe!main_low()[xtrabackup.cc:5496]
mariabackup.exe!main()[xtrabackup.cc:5293]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
 
 
 
The result from queries just before the failure was:
call mtr.add_suppression("InnoDB: New log files created");
CREATE TABLE t(i INT) ENGINE INNODB ENCRYPTED=YES;
INSERT INTO t VALUES(1);
# Create full backup , modify table, then create incremental/differential backup
INSERT INTO t VALUES(2);
SELECT * FROM t;
i
1
2
# Prepare full backup, apply incremental one

Comment by Elena Stepanova [ 2018-06-25 ]

Another one:
http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/9237

mariabackup.backup_ssl                   w4 [ fail ]
        Test ended at 2018-06-13 13:09:21
 
CURRENT_TEST: mariabackup.backup_ssl
mysqltest: At line 11: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/win32-debug/build/mysql-test/var/4/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 0
Output from before failure:
D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.16-MariaDB Win32 (AMD64) 
mariabackup: cd to D:/win32-debug/build/mysql-test/var/4/tmp/backup/
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-06-13 13:09:17 3176 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2018-06-13 13:09:17 3176 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-06-13 13:09:17 3176 [Note] InnoDB: Uses event mutexes
2018-06-13 13:09:17 3176 [Note] InnoDB: Compressed tables use zlib 1.2.3
2018-06-13 13:09:17 3176 [Note] InnoDB: Number of pools: 1
2018-06-13 13:09:17 3176 [Note] InnoDB: Using SSE2 crc32 instructions
2018-06-13 13:09:17 3176 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-06-13 13:09:17 3176 [Note] InnoDB: Completed initialization of buffer pool
2018-06-13 13:09:17 3176 [Note] InnoDB: Highest supported file format is Barracuda.
2018-06-13 13:09:17 0xc68  InnoDB: Assertion failure in file d:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 5191
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
180613 13:09:17 [ERROR] mysqld got exception 0x80000003 ;
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.2.16-MariaDB-debug
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 = 4191 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:487]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5191]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:677]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3005]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3283]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2230]
mariabackup.exe!innodb_init()[xtrabackup.cc:1822]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5091]
mariabackup.exe!main_low()[xtrabackup.cc:5781]
mariabackup.exe!main()[xtrabackup.cc:5574]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
 
 
 
The result from queries just before the failure was:
GRANT ALL PRIVILEGES on *.* TO backup_user IDENTIFIED by 'x' REQUIRE SSL;
FLUSH PRIVILEGES;
# xtrabackup backup
# xtrabackup prepare

Comment by Elena Stepanova [ 2018-08-11 ]

Another one:
http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/9751

mariabackup.xb_partition                 w3 [ fail ]
        Test ended at 2018-07-25 11:06:27
 
CURRENT_TEST: mariabackup.xb_partition
mysqltest: At line 73: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe --innobackupex --defaults-file=D:/win32-debug/build/mysql-test/var/3/my.cnf --apply-log --incremental-dir=D:/win32-debug/build/mysql-test/var/3/tmp/inc D:/win32-debug/build/mysql-test/var/3/tmp/full 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
180725 11:06:19 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.2.17-MariaDB Win32 (AMD64) 
incremental backup from 1650188 is enabled.
mariabackup: cd to D:/win32-debug/build/mysql-test/var/3/tmp/full/
mariabackup: This target seems to be already prepared.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = D:/win32-debug/build/mysql-test/var/3/tmp/inc/
mariabackup: Generating a list of tablespaces
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//ibdata1.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//ibdata1.delta to .\ibdata1...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//mysql/innodb_index_stats.ibd.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//mysql/innodb_index_stats.ibd.delta to .\mysql\innodb_index_stats.ibd...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//mysql/innodb_table_stats.ibd.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//mysql/innodb_table_stats.ibd.delta to .\mysql\innodb_table_stats.ibd...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p2.ibd.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p2.ibd.delta to ./test/p#p#p2.ibd...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p3.ibd.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p3.ibd.delta to ./test/p#p#p3.ibd...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p4.ibd.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p4.ibd.delta to ./test/p#p#p4.ibd...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p5.ibd.delta is 16384 bytes
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/p#p#p5.ibd.delta to ./test/p#p#p5.ibd...
mariabackup: page size for D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/t2.ibd.delta is 16384 bytes
mariabackup: Renaming test/t2 to test/xtrabackup_tmp_#10.ibd
Applying D:/win32-debug/build/mysql-test/var/3/tmp/inc//test/t2.ibd.delta to ./test/t2.ibd...
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = D:/win32-debug/build/mysql-test/var/3/tmp/inc/
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-07-25 11:06:19 2724 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2018-07-25 11:06:19 2724 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-07-25 11:06:19 2724 [Note] InnoDB: Uses event mutexes
2018-07-25 11:06:19 2724 [Note] InnoDB: Compressed tables use zlib 1.2.3
2018-07-25 11:06:19 2724 [Note] InnoDB: Number of pools: 1
2018-07-25 11:06:19 2724 [Note] InnoDB: Using SSE2 crc32 instructions
2018-07-25 11:06:19 2724 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-07-25 11:06:19 2724 [Note] InnoDB: Completed initialization of buffer pool
2018-07-25 11:06:19 2724 [Note] InnoDB: Highest supported file format is Barracuda.
2018-07-25 11:06:19 0xaa4  InnoDB: Assertion failure in file d:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 5191
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
180725 11:06:19 [ERROR] mysqld got exception 0x80000003 ;
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.2.17-MariaDB-debug
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 = 4192 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:487]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5191]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:677]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3027]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3305]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2234]
mariabackup.exe!innodb_init()[xtrabackup.cc:1826]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5103]
mariabackup.exe!main_low()[xtrabackup.cc:5793]
mariabackup.exe!main()[xtrabackup.cc:5586]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
 
 
 
The result from queries just before the failure was:
< snip >
PARTITION p3 VALUES LESS THAN (400));
INSERT INTO isam_p VALUES (1), (101), (201), (301);
DROP TABLE t1;
DROP TABLE t2;
CREATE TABLE t2(a INT) ENGINE=InnoDB;
INSERT INTO t2 VALUES (40), (50), (60);
ALTER TABLE p DROP PARTITION p0;
ALTER TABLE p DROP PARTITION p1;
ALTER TABLE p ADD PARTITION (PARTITION p4 VALUES LESS THAN (500));
ALTER TABLE p ADD PARTITION (PARTITION p5 VALUES LESS THAN (600));
INSERT INTO p VALUES (401), (501);
DROP TABLE isam_t1;
DROP TABLE isam_t2;
CREATE TABLE isam_t2(a INT) ENGINE=MyISAM;
INSERT INTO isam_t2 VALUES (40), (50), (60);
ALTER TABLE isam_p DROP PARTITION p0;
ALTER TABLE isam_p DROP PARTITION p1;
ALTER TABLE isam_p ADD PARTITION (PARTITION p4 VALUES LESS THAN (500));
ALTER TABLE isam_p ADD PARTITION (PARTITION p5 VALUES LESS THAN (600));
INSERT INTO isam_p VALUES (401), (501);

Comment by Elena Stepanova [ 2018-08-13 ]

http://buildbot.askmonty.org/buildbot/builders/winx64-packages/builds/9296

mariabackup.unsupported_redo 'innodb'    w2 [ fail ]
        Test ended at 2018-08-07 08:53:42
 
CURRENT_TEST: mariabackup.unsupported_redo
mysqltest: At line 100: exec of 'D:/winx64-packages/build/extra/mariabackup/RelWithDebInfo/mariabackup.exe --prepare --target-dir=D:/winx64-packages/build/mysql-test/var/2/tmp/bk 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/winx64-packages/build/extra/mariabackup/RelWithDebInfo/mariabackup.exe based on MariaDB server 10.3.9-MariaDB Win64 (AMD64) 
mariabackup: cd to D:/winx64-packages/build/mysql-test/var/2/tmp/bk/
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-08-07  8:53:38 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-08-07  8:53:38 0 [Note] InnoDB: Uses event mutexes
2018-08-07  8:53:38 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2018-08-07  8:53:38 0 [Note] InnoDB: Number of pools: 1
2018-08-07  8:53:38 0 [Note] InnoDB: Using SSE2 crc32 instructions
2018-08-07  8:53:38 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-08-07  8:53:38 0 [Note] InnoDB: Completed initialization of buffer pool
2018-08-07 08:53:38 0x19a0  InnoDB: Assertion failure in file d:\winx64-packages\build\src\storage\innobase\fil\fil0fil.cc line 4505
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
180807  8:53:38 [ERROR] mysqld got exception 0x80000003 ;
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.3.9-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 = 5109 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:485]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:61]
mariabackup.exe!fil_io()[fil0fil.cc:4505]
mariabackup.exe!log_t::files::read_log_seg()[log0recv.cc:676]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2932]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3204]
mariabackup.exe!srv_start()[srv0start.cc:2001]
mariabackup.exe!innodb_init()[xtrabackup.cc:1814]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5044]
mariabackup.exe!main_low()[xtrabackup.cc:5720]
mariabackup.exe!main()[xtrabackup.cc:5513]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
 
 
 
The result from queries just before the failure was:
< snip >
ALTER TABLE t1 FORCE, ALGORITHM=INPLACE;
# Fails during full backup
DROP TABLE t1;
CREATE TABLE t1(i INT PRIMARY KEY auto_increment, a int) ENGINE INNODB;
INSERT INTO t1(a) select 1 union select 2 union select 3;
# Create full backup , modify table, then fails during creation of
#		incremental/differential backup
ALTER TABLE t1 FORCE, ALGORITHM=INPLACE;
DROP TABLE t1;
CREATE TABLE t1(i INT) ENGINE INNODB;
INSERT INTO t1 VALUES(1);
CREATE TABLE t21(i INT) ENGINE INNODB;
INSERT INTO t21 VALUES(1);
CREATE TABLE t2(i int) ENGINE INNODB;
ALTER TABLE t21 FORCE, ALGORITHM=INPLACE;
# Create partial backup (excluding table t21), Ignore the
# unsupported redo log for the table t21.
t1.ibd
t2.ibd
# Prepare the full backup

Comment by Elena Stepanova [ 2018-10-01 ]

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/10190

mariabackup.mlog_index_load              w1 [ fail ]
        Test ended at 2018-08-30 20:06:36
 
CURRENT_TEST: mariabackup.mlog_index_load
mysqltest: At line 19: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/win32-debug/build/mysql-test/var/1/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.3.10-MariaDB Win32 (AMD64) 
mariabackup: cd to D:/win32-debug/build/mysql-test/var/1/tmp/backup/
Removing ./test/t1.ibd
Renaming ./test/t1.new to ./test/t1.ibd
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-08-30 20:06:24 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2018-08-30 20:06:24 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-08-30 20:06:24 0 [Note] InnoDB: Uses event mutexes
2018-08-30 20:06:24 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2018-08-30 20:06:24 0 [Note] InnoDB: Number of pools: 1
2018-08-30 20:06:24 0 [Note] InnoDB: Using SSE2 crc32 instructions
2018-08-30 20:06:24 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-08-30 20:06:24 0 [Note] InnoDB: Completed initialization of buffer pool
2018-08-30 20:06:24 0x1754  InnoDB: Assertion failure in file d:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 4498
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
180830 20:06:24 [ERROR] mysqld got exception 0x80000003 ;
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.3.10-MariaDB-debug
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 = 4288 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:485]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:4498]
mariabackup.exe!log_t::files::read_log_seg()[log0recv.cc:689]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:2959]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3226]
mariabackup.exe!srv_start()[srv0start.cc:2001]
mariabackup.exe!innodb_init()[xtrabackup.cc:1870]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5527]
mariabackup.exe!main_low()[xtrabackup.cc:6202]
mariabackup.exe!main()[xtrabackup.cc:5995]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:283]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
 
 
 
The result from queries just before the failure was:
CREATE TABLE t1(i INT PRIMARY KEY auto_increment, a int) ENGINE INNODB;
INSERT INTO t1(a) SELECT * from seq_1_to_10000;
# xtrabackup backup
t1.frm
t1.ibd
t1.new
# xtrabackup prepare

Comment by Elena Stepanova [ 2018-11-12 ]

http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/10893

mariabackup.rename_during_mdl_lock       w1 [ fail ]
        Test ended at 2018-11-10 08:30:07
 
CURRENT_TEST: mariabackup.rename_during_mdl_lock
181110 08:29:59 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: D:/winx64-debug/build/mysql-test/var/tmp/1/mysqld.1.sock
Using server version 10.2.19-MariaDB-debug-log
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.19-MariaDB Win64 (AMD64) 
mariabackup: cd to D:\winx64-debug\build\mysql-test\var\1\mysqld.1\data\
mariabackup: open files limit requested 1024, set to 0
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 = .\
2018-11-10  8:29:59 4748 [Note] InnoDB: Number of pools: 1
mariabackup: Generating a list of tablespaces
2018-11-10  8:29:59 4748 [Warning] InnoDB: Allocated tablespace ID 2 for mysql/innodb_index_stats, old maximum was 0
DDL tracking : delete 33 ".\test\t1_renamed.ibd"
DDL tracking : delete 34 ".\test\t2_renamed.ibd"
DDL tracking : delete 35 ".\test\t3.ibd"
DDL tracking : delete 36 ".\test\t4.ibd"
DDL tracking : delete 38 ".\test\a.ibd"
DDL tracking : delete 37 ".\test\b.ibd"
DDL tracking : delete 40 ".\test\a1.ibd"
DDL tracking : delete 39 ".\test\b1.ibd"
DDL tracking :  create 41 ".\test\t1.ibd": 21000e
DDL tracking :  create 41 ".\test\t1.ibd": 21000e
181110 08:29:59 >> log scanned up to (4727711)
181110 08:29:59 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: D:/winx64-debug/build/mysql-test/var/tmp/1/mysqld.1.sock
181110 08:29:59 Locking MDL for `mysql`.`innodb_index_stats`
181110 08:29:59 Locking MDL for `mysql`.`innodb_table_stats`
181110 08:29:59 Locking MDL for `test`.`t1`
181110 08:29:59 Warning : locking MDL failed for space id 41, name `test`.`t1`
181110 08:29:59 [01] Copying ibdata1 to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\ibdata1
181110 08:29:59 [01]        ...done
181110 08:29:59 [01] Copying .\mysql\innodb_index_stats.ibd to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\innodb_index_stats.ibd
181110 08:29:59 [01]        ...done
181110 08:29:59 [01] Copying .\mysql\innodb_table_stats.ibd to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\innodb_table_stats.ibd
181110 08:29:59 [01]        ...done
181110 08:29:59 [01] Copying .\test\t1.ibd to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\test\t1.ibd
181110 08:30:00 [01]        ...done
DDL tracking : rename 41 ".\test\t1.ibd",".\test\t2.ibd"
DDL tracking : rename 41 ".\test\t1.ibd",".\test\t2.ibd"
181110 08:30:00 >> log scanned up to (4729096)
181110 08:30:00 Executing FLUSH NO_WRITE_TO_BINLOG TABLES...
181110 08:30:00 Executing FLUSH TABLES WITH READ LOCK...
181110 08:30:00 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: D:/winx64-debug/build/mysql-test/var/tmp/1/mysqld.1.sock
181110 08:30:00 Kill mdl waiters thread stopped
181110 08:30:01 Starting to backup non-InnoDB tables and files
181110 08:30:01 [01] Copying .\mtr\db.opt to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\db.opt
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\global_suppressions.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\global_suppressions.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\global_suppressions.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\global_suppressions.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\global_suppressions.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\global_suppressions.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\global_suppressions.TRG to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\global_suppressions.TRG
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\gs_insert.TRN to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\gs_insert.TRN
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\test_suppressions.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\test_suppressions.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\test_suppressions.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\test_suppressions.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\test_suppressions.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\test_suppressions.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\test_suppressions.TRG to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\test_suppressions.TRG
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mtr\ts_insert.TRN to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mtr\ts_insert.TRN
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\columns_priv.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\columns_priv.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\columns_priv.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\columns_priv.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\columns_priv.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\columns_priv.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\column_stats.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\column_stats.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\column_stats.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\column_stats.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\column_stats.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\column_stats.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\db.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\db.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\db.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\db.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\db.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\db.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\event.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\event.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\event.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\event.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\event.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\event.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\func.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\func.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\func.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\func.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\func.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\func.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\general_log.CSM to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\general_log.CSM
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\general_log.CSV to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\general_log.CSV
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\general_log.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\general_log.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\gtid_slave_pos.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\gtid_slave_pos.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\gtid_slave_pos.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\gtid_slave_pos.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\gtid_slave_pos.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\gtid_slave_pos.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_category.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_category.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_category.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_category.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_category.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_category.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_keyword.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_keyword.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_keyword.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_keyword.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_keyword.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_keyword.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_relation.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_relation.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_relation.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_relation.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_relation.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_relation.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_topic.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_topic.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_topic.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_topic.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\help_topic.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\help_topic.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\host.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\host.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\host.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\host.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\host.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\host.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\index_stats.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\index_stats.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\index_stats.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\index_stats.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\index_stats.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\index_stats.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\innodb_index_stats.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\innodb_index_stats.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\innodb_table_stats.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\innodb_table_stats.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\plugin.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\plugin.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\plugin.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\plugin.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\plugin.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\plugin.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\proc.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\proc.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\proc.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\proc.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\proc.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\proc.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\procs_priv.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\procs_priv.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\procs_priv.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\procs_priv.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\procs_priv.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\procs_priv.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\proxies_priv.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\proxies_priv.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\proxies_priv.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\proxies_priv.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\proxies_priv.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\proxies_priv.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\roles_mapping.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\roles_mapping.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\roles_mapping.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\roles_mapping.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\roles_mapping.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\roles_mapping.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\servers.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\servers.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\servers.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\servers.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\servers.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\servers.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\slow_log.CSM to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\slow_log.CSM
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\slow_log.CSV to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\slow_log.CSV
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\slow_log.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\slow_log.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\tables_priv.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\tables_priv.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\tables_priv.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\tables_priv.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\tables_priv.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\tables_priv.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\table_stats.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\table_stats.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\table_stats.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\table_stats.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\table_stats.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\table_stats.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_leap_second.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_leap_second.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_leap_second.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_leap_second.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_leap_second.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_leap_second.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_name.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_name.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_name.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_name.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_name.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_name.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_transition.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_transition.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_transition.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_transition.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_transition.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_transition.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_transition_type.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_transition_type.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_transition_type.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_transition_type.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\time_zone_transition_type.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\time_zone_transition_type.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\user.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\user.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\user.MYD to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\user.MYD
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\mysql\user.MYI to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\mysql\user.MYI
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\performance_schema\db.opt to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\performance_schema\db.opt
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\test\db.opt to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\test\db.opt
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying .\test\t2.frm to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\test\t2.frm
181110 08:30:01 [01]        ...done
181110 08:30:01 Finished backing up non-InnoDB tables and files
181110 08:30:01 [01] Copying aria_log.00000001 to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\aria_log.00000001
181110 08:30:01 [01]        ...done
181110 08:30:01 [01] Copying aria_log_control to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\aria_log_control
181110 08:30:01 [01]        ...done
181110 08:30:01 Waiting for log copy thread to read lsn 4729096
181110 08:30:01 >> log scanned up to (4729096)
181110 08:30:01 [00] Writing test/t1.ren
181110 08:30:01 [00]        ...done
181110 08:30:01 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
mariabackup: The latest check point (for incremental): '4724579'
mariabackup: Stopping log copying thread.181110 08:30:01 >> log scanned up to (4729096)
 
181110 08:30:02 >> log scanned up to (4729096)
181110 08:30:02 Executing UNLOCK TABLES
181110 08:30:02 All tables unlocked
181110 08:30:02 Unlocking MDL for all tables
181110 08:30:02 [00] Copying ib_buffer_pool to D:\winx64-debug\build\mysql-test\var\1\tmp\backup\ib_buffer_pool
181110 08:30:02 [00]        ...done
181110 08:30:02 Backup created in directory 'D:\winx64-debug\build\mysql-test\var\1\tmp\backup\'
181110 08:30:02 [00] Writing backup-my.cnf
181110 08:30:02 [00]        ...done
181110 08:30:02 [00] Writing xtrabackup_info
181110 08:30:02 [00]        ...done
mariabackup: Redo log (from LSN 4717068 to 4729096) was copied.
181110 08:30:02 completed OK!
mysqltest: At line 9: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/winx64-debug/build/mysql-test/var/1/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.19-MariaDB Win64 (AMD64) 
mariabackup: cd to D:/winx64-debug/build/mysql-test/var/1/tmp/backup/
Renaming ./test/t1.ibd to ./test/t2.ibd
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-11-10  8:30:02 4720 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2018-11-10  8:30:02 4720 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-11-10  8:30:02 4720 [Note] InnoDB: Uses event mutexes
2018-11-10  8:30:02 4720 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-11-10  8:30:02 4720 [Note] InnoDB: Number of pools: 1
2018-11-10  8:30:02 4720 [Note] InnoDB: Using SSE2 crc32 instructions
2018-11-10  8:30:02 4720 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-11-10  8:30:02 4720 [Note] InnoDB: Completed initialization of buffer pool
2018-11-10  8:30:02 4720 [Note] InnoDB: Highest supported file format is Barracuda.
2018-11-10 08:30:02 0x1270  InnoDB: Assertion failure in file d:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 5225
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
181110  8:30:02 [ERROR] mysqld got exception 0x80000003 ;
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.2.19-MariaDB-debug
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 = 5001 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:487]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:62]
mariabackup.exe!fil_io()[fil0fil.cc:5225]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:803]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3195]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3486]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2218]
mariabackup.exe!innodb_init()[xtrabackup.cc:1965]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5649]
mariabackup.exe!main_low()[xtrabackup.cc:6338]
mariabackup.exe!main()[xtrabackup.cc:6131]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:288]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
 
 
 
The result from queries just before the failure was:
CREATE TABLE t1(i int) ENGINE INNODB;
# xtrabackup prepare

Comment by Elena Stepanova [ 2018-12-21 ]

http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/11027

mariabackup.absolute_ibdata_paths        w2 [ fail ]
        Test ended at 2018-11-20 00:40:06
 
CURRENT_TEST: mariabackup.absolute_ibdata_paths
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.20-MariaDB Win64 (AMD64) 
mariabackup: cd to D:\winx64-debug\build\mysql-test\var\2\tmp\backup\
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = absolute_path_ibdata1:3M;ibdata_second:1M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-11-20  0:39:57 6828 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2018-11-20  0:39:57 6828 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-11-20  0:39:57 6828 [Note] InnoDB: Uses event mutexes
2018-11-20  0:39:57 6828 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-11-20  0:39:57 6828 [Note] InnoDB: Number of pools: 1
2018-11-20  0:39:57 6828 [Note] InnoDB: Using SSE2 crc32 instructions
2018-11-20  0:39:57 6828 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-11-20  0:39:57 6828 [Note] InnoDB: Completed initialization of buffer pool
2018-11-20  0:39:57 6828 [Note] InnoDB: Opened 2 undo tablespaces
2018-11-20  0:39:57 6828 [Note] InnoDB: Highest supported file format is Barracuda.
2018-11-20 00:39:57 0x1aac  InnoDB: Assertion failure in file d:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 5221
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
181120  0:39:57 [ERROR] mysqld got exception 0x80000003 ;
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.2.20-MariaDB-debug
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 = 5001 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:487]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:61]
mariabackup.exe!fil_io()[fil0fil.cc:5221]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:801]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3193]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3484]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2214]
mariabackup.exe!innodb_init()[xtrabackup.cc:1965]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5649]
mariabackup.exe!main_low()[xtrabackup.cc:6338]
mariabackup.exe!main()[xtrabackup.cc:6131]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:288]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
mysqltest: At line 15: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/winx64-debug/build/mysql-test/var/2/tmp/backup' failed, error: 255, status: 255, errno: 0

Comment by Elena Stepanova [ 2019-01-04 ]

http://buildbot.askmonty.org/buildbot/builders/winx64-debug/builds/11468

mariabackup.system_versioning            w4 [ fail ]
        Test ended at 2018-12-18 14:27:06
 
CURRENT_TEST: mariabackup.system_versioning
mysqltest: At line 14: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/winx64-debug/build/mysql-test/var/4/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 0
Output from before failure:
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.3.12-MariaDB Win64 (AMD64) 
mariabackup: cd to D:/winx64-debug/build/mysql-test/var/4/tmp/backup/
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2018-12-18 14:27:01 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2018-12-18 14:27:01 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2018-12-18 14:27:01 0 [Note] InnoDB: Uses event mutexes
2018-12-18 14:27:01 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-12-18 14:27:01 0 [Note] InnoDB: Number of pools: 1
2018-12-18 14:27:01 0 [Note] InnoDB: Using SSE2 crc32 instructions
2018-12-18 14:27:01 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-12-18 14:27:01 0 [Note] InnoDB: Completed initialization of buffer pool
2018-12-18 14:27:01 0x574  InnoDB: Assertion failure in file d:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 4420
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/
InnoDB: about forcing recovery.
181218 14:27:01 [ERROR] mysqld got exception 0x80000003 ;
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.3.12-MariaDB-debug
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 = 5121 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:485]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:71]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:61]
mariabackup.exe!fil_io()[fil0fil.cc:4420]
mariabackup.exe!log_t::files::read_log_seg()[log0recv.cc:777]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3120]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3389]
mariabackup.exe!srv_start()[srv0start.cc:1949]
mariabackup.exe!innodb_init()[xtrabackup.cc:1960]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5560]
mariabackup.exe!main_low()[xtrabackup.cc:6395]
mariabackup.exe!main()[xtrabackup.cc:6188]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:288]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlUserThreadStart()
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.
 
 
 
The result from queries just before the failure was:
create table t (a int) with system versioning;
insert into t values (1);
update t set a=2;
insert into t values (3);

Comment by Elena Stepanova [ 2019-01-04 ]

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/11932

mariabackup.innodb_log_optimize_ddl 'innodb' w4 [ fail ]
        Test ended at 2019-01-02 20:41:45
 
CURRENT_TEST: mariabackup.innodb_log_optimize_ddl
D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.22-MariaDB Win32 (AMD64) 
mariabackup: cd to D:\win32-debug\build\mysql-test\var\4\tmp\backup\
mariabackup: This target seems to be not prepared yet.
mariabackup: using the following InnoDB configuration for recovery:
mariabackup:   innodb_data_home_dir = .
mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
mariabackup:   innodb_log_group_home_dir = .
mariabackup: Starting InnoDB instance for recovery.
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2019-01-02 20:41:42 7660 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2019-01-02 20:41:42 7660 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-01-02 20:41:42 7660 [Note] InnoDB: Uses event mutexes
2019-01-02 20:41:42 7660 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-01-02 20:41:42 7660 [Note] InnoDB: Number of pools: 1
2019-01-02 20:41:42 7660 [Note] InnoDB: Using SSE2 crc32 instructions
2019-01-02 20:41:42 7660 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2019-01-02 20:41:42 7660 [Note] InnoDB: Completed initialization of buffer pool
2019-01-02 20:41:42 7660 [Note] InnoDB: Highest supported file format is Barracuda.
2019-01-02 20:41:42 0x1dec  InnoDB: Assertion failure in file d:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 5158
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
190102 20:41:42 [ERROR] mysqld got exception 0x80000003 ;
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.2.22-MariaDB-debug
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 = 4193 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:487]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:61]
mariabackup.exe!fil_io()[fil0fil.cc:5158]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:784]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3172]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3464]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2188]
mariabackup.exe!innodb_init()[xtrabackup.cc:1990]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5637]
mariabackup.exe!main_low()[xtrabackup.cc:6484]
mariabackup.exe!main()[xtrabackup.cc:6277]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:288]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
mysqltest: At line 33: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/win32-debug/build/mysql-test/var/4/tmp/backup' failed, error: 255, status: 255, errno: 2
Output from before failure:
 
 
 
The result from queries just before the failure was:
< snip >
INSERT INTO tz(id) select * from seq_1_to_10000;
CREATE TABLE tr(id BIGINT PRIMARY KEY, i INT)
ENGINE=InnoDB ROW_FORMAT=REDUNDANT;
INSERT INTO tr(id) select * from seq_1_to_10000;
CREATE TABLE td(id BIGINT PRIMARY KEY, i INT)
ENGINE=InnoDB;
INSERT INTO td(id) select * from seq_1_to_10000;
CREATE PROCEDURE a()
BEGIN
ALTER TABLE tz ADD INDEX(i);
ALTER TABLE tr ADD INDEX(i);
ALTER TABLE td ADD INDEX(i);
END //
call a();

Comment by Marko Mäkelä [ 2019-02-01 ]

MDEV-18370 reports a case of this in InnoDB redo log scrubbing (apparently not involving mariabackup at all). Could log scrubbing be what is causing this issue? Log scrubbing was introduced in MariaDB 10.1.3.

Comment by Marko Mäkelä [ 2019-03-06 ]

I think that this can happen in any mariabackup test. Here is one more occurrence from (almost) 10.4:

CURRENT_TEST: mariabackup.rename_during_backup
mysqltest: At line 50: exec of 'D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/winx64-debug/build/mysql-test/var/1/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/winx64-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.4.4-MariaDB Win64 (AMD64)
[00] 2019-03-05 20:38:12 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2019-03-05 20:38:12 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2019-03-05 20:38:12 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-03-05 20:38:12 0 [Note] InnoDB: Uses event mutexes
2019-03-05 20:38:12 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-03-05 20:38:12 0 [Note] InnoDB: Number of pools: 1
2019-03-05 20:38:12 0 [Note] InnoDB: Using SSE2 crc32 instructions
2019-03-05 20:38:12 0 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2019-03-05 20:38:12 0 [Note] InnoDB: Completed initialization of buffer pool
2019-03-05 20:38:13 0x16f4  InnoDB: Assertion failure in file D:\winx64-debug\build\src\storage\innobase\fil\fil0fil.cc line 4317
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0

Comment by Elena Stepanova [ 2019-03-06 ]

It does happen in nearly every mariabackup test. Can we have it fixed?

Comment by Elena Stepanova [ 2019-03-22 ]

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/13048

10.2 5e044f78c0a9a8cd40dedff0e4bc857c

mariabackup.drop_table_during_backup     w4 [ fail ]
        Test ended at 2019-03-16 22:51:12
 
CURRENT_TEST: mariabackup.drop_table_during_backup
mysqltest: At line 20: exec of 'D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe  --prepare --target-dir=D:/win32-debug/build/mysql-test/var/4/tmp/backup 2>&1' failed, error: 255, status: 255, errno: 2
Output from before failure:
D:/win32-debug/build/extra/mariabackup/Debug/mariabackup.exe based on MariaDB server 10.2.23-MariaDB Win32 (AMD64)
[00] 2019-03-16 22:51:08 cd to D:/win32-debug/build/mysql-test/var/4/tmp/backup/
[00] 2019-03-16 22:51:08 Renaming ./test/t4.ibd to ./test/t5.ibd
 
[00] 2019-03-16 22:51:08 This target seems to be not prepared yet.
[00] 2019-03-16 22:51:08 mariabackup: using the following InnoDB configuration for recovery:
[00] 2019-03-16 22:51:08 innodb_data_home_dir = .
[00] 2019-03-16 22:51:08 innodb_data_file_path = ibdata1:12M:autoextend
[00] 2019-03-16 22:51:08 innodb_log_group_home_dir = .
[00] 2019-03-16 22:51:08 Starting InnoDB instance for recovery.
[00] 2019-03-16 22:51:08 mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
2019-03-16 22:51:08 5892 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2019-03-16 22:51:08 5892 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
2019-03-16 22:51:08 5892 [Note] InnoDB: Uses event mutexes
2019-03-16 22:51:08 5892 [Note] InnoDB: Compressed tables use zlib 1.2.11
2019-03-16 22:51:08 5892 [Note] InnoDB: Number of pools: 1
2019-03-16 22:51:08 5892 [Note] InnoDB: Using SSE2 crc32 instructions
2019-03-16 22:51:08 5892 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2019-03-16 22:51:09 5892 [Note] InnoDB: Completed initialization of buffer pool
2019-03-16 22:51:09 5892 [Note] InnoDB: Highest supported file format is Barracuda.
2019-03-16 22:51:09 0x1704  InnoDB: Assertion failure in file D:\win32-debug\build\src\storage\innobase\fil\fil0fil.cc line 5117
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
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: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
190316 22:51:09 [ERROR] mysqld got exception 0x80000003 ;
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.2.23-MariaDB-debug
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 = 4194 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...
mariabackup.exe!my_sigabrt_handler()[my_thr_init.c:487]
mariabackup.exe!raise()[signal.cpp:516]
mariabackup.exe!abort()[abort.cpp:64]
mariabackup.exe!ut_dbg_assertion_failed()[ut0dbg.cc:61]
mariabackup.exe!fil_io()[fil0fil.cc:5117]
mariabackup.exe!log_group_read_log_seg()[log0recv.cc:793]
mariabackup.exe!recv_group_scan_log_recs()[log0recv.cc:3197]
mariabackup.exe!recv_recovery_from_checkpoint_start()[log0recv.cc:3489]
mariabackup.exe!innobase_start_or_create_for_mysql()[srv0start.cc:2192]
mariabackup.exe!innodb_init()[xtrabackup.cc:1995]
mariabackup.exe!xtrabackup_prepare_func()[xtrabackup.cc:5579]
mariabackup.exe!main_low()[xtrabackup.cc:6406]
mariabackup.exe!main()[xtrabackup.cc:6199]
mariabackup.exe!__scrt_common_main_seh()[exe_common.inl:288]
KERNEL32.DLL!BaseThreadInitThunk()
ntdll.dll!RtlInitializeExceptionChain()
ntdll.dll!RtlInitializeExceptionChain()
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.
 
 
 
The result from queries just before the failure was:
CREATE TABLE t1 (i int) ENGINE=INNODB;
CREATE TABLE t2 (i int) ENGINE=INNODB;
CREATE TABLE t3 (i int) ENGINE=INNODB;
CREATE TABLE t4 (i int) ENGINE=INNODB;
CREATE TABLE t5 (i int) ENGINE=INNODB;
# xtrabackup prepare

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

The initial fix did not seem to help. Here is a failure:

10.3 4dc10ec68d354241768ce4779c024b4bb2ca897b

2019-04-12 10:49:54 0x564  InnoDB: Assertion failure in file d:\winx64-packages\build\src\storage\innobase\fil\fil0fil.cc line 4359
InnoDB: Failing assertion: byte_offset % OS_FILE_LOG_BLOCK_SIZE == 0

Comment by Elena Stepanova [ 2019-05-07 ]

Another victim: mariabackup.create_with_data_directory_during_backup on 10.2 c676f58c

Comment by Vladislav Lesin [ 2019-05-24 ]

Pushed new fix in 10.2: bff9b8026bd69f44d62d0eb33364d4a1ca1788f4. The fix is still under the question because I failed to create stable test case for it.

Comment by Vladislav Lesin [ 2019-06-11 ]

elenst, marko Did you see the failures after the fix was pushed?

Comment by Vladislav Lesin [ 2019-06-19 ]

elenst:
I can't say yet, I mainly see those failures in my pre-release chores, and there haven't been any pre-release chores since the fix. Anyway, it's mainly for the cross-reference to tell. If it doesn't show anything yet, you can close it right away and we'll open a new one if it happens again

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