InnoDB log scanning failure results in SST failure
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
Percona XtraBackup moved to https://jira.percona.com/projects/PXB |
Fix Released
|
Medium
|
Sergei Glushchenko | ||
2.1 |
Won't Fix
|
Undecided
|
Unassigned | ||
2.2 |
Fix Released
|
Medium
|
Sergei Glushchenko |
Bug Description
Running automated tests using percona-
===== Platform: Centos 6.5 - x86_64
updated to 2014-09-23
direct on hardware - Dell PowerEdge R200
===== Software Versions
Percona-
(Jenkins debug build)
percona-
Built with -DCMAKE_
====== node 1 (donor) configuration
# xbstream+
[mysqld]
core_file
thread_
extra_port=50002
[xtrabackup]
core_file
compress
compact
parallel=4
compress-threads=4
[sst]
streamfmt=xbstream
time=1
progress=1
encrypt=2
tca=/tmp/
tcert=/
use_extra=1
====== node 1 (donor) pertinent mysqld log excerpt
...
WSREP_SST: [INFO] Streaming with xbstream (20140928 03:09:24.179)
WSREP_SST: [INFO] Using socat as streamer (20140928 03:09:24.181)
WSREP_SST: [INFO] Using openssl based encryption with socat: with crt and pem (20140928 03:09:24.187)
WSREP_SST: [INFO] Encrypting with PEM /tmp/certs/
WSREP_SST: [INFO] Using /tmp/xbtemp.
WSREP_SST: [INFO] SST through extra_port 50002 (20140928 03:09:24.436)
WSREP_SST: [INFO] Streaming GTID file before SST (20140928 03:09:24.438)
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio openssl-
WSREP_SST: [INFO] NOTE: donor-OpenSSL-
WSREP_SST: [INFO] Sleeping before data transfer for SST (20140928 03:09:24.508)
2014-09-28 03:09:25 20391 [Note] WSREP: (576ea228, 'tcp://
WSREP_SST: [INFO] Streaming the backup to joiner at 127.0.0.1 26168 (20140928 03:09:34.511)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-
ream=$sfmt $itmpdir 2>${LOGDIR}
) (20140928 03:09:34.515)
donor: 695kB 0:00:10 [69.1kB/s] [> ] 6% ETA 0:02:33^M donor: 695kB 0:00:20 [ 0B/s ] [> ] 6% ETA 0:05:07^M donor: 695kB 0:00:30 [ 0B/s ] [> ] 6% ETA 0:07
:41^M donor: 695kB 0:00:31 [22.3kB/s] [> ] 6%
WSREP_SST: [INFO] NOTE: donor-OpenSSL-
WSREP_SST: [ERROR] innobackupex finished with error: 1. Check /home/dbennett/
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20140928 03:10:05.757)
WSREP_SST: [INFO] Cleaning up temporary directories (20140928 03:10:05.760)
2014-09-28 03:10:05 20391 [ERROR] WSREP: Failed to read from: wsrep_sst_
tt/work/
ar1/my.cnf' '' --gtid '576f4183-
2014-09-28 03:10:05 20391 [ERROR] WSREP: Process completed with error: wsrep_sst_
me/dbennett/
/var/w1/
2014-09-28 03:10:05 20391 [ERROR] WSREP: Command did not run: wsrep_sst_
tt/work/
ar1/my.cnf' '' --gtid '576f4183-
2014-09-28 03:10:05 20391 [Warning] WSREP: 0.0 (c-p130-
====== node 1 (donor) pertinent xtrabackup log excerpt
xtrabackup: open files limit requested 0, set to 1024
xtrabackup: using the following InnoDB configuration:
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
xtrabackup: innodb_
>> log scanned up to (2462007)
xtrabackup: Starting 4 threads for parallel data files transfer
[01] Compressing and streaming ./ibdata1
[03] Compressing and streaming ./mysql/
[04] Compressing and streaming ./mysql/
[02] Compressing and streaming ./sbtest/
[03] ...done
[04] ...done
[03] Compressing and streaming ./mysql/
[04] Compressing and streaming ./mysql/
[04] ...done
[04] Compressing and streaming ./mysql/
[03] ...done
[04] ...done
[01] ...done
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
>> log scanned up to (2462007)
InnoDB: Tried to read 1048576 bytes at offset 6291456. Was only able to read 16384.
InnoDB: File (unknown): 'read' returned OS error 0. Cannot continue operation
innobackupex: Error: The xtrabackup child process has died at /home/dbennett/
====== node 2 (joiner) pertinent mysqld log excerpt
...
WSREP_SST: [INFO] Decompression with 4 threads (20140928 03:10:05.769)
WSREP_SST: [INFO] Evaluating find /home/dbennett/
Decompression: 12 0:00:00 [ 167k/s] [======
WSREP_SST: [INFO] NOTE: Joiner-
WSREP_SST: [INFO] Removing qpress files after decompression (20140928 03:10:05.819)
WSREP_SST: [INFO] Preparing the backup at /home/dbennett/
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${LOGDIR}
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20140928 03:10:06.024)
WSREP_SST: [INFO] Removing the sst_in_progress file (20140928 03:10:06.026)
2014-09-28 03:10:06 20559 [ERROR] WSREP: Process completed with error: wsrep_sst_
2014-09-28 03:10:06 20559 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
2014-09-28 03:10:06 20559 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2014-09-28 03:10:06 20559 [ERROR] Aborting
====== node 2 (joiner) pertinent xtrabackup log excerpt
...
xtrabackup: Error: cannot open ./xtrabackup_
xtrabackup: error: xtrabackup_
xtrabackup: This target seems not to have correct metadata...
2014-09-28 03:10:06 7f8c0d376720 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: Warning: cannot open ./xtrabackup_
2014-09-28 03:10:06 7f8c0d376720 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
xtrabackup: Fatal error: cannot find ./xtrabackup_
xtrabackup: Error: xtrabackup_
innobackupex: Error:
innobackupex: ibbackup failed at /home/dbennett/
Related branches
- Alexey Kopytov (community): Approve
-
Diff: 429 lines (+166/-150)1 file modifiedstorage/innobase/os/os0file.cc (+166/-150)
This is most likely http:// bugs.mysql. com/bug. php?id= 60788