Backup over IP stuck

Fuss · 2019-09-03 21:41:29

Hi there,

I'm running into an issue: the backup over rsync to a different host seems to be stuck, now for >30 minutes without writing anything to the logs and without copying any further files.

My command:

[root@xxx:/vmfs/volumes/5b8555ab-94e03f86-bfab-e0d55e6aa26b/xsi-backups] /vmfs/volumes/NVMe1TB/xsi-dir/xsibackup \
> --backup-point="xxx:22:/vmfs/volumes/NVMe1TB_1/xsi-backups" \
> --backup-type=custom \
> --backup-vms="Server-V2" \
> --backup-prog=rsync \
> --backup-id=001 \
> --date-dir=yes \
> --use-smtp=1 \
> --mail-to=xxx@xxx.com \
> --subject="xxx" \
> --description="xxx" \
> --exec=yes >> /vmfs/volumes/NVMe1TB/xsi-backups/xsibackup.log

A tail -f of the log file (in a different terminal) reveals:

--------------------------------------------------------------------------------------------
|                        Rsyslog is not available in XSIBACKUP-FREE                        |
|                          Get XSIBACKUP-PRO at https://33hops.com                          |
--------------------------------------------------------------------------------------------

2019-09-03T21:09:21|  ###############################################################################
2019-09-03T21:09:21|     XSIBACKUP-FREE 11.2.8: new execution request
2019-09-03T21:09:21|  ###############################################################################
2019-09-03T21:09:21|
--------------------------------------------------------------------------------------------
|              High speed and deduplication is not available in XSIBACKUP-FREE             |
|                          Get XSIBACKUP-PRO at https://33hops.com                          |
|                              USE DISCOUNT COUPON: xxx                              |
--------------------------------------------------------------------------------------------

2019-09-03T21:09:21|  NOTICE: (c) XSIBackup kills any user launched jobs, make sure you don't overlap manual jobs
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:21|  NOTICE: (c) XSIBackup-Pro 11.2.9 is available to download
---------------------------------------------------------------------------------------------------------------------------------
XSIBackup PID:          1963493                                               xxx
Tue, 03 Sep 2019 21:09:21 +0000                                   IPv4: xxx/255.255.255.0
VMware ESXi 6.5.0 build-5969303                              (c) Rsync 3.1.0 as opt. dependency
---------------------------------------------------------------------------------------------------------------------------------
Backup Id:                  001                       Intel(R) Xeon(R) CPU E3-1230 v6 @ 3.50GHz
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:22|  Backup description: xxx
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:22|  Alert: crontab is not installed for user root
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:22|  Backup user is: root
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:22|  Backup program is: rsync
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:24|  Remote OpenSSH version is: 7.5
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:24|  Negotiated Cipher (server->client): aes128-ctr
2019-09-03T21:09:24|  Negotiated Cipher (client->server): aes128-ctr
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:24|  Service OpenSSH ready at server xxx:22
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:24|  Remote ESXi version is 6.5.0
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:24|  Info: XSIBACKUP-FREE will now try to determine the remote's XSIBACKUP-FREE installation point...
2019-09-03T21:09:24|  Tip: should this process take too long, use the --remote-xsipath argument to set it
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:26|  Found (c) XSIBackup installation. Remote path is set dynamically
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:26|  Remote xsi path set to: /vmfs/volumes/5caf8291-5027343a-8761-ac1f6bad6525/xsi-dir (filesystem: VMFS-6)
---------------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------
|                     Custom ciphers is not available in XSIBACKUP-FREE                    |
|                          Get XSIBACKUP-PRO at https://33hops.com                          |
--------------------------------------------------------------------------------------------

2019-09-03T21:09:27|  Mirroring to server xxx port 22
2019-09-03T21:09:27|  Checking Rsync exists on the other side...
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:28|  (c)Rsync (samba.org) found at [ xxx:22:/vmfs/volumes/5caf8291-5027343a-8761-ac1f6bad652... ]
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:28|  (c)XSIDiff found at [ xxx:22:/vmfs/volumes/5caf8291-5027343a-8761-ac1f6bad6525/xsi-dir/... ]
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:29|  Getting list of all VMs...
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:29|  5      Server-V1         [NVMe1TB] Server-V1/Server-V1.vmx               ubuntu64Guest           vmx-13
2019-09-03T21:09:30|  7      Server-V2         [NVMe1TB] Server-V2/Server-V2.vmx               ubuntu64Guest           vmx-07
2019-09-03T21:09:30|  8      Server-Voice      [NVMe1TB] Server-Voice/Server-Voice.vmx         debian7_64Guest         vmx-10
2019-09-03T21:09:31|  9      Server-Firewall   [NVMe1TB] Server-Firewall/Server-Firewall.vmx   otherLinux64Guest       vmx-13
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:31|  VMs to backup:
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:31|  7      Server-V2         [NVMe1TB] Server-V2/Server-V2.vmx               ubuntu64Guest           vmx-07
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:39|  Calculating sizes...
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:40|  [Server-V2] Starting backup (size is 213035M on 218184M file)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:40|  XSIBackup will backup your VMs while they are running, so that users can continue to use the VM
2019-09-03T21:09:40|  while the backup is taking place. You can also run --backup-how=cold|warm
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:40|  Hot backup selected for VM: [Server-V2], will not be switched off
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:40|  [Server-V2] info: boot partition is MBR
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:41|  Removing snapshots, please wait...
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:42|  Syncronizing config files
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:43|  [Server-V2] info: created dir to host VM backup
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:44|  [Server-V2] info: VMX file succesfully queued
2019-09-03T21:09:45|  [Server-V2] info: VMSD file succesfully queued
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:45|  [Server-V2] info: NVRAM file succesfully queued
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:09:45|  [Server-V2] info: VMWare Tools detected, taking snapshot QUIESCED(false)...
2019-09-03T21:09:45|  [Server-V2] info: set argument --snapshot=doquiesce to quiesce your VMs
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:10|  Backing up virtual disks...
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000001-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000001.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000002-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000002.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000003-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000003.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000004-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000004.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000005-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000005.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000006-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000006.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000007-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000007.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000008-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000008.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000009-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000009.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000010-sesparse.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000010.vmdk
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot1.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot11.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot2.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot3.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot4.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot5.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot6.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot7.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot8.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2-Snapshot9.vmsn
2019-09-03T21:10:10|  DISK=/vmfs/volumes/NVMe1TB/Server-V2/Server-V2.vmdk
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:11|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:11|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000001-sesparse.vmdk
2019-09-03T21:10:11|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000001-sesparse.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000001-sesparse.vmdk
    688,209,920 100%   71.83MB/s    0:00:09 (xfr#1, to-chk=0/1)

sent 688,378,047 bytes  received 35 bytes  65,559,817.33 bytes/sec
total size is 688,209,920  speedup is 1.00
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:44|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:44|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000001.vmdk
2019-09-03T21:10:44|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000001.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000001.vmdk
            349 100%    0.00kB/s    0:00:00 (xfr#1, to-chk=0/1)

sent 454 bytes  received 35 bytes  326.00 bytes/sec
total size is 349  speedup is 0.71
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:45|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:10:45|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000002-sesparse.vmdk
2019-09-03T21:10:45|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000002-sesparse.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000002-sesparse.vmdk
    671,735,808 100%   72.02MB/s    0:00:08 (xfr#1, to-chk=0/1)

sent 671,899,911 bytes  received 35 bytes  63,990,471.05 bytes/sec
total size is 671,735,808  speedup is 1.00
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:18|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:18|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000002.vmdk
2019-09-03T21:11:18|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000002.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000002.vmdk
            356 100%    0.00kB/s    0:00:00 (xfr#1, to-chk=0/1)

sent 461 bytes  received 35 bytes  992.00 bytes/sec
total size is 356  speedup is 0.72
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:19|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:19|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000003-sesparse.vmdk
2019-09-03T21:11:19|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000003-sesparse.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000003-sesparse.vmdk
    654,356,480 100%   72.05MB/s    0:00:08 (xfr#1, to-chk=0/1)

sent 654,516,343 bytes  received 35 bytes  68,896,460.84 bytes/sec
total size is 654,356,480  speedup is 1.00
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:50|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:50|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000003.vmdk
2019-09-03T21:11:50|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000003.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000003.vmdk
            356 100%    0.00kB/s    0:00:00 (xfr#1, to-chk=0/1)

sent 461 bytes  received 35 bytes  330.67 bytes/sec
total size is 356  speedup is 0.72
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:51|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:11:51|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000004-sesparse.vmdk
2019-09-03T21:11:51|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000004-sesparse.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000004-sesparse.vmdk
    654,331,904 100%   72.51MB/s    0:00:08 (xfr#1, to-chk=0/1)

sent 654,491,759 bytes  received 35 bytes  68,893,873.05 bytes/sec
total size is 654,331,904  speedup is 1.00
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:12:23|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:12:23|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000004.vmdk
2019-09-03T21:12:23|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000004.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000004.vmdk
            356 100%    0.00kB/s    0:00:00 (xfr#1, to-chk=0/1)

sent 461 bytes  received 35 bytes  992.00 bytes/sec
total size is 356  speedup is 0.72
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:12:24|  Rsync file transfer (1st)
---------------------------------------------------------------------------------------------------------------------------------
2019-09-03T21:12:24|  From: /vmfs/volumes/NVMe1TB/Server-V2/Server-V2-000005-sesparse.vmdk
2019-09-03T21:12:24|  To: /vmfs/volumes/NVMe1TB_1/xsi-backups/20190903210921/Server-V2/Server-V2-000005-sesparse.vmdk
---------------------------------------------------------------------------------------------------------------------------------
sending incremental file list
Server-V2-000005-sesparse.vmdk
    808,325,120 100%   72.52MB/s    0:00:10 (xfr#1, to-chk=0/1)

sent 808,522,575 bytes  received 35 bytes  70,306,313.91 bytes/sec
total size is 808,325,120  speedup is 1.00
---------------------------------------------------------------------------------------------------------------------------------

So after the 5th sesparse.vmdk, everything seems to be stopped for > 30 minutes. Disk/network are all almost idle as well.

My server load is 0.31 which seems normal.

Any idea what I'm doing wrong and/or what XSI Backup is waiting on/for?

*Edit: I left the terminal open overnight; the process is still 'active' (i.e. not killed) but no updated in the log file and no files copied. Still 'paused'.

Last edited by Fuss (2019-09-04 08:34:46)

admin · 2019-09-07 11:22:20

All that we can think of is an open socket waiting for data but not receiving it.
Do you have room to fit your data on both ends?
Are the two ESXi boxes still reachable?
Looks like a network issue.

Fuss · 2019-09-09 11:34:40

Well, backup of my other VMs (with fewer snapshots) worked fine.
I'm not aware of any network issues between the two hosts, which are on the same LAN.

Last edited by Fuss (2019-09-09 11:34:58)

admin · 2019-09-11 14:33:13

The issue seems to be affecting Rsync. I would just try to transfer the offending file manually and see it you get some further error message from part of Rsync.

./bin/xsibackup-rsync -rlpDv --progress --partial --whole-file \
--rsh="ssh -o PreferredAuthentications=publickey -o StrictHostKeyChecking=no \
-i xsibackup_id_rsa -p22 --rsync-path="/vmfs/volumes/datastore1/xsi-dir/bin/xsibackup-rsync" \
your-flat.vmdk root@a.b.c.d:/vmfs/volumes/backup/your-flat.vmdk

Forum ©XSIBackup: ©VMWare ©ESXi Backup Software

#1 2019-09-03 21:41:29

Backup over IP stuck

#2 2019-09-07 11:22:20

Re: Backup over IP stuck

#3 2019-09-09 11:34:40

Re: Backup over IP stuck

#4 2019-09-11 14:33:13

Re: Backup over IP stuck

Board footer