Decryption fails at a later stage

Reported by Raghavendra D Prabhu on 2013-06-13
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona XtraBackup
High
George Ormond Lorch III
2.1
High
George Ormond Lorch III

Bug Description

I see another error even with parameters provided through innobackupex:

xbcrypt:xb_crypt_read_chunk: failed to read 65536 bytes for chunk payload at offset 0x1ec.

is the error on receiving side.

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
and Percona Ireland Ltd 2009-2012. All Rights Reserved.

This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

130613 01:37:12 innobackupex: Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_file=/etc/my.cnf;mysql_read_default_group=xtrabackup;mysql_socket=/var/lib/mysql/mysql.sock' as 'root' (using pass
word: YES).
130613 01:37:12 innobackupex: Connected to MySQL server
IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

innobackupex: Using mysql server version 5.5.30-log

innobackupex: Created backup directory /tmp

130613 01:37:12 innobackupex: Starting ibbackup with command: xtrabackup_55 --defaults-file="/etc/my.cnf" --defaults-group="mysqld" --backup --suspend-at-end --target-dir=/tmp --tmpdir=/tmp --encrypt=AES256 --e
ncrypt-key=6F3AD9F428143F133FD7D50D77D91EA4 --encrypt-threads=1 --stream=xbstream
innobackupex: Waiting for ibbackup (pid=6175) to suspend
innobackupex: Suspend file '/tmp/xtrabackup_suspended_2'

xtrabackup_55 version 2.1.3 for Percona Server 5.5.16 Linux (x86_64) (revision id: 608)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql
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 = 536870912
xtrabackup: using O_DIRECT
130613 1:37:12 InnoDB: Warning: allocated tablespace 10, old maximum was 9
>> log scanned up to (9616286)
[01] Compressing, encrypting and streaming ./ibdata1
^Gxtrabackup_55: Error writing file 'UNOPENED' (Errcode: 32)
encrypt: write to the destination file failed.
xb_stream_write_data() failed.
compress: write to the destination stream failed.
>> log scanned up to (9616286)
>> log scanned up to (9616286)
>> log scanned up to (9616286)
>> log scanned up to (9616286)
>> log scanned up to (9616286)
>> log scanned up to (9616286)
>> log scanned up to (9616286)

is the error on sending side.

I tried with https://bazaar.launchpad.net/~gl-az/percona-xtrabackup/BT23557-2.1-lp1160778/download/head:/innobackup1.5.1-20090305061108-fxjvmhr914de7q81-1/innobackupex

from commit of https://bugs.launchpad.net/percona-xtrabackup/+bug/1160778

but it has not helped.

backup-my.cnf was transferred correctly, only after that it failed (as the offset explains).

To reliably repeat this:

a) Consider NodeA NodeB

b) Run netcat listener on nodeB: nc -dl $ip-addr2 $port | xbcrypt -d --encrypt-algo=$ealgo --encrypt-key=$ekey | xbstream -x -C ${dir}

c) Write to netcat on nodeA: innobackupex --galera-info --encrypt=$ealgo --encrypt-key=$ekey --stream=xbstream /tmp | nc $ip-addr2 $port

Got

xbcrypt:xb_crypt_read_chunk: failed to read 65536 bytes for chunk payload at offset 0x19c.

in another instance.

Since it happens at a latter offset, I wonder if this is for xtrabackup_galera_info file which may not be encrypted in the current streaming code in innobackupex.

Alexey Kopytov (akopytov) wrote :

In the branch for bug #1160778 I see that xtrabackup_galera_info is encrypted:

86 + write_to_backup_file("$galera_info", "$con->{status}->{wsrep_local_state_uuid}->{Value}" .
87 + ":" . "$con->{status}->{wsrep_last_committed}->{Value}" . "\n");

(unless there's a bug in write_to_backup_file, I didn't do a full review yet).

George Ormond Lorch III (gl-az) wrote :

You seem to still have 'compress' in your .cnf file:
  [01] Compressing, encrypting and streaming ./ibdata1

Since non-innodb files are not compressed in the stream, you can not use compress in this manner. I made the same mistake when reproducing this. It will fail the same way even with no encryption in this case...

There is still a problem though. Even with the compression removed I get the xtrabackup_55: Error writing file 'UNOPENED' (Errcode: 32) and .xbcrypt:xb_crypt_read_chunk: failed to read 65536 bytes for chunk payload at offset 0x10209.

This appears to be a netcat/pipe bufer over/under run issue. Still poking and prodding...

George Ormond Lorch III (gl-az) wrote :

OK, seems that xbcrypt is calling my_read without MY_FULL_IO...dunno how that happened, but there it is...

George Ormond Lorch III (gl-az) wrote :

Annnd I forgot, since xbcrypt format doesn't have file begin/end markers within it, it relys on getting EOF on the chunk header read which hangs if MY_FULL_IO is specified...fixing...

To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers