Running a backup issue

[GoogleCodeExporter]

Hi, if i run my backup with:

xbm backup run localhost backupname

i get this:
2011-12-28 21:54:02 [INFO] : [ Initializing Scheduled Backup "backupname" (ID 
#2) for host: localhost ...  ]
2011-12-28 21:54:02 [INFO] : [ Using Backup Strategy: Rotating sets of 
Incremental Backups ]
2011-12-28 21:54:02 [INFO] : [ Using DAY_OF_WEEK as the rotation method... ]
2011-12-28 21:54:02 [INFO] : [ No snapshots found for this scheduled backup at 
all - taking an initial full backup. ]
2011-12-28 21:54:02 [INFO] : [ Attempting to find available ports for use... ]
2011-12-28 21:54:02 [INFO] : [ Got lock on port 10000. ]
2011-12-28 21:54:02 [INFO] : [ Started Netcat (nc) listener on port 10000 to 
receive backup tar stream into directory /home/xbm/backup/localhost/23 ... ]
2011-12-28 21:54:02 [INFO] : [ Running FULL xtrabackup snapshot of 
/home/xbm/backup via ssh: mysql@localhost ... ]
2011-12-28 21:54:12 [INFO] : [ Cleaning up files after failure... ]
2011-12-28 21:54:12 [ERROR] : [ genericBackupTaker->takeFullBackupSnapshot: 
Error: There was an error backing up - The process returned code 25. The output 
from the backup is as follows:
Warning: Permanently added 'localhost' (RSA) to the list of known hosts.

[MOTD of my server...]

domain.com [IP4V-Adress] 10000 (webmin) : Connection refused

heres the stacktrace..

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}

additional info:

ssh mysql@localhost with xbm logged in works, seems to be not a key issue, 
thanks for your help ^_~

PS: Rev 201

Original issue reported on code.google.com by sascha.a...@gmail.com on 28 Dec 2011 at 9:00

[GoogleCodeExporter]

Hi Sascha,

This sounds like an issue with your ability to connect to the host on port 
10000 -- Basically XtraBackup Manager is trying to stream the backup data via a 
TCP connection to port 10000 and is getting connection refused.

Do you have any firewall or similar running that could be blocking/refusing the 
connection?

You can try this to confirm:

telnet `hostname` 10000

The above should also get connection refused if there is something blocking 
connections to port 10000.

You will need to find a port range that is not firewalled out and also unused 
by any other service and edit the includes/config.php file lines below:

    // The port range made available for use by XBM with netcat - 
    // these ports need to be openable on the backup hsot
    $config['SYSTEM']['port_range']['low'] = 10000;
    $config['SYSTEM']['port_range']['high'] = 11000;

You can change the low and high ends to any range you want if that will work 
better for your environment.

Please let me know how you go.

Lachlan

Original comment by lachlan....@gmail.com on 30 Dec 2011 at 5:43

• Changed state: Started

[GoogleCodeExporter]

Hi,
thanks for your support :).

Well sure theres a firewall on my system, i assumed this could be the problem 
and deactivated it for testing purpose.

`telnet `hostname` 10000`
Is is also giving me a connection refused. But in my opinion this is fully 
correct due to the fact im not running any service on port 10000.

So I used
`netstat -n | grep 10000`
which doesnt give me any output.

My backup strategie (due to my hosting provider) is to backup locally and scp 
it to my hosting providers backup space. So my idear about this problem 
(without reading deep into code) is, thats maybe not possible to backup with 
xtrabackup-manager on the same system (localhost)?

PS: (if im starting a service on 10000 (sshd), im possible to connect to it via 
ssh -p 10000 localhost)

Original comment by sascha.a...@gmail.com on 30 Dec 2011 at 5:56

[GoogleCodeExporter]

Hi Sascha,

It seems like there is a need for some better logging to aid in troubleshooting.

I'm going to work on modifying things so that we get some more detailed logging 
info so look at which should help us figure out what is causing this issue.

I hope to have something ready soon.

Lachlan

Original comment by lachlan....@gmail.com on 30 Dec 2011 at 9:57

[GoogleCodeExporter]

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

Original comment by lachlan....@gmail.com on 30 Dec 2011 at 10:35

[GoogleCodeExporter]

2011-12-31 01:26:43 [INFO] : [ Initializing Scheduled Backup "pricewatch" (ID 
#2) for host: localhost ...  ]
2011-12-31 01:26:43 [INFO] : [ Using Backup Strategy: Rotating sets of 
Incremental Backups ]
2011-12-31 01:26:43 [INFO] : [ Using DAY_OF_WEEK as the rotation method... ]
2011-12-31 01:26:43 [INFO] : [ No snapshots found for this scheduled backup at 
all - taking an initial full backup. ]
2011-12-31 01:26:43 [INFO] : [ Attempting to find available ports for use... ]
2011-12-31 01:26:43 [INFO] : [ Got lock on port 10000. ]
2011-12-31 01:26:43 [INFO] : [ Started Netcat (nc) listener on port 10000 to 
receive backup tar stream into directory /home/xbm/backup/localhost/29 ... ]
2011-12-31 01:26:43 [INFO] : [ Running FULL xtrabackup snapshot of 
/home/xbm/backup via ssh: mysql@localhost ... ]
2011-12-31 01:26:53 [INFO] : [ Cleaning up files after failure... ]
2011-12-31 01:26:53 [ERROR] : [ genericBackupTaker->takeFullBackupSnapshot: 
Error: There was an error backing up - The process returned code 25. The output 
from the backup is as follows:

[ MOTD here ]
domain [IP.V4-IP] 10000 (webmin) : Connection refused

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.5.18, for Linux (x86_64) using 
readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2011, Oracle 
and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /home/xbm/backup
tar: -: Kann write nicht ausführen: Datenübergabe unterbrochen (broken pipe)
tar: Error is not recoverable: exiting now
innobackupex: Error: Failed to stream 'backup-my.cnf': Unpassender IOCTL 
(I/O-Control) für das Gerät at /usr/bin/innobackupex line 341.
 ]
2011-12-31 01:26:53 [INFO] : [ Released lock on port 10000. ]

Translation as good as possible :P :

tar: -: Kann write nicht ausführen: Datenübergabe unterbrochen (broken pipe)
tar: unable to write: datastream broken (broken pipe)

Unpassender IOCTL (I/O-Control) für das Gerät at /usr/bin/innobackupex line 
341.
Wrong IOCTL (I/O-Control) for the device at /usr/bin/innobackupex line 341.

Original comment by sascha.a...@gmail.com on 31 Dec 2011 at 12:30

[GoogleCodeExporter]

oh sorry 4 two posts,

netcat log is empty :o

Original comment by sascha.a...@gmail.com on 31 Dec 2011 at 12:31

[GoogleCodeExporter]

Hi Sascha,

I'll pick this up again with you after the NY break. I have some more ideas 
with things I can mess with in the code to try to figure out what is happening, 
but I'm taking some time off until next Tuesday.

Lachlan

Original comment by lachlan....@gmail.com on 31 Dec 2011 at 2:23

[GoogleCodeExporter]

Allright,
its not that important :)
i wish you a happy new year!

Original comment by sascha.a...@gmail.com on 31 Dec 2011 at 2:26

[GoogleCodeExporter]

Hi Sascha,

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.

Original comment by lachlan....@gmail.com on 3 Jan 2012 at 10:15

• Changed state: Fixed

[GoogleCodeExporter]

well seems that i was to slow?

next time just gimme some time to respond :O..

issue still exists, seems that you updated a bit your logfiles, heres the new 
one:

2012-01-05 18:58:06 [INFO] : [ Initializing Scheduled Backup "xxx" (ID #2) for 
host: localhost ...  ]
2012-01-05 18:58:06 [INFO] : [ Using Backup Strategy: Rotating sets of 
Incremental Backups ]
2012-01-05 18:58:06 [INFO] : [ Using DAY_OF_WEEK as the rotation method... ]
2012-01-05 18:58:06 [INFO] : [ No snapshots found for this scheduled backup at 
all - taking an initial full backup. ]
2012-01-05 18:58:06 [INFO] : [ Attempting to find available ports for use... ]
2012-01-05 18:58:06 [INFO] : [ Got lock on port 10000. ]
2012-01-05 18:58:06 [INFO] : [ Started Netcat (nc) listener on port 10000 to 
receive backup tar stream into directory /home/xbm/backup/localhost/39 ... ]
2012-01-05 18:58:06 [INFO] : [ Running FULL xtrabackup snapshot of 
/home/xbm/backup via ssh: mysql@localhost ... ]
2012-01-05 18:58:21 [INFO] : [ Cleaning up files after failure... ]
2012-01-05 18:58:21 [ERROR] : [ genericBackupTaker->takeFullBackupSnapshot: 
Error: There was an error backing up - The process returned code 25. The output 
$

modt
              |_|
xxx.com [xxx.x.xx.xxx] 10000 (webmin) : Connection refused

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.

120105 18:58:07  innobackupex: Starting mysql with options:  --password='xxx' 
--user='backup' --unbuffered --
120105 18:58:07  innobackupex: Connected to database with mysql child process 
(pid=10387)
120105 18:58:13  innobackupex: Connection to database server closed
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.5.15, for Linux (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 /home/xbm/backup
tar: -: Kann write nicht ausführen: Datenübergabe unterbrochen (broken pipe)
tar: Error is not recoverable: exiting now
innobackupex: Error: Failed to stream 'backup-my.cnf': Unpassender IOCTL 
(I/O-Control) für das Gerät at /usr/bin/innobackupex line 336.
 ]
2012-01-05 18:58:21 [INFO] : [ Released lock on port 10000. ]

if i still can help you somehow let me know ~

Original comment by sascha.a...@gmail.com on 5 Jan 2012 at 6:01

[GoogleCodeExporter]

Hi Sascha,

It seems like this issue is separate from the other issue I encountered with 
another user on the mailing list, although the error messages were the same it 
seems the cause it different -- putting this back into a "Started" status while 
we work on it...

Can you let me know which OS version you are running XtraBackup Manager on?

Doing some Googling around, I think I might have an idea what the issue is, but 
it would be helpful to know the platform so that I can set it up on a VM and do 
some testing for myself.

In the meantime, if you would like to try something else -- could you please 
try and recreate the host with, instead of the hostname "localhost", either the 
IP address of a physical interface (not 127.0.0.1) for the machine or else a 
hostname that resolves to one?

Please let me know how you go?

Thanks,
L

Original comment by lachlan....@gmail.com on 6 Jan 2012 at 6:35

• Changed state: Started
• Added labels: Milestone-Release1.0

[GoogleCodeExporter]

Hi, im running

Debian 6.0.3

uname -a
"Linux example.com 2.6.32-5-amd64 #1 SMP Mon Oct 3 03:59:20 UTC 2011 x86_64 
GNU/Linux"

testet it with another ethernet interface (still on the same host), same issue

Original comment by sascha.a...@gmail.com on 6 Jan 2012 at 7:04

[GoogleCodeExporter]

i think i got the problem..

backup manager seems to run something like this:

"xtrabackup_55 --backup --stream --target-dir=/backup | pv -q -L10m | nc 
localhost 10000"

(found this in your blog) it exactly fails with connection refused

but if im running

"xtrabackup_55 --backup --stream --target-dir=/backup | pv -q -L10m | nc -l 
localhost 10000"

nc -l listen mode, for inbound connects

the backups are going to work, but maybe im the wrong way? ;)

Original comment by sascha.a...@gmail.com on 6 Jan 2012 at 7:27

[GoogleCodeExporter]

Hi Sascha,

Thanks for the Info - I'm working on installing Debian 6.0.3 on a VM now. Will 
let you know what I find!

Lachlan

Original comment by lachlan....@gmail.com on 6 Jan 2012 at 7:27

[GoogleCodeExporter]

Hi Sascha,

the -l parameter to netcat (nc) tells it to listen, however, in the case of the 
command we are actually piping output into netcat that we want it to send to 
another netcat process that should be listening.

We do this in the code by first starting :

nc -l 10000 | tar xvif - 

^-- This listens for incoming data on port 10000 and pipes it through to tar 
for expansion into the individual files on disk

then we run

xtrabackup_55 --backup --stream --target-dir=/backup | pv -q -L10m | nc 
localhost 10000

Which is pushing data out through the pv command and then to "nc localhost 
10000" which is going to send the data from STDIN to localhost port 10000.

It's possible your command works because netcat in listen mode will not care 
about data on STDIN. So unfortunately I don't think it's the solution :/

Original comment by lachlan....@gmail.com on 6 Jan 2012 at 8:22

[GoogleCodeExporter]

Hi Sascha,

I was able to reproduce the issue and I believe I have fixed it -- it seems 
netcat on Debian is slightly different than on other Linux platforms I've 
tested on and so I need to give different parameters to tell it to listen:

nc -l -p 10000

instead of

nc -l 10000

on other platforms..

I've update the code tree with a fix to handle this case as rev 207 -- could 
you please try that out and let me know how you go?

L

Original comment by lachlan....@gmail.com on 6 Jan 2012 at 10:38

[GoogleCodeExporter]

Found a small bug in 207 - so make that rev 208 :)

Original comment by lachlan....@gmail.com on 6 Jan 2012 at 10:51

[GoogleCodeExporter]

[deleted comment]

[GoogleCodeExporter]

sorry did not receive last update :o

208 is fully working, what was the problem? :P

Original comment by sascha.a...@gmail.com on 7 Jan 2012 at 11:09

[GoogleCodeExporter]

The problem was that the version of "nc" aka netcat used on the Debian platform 
differs slightly from the version that appears on CentOS. 

On Debian, to tell netcat to open up port 10000 to listen for incoming data, 
one must use:

nc -l -p 10000

On CentOS and other Linux distros that use a similar version to CentOS, one 
must use:

nc -l 10000

So the syntax required actually differs.

I added in some code to XtraBackup Manager that will look for some 
distinguishing information in the "help" output of the "nc" command first, and 
then decide which syntax is most appropriate to use.

This is a little bit hacky, but it works pretty well so far.

I'll close this out as Resolved -- meanwhile please feel free to join the 
Google Group discussion to talk about your experiences and give any other 
feedback as you try it out!

Thanks again
Lachlan

Original comment by lachlan....@gmail.com on 10 Jan 2012 at 5:20

• Changed state: Resolved