************************************************************************ Testing incremental backup with compressed page size=1KB ************************************************************************ 2012-07-09 16:07:09: xb_incremental_compressed.sh: Starting server with id=1... 2012-07-09 16:07:09: xb_incremental_compressed.sh: Creating server root directory: /home/laurynas/percona/src/bug1021249-2.0/test/var1 2012-07-09 16:07:09: xb_incremental_compressed.sh: Creating server temporary directory: /home/laurynas/percona/src/bug1021249-2.0/test/var1/tmp 2012-07-09 16:07:09: xb_incremental_compressed.sh: Creating server data directory: /home/laurynas/percona/src/bug1021249-2.0/test/var1/data 2012-07-09 16:07:09: xb_incremental_compressed.sh: Calling mysql_install_db Installing MySQL system tables... 120709 16:07:09 [Note] Flashcache bypass: disabled 120709 16:07:09 [Note] Flashcache setup error is : open flash device failed OK Filling help tables... 120709 16:07:09 [Note] Flashcache bypass: disabled 120709 16:07:09 [Note] Flashcache setup error is : open flash device failed OK To start mysqld at boot time you have to copy support-files/mysql.server to the right place for your system PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER ! To do so, start the server, then issue the following commands: /home/laurynas/percona/src/bug1021249-2.0/test/server/bin/mysqladmin -u root password 'new-password' /home/laurynas/percona/src/bug1021249-2.0/test/server/bin/mysqladmin -u root -h laurynas-ThinkPad-T410 password 'new-password' Alternatively you can run: /home/laurynas/percona/src/bug1021249-2.0/test/server/bin/mysql_secure_installation which will also give you the option of removing the test databases and anonymous user created by default. This is strongly recommended for production servers. See the manual for more instructions. You can start the MySQL daemon with: cd /home/laurynas/percona/src/bug1021249-2.0/test/server ; /home/laurynas/percona/src/bug1021249-2.0/test/server/bin/mysqld_safe & You can test the MySQL daemon with mysql-test-run.pl cd /home/laurynas/percona/src/bug1021249-2.0/test/server/mysql-test ; perl mysql-test-run.pl Please report any problems with the /home/laurynas/percona/src/bug1021249-2.0/test/server/scripts/mysqlbug script! Percona recommends that all production deployments be protected with a support contract (http://www.percona.com/mysql-suppport/) to ensure the highest uptime, be eligible for hot fixes, and boost your team's productivity. 120709 16:07:09 [Note] Flashcache bypass: disabled 120709 16:07:09 [Note] Flashcache setup error is : open flash device failed 120709 16:07:09 [Note] Plugin 'FEDERATED' is disabled. InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins InnoDB: Compressed tables use zlib 1.2.3 120709 16:07:09 InnoDB: Initializing buffer pool, size = 128.0M 120709 16:07:09 InnoDB: Completed initialization of buffer pool InnoDB: The first specified data file ./ibdata1 did not exist: InnoDB: a new database to be created! 120709 16:07:09 InnoDB: Setting file ./ibdata1 size to 10 MB InnoDB: Database physically writes the file full: wait... 120709 16:07:09 InnoDB: Log file ./ib_logfile0 did not exist: new to be created InnoDB: Setting log file ./ib_logfile0 size to 5 MB InnoDB: Database physically writes the file full: wait... 120709 16:07:10 InnoDB: Log file ./ib_logfile1 did not exist: new to be created InnoDB: Setting log file ./ib_logfile1 size to 5 MB InnoDB: Database physically writes the file full: wait... InnoDB: Doublewrite buffer not found: creating new InnoDB: Doublewrite buffer created InnoDB: Creating foreign key constraint system tables InnoDB: Foreign key constraint system tables created 120709 16:07:10 Percona XtraDB (http://www.percona.com) 1.0.17-rel13.1 started; log sequence number 0 120709 16:07:10 [Note] Event Scheduler: Loaded 0 events 120709 16:07:10 [Note] /home/laurynas/percona/src/bug1021249-2.0/test/server/libexec/mysqld: ready for connections. Version: '5.1.60rel13.1-log' socket: '/tmp/xtrabackup.mysql.sock.9rcCVn' port: 30566 Percona Server with XtraDB (GPL), Release rel13.1, Revision 413 2012-07-09 16:07:14: xb_incremental_compressed.sh: Server with id=1 has been started on port 30566, socket /tmp/xtrabackup.mysql.sock.9rcCVn 2012-07-09 16:07:14: xb_incremental_compressed.sh: Loading incremental_sample database schema 2012-07-09 16:07:14: xb_incremental_compressed.sh: Compressing the table 2012-07-09 16:07:14: xb_incremental_compressed.sh: ===> /home/laurynas/percona/src/bug1021249-2.0/test/server/bin/mysql --no-defaults --socket=/tmp/xtrabackup.mysql.sock.9rcCVn --user=root -e ALTER TABLE test ENGINE=InnoDB ROW_FORMAT=compressed KEY_BLOCK_SIZE=1 incremental_sample 2012-07-09 16:07:14: xb_incremental_compressed.sh: Adding initial rows to database... 2012-07-09 16:07:16: xb_incremental_compressed.sh: Initial rows added 2012-07-09 16:07:16: xb_incremental_compressed.sh: Starting backup 2012-07-09 16:07:16: xb_incremental_compressed.sh: ===> /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup --no-defaults --datadir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data --backup --target-dir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup version 2.0.0 for Percona Server 5.1.59 unknown-linux-gnu (x86_64) (revision id: undefined) xtrabackup: uses posix_fadvise(). xtrabackup: cd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data xtrabackup: Target instance is assumed as followings. xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend xtrabackup: innodb_log_group_home_dir = ./ xtrabackup: innodb_log_files_in_group = 2 xtrabackup: innodb_log_file_size = 5242880 120709 16:07:16 InnoDB: Warning: allocated tablespace 11, old maximum was 9 >> log scanned up to (1618746) [01] Copying ./ibdata1 to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full/ibdata1 [01] ...done [01] ./incremental_sample/test.ibd is compressed with page size = 1024 bytes [01] Copying ./incremental_sample/test.ibd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full/./incremental_sample/test.ibd [01] ...done xtrabackup: The latest check point (for incremental): '45342' xtrabackup: Stopping log copying thread. .>> log scanned up to (1618746) xtrabackup: Transaction log of lsn (45342) to (1618746) was copied. 2012-07-09 16:07:18: xb_incremental_compressed.sh: Full backup done 2012-07-09 16:07:18: xb_incremental_compressed.sh: Making changes to database 2012-07-09 16:07:19: xb_incremental_compressed.sh: Changes done 2012-07-09 16:07:19: xb_incremental_compressed.sh: Table 'test' checksum is 3194601875 2012-07-09 16:07:19: xb_incremental_compressed.sh: Table 't2' checksum is 3186283803 2012-07-09 16:07:19: xb_incremental_compressed.sh: Making incremental backup 2012-07-09 16:07:19: xb_incremental_compressed.sh: ===> /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup --no-defaults --datadir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data --backup --target-dir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta --incremental-basedir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup version 2.0.0 for Percona Server 5.1.59 unknown-linux-gnu (x86_64) (revision id: undefined) incremental backup from 45342 is enabled. xtrabackup: uses posix_fadvise(). xtrabackup: cd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data xtrabackup: Target instance is assumed as followings. xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend xtrabackup: innodb_log_group_home_dir = ./ xtrabackup: innodb_log_files_in_group = 2 xtrabackup: innodb_log_file_size = 5242880 120709 16:07:20 InnoDB: Warning: allocated tablespace 11, old maximum was 9 >> log scanned up to (3218916) [01] Copying ./ibdata1 to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/ibdata1.delta [01] xtrabackup: Page 64 seems double write buffer. passing the check. [01] xtrabackup: Page 65 seems double write buffer. passing the check. [01] xtrabackup: Page 66 seems double write buffer. passing the check. [01] xtrabackup: Page 67 seems double write buffer. passing the check. [01] xtrabackup: Page 68 seems double write buffer. passing the check. [01] xtrabackup: Page 69 seems double write buffer. passing the check. [01] xtrabackup: Page 70 seems double write buffer. passing the check. [01] xtrabackup: Page 71 seems double write buffer. passing the check. [01] xtrabackup: Page 72 seems double write buffer. passing the check. [01] xtrabackup: Page 73 seems double write buffer. passing the check. [01] xtrabackup: Page 74 seems double write buffer. passing the check. [01] xtrabackup: Page 75 seems double write buffer. passing the check. [01] xtrabackup: Page 76 seems double write buffer. passing the check. [01] xtrabackup: Page 77 seems double write buffer. passing the check. [01] xtrabackup: Page 78 seems double write buffer. passing the check. [01] xtrabackup: Page 79 seems double write buffer. passing the check. [01] xtrabackup: Page 80 seems double write buffer. passing the check. [01] xtrabackup: Page 81 seems double write buffer. passing the check. [01] xtrabackup: Page 82 seems double write buffer. passing the check. [01] xtrabackup: Page 83 seems double write buffer. passing the check. [01] xtrabackup: Page 84 seems double write buffer. passing the check. [01] xtrabackup: Page 85 seems double write buffer. passing the check. [01] xtrabackup: Page 86 seems double write buffer. passing the check. [01] xtrabackup: Page 87 seems double write buffer. passing the check. [01] xtrabackup: Page 88 seems double write buffer. passing the check. [01] xtrabackup: Page 89 seems double write buffer. passing the check. [01] xtrabackup: Page 90 seems double write buffer. passing the check. [01] xtrabackup: Page 91 seems double write buffer. passing the check. [01] xtrabackup: Page 92 seems double write buffer. passing the check. [01] xtrabackup: Page 93 seems double write buffer. passing the check. [01] xtrabackup: Page 94 seems double write buffer. passing the check. [01] xtrabackup: Page 95 seems double write buffer. passing the check. [01] xtrabackup: Page 96 seems double write buffer. passing the check. [01] xtrabackup: Page 97 seems double write buffer. passing the check. [01] xtrabackup: Page 98 seems double write buffer. passing the check. [01] xtrabackup: Page 99 seems double write buffer. passing the check. [01] xtrabackup: Page 100 seems double write buffer. passing the check. [01] xtrabackup: Page 101 seems double write buffer. passing the check. [01] xtrabackup: Page 102 seems double write buffer. passing the check. [01] xtrabackup: Page 103 seems double write buffer. passing the check. [01] xtrabackup: Page 104 seems double write buffer. passing the check. [01] xtrabackup: Page 105 seems double write buffer. passing the check. [01] xtrabackup: Page 106 seems double write buffer. passing the check. [01] xtrabackup: Page 107 seems double write buffer. passing the check. [01] xtrabackup: Page 108 seems double write buffer. passing the check. [01] xtrabackup: Page 109 seems double write buffer. passing the check. [01] xtrabackup: Page 110 seems double write buffer. passing the check. [01] xtrabackup: Page 111 seems double write buffer. passing the check. [01] xtrabackup: Page 112 seems double write buffer. passing the check. [01] xtrabackup: Page 113 seems double write buffer. passing the check. [01] xtrabackup: Page 114 seems double write buffer. passing the check. [01] xtrabackup: Page 115 seems double write buffer. passing the check. [01] xtrabackup: Page 116 seems double write buffer. passing the check. [01] xtrabackup: Page 117 seems double write buffer. passing the check. [01] xtrabackup: Page 118 seems double write buffer. passing the check. [01] xtrabackup: Page 119 seems double write buffer. passing the check. [01] xtrabackup: Page 120 seems double write buffer. passing the check. [01] xtrabackup: Page 121 seems double write buffer. passing the check. [01] xtrabackup: Page 122 seems double write buffer. passing the check. [01] xtrabackup: Page 123 seems double write buffer. passing the check. [01] xtrabackup: Page 124 seems double write buffer. passing the check. [01] xtrabackup: Page 125 seems double write buffer. passing the check. [01] xtrabackup: Page 126 seems double write buffer. passing the check. [01] xtrabackup: Page 127 seems double write buffer. passing the check. [01] xtrabackup: Page 128 seems double write buffer. passing the check. [01] xtrabackup: Page 129 seems double write buffer. passing the check. [01] xtrabackup: Page 130 seems double write buffer. passing the check. [01] xtrabackup: Page 131 seems double write buffer. passing the check. [01] xtrabackup: Page 132 seems double write buffer. passing the check. [01] xtrabackup: Page 133 seems double write buffer. passing the check. [01] xtrabackup: Page 134 seems double write buffer. passing the check. [01] xtrabackup: Page 135 seems double write buffer. passing the check. [01] xtrabackup: Page 136 seems double write buffer. passing the check. [01] xtrabackup: Page 137 seems double write buffer. passing the check. [01] xtrabackup: Page 138 seems double write buffer. passing the check. [01] xtrabackup: Page 139 seems double write buffer. passing the check. [01] xtrabackup: Page 140 seems double write buffer. passing the check. [01] xtrabackup: Page 141 seems double write buffer. passing the check. [01] xtrabackup: Page 142 seems double write buffer. passing the check. [01] xtrabackup: Page 143 seems double write buffer. passing the check. [01] xtrabackup: Page 144 seems double write buffer. passing the check. [01] xtrabackup: Page 145 seems double write buffer. passing the check. [01] xtrabackup: Page 146 seems double write buffer. passing the check. [01] xtrabackup: Page 147 seems double write buffer. passing the check. [01] xtrabackup: Page 148 seems double write buffer. passing the check. [01] xtrabackup: Page 149 seems double write buffer. passing the check. [01] xtrabackup: Page 150 seems double write buffer. passing the check. [01] xtrabackup: Page 151 seems double write buffer. passing the check. [01] xtrabackup: Page 152 seems double write buffer. passing the check. [01] xtrabackup: Page 153 seems double write buffer. passing the check. [01] xtrabackup: Page 154 seems double write buffer. passing the check. [01] ...done [01] ./incremental_sample/test.ibd is compressed with page size = 1024 bytes [01] Copying ./incremental_sample/test.ibd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/./incremental_sample/test.ibd.delta [01] ...done [01] ./incremental_sample/t2.ibd is compressed with page size = 1024 bytes [01] Copying ./incremental_sample/t2.ibd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/./incremental_sample/t2.ibd.delta [01] ...done xtrabackup: The latest check point (for incremental): '45342' xtrabackup: Stopping log copying thread. .>> log scanned up to (3218972) xtrabackup: Transaction log of lsn (45342) to (3218972) was copied. 2012-07-09 16:07:21: xb_incremental_compressed.sh: Incremental backup done 2012-07-09 16:07:21: xb_incremental_compressed.sh: Preparing backup 2012-07-09 16:07:21: xb_incremental_compressed.sh: ===> /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup --no-defaults --datadir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data --prepare --apply-log-only --target-dir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup version 2.0.0 for Percona Server 5.1.59 unknown-linux-gnu (x86_64) (revision id: undefined) xtrabackup: cd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full xtrabackup: This target seems to be not prepared yet. xtrabackup: xtrabackup_logfile detected: size=2097152, start_lsn=(45342) xtrabackup: Temporary instance for recovery is set as followings. xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend xtrabackup: innodb_log_group_home_dir = ./ xtrabackup: innodb_log_files_in_group = 1 xtrabackup: innodb_log_file_size = 2097152 xtrabackup: Starting InnoDB instance for recovery. xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter) InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins InnoDB: Compressed tables use zlib 1.2.3 InnoDB: Warning: innodb_file_io_threads is deprecated. Please use innodb_read_io_threads and innodb_write_io_threads instead 120709 16:07:21 InnoDB: Initializing buffer pool, size = 100.0M 120709 16:07:21 InnoDB: Completed initialization of buffer pool 120709 16:07:21 InnoDB: highest supported file format is Barracuda. InnoDB: Log scan progressed past the checkpoint lsn 45342 120709 16:07:21 InnoDB: Database was not shut down normally! InnoDB: Starting crash recovery. InnoDB: Reading tablespace information from the .ibd files... InnoDB: Doing recovery: scanned up to log sequence number 1618746 (84 %) 120709 16:07:21 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Apply batch completed InnoDB: Last MySQL binlog file position 0 160454, file name ./mysql-bin.000001 [notice (again)] If you use binary log and don't use any hack of group commit, the binary log position seems to be: InnoDB: Last MySQL binlog file position 0 160454, file name ./mysql-bin.000001 xtrabackup: starting shutdown with innodb_fast_shutdown = 1 120709 16:07:21 InnoDB: Starting shutdown... 120709 16:07:22 InnoDB: Shutdown completed; log sequence number 1618746 2012-07-09 16:07:22: xb_incremental_compressed.sh: Log applied to backup 2012-07-09 16:07:22: xb_incremental_compressed.sh: ===> /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup --no-defaults --datadir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data --prepare --apply-log-only --target-dir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full --incremental-dir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup version 2.0.0 for Percona Server 5.1.59 unknown-linux-gnu (x86_64) (revision id: undefined) incremental backup from 45342 is enabled. xtrabackup: cd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full xtrabackup: This target seems to be already prepared. xtrabackup: xtrabackup_logfile detected: size=3571712, start_lsn=(45342) xtrabackup: page size for /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/ibdata1.delta is 16384 bytes Applying /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/ibdata1.delta ... xtrabackup: page size for /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/incremental_sample/test.ibd.delta is 1024 bytes Applying /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/incremental_sample/test.ibd.delta ... xtrabackup: page size for /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/incremental_sample/t2.ibd.delta is 1024 bytes 120709 16:07:22 InnoDB: Operating system error number 2 in a file operation. InnoDB: The error means the system cannot find the path specified. xtrabackup: target data file /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full/incremental_sample/t2.ibd is not found, creating a new one Applying /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta/incremental_sample/t2.ibd.delta ... xtrabackup: Temporary instance for recovery is set as followings. xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend xtrabackup: innodb_log_group_home_dir = /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/delta xtrabackup: innodb_log_files_in_group = 1 xtrabackup: innodb_log_file_size = 3571712 xtrabackup: Starting InnoDB instance for recovery. xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter) InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins InnoDB: Compressed tables use zlib 1.2.3 InnoDB: Warning: innodb_file_io_threads is deprecated. Please use innodb_read_io_threads and innodb_write_io_threads instead 120709 16:07:22 InnoDB: Initializing buffer pool, size = 100.0M 120709 16:07:22 InnoDB: Completed initialization of buffer pool 120709 16:07:22 InnoDB: highest supported file format is Barracuda. InnoDB: Log scan progressed past the checkpoint lsn 45342 120709 16:07:22 InnoDB: Database was not shut down normally! InnoDB: Starting crash recovery. InnoDB: Reading tablespace information from the .ibd files... InnoDB: Error: tablespace id 18446744073709551615 in file ./incremental_sample/t2.ibd is not sensible 120709 16:07:22 InnoDB: Error creating file './incremental_sample/t2.ibd'. 120709 16:07:22 InnoDB: Operating system error number 17 in a file operation. InnoDB: Error number 17 means 'File exists'. InnoDB: Some operating system error numbers are described at InnoDB: http://dev.mysql.com/doc/refman/5.1/en/operating-system-error-codes.html InnoDB: The file already exists though the corresponding table did not InnoDB: exist in the InnoDB data dictionary. Have you moved InnoDB InnoDB: .ibd files around without using the SQL commands InnoDB: DISCARD TABLESPACE and IMPORT TABLESPACE, or did InnoDB: mysqld crash in the middle of CREATE TABLE? You can InnoDB: resolve the problem by removing the file './incremental_sample/t2.ibd' InnoDB: under the 'datadir' of MySQL. InnoDB: Doing recovery: scanned up to log sequence number 3218972 (100 %) 120709 16:07:22 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Apply batch completed InnoDB: Last MySQL binlog file position 0 331453, file name ./mysql-bin.000001 [notice (again)] If you use binary log and don't use any hack of group commit, the binary log position seems to be: InnoDB: Last MySQL binlog file position 0 331453, file name ./mysql-bin.000001 xtrabackup: starting shutdown with innodb_fast_shutdown = 1 120709 16:07:23 InnoDB: Starting shutdown... 120709 16:07:23 InnoDB: Shutdown completed; log sequence number 3218972 2012-07-09 16:07:23: xb_incremental_compressed.sh: Delta applied to backup 2012-07-09 16:07:23: xb_incremental_compressed.sh: ===> /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup --no-defaults --datadir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data --prepare --target-dir=/home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full /home/laurynas/percona/src/bug1021249-2.0/test/../src/xtrabackup version 2.0.0 for Percona Server 5.1.59 unknown-linux-gnu (x86_64) (revision id: undefined) xtrabackup: cd to /home/laurynas/percona/src/bug1021249-2.0/test/var1/data/full xtrabackup: This target seems to be already prepared. xtrabackup: notice: xtrabackup_logfile was already used to '--prepare'. xtrabackup: Temporary instance for recovery is set as followings. xtrabackup: innodb_data_home_dir = ./ xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend xtrabackup: innodb_log_group_home_dir = ./ xtrabackup: innodb_log_files_in_group = 2 xtrabackup: innodb_log_file_size = 5242880 xtrabackup: Starting InnoDB instance for recovery. xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter) InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins InnoDB: Compressed tables use zlib 1.2.3 InnoDB: Warning: innodb_file_io_threads is deprecated. Please use innodb_read_io_threads and innodb_write_io_threads instead 120709 16:07:23 InnoDB: Initializing buffer pool, size = 100.0M 120709 16:07:23 InnoDB: Completed initialization of buffer pool 120709 16:07:23 InnoDB: Log file ./ib_logfile0 did not exist: new to be created InnoDB: Setting log file ./ib_logfile0 size to 5 MB InnoDB: Database physically writes the file full: wait... 120709 16:07:23 InnoDB: Log file ./ib_logfile1 did not exist: new to be created InnoDB: Setting log file ./ib_logfile1 size to 5 MB InnoDB: Database physically writes the file full: wait... 120709 16:07:23 InnoDB: highest supported file format is Barracuda. InnoDB: The log sequence number in ibdata files does not match InnoDB: the log sequence number in the ib_logfiles! 120709 16:07:23 InnoDB: Database was not shut down normally! InnoDB: Starting crash recovery. InnoDB: Reading tablespace information from the .ibd files... InnoDB: Error: tablespace id 18446744073709551615 in file ./incremental_sample/t2.ibd is not sensible InnoDB: Last MySQL binlog file position 0 331453, file name ./mysql-bin.000001 120709 16:07:23 InnoDB: Error: table 'incremental_sample/t2' InnoDB: in InnoDB data dictionary has tablespace id 12, InnoDB: but tablespace with that id or name does not exist. It will be removed from data dictionary. 120709 16:07:23 Percona XtraDB (http://www.percona.com) 1.0.17-12.5 started; log sequence number 3219468 [notice (again)] If you use binary log and don't use any hack of group commit, the binary log position seems to be: InnoDB: Last MySQL binlog file position 0 331453, file name ./mysql-bin.000001 xtrabackup: starting shutdown with innodb_fast_shutdown = 1 120709 16:07:23 InnoDB: Starting shutdown... 120709 16:07:23 InnoDB: Shutdown completed; log sequence number 3219910 2012-07-09 16:07:23: xb_incremental_compressed.sh: Data prepared for restore 2012-07-09 16:07:23: xb_incremental_compressed.sh: Tables cleared 2012-07-09 16:07:23: xb_incremental_compressed.sh: Stopping server with id=1... 120709 16:07:23 [Note] /home/laurynas/percona/src/bug1021249-2.0/test/server/libexec/mysqld: Normal shutdown 120709 16:07:23 [Note] Event Scheduler: Purging the queue. 0 events 120709 16:07:23 InnoDB: Starting shutdown... 120709 16:07:24 InnoDB: Shutdown completed; log sequence number 4779298 120709 16:07:24 [Note] /home/laurynas/percona/src/bug1021249-2.0/test/server/libexec/mysqld: Shutdown complete 2012-07-09 16:07:24: xb_incremental_compressed.sh: Server with id=1 has been stopped 2012-07-09 16:07:25: xb_incremental_compressed.sh: Copying files /home/laurynas/percona/src/bug1021249-2.0/test 2012-07-09 16:07:25: xb_incremental_compressed.sh: Data restored 2012-07-09 16:07:25: xb_incremental_compressed.sh: Starting server with id=1... 120709 16:07:25 [Note] Flashcache bypass: disabled 120709 16:07:25 [Note] Flashcache setup error is : open flash device failed 120709 16:07:25 [Note] Plugin 'FEDERATED' is disabled. InnoDB: The InnoDB memory heap is disabled InnoDB: Mutexes and rw_locks use GCC atomic builtins InnoDB: Compressed tables use zlib 1.2.3 120709 16:07:25 InnoDB: Initializing buffer pool, size = 128.0M 120709 16:07:25 InnoDB: Completed initialization of buffer pool 120709 16:07:25 InnoDB: highest supported file format is Barracuda. 120709 16:07:25 Percona XtraDB (http://www.percona.com) 1.0.17-rel13.1 started; log sequence number 3219910 120709 16:07:25 [Note] Event Scheduler: Loaded 0 events 120709 16:07:25 [Note] /home/laurynas/percona/src/bug1021249-2.0/test/server/libexec/mysqld: ready for connections. Version: '5.1.60rel13.1-log' socket: '/tmp/xtrabackup.mysql.sock.2bO8Ya' port: 30566 Percona Server with XtraDB (GPL), Release rel13.1, Revision 413 2012-07-09 16:07:30: xb_incremental_compressed.sh: Server with id=1 has been started on port 30566, socket /tmp/xtrabackup.mysql.sock.2bO8Ya 2012-07-09 16:07:30: xb_incremental_compressed.sh: Checking checksums 120709 16:07:30 [ERROR] Cannot find or open table incremental_sample/t2 from the internal data dictionary of InnoDB though the .frm file for the table exists. Maybe you have deleted and recreated InnoDB data files but have forgotten to delete the corresponding .frm files of InnoDB tables, or you have moved .frm files to another database? or, the table contains indexes that this version of the engine doesn't support. See http://dev.mysql.com/doc/refman/5.1/en/innodb-troubleshooting.html how you can resolve the problem. 2012-07-09 16:07:30: xb_incremental_compressed.sh: Checksums of table 't2' are not equal 2012-07-09 16:07:30: run.sh: Found a leftover mysqld processes with PID 11093, stopping it