Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1.3, 10.2.4, 10.3.0
-
None
Description
basic tests work, but e.g. if I force checkpoint in xb_file_key_management test by restarting Server right before backup:
--source include/restart_mysqld.inc
|
Then backup operation
exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir |
will not be able parse logs ( note 'aborted at' is bigger than 'recovery from' ):
2017-07-13 16:24:34 139729790940992 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1637690
|
2017-07-13 16:24:34 139729790940992 [ERROR] InnoDB: Incorrect log record type:73
|
2017-07-13 16:24:34 139729790940992 [Warning] InnoDB: Log scan aborted at LSN 1637376
|
2017-07-13 16:24:34 139729790940992 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
|
xtrabackup: innodb_init() returned 11 (Generic error).
|
Full log:
bash-4.2$ ./mtr xb_file_key_management
|
Logging: ./mtr xb_file_key_management
|
vardir: /home/a/spd/_depot/m-tar/10.2.7/mysql-test/var
|
Checking leftover processes...
|
Removing old var directory...
|
Creating var directory '/home/a/spd/_depot/m-tar/10.2.7/mysql-test/var'...
|
Checking supported features...
|
MariaDB Version 10.2.7-MariaDB
|
- SSL connections supported
|
Collecting tests...
|
Installing system database...
|
|
==============================================================================
|
|
TEST RESULT TIME (ms) or COMMENT
|
--------------------------------------------------------------------------
|
|
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
|
mariabackup.xb_file_key_management [ fail ]
|
Test ended at 2017-07-13 16:26:36
|
|
CURRENT_TEST: mariabackup.xb_file_key_management
|
mysqltest: At line 26: exec of '/home/a/spd/_depot/m-tar/10.2.7/bin/mariabackup --prepare --target-dir=/home/a/spd/_depot/m-tar/10.2.7/mysql-test/var/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 11
|
Output from before failure:
|
/home/a/spd/_depot/m-tar/10.2.7/bin/mariabackup based on MariaDB server 10.2.7-MariaDB Linux (x86_64)
|
xtrabackup: cd to /home/a/spd/_depot/m-tar/10.2.7/mysql-test/var/tmp/backup/
|
Loading encryption plugin
|
Encryption plugin parameter : '--file_key_management_encryption_algorithm=aes_cbc'
|
Encryption plugin parameter : '--file_key_management_filekey=FILE:/home/a/spd/_depot/m-tar/10.2.7/mysql-test/suite/mariabackup/filekeys-data.key'
|
Encryption plugin parameter : '--file_key_management_filename=/home/a/spd/_depot/m-tar/10.2.7/mysql-test/suite/mariabackup/filekeys-data.enc'
|
Encryption plugin parameter : '--prepare'
|
Encryption plugin parameter : '--target-dir=/home/a/spd/_depot/m-tar/10.2.7/mysql-test/var/tmp/backup'
|
xtrabackup: This target seems to be not prepared yet.
|
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-07-13 16:26:35 140656125790016 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Uses event mutexes
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Number of pools: 1
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Using SSE2 crc32 instructions
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Completed initialization of buffer pool
|
2017-07-13 16:26:35 140655682647808 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Highest supported file format is Barracuda.
|
2017-07-13 16:26:35 140656125790016 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1637690
|
2017-07-13 16:26:35 140656125790016 [ERROR] InnoDB: Incorrect log record type:104
|
2017-07-13 16:26:35 140656125790016 [Warning] InnoDB: Log scan aborted at LSN 1637376
|
2017-07-13 16:26:35 140656125790016 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
|
xtrabackup: innodb_init() returned 11 (Generic error).
|
|
|
|
The result from queries just before the failure was:
|
CREATE TABLE t(c VARCHAR(10)) ENGINE INNODB encrypted=yes;
|
INSERT INTO t VALUES('foobar1');
|
# xtrabackup backup
|
NOT FOUND /foobar1/ in ib_logfile0
|
# expect NOT FOUND
|
INSERT INTO t VALUES('foobar2');
|
# xtrabackup prepare
|
|
- saving '/home/a/spd/_depot/m-tar/10.2.7/mysql-test/var/log/mariabackup.xb_file_key_management/' to '/home/a/spd/_depot/m-tar/10.2.7/mysql-test/var/log/mariabackup.xb_file_key_management/'
|
--------------------------------------------------------------------------
|
The servers were restarted 0 times
|
Spent 0.000 of 8 seconds executing testcases
|
|
Failure: Failed 1/1 tests, 0.00% were successful.
|
|
Failing test(s): mariabackup.xb_file_key_management
|
|
The log files in var/log may give you some hint of what went wrong.
|
|
If you want to report this error, please read first the documentation
|
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
|
|
mysql-test-run: *** ERROR: there were failing test cases
|
Attachments
Issue Links
- causes
-
MDEV-13813 Assertion `size % 512U == 0' failed in log_crypt upon upgrade from 10.2
-
- Closed
-
-
MDEV-23982 Mariabackup hangs during backup
-
- Closed
-
- is caused by
-
MDEV-8041 InnoDB redo log encryption
-
- Closed
-
- relates to
-
MDEV-11782 Redefine the innodb_encrypt_log format
-
- Closed
-
-
MDEV-12041 Implement key rotation for innodb_encrypt_log
-
- Closed
-
-
MDEV-13044 Do not create a redo log checkpoint at startup
-
- Closed
-
-
MDEV-14874 innodb_encrypt_log corrupts the log when the LSN crosses 32-bit boundary
-
- Closed
-
Activity
Field | Original Value | New Value |
---|---|---|
Assignee | Marko Mäkelä [ marko ] | Andrii Nikitin [ anikitin ] |
Assignee | Andrii Nikitin [ anikitin ] | Marko Mäkelä [ marko ] |
Affects Version/s | 10.2.8 [ 22544 ] | |
Affects Version/s | 10.3 [ 22126 ] |
Fix Version/s | 10.3 [ 22126 ] |
Link |
This issue is caused by |
Affects Version/s | 10.3.0 [ 22127 ] | |
Affects Version/s | 10.2.4 [ 22116 ] | |
Affects Version/s | 10.3 [ 22126 ] | |
Affects Version/s | 10.2.7 [ 22543 ] | |
Affects Version/s | 10.2.8 [ 22544 ] |
Status | Open [ 1 ] | Confirmed [ 10101 ] |
Status | Confirmed [ 10101 ] | In Progress [ 3 ] |
Summary | mariabackup with innodb-encrypt-log=ON may show 'Incorrect log record type' | Crash recovery failure after the server is killed during innodb_encrypt_log startup |
Assignee | Marko Mäkelä [ marko ] | Jan Lindström [ jplindst ] |
Status | In Progress [ 3 ] | In Review [ 10002 ] |
Affects Version/s | 10.1.3 [ 18000 ] |
Link |
This issue relates to |
Link |
This issue is caused by |
Assignee | Jan Lindström [ jplindst ] | Marko Mäkelä [ marko ] |
Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Link |
This issue relates to |
issue.field.resolutiondate | 2017-09-12 08:38:26.0 | 2017-09-12 08:38:26.655 |
Fix Version/s | 10.2.9 [ 22611 ] | |
Fix Version/s | 10.3.2 [ 22533 ] | |
Fix Version/s | 10.2 [ 14601 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Resolution | Fixed [ 1 ] | |
Status | Stalled [ 10000 ] | Closed [ 6 ] |
Link |
This issue causes |
Link |
This issue relates to |
Link |
This issue relates to |
Link |
This issue causes |
Workflow | MariaDB v3 [ 81663 ] | MariaDB v4 [ 152483 ] |
LSN=1637690 rounded down to a multiple of 512 is LSN 1637376. This (together with the invalid redo log record type 71) means that Mariabackup was unable to read the encrypted redo log file.
Where exactly was the line
--source include/restart_mysqld.inc
added? Please post an exact patch.