genericBackupTaker->takeFullBackupSnapshot: Error: There was an error backing up - The process returned code 25

379 views
Skip to first unread message

Prashant

unread,
Dec 26, 2011, 7:48:21 AM12/26/11
to Xtrabackup Manager
Hi,

I am trying to use the xbm for backing up MySQL databases. I have
added the backup volume, host and job / cron expression.

1. Backup volume added as (as the 'xbm' user): ./xbm volume add
"Backup" /backup/path/xbm/

2. Backup host added as (as the 'xbm' user): ./xbm host add "FQHN"
"Test DB Server"

3. Backup schedule added as (as the 'xbm' user): ./xbm backup add
"FQHN" "NightlyBackup" ROTATING "30 16 * * *" "Backup" /var/lib/mysql/
data username "password"

For testing purposes, when I run: ./xbm backup run "FQHN"
"NightlyBackup", I get:
======================================================
XtraBackup Manager v0.7 - Copyright 2011 Marin Software

2011-12-26 17:41:24 [INFO] : [ Initializing Scheduled Backup
"NightlyBackup" (ID #21) for host: blr-cos-mtarc.digi.com ... ]
2011-12-26 17:41:24 [INFO] : [ Using Backup Strategy: Rotating sets of
Incremental Backups ]
2011-12-26 17:41:24 [INFO] : [ Using DAY_OF_WEEK as the rotation
method... ]
2011-12-26 17:41:24 [INFO] : [ No snapshots found for this scheduled
backup at all - taking an initial full backup. ]
2011-12-26 17:41:24 [INFO] : [ Attempting to find available ports for
use... ]
2011-12-26 17:41:25 [INFO] : [ Got lock on port 10000. ]
2011-12-26 17:41:25 [INFO] : [ Started Netcat (nc) listener on port
10000 to receive backup tar stream into directory /backup/tds/xbm/blr-
cos-mtarc.digi.com/101 ... ]
2011-12-26 17:41:25 [INFO] : [ Running FULL xtrabackup snapshot of /
var/lib/mysql/data via ssh: my...@blr-cos-mtarc.digi.com ... ]
2011-12-26 17:41:35 [INFO] : [ Cleaning up files after failure... ]
2011-12-26 17:41:35 [ERROR] : [ genericBackupTaker-
>takeFullBackupSnapshot: Error: There was an error backing up - The
process returned code 25. The output from the backup is as follows:

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

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

IMPORTANT: Please check that the backup run completes successfully.
At the end of a successful backup run innobackupex
prints "completed OK!".

innobackupex: Using mysql Ver 14.14 Distrib 5.1.54, for unknown-linux-
gnu (x86_64) using readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2010,
Oracle and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /var/lib/mysql/data
innobackupex: Error: Failed to stream 'backup-my.cnf': Inappropriate
ioctl for device at /usr/bin/innobackupex line 341.
]
2011-12-26 17:41:35 [INFO] : [ Released lock on port 10000. ]
cliHandler.class.php: genericBackupTaker->takeFullBackupSnapshot:
Error: There was an error backing up - The process returned code 25.
The output from the backup is as follows:

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

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

IMPORTANT: Please check that the backup run completes successfully.
At the end of a successful backup run innobackupex
prints "completed OK!".

innobackupex: Using mysql Ver 14.14 Distrib 5.1.54, for unknown-linux-
gnu (x86_64) using readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2010,
Oracle and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /var/lib/mysql/data
innobackupex: Error: Failed to stream 'backup-my.cnf': Inappropriate
ioctl for device at /usr/bin/innobackupex line 341.

Trace:
#0 /home/xbm/xtrabackup-manager/includes/
rotatingBackupTaker.class.php(205): genericBackupTaker-
>takeFullBackupSnapshot(Object(scheduledBackup),
Object(backupSnapshotGroup))
#1 /home/xbm/xtrabackup-manager/includes/
backupSnapshotTaker.class.php(182): rotatingBackupTaker-
>takeScheduledBackupSnapshot(Object(scheduledBackup))
#2 /home/xbm/xtrabackup-manager/includes/cliHandler.class.php(875):
backupSnapshotTaker-
>takeScheduledBackupSnapshot(Object(scheduledBackup))
#3 /home/xbm/xtrabackup-manager/includes/cliHandler.class.php(97):
cliHandler->handleBackupActions(Array)
#4 /home/xbm/xtrabackup-manager/xbm(36): cliHandler-
>handleArguments(Array)
#5 {main}
==================================================

The xbm user can login into the mysql@FQHN without password. The
backup volume is owned by the user xbm.

FYI:

OS: CentOS 5.7 64 bit
MySQL: 5.1.54 64 bit
PHP: 5.1.6
PHP-MySQL: 5.1.6
xtrabackup: 1.6.4-314.rhel5

What is causing the error and how to resolve it ?

Regards
Prashant

Lachlan Mulcahy

unread,
Dec 28, 2011, 2:33:15 PM12/28/11
to xtrabac...@googlegroups.com
Hi Prashant,

On 26/12/2011, at 4:48 AM, Prashant wrote:

> innobackupex: Error: Failed to stream 'backup-my.cnf': Inappropriate
> ioctl for device at /usr/bin/innobackupex line 341.
>

> The xbm user can login into the mysql@FQHN without password. The
> backup volume is owned by the user xbm.
>
> FYI:
>
> OS: CentOS 5.7 64 bit
> MySQL: 5.1.54 64 bit
> PHP: 5.1.6
> PHP-MySQL: 5.1.6
> xtrabackup: 1.6.4-314.rhel5
>
> What is causing the error and how to resolve it ?

This error that you are seeing says that there was an issue sending the backup via netcat from the MySQL database machine to your XtraBackup Manager server.

From the log information, you can see that XBM is setting up a netcat listener on port 10000 on your backup host and attempting to stream the data over the network through that.

The error "Inappropriate ioctl for device" usually means that the xtrabackup/innobackupex was trying to write to the stream, but something happened where it could not.

This generally means a problem with the netcat stream -- please can you check the following things:

#1. Does the hostname of your XtraBackup Manager resolve via DNS on the database you are trying to backup:

eg. Run "hostname" command on the XtraBackup Manager host -- Then on the database machine, try to execute "ping <output from hostname>" and confirm the ping will resolve the host and ping correctly.

#2. Can you netcat a sample file via port 10000 from the DB system to your XBM host?

On the XtraBackup Manager host try and manually start a netcat listener on port 10000 with:

cd /tmp ; nc -l 10000 > testfile

The above command should seem to hang as it is waiting for a remote connection.

Then, on the Database system you are trying to backup:

echo "1234" > /tmp/testfile
cat /tmp/testfile | nc <xtrabackup-manager-hostname> 10000

This will just create a small testfile and attempt to send it via netcat port 10000.

If this completes correctly you should be able to confirm that /tmp/testfile exists on the XBM machine and contains "1234".

#3. Can you provide output of "nc -h" on both your XBM system and the database you are trying to backup?

#4. Provide output of "ls -la /backup/tds/xbm/blr-
cos-mtarc.digi.com/"

The above should help us figure out why the backup is not able to write to the stream correctly.

If we are still having some issues, I can add some extra logging to the code so we can try to capture any output from the netcat listener on the XBM server, rather than just discard it to /dev/null.

Let me know how you go.

Best Regards,
Lachlan

Prashant N

unread,
Dec 29, 2011, 7:58:02 AM12/29/11
to xtrabac...@googlegroups.com
Hi Lachlan
Thanks for the reply. I am testing the backup mechansim on the same
host meaning that the backup server and the client are the same
system. I have also tried with "localhost" and "127.0.0.1" with the
results being the same.

Please find my answers to your questions
below:============================================================


#1. Does the hostname of your XtraBackup Manager resolve via DNS on
the database you are trying to backup:

Prashant: Yes it does resolve the DNS to IP Address and IP Address to
DNS. xbm $> ping FQHNPING FQHN (a.b.c.d) 56(84) bytes of data.--- FQHN
ping statistics ---20 packets transmitted, 20 received, 0% packet
loss, time 1000msrtt min/avg/max/mdev = 0.228/0.332/0.437/0.106 ms
xbm $> hostnameOutput: FQHN ... exactly the same as the ping output,
host in the xbm's
host-list============================================================


#2. Can you netcat a sample file via port 10000 from the DB system to
your XBM host?

Prashant:xbm $> cd \tmp;  nc -l 10000 > nctestfileYes the command
results in a socket is waiting for a remote connection. The netstat
output:netstat -tulpn |grep 10000tcp        0      0 0.0.0.0:10000
          0.0.0.0:*                   LISTEN      32174/nc
In another shell sessionxbm $> echo "1234" > /tmp/testfilexbm $> cat
/tmp/testfile | nc <xtrabackup-manager-hostname> 10000
The above gets completed sucessfully and the "nctestfile" has the
"1234" entries in it and the netcat socket closes itself after the
successful transmission of the
file============================================================


#3. Can you provide output of "nc -h" on both your XBM system and the
database you are trying to backup?

Prashant: xbm $> nc -husage: nc [-46DdhklnrStUuvzC] [-i interval] [-p
source_port]          [-s source_ip_address] [-T ToS] [-w timeout] [-X
proxy_version]          [-x proxy_address[:port]] [hostname] [port[s]]
      Command Summary:                -4              Use IPv4
        -6              Use IPv6                -D              Enable
the debug socket option                -d              Detach from
stdin                -h              This help text                -i
secs         Delay interval for lines sent, ports scanned
  -k              Keep inbound sockets open for multiple connects
          -l              Listen mode, for inbound connects
    -n              Suppress name/port resolutions                -p
port         Specify local port for remote connects                -r
           Randomize remote ports                -s addr
Local source address                -T ToS          Set IP Type of
Service                -C              Send CRLF as line-ending
        -t              Answer TELNET negotiation                -U
         Use UNIX domain socket                -u              UDP
mode                -v              Verbose                -w secs
    Timeout for connects and final net reads                -X proto
     Proxy protocol: "4", "5" (SOCKS) or "connect"                -x
addr[:port]  Specify proxy address and port                -z
   Zero-I/O mode [used for scanning]        Port numbers can be
individual or ranges: lo-hi
[inclusive]============================================================


#4. Provide output of "ls -la /backup/tds/xbm/blr-cos-mtarc.digi.com/"

Prashant: ls -la /backup/tds/xbm/blr-cos-mtarc.digi.com/ producestotal
8drwx--S--- 2 xbm xbm 4096 Dec 29 16:30 .drwxrwsr-x 3 xbm xbm 4096 Dec
26 17:34 ..============================================================--
Thanks & Regards
Prashant N

Lachlan Mulcahy

unread,
Dec 30, 2011, 5:00:22 PM12/30/11
to xtrabac...@googlegroups.com
Hi Prashant,

It seems like there is a need for some better logging to help troubleshoot this, as I have a report of a similar issue in the Issues system on the Google Code project (issue 39)

I am going to work on adding that to the code and will let you know when that is done. I hope to have it ready soon.

Thanks for your patience.

Lachlan

Lachlan Mulcahy

unread,
Dec 30, 2011, 5:34:16 PM12/30/11
to xtrabac...@googlegroups.com
Hi Prashant,

Please do an svn up and ensure you are running revision 202 or higher and then retry running the backup.

There should now be two log files:

<xbm-installdir>/logs/hosts/hostname.log
<xbm-installdir>/logs/hosts/hostname.netcat.log

Could you please sanitise your logs by removing any password information that may be in there and then attach them?

I would like to see what output we're getting in them.

Thanks,


Lachlan
On 29/12/2011, at 4:58 AM, Prashant N wrote:

Prashant

unread,
Dec 31, 2011, 10:17:13 AM12/31/11
to Xtrabackup Manager
Hi Lachan,

Pleaser find the logs.

the logs/hosts/host.log is
======================================
2011-12-31 20:38:37 [INFO] : [ Initializing Scheduled Backup
"NightlyBackup" (ID #21) for host: blr-cos-mtarc.digi.com ... ]
2011-12-31 20:38:37 [INFO] : [ Using Backup Strategy: Rotating sets of
Incremental Backups ]
2011-12-31 20:38:37 [INFO] : [ Using DAY_OF_WEEK as the rotation
method... ]
2011-12-31 20:38:37 [INFO] : [ No snapshots found for this scheduled
backup at all - taking an initial full backup. ]
2011-12-31 20:38:37 [INFO] : [ Attempting to find available ports for
use... ]
2011-12-31 20:38:37 [INFO] : [ Got lock on port 10000. ]
2011-12-31 20:38:37 [INFO] : [ Started Netcat (nc) listener on port
10000 to receive backup tar stream into directory /backup/tds/xbm/blr-
cos-mtarc.digi.com/181 ... ]
2011-12-31 20:38:37 [INFO] : [ Running FULL xtrabackup snapshot of /
var/lib/mysql/data via ssh: my...@blr-cos-mtarc.digi.com ... ]
2011-12-31 20:38:47 [INFO] : [ Cleaning up files after failure... ]
2011-12-31 20:38:47 [ERROR] : [ genericBackupTaker-
>takeFullBackupSnapshot: Error: There was an error backing up - The
process returned code 25. The output from the backup is as follows:

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

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

IMPORTANT: Please check that the backup run completes successfully.
At the end of a successful backup run innobackupex
prints "completed OK!".

innobackupex: Using mysql Ver 14.14 Distrib 5.1.54, for unknown-linux-
gnu (x86_64) using readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2010,
Oracle and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /var/lib/mysql/data
innobackupex: Error: Failed to stream 'backup-my.cnf': Inappropriate
ioctl for device at /usr/bin/innobackupex line 341.
]
2011-12-31 20:38:47 [INFO] : [ Released lock on port 10000. ]
======================================

the logs/hosts/host.netcat.log
======================================
tar: This does not look like a tar archive
tar: Error exit delayed from previous errors
======================================

I will send the xbm.log in the next post

Prashant N

unread,
Dec 31, 2011, 10:17:59 AM12/31/11
to Xtrabackup Manager
The logs/xbm.log
======================================
2011-12-31 20:38:37 [DEBUG] : [ hostGetter->getByName: Sending SQL:
SELECT host_id FROM hosts WHERE hostname='blr-cos-mtarc.digi.com' ]
2011-12-31 20:38:37 [DEBUG] : [ hostGetter->getByName: Query took
8.392333984375E-05 ]
2011-12-31 20:38:37 [DEBUG] : [
scheduledBackupGetter->getByHostnameAndName: Sending SQL: SELECT
scheduled_backup_id FROM scheduled_backups
WHERE host_id=21 AND
name='NightlyBackup' ]
2011-12-31 20:38:37 [DEBUG] : [
scheduledBackupGetter->getByHostnameAndName: Query took
4.9829483032227E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
7.0095062255859E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.9114227294922E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
6.2942504882812E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6028366088867E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6028366088867E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:21' ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.0002748966217041 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
DELETE FROM queue_tickets WHERE queue_ticket_id=571 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.0019950866699219 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->getTicketNumber: Sending
SQL: INSERT INTO queue_tickets (queue_ticket_id, queue_name,
entry_time, pid) VALUES (NULL, 'scheduledBackup:21', NOW(), 17561) ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->getTicketNumber: Query
took 0.0027570724487305 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='hostBackup:21' ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00012898445129395 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->getTicketNumber: Sending
SQL: INSERT INTO queue_tickets (queue_ticket_id, queue_name,
entry_time, pid) VALUES (NULL, 'hostBackup:21', NOW(), 17561) ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->getTicketNumber: Query
took 0.0023481845855713 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:21' ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00013589859008789 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:21' AND queue_ticket_id=601 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00012993812561035 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:21' ORDER BY entry_time ASC LIMIT 1 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00014114379882812 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='hostBackup:21' ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00012993812561035 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='hostBackup:21' AND queue_ticket_id=611 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00011897087097168 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='hostBackup:21' ORDER BY entry_time ASC LIMIT 1 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00013208389282227 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00013017654418945 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->getTicketNumber: Sending
SQL: INSERT INTO queue_tickets (queue_ticket_id, queue_name,
entry_time, pid) VALUES (NULL, 'scheduledBackup:GLOBAL', NOW(), 17561)
]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->getTicketNumber: Query
took 0.0019979476928711 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00014305114746094 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' AND queue_ticket_id=621 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00011801719665527 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' ORDER BY entry_time ASC LIMIT 1 ]
2011-12-31 20:38:37 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00013303756713867 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6982040405273E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6028366088867E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getParameters:
Sending SQL: SELECT bsp.param_name, sbp.param_value FROM
scheduled_backups sb
JOIN backup_strategy_params bsp
ON
sb.backup_strategy_id = bsp.backup_strategy_id
JOIN scheduled_backup_params sbp
ON
sbp.scheduled_backup_id = sb.scheduled_backup_id AND

bsp.backup_strategy_param_id = sbp.backup_strategy_param_id
WHERE
sb.scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getParameters: Query
took 5.3882598876953E-05 ]
2011-12-31 20:38:37 [DEBUG] : [
scheduledBackup->getSnapshotGroupsNewestToOldest: Sending SQL: SELECT
DISTINCT snapshot_group_num FROM backup_snapshots WHERE
scheduled_backup_id=21 AND status='COMPLETED' ORDER BY
snapshot_group_num DESC ]
2011-12-31 20:38:37 [DEBUG] : [
scheduledBackup->getSnapshotGroupsNewestToOldest: Query took
0.0002138614654541 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
6.103515625E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.9843063354492E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
6.7949295043945E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6982040405273E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6028366088867E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.6028366088867E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:37 [DEBUG] : [ scheduledBackup->getInfo: Query took
7.2956085205078E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ mysqlTypeGetter->getById: Sending SQL:
SELECT mysql_type_id FROM mysql_types WHERE mysql_type_id=1 ]
2011-12-31 20:38:37 [DEBUG] : [ mysqlTypeGetter->getById: Query took
4.5061111450195E-05 ]
2011-12-31 20:38:37 [DEBUG] : [ mysqlType->getInfo: Sending SQL:
SELECT * FROM mysql_types WHERE mysql_type_id=1 ]
2011-12-31 20:38:37 [DEBUG] : [ mysqlType->getInfo: Query took
4.5061111450195E-05 ]
2011-12-31 20:38:47 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:47 [DEBUG] : [ scheduledBackup->getInfo: Query took
9.2029571533203E-05 ]
2011-12-31 20:38:47 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=21 ]
2011-12-31 20:38:47 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.1021575927734E-05 ]
======================================

Lachlan Mulcahy

unread,
Jan 3, 2012, 2:34:44 PM1/3/12
to xtrabac...@googlegroups.com
Hi Prashant,

Thanks for taking the time to try that out for me -- sadly I can't seem to find anything helpful in there that is giving me a hint on what might be happening.

It seems like either tar does not like the output it is receiving, or the netcat connection itself is getting broken for another reason.

I am installing CentOS 5.7 on a VM to see if I can reproduce.

Thanks for your patience.

Best,
Lachlan

Lachlan Mulcahy

unread,
Jan 3, 2012, 5:16:07 PM1/3/12
to xtrabac...@googlegroups.com
Hi Prashant,

I believe I was able to reproduce the issue you described on a CentOS 5.7 VM and have now committed a fix. Please update to revision 205 and retry to see if you still experience the issue.

It seems like there was an issue where the proc_open() that spawned the netcat listener process was trying to force STDIN to listen to /dev/null and it was causing a problem for netcat in being able to operate as it should.

Let me know how you go!

Thanks,
Lachlan

On 31/12/2011, at 7:17 AM, Prashant N wrote:

Prashant N

unread,
Jan 4, 2012, 3:00:27 AM1/4/12
to xtrabac...@googlegroups.com
Hi Lachlan,

KUDO'S. Its' working now.

Thanks for debugging and nailing the issue. I did "svn up" and I am
able to successfully backup the databases hosted in the configured
FQHN.

For the sake of complete testing I added another host and tried to
back it up. I have issues while backing the newly configured host.
More on that in another thread.

--

Reply all
Reply to author
Forward
0 new messages