Backup Central

Hello,

I'm having an issue with both of my ftp xfer hosts.  I'm using BackupPC 3.2.1.  Both FTP servers are running Filezilla Server on Windows systems, and are perfectly accessible using gFTP as my ftp client.

The backup starts, but then terminates within a few seconds.

LOG file:

2012-01-22 04:00:02 Full backup of foo.hopto.org failed
2012-01-22 04:00:07 Backup aborted (0)


XferLOG:

ftp full backup for host foo.hopto.org started on directory /
remotels: can't retrieve remote directory contents of :
handleDir failed: can't retrieve remote directory contents of :
 fail       0       -/-           0
Full backup of foo.hopto.org failed
Backup aborted (0)
Not saving this as a partial backup since it has fewer files than the prior one (got 0 and 0 files versus 0)


host.pl:

$Conf{XferMethod} = 'ftp';
$Conf{FtpUserName} = 'foobar';
$Conf{FtpPasswd} = 'foobar';
$Conf{FtpPassive} = 1;
$Conf{FtpShareName} = '/';

$Conf{PingPath} = '/etc/backuppc/checkftp.sh';
$Conf{PingCmd} = '$pingPath $host';


As I said above, this happens for both of my two ftp xfer hosts.  They both have an almost identical configuration, in terms of the files they're sharing, the FTP server software & configuration, and the BackupPC configuration.

An aside: checkftp.sh is just a short script which runs nmap to "ping" the port 21 on the ftp server. I assume this isn't relevant, since the pinging is running successfully.


An one odd thing is that one of these hosts backed up just fine a few days ago when I set it up, but it no longer works.  I realized this just an hour ago, as I tried to add the second ftp xfer host.


Any assistance you can provide would be appreciated!


Thank you,


Michael

Hello everyone,


I've done a little more testing, and noted the differences in the log on the FTP server side between when I log on using gFTP and when BackupPC attempts to log on.

With gFTP I get:
   SYST
   215 UNIX emulated by Filezilla


With BackupPC, no such message appears.


The only other difference is that gFTP sends a "LIST -aL" command, whereas BackupPC simply sends "LIST".  I don't expect this matters, though.


I've done my best to provide as much information as possible documenting the problem - if there's anything more that would be useful, please let me know.  I'd really appreciate some guidance here.


-Michael




Here are the full server side logs:


For gFTP:
(000090)26/01/2012 0:49:32 AM - (not logged in) (xxx.xxx.xxx.xxx)> Connected, sending welcome message...
(000090)26/01/2012 0:49:32 AM - (not logged in) (xxx.xxx.xxx.xxx)> 220-FileZilla Server version 0.9.39 beta
(000090)26/01/2012 0:49:32 AM - (not logged in) (xxx.xxx.xxx.xxx)> 220-written by Tim Kosse (Tim.Kosse < at > gmx.de ([email]Tim.Kosse < at > gmx.de[/email]))
(000090)26/01/2012 0:49:32 AM - (not logged in) (xxx.xxx.xxx.xxx)> 220 Please visit http://sourceforge.net/projects/filezilla/
(000090)26/01/2012 0:49:32 AM - (not logged in) (xxx.xxx.xxx.xxx)> USER backup
(000090)26/01/2012 0:49:32 AM - (not logged in) (xxx.xxx.xxx.xxx)> 331 Password required for backup
(000090)26/01/2012 0:49:33 AM - (not logged in) (xxx.xxx.xxx.xxx)> PASS  ********************
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 230 Logged on
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> SYST
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 215 UNIX emulated by FileZilla
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> TYPE I
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 200 Type set to I
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> PWD
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 257 "/" is current directory.
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> PASV
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 227 Entering Passive Mode (xx,xxx,xxx,xx,xxx,xxx)
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> LIST -aL
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection accepted
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK



For BackupPC:
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> Connected, sending welcome message...
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> 220-FileZilla Server version 0.9.39 beta
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> 220-written by Tim Kosse (Tim.Kosse < at > gmx.de ([email]Tim.Kosse < at > gmx.de[/email]))
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> 220 Please visit http://sourceforge.net/projects/filezilla/
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> USER backup
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> 331 Password required for backup
(000089)26/01/2012 0:45:13 AM - (not logged in) (xxx.xxx.xxx.xxx)> PASS ********************
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 230 Logged on
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> TYPE I
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 200 Type set to I
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> CWD /
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 250 CWD successful. "/" is current directory.
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> PWD
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 257 "/" is current directory.
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> PWD
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 257 "/" is current directory.
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> PASV
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 227 Entering Passive Mode (xx,xxx,xxx,xx,xxx,xxx)
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> LIST
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection accepted
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK
(000089)26/01/2012 0:45:18 AM - backup (xxx.xxx.xxx.xxx)> disconnected.




On 22 January 2012 04:19, Michael Stepner <michaelstepner < at > gmail.com ([email]michaelstepner < at > gmail.com[/email])> wrote:
Hello,

I'm having an issue with both of my ftp xfer hosts.  I'm using BackupPC 3.2.1.  Both FTP servers are running Filezilla Server on Windows systems, and are perfectly accessible using gFTP as my ftp client.

The backup starts, but then terminates within a few seconds.

LOG file:

[url=tel:2012-01-22%2004]2012-01-22 04[/url]:00:02 Full backup of foo.hopto.org failed
[url=tel:2012-01-22%2004]2012-01-22 04[/url]:00:07 Backup aborted (0)


XferLOG:

ftp full backup for host foo.hopto.org started on directory /
remotels: can't retrieve remote directory contents of :
handleDir failed: can't retrieve remote directory contents of :
 fail       0       -/-           0
Full backup of foo.hopto.org failed
Backup aborted (0)
Not saving this as a partial backup since it has fewer files than the prior one (got 0 and 0 files versus 0)


host.pl:

$Conf{XferMethod} = 'ftp';
$Conf{FtpUserName} = 'foobar';
$Conf{FtpPasswd} = 'foobar';
$Conf{FtpPassive} = 1;
$Conf{FtpShareName} = '/';

$Conf{PingPath} = '/etc/backuppc/checkftp.sh';
$Conf{PingCmd} = '$pingPath $host';


As I said above, this happens for both of my two ftp xfer hosts.  They both have an almost identical configuration, in terms of the files they're sharing, the FTP server software & configuration, and the BackupPC configuration.

An aside: checkftp.sh is just a short script which runs nmap to "ping" the port 21 on the ftp server. I assume this isn't relevant, since the pinging is running successfully.


An one odd thing is that one of these hosts backed up just fine a few days ago when I set it up, but it no longer works.  I realized this just an hour ago, as I tried to add the second ftp xfer host.


Any assistance you can provide would be appreciated!


Thank you,


Michael

On Wed, Jan 25, 2012 at 11:56 PM, Michael Stepner
<michaelstepner < at > gmail.com> wrote:

(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> PWD
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 257 "/" is current
directory.
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> PASV
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 227 Entering
Passive Mode (xx,xxx,xxx,xx,xxx,xxx)
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> LIST
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection
accepted
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK
(000089)26/01/2012 0:45:18 AM - backup (xxx.xxx.xxx.xxx)> disconnected.


I haven't used the ftp module so I can't help much, but is that LIST
command actually sending any filenames?

Since you are installing a 3rd party service on the client for the
transfer anyway, why not use cwrRsync which is known to work and
probably more efficient?

--
Les Mikesell
lesmikesell < at > gmail.com

------------------------------------------------------------------------------
Keep Your Developer Skills Current with LearnDevNow!
The most comprehensive online learning library for Microsoft developers
is just $99.99! Visual Studio, SharePoint, SQL - plus HTML5, CSS3, MVC3,
Metro Style Apps, more. Free future releases when you subscribe now!
http://p.sf.net/sfu/learndevnow-d2d
_______________________________________________
BackupPC-users mailing list
BackupPC-users < at > lists.sourceforge.net
List: https://lists.sourceforge.net/lists/listinfo/backuppc-users
Wiki: http://backuppc.wiki.sourceforge.net
Project: http://backuppc.sourceforge.net/

On 26 January 2012 10:43, Les Mikesell <lesmikesell < at > gmail.com ([email]lesmikesell < at > gmail.com[/email])> wrote:
 

I haven't used the ftp module so I can't help much, but is that LIST
command actually sending any filenames?
 
I don't know how to check for certain, but the with gFTP I certainly get a file listing, and the log shows:


(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> LIST -aL
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection accepted
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK

 
BackupPC might not be getting a file listing, and it shows:


 (000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> LIST
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection accepted
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK


Although, as I said in a previous post, I speculate that that could be due to the lack of BackupPC sending a "SYST" command, which gFTP did:

(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> SYST
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 215 UNIX emulated by FileZilla



 
Since you are installing a 3rd party service on the client for the
transfer anyway, why not use cwrRsync which is known to work and
probably more efficient?


A fair point.  I already have an FTP server running on the clients for services apart from backups, so the decision is whether or not to install a second 3rd party service.  I'm probably willing to do that, although I'd prefer to use the existing FTP server.


Moreover, that might not be an option for all users.  I do think this bug is worth sorting out.


- Michael

On Thu, Jan 26, 2012 at 10:57 AM, Michael Stepner
<michaelstepner < at > gmail.com> wrote:

I haven't used the ftp module so I can't help much, but is that LIST
command actually sending any filenames?


I don't know how to check for certain, but the with gFTP I certainly get a
file listing, and the log shows:

(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> LIST -aL
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection
accepted
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK

Can you try the command line ftp program? 'ls' should correspond to
LIST, and 'ls -a' should show hidden files. Alternatively, you could
use wireshark to observe the network activity on either the linux or
windows side.

BackupPC might not be getting a file listing, and it shows:

 (000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> LIST
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection
accepted
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK

Although, as I said in a previous post, I speculate that that could be due
to the lack of BackupPC sending a "SYST" command, which gFTP did:
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> SYST
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 215 UNIX
emulated by FileZilla

SYST is just a request for the OS version name - it should not change
subsequent behavior.

man ftp and man ftpd on the linux system should give the details of
commands and expected responses.

Since you are installing a 3rd party service on the client for the
transfer anyway, why not use cwrRsync which is known to work and
probably more efficient?


A fair point.  I already have an FTP server running on the clients for
services apart from backups, so the decision is whether or not to install a
second 3rd party service.  I'm probably willing to do that, although I'd
prefer to use the existing FTP server.

You'll probably get more correct incremental backups with rsync
(deletions and changes with old timestamps tracked) and if you have
low bandwidth connections, fulls will be much more efficient.

Moreover, that might not be an option for all users.  I do think this bug is
worth sorting out.

I think you'll have to sort out whether it is filezilla doing
something non-standard or a backuppc bug, though.

--
Les Mikesell
lesmikesell < at > gmail.com

------------------------------------------------------------------------------
Keep Your Developer Skills Current with LearnDevNow!
The most comprehensive online learning library for Microsoft developers
is just $99.99! Visual Studio, SharePoint, SQL - plus HTML5, CSS3, MVC3,
Metro Style Apps, more. Free future releases when you subscribe now!
http://p.sf.net/sfu/learndevnow-d2d
_______________________________________________
BackupPC-users mailing list
BackupPC-users < at > lists.sourceforge.net
List: https://lists.sourceforge.net/lists/listinfo/backuppc-users
Wiki: http://backuppc.wiki.sourceforge.net
Project: http://backuppc.sourceforge.net/

On 26 January 2012 14:59, Les Mikesell <lesmikesell < at > gmail.com ([email]lesmikesell < at > gmail.com[/email])> wrote:
On Thu, Jan 26, 2012 at 10:57 AM, Michael Stepner
<michaelstepner < at > gmail.com ([email]michaelstepner < at > gmail.com[/email])> wrote:

I haven't used the ftp module so I can't help much, but is that LIST
command actually sending any filenames?


I don't know how to check for certain, but the with gFTP I certainly get a
file listing, and the log shows:

(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> LIST -aL
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection
accepted
(000090)26/01/2012 0:49:34 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK


Can you try the command line ftp program?   'ls' should correspond to
LIST, and 'ls -a' should show hidden files.  Alternatively, you could
use wireshark to observe the network activity on either the linux or
windows side.


I used the command line ftp program on my desktop, which the man page indicates is supplied by gFTP (see my next statements for more details).  It behaves exactly as the GTK GUI version does: when I log in, it automatically sends SYST and the server responds "215 UNIX emulated by FileZilla".  And when I send ls or ls -a, the server responds with LIST -aL.


When I tried to run the command line ftp program on my server, I realized I didn't have one.


I considered that that may be the problem, but I doubted it, since BackupPC must be using its own mechanism for making FTP connections, without relying on an external program.  The server is seeing a connection, after all, and I note that in its Debian/Ubuntu packages, there is no ftp-related dependency or suggested/recommended package. But I decided to try installing gFTP's console client on the server anyway.  I did, it behaves the same way as it does on my desktop when connecting to the FTP server, and installing it did not solve my issues with BackupPC.
 

BackupPC might not be getting a file listing, and it shows:

 (000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> LIST
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 150 Connection
accepted
(000089)26/01/2012 0:45:13 AM - backup (xxx.xxx.xxx.xxx)> 226 Transfer OK

Although, as I said in a previous post, I speculate that that could be due
to the lack of BackupPC sending a "SYST" command, which gFTP did:
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> SYST
(000090)26/01/2012 0:49:33 AM - backup (xxx.xxx.xxx.xxx)> 215 UNIX
emulated by FileZilla


SYST is just a request for the OS version name - it should not change
subsequent behavior.

man ftp and man ftpd on the linux system should give the details of
commands and expected responses.


You're right, I looked it up, and SYST shouldn't be changing subsequent behaviour. This difference in the logs is immaterial.




>> Since you are installing a 3rd party service on the client for the
transfer anyway, why not use cwrRsync which is known to work and
probably more efficient?


A fair point.  I already have an FTP server running on the clients for
services apart from backups, so the decision is whether or not to install a
second 3rd party service.  I'm probably willing to do that, although I'd
prefer to use the existing FTP server.


You'll probably get more correct incremental backups with rsync
(deletions and changes with old timestamps tracked) and if you have
low bandwidth connections, fulls will be much more efficient.


So, I'm stumped by this bug. It might be client side: gFTP works fine in fetching a directory listing and files from the server, but BackupPC does not.  It could also be server side: perhaps FileZilla has some non-standard behaviour (as you said), and perhaps gFTP is able to adapt to it whereas BackupPC is not.


As you suggest, I'm going to give up and switch to rsync.  I don't really want to spend more time investigating this, and even if I did, I wouldn't know what to do next.  I hope this conversation is useful if someone else encounters a similar issue in the future.  I know that when I googled the error message I had in my BackupPC logs, I found nothing.


A final note about my switch to rsync, for any future readers:


I once used cwRsync, quite a few years ago, but it seems it's no longer freeware! You now have to pay for a license, which only receives updates for one year.  So, I'm going to simply set up rsync and SSH in cygwin, for free.  I intend to use these instructions to guide me: [url=http://www.cs.umd.edu/~cdunne/projs/backuppc_guide.html#Client Setup (Windows 7/Vista/XP)]http://www.cs.umd.edu/~cdunne/projs/backuppc_guide.html#Client Setup (Windows 7/Vista/XP)[/url]
 

Moreover, that might not be an option for all users.  I do think this bug is
worth sorting out.


I think you'll have to sort out whether it is filezilla doing
something non-standard or a backuppc bug, though.


--
 Les Mikesell
   lesmikesell < at > gmail.com ([email]lesmikesell < at > gmail.com[/email])





Thank you for your help, Les.


Michael