[rdiff-backup-users] Restoring to remote destination fails

[Stewart Stafford]

Greetings,

I am having some difficulty restoring directories to a remote server. 
This works fine restoring a single file to a remote server and works 
fine restoring a directory locally  Even trying to restore using the 
"localhost::/path/to/dir" fails.  Attached is a debug of a failed 
restore to a remote server.  Running CentOS 5.2 with rdiff-backup 
version 1.3.1.

Any help would be greatly appreciated.

Thanks,
Stew

Tue Feb 17 09:05:46 2009  Using rdiff-backup version 1.3.1
Tue Feb 17 09:05:46 2009  Using mirror root directory 
/export/5tank/stokes/rdiff/testa1
Tue Feb 17 09:05:46 2009  Executing ssh -C bup rdiff-backup --server
Tue Feb 17 09:05:46 2009  Client sending (0): ConnectionRequest: Globals.get 
with 1 arguments
Tue Feb 17 09:05:46 2009  Client sending (0): 'version'
Tue Feb 17 09:05:47 2009  Client received (0): '1.3.1'
Tue Feb 17 09:05:47 2009  Registering connection 1
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
SetConnections.init_connection_remote with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 1
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
log.Log.setverbosity with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 9
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
log.Log.setterm_verbosity with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 9
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 'rbdir'
Tue Feb 17 09:05:47 2009  Client sending (0): Path: 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data
Index: ()
Data: {'uid': 0, 'perms': 448, 'type': 'dir', 'gname': 'root', 'ctime': 
1234880303, 'devloc': 64778L, 'uname': 'root', 'nlink': 3, 'gid': 0, 'mtime': 
1234880303, 'atime': 1234880399, 'inode': 212533272, 'size': 4096}
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
rpath.make_file_dict with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): '/tmp/test/'
Tue Feb 17 09:05:47 2009  Client received (0): {'type': None}
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
rpath.make_file_dict with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): '/tmp/test'
Tue Feb 17 09:05:47 2009  Client received (0): {'type': None}
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
Time.setcurtime_local with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 1234883147
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 'client_conn'
Tue Feb 17 09:05:47 2009  Client sending (0): LocalConnection
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
Globals.postset_regexp_local with 3 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): 'no_compression_regexp'
Tue Feb 17 09:05:47 2009  Client sending (0): 
'(?i).*\\.(gz|z|bz|bz2|tgz|zip|rpm|deb|jpg|jpeg|gif|png|jp2|mp3|ogg|avi|wmv|mpeg|mpg|rm|mov|flac|shn|pgp|gpg|rz|lzh|zoo|lharc|rar|arj|asc)$'
Tue Feb 17 09:05:47 2009  Client sending (0): None
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
robust.install_signal_handlers with 0 arguments
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
Hardlink.initialize_dictionaries with 0 arguments
Tue Feb 17 09:05:47 2009  Client received (0): None
Tue Feb 17 09:05:47 2009  Client sending (0): ConnectionRequest: 
fs_abilities.restore_set_globals with 1 arguments
Tue Feb 17 09:05:47 2009  Client sending (0): Path: /tmp/test
Index: ()
Data: {'type': None}
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: 
fs_abilities.get_readonly_fsa with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'rdiff-backup repository'
Tue Feb 17 09:05:47 2009  Client received (1): Path: 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data
Index: ()
Data: {'ctime': 1234880303, 'perms': 448, 'type': 'dir', 'gname': 'root', 
'devloc': 64778L, 'uname': 'root', 'nlink': 3, 'mtime': 1234880303, 'uid': 0, 
'gid': 0, 'atime': 1234880399, 'inode': 212533272, 'size': 4096}
Tue Feb 17 09:05:47 2009  Unable to import module xattr.
Extended attributes not supported on filesystem at 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data
Tue Feb 17 09:05:47 2009  Unable to import module posix1e from pylibacl package.
POSIX ACLs not supported on filesystem at 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data
Tue Feb 17 09:05:47 2009  Unable to import win32security module. Windows ACLs
not supported by filesystem at 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data
Tue Feb 17 09:05:47 2009  Client sending (1): 
-----------------------------------------------------------------
Detected abilities for rdiff-backup repository (read only) file system:
  Access control lists                         Off
  Extended attributes                          Off
  Windows access control lists                 Off
  Case sensitivity                             On
  Escape DOS devices                           Off
  Escape trailing spaces                       Off
  Mac OS X style resource forks                Off
  Mac OS X Finder information                  Off
-----------------------------------------------------------------
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'eas_active'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'eas_write'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'eas_conn'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'acls_active'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'acls_write'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'acls_conn'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'win_acls_active'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:47 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:47 2009  Client received (1): 'win_acls_write'
Tue Feb 17 09:05:47 2009  Client received (1): None
Tue Feb 17 09:05:47 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'win_acls_conn'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'resource_forks_active'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'resource_forks_write'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'resource_forks_conn'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'carbonfile_active'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'carbonfile_write'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'carbonfile_conn'
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'preserve_hardlinks'
Tue Feb 17 09:05:48 2009  Client received (1): 1
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'change_ownership'
Tue Feb 17 09:05:48 2009  Client received (1): 1
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'symlink_perms'
Tue Feb 17 09:05:48 2009  Client received (1): 0
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
rpath.make_file_dict with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 
'/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/chars_to_quote'
Tue Feb 17 09:05:48 2009  Client sending (1): {'uid': 0, 'perms': 384, 'type': 
'reg', 'ctime': 1234809147, 'devloc': 64778L, 'nlink': 1, 'gid': 0, 'mtime': 
1234288906, 'atime': 1234880398, 'inode': 212533274, 'size': 0}
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
rpath.setdata_local with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): Path: 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/chars_to_quote
Index: ('chars_to_quote',)
Data: {'uid': 0, 'perms': 384, 'type': 'reg', 'ctime': 1234809147, 'devloc': 
64778L, 'nlink': 1, 'mtime': 1234288906, 'gid': 0, 'atime': 1234880398, 
'inode': 212533274, 'size': 0}
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
rpath.open_local_read with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): Path: 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/chars_to_quote
Index: ('chars_to_quote',)
Data: {'uid': 0, 'perms': 384, 'type': 'reg', 'ctime': 1234809147, 'devloc': 
64778L, 'nlink': 1, 'mtime': 1234288906, 'gid': 0, 'atime': 1234880398, 
'inode': 212533274, 'size': 0}
Tue Feb 17 09:05:48 2009  Client sending (1): <open file 
'/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/chars_to_quote', mode 'rb' 
at 0x2b149c394cd8>
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
VirtualFile.readfromid with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 0
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): ''
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
VirtualFile.closebyid with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 0
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'chars_to_quote'
Tue Feb 17 09:05:48 2009  Client received (1): ''
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
rpath.make_file_dict with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 
'/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/special_escapes'
Tue Feb 17 09:05:48 2009  Client sending (1): {'uid': 0, 'perms': 384, 'type': 
'reg', 'ctime': 1234817485, 'devloc': 64778L, 'nlink': 1, 'gid': 0, 'mtime': 
1234817485, 'atime': 1234880398, 'inode': 212534204, 'size': 0}
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
rpath.setdata_local with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): Path: 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/special_escapes
Index: ('special_escapes',)
Data: {'uid': 0, 'perms': 384, 'type': 'reg', 'ctime': 1234817485, 'devloc': 
64778L, 'nlink': 1, 'mtime': 1234817485, 'gid': 0, 'atime': 1234880398, 
'inode': 212534204, 'size': 0}
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
rpath.open_local_read with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): Path: 
/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/special_escapes
Index: ('special_escapes',)
Data: {'uid': 0, 'perms': 384, 'type': 'reg', 'ctime': 1234817485, 'devloc': 
64778L, 'nlink': 1, 'mtime': 1234817485, 'gid': 0, 'atime': 1234880398, 
'inode': 212534204, 'size': 0}
Tue Feb 17 09:05:48 2009  Client sending (1): <open file 
'/export/5tank/stokes/rdiff/testa1/rdiff-backup-data/special_escapes', mode 
'rb' at 0x2b149c394cd8>
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
VirtualFile.readfromid with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 1
Tue Feb 17 09:05:48 2009  Client received (1): None
Tue Feb 17 09:05:48 2009  Client sending (1): ''
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: 
VirtualFile.closebyid with 1 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 1
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'escape_dos_devices'
Tue Feb 17 09:05:48 2009  Client received (1): False
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (1): ConnectionRequest: Globals.set 
with 2 arguments
Tue Feb 17 09:05:48 2009  Client received (1): 'escape_trailing_spaces'
Tue Feb 17 09:05:48 2009  Client received (1): False
Tue Feb 17 09:05:48 2009  Client sending (1): None
Tue Feb 17 09:05:48 2009  Client received (0): None
Tue Feb 17 09:05:48 2009  Client sending (0): ConnectionRequest: 
user_group.init_user_mapping with 2 arguments
Tue Feb 17 09:05:48 2009  Client sending (0): None
Tue Feb 17 09:05:48 2009  Client sending (0): None
Tue Feb 17 09:05:48 2009  Client received (0): None
Tue Feb 17 09:05:48 2009  Client sending (0): ConnectionRequest: 
user_group.init_group_mapping with 2 arguments
Tue Feb 17 09:05:48 2009  Client sending (0): None
Tue Feb 17 09:05:48 2009  Client sending (0): None
Tue Feb 17 09:05:49 2009  Client received (0): None
Tue Feb 17 09:05:49 2009  Client sending (0): ConnectionRequest: 
log.Log.open_logfile_allconn with 1 arguments
Tue Feb 17 09:05:49 2009  Client sending (0): LocalConnection
Tue Feb 17 09:05:49 2009  Client received (0): None
Tue Feb 17 09:05:49 2009  Starting restore of testa1/.mozilla to /tmp/test as 
it was as of Tue Feb 17 08:16:46 2009.
Tue Feb 17 09:05:49 2009  Client sending (0): ConnectionRequest: 
restore.TargetStruct.get_initial_iter with 1 arguments
Tue Feb 17 09:05:49 2009  Client sending (0): Path: /tmp/test
Index: ()
Data: {'type': None}
Tue Feb 17 09:05:49 2009  Client received (0): 
<rdiff_backup.iterfile.FileToMiscIter instance at 0x2b149c397248>
Tue Feb 17 09:05:49 2009  Client sending (0): ConnectionRequest: 
restore.TargetStruct.patch with 2 arguments
Tue Feb 17 09:05:49 2009  Client sending (0): Path: /tmp/test
Index: ()
Data: {'type': None}
Tue Feb 17 09:05:49 2009  Client sending (0): <generator object at 
0x2b149c3a3d88>
Tue Feb 17 09:05:49 2009  Client received (1): ConnectionRequest: 
VirtualFile.readfromid with 2 arguments
Tue Feb 17 09:05:49 2009  Client received (1): 2
Tue Feb 17 09:05:49 2009  Client received (1): None
Tue Feb 17 09:05:49 2009  Client sending (2): ConnectionRequest: 
VirtualFile.readfromid with 2 arguments
Tue Feb 17 09:05:49 2009  Client sending (2): 0
Tue Feb 17 09:05:49 2009  Client sending (2): None
Tue Feb 17 09:05:49 2009  Client received (2): 
'r\x00\x00\x00\x00\x00\x00\xba()}q\x01(U\x03uidq\x02K\x00U\x05permsq\x03M\xc0\x01U\x04typeq\x04U\x03dirq\x05U\x05gnameq\x06U\x04rootq\x07U\x05ctimeq\x08JK\xd2\x9aIU\x06devlocq\tL64769L\nU\x05unameq\nU\x04rootq\x0bU\x05nlinkq\x0cK\x02U\x03gidq\rK\x00U\x05mtimeq\x0eJK\xd2\x9aIU\x05atimeq\x0fJK\xd2\x9aIU\x05inodeq\x10J\x01\x80\x05\x00U\x04sizeq\x11M\x00\x10uK\x00t.z\x00\x00\x00\x00\x00\x00\x00'
Tue Feb 17 09:05:49 2009  Client sending (1): 
'r\x00\x00\x00\x00\x00\x00,()}q\x01(U\x08filetypeq\x02U\x08snapshotq\x03U\x04typeq\x04NuK\x00t.z\x00\x00\x00\x00\x00\x00\x00'
Tue Feb 17 09:05:49 2009  Client received (1): ConnectionRequest: 
log.Log.log_to_file with 1 arguments
Tue Feb 17 09:05:49 2009  Client received (1): 'Processing changed file .'
Tue Feb 17 09:05:49 2009  Client sending (1): None
Tue Feb 17 09:05:49 2009  Client received (1): ConnectionRequest: 
log.Log.log_to_file with 1 arguments
Tue Feb 17 09:05:49 2009  Client received (1): 'Regular copying () to 
/tmp/rdiff-backup.tmp.1'
Tue Feb 17 09:05:49 2009  Client sending (1): None
Tue Feb 17 09:05:49 2009  Client received (1): ConnectionRequest: 
log.Log.log_to_file with 1 arguments
Tue Feb 17 09:05:49 2009  Client received (1): 'Removing directory /tmp/test'
Tue Feb 17 09:05:49 2009  Client sending (1): None
Tue Feb 17 09:05:49 2009  Client received (0): None
Tue Feb 17 09:05:49 2009  Restore finished
Tue Feb 17 09:05:49 2009  Cleaning up
Tue Feb 17 09:05:49 2009  Client sending (0): ConnectionRequest: 
log.Log.close_logfile_allconn with 0 arguments
Tue Feb 17 09:05:49 2009  Client received (0): None
Tue Feb 17 09:05:49 2009  Client received (0): 'quitting'