Backup stops: No space left on device

tvh_solutions · April 13, 2018, 7:40pm

I use ESXi 6.5U1. Backing up to a B2 bucket, backups fail if we try to backup more than one virtual machine in a row.

Command line is:
vertical backup --exclude ‘Napp-IT*’ --email --threads 32

–threads 32 gives the most upload speed. Reducing threads does not change the errors.

There are no network outages during backup. I see no problems on the backblaze console. From my testing, the problems seem to always occur during backup of the second powered-on VM. Storage is via NFS, there is plenty of free storage (75%). Also, the ramdisks do not seem to fill up (although, for the latter, I have no output right at the time of the abort)

2018-04-13 02:45:02.643394 INFO PROGRAM_VERSION Vertical Backup 1.1.5
2018-04-13 02:45:03.028537 INFO LICENSE_INFO Trial license expires on 2018-04-20
2018-04-13 02:45:09.878426 INFO STORAGE_CREATE Storage set to b2://van-hees-vm-backups
2018-04-13 02:45:11.998846 INFO SNAPSHOT_GETALLVM Listing all virtual machines
2018-04-13 02:45:12.190802 INFO BACKUP_VM Backing up Solaris SAN1, id: 111, vmx path: /vmfs/volumes/SSD/Solaris SAN1/Solaris SAN1.vmx, guest os: solaris11_64Guest
2018-04-13 02:45:12.378573 INFO BACKUP_PREV Last backup at revision 2 found
2018-04-13 02:45:12.952198 INFO SNAPSHOT_POWER Virtual machine Solaris SAN1 is powered off
2018-04-13 02:45:12.952323 INFO SNAPSHOT_REMOVE Removing all snapshots of Solaris SAN1
2018-04-13 02:45:15.893177 INFO BACKUP_UPLOAD Uploaded file /vmfs/volumes/SSD/Solaris SAN1/Solaris SAN1.vmdk
2018-04-13 02:45:15.895619 INFO BACKUP_UPLOAD Uploading file Solaris SAN1-flat.vmdk
2018-04-13 02:45:15.896359 INFO RESTORE_THREAD Using 32 uploading threads
2018-04-13 02:46:29.450089 INFO BACKUP_UPLOAD Uploaded file Solaris SAN1-flat.vmdk 556.87MB/s 00:01:13
2018-04-13 02:46:30.021988 INFO BACKUP_UPLOAD Uploaded file Solaris SAN1.vmx
2018-04-13 02:46:35.738060 INFO BACKUP_DONE Backup Solaris SAN1@fast at revision 3 has been successfully completed
2018-04-13 02:46:35.738138 INFO BACKUP_STATS Total 40967 chunks, 40963.01M bytes; 128 new, 124.01M bytes, 68.49M uploaded
2018-04-13 02:46:35.738165 INFO BACKUP_TIME Total backup time: 00:01:21
2018-04-13 02:46:35.739604 INFO BACKUP_VM Backing up Win Server 2016 Secondary, id: 114, vmx path: /vmfs/volumes/NFSFast/Win Server 2016 Secondary/Win Server 2016 Secondary.vmx, guest os: windows9Server64Guest
2018-04-13 02:46:35.942196 INFO BACKUP_PREV Last backup at revision 2 found
2018-04-13 02:46:36.660627 INFO SNAPSHOT_POWER Virtual machine Win Server 2016 Secondary is powered on
2018-04-13 02:46:36.660854 INFO SNAPSHOT_REMOVE Removing all snapshots of Win Server 2016 Secondary
2018-04-13 02:46:37.859242 INFO SNAPSHOT_CREATE Creating a new virtual machine snapshot for Win Server 2016 Secondary
2018-04-13 02:46:51.639065 INFO BACKUP_UPLOAD Uploaded file /vmfs/volumes/NFSFast/Win Server 2016 Secondary/Win Server 2016 Secondary.vmdk
2018-04-13 02:46:51.639951 INFO BACKUP_UPLOAD Uploading file Win Server 2016 Secondary-flat.vmdk
2018-04-13 02:46:51.641243 INFO RESTORE_THREAD Using 32 uploading threads
2018-04-13 02:58:06.061491 INFO BACKUP_UPLOAD Uploaded file Win Server 2016 Secondary-flat.vmdk 60.73MB/s 00:11:14
2018-04-13 02:58:06.063016 INFO BACKUP_UPLOAD Uploaded file Win Server 2016 Secondary.vmx
2018-04-13 02:58:19.731861 INFO BACKUP_DONE Backup Win Server 2016 Secondary@fast at revision 3 has been successfully completed
2018-04-13 02:58:19.731931 INFO BACKUP_STATS Total 40967 chunks, 40963.01M bytes; 2632 new, 2630.00M bytes, 1207.66M uploaded
2018-04-13 02:58:19.731959 INFO BACKUP_TIME Total backup time: 00:11:29
2018-04-13 02:58:19.733926 INFO SNAPSHOT_REMOVE Removing all snapshots of Win Server 2016 Secondary
2018-04-13 02:58:21.276001 INFO BACKUP_VM Backing up Sophos, id: 115, vmx path: /vmfs/volumes/NFSFast/Sophos/Sophos.vmx, guest os: sles12_64Guest
2018-04-13 02:58:21.464798 INFO BACKUP_LISTING No previous backup found.  Listing existing chunks
2018-04-13 02:59:45.073078 INFO SNAPSHOT_POWER Virtual machine Sophos is powered on
2018-04-13 02:59:45.073327 INFO SNAPSHOT_REMOVE Removing all snapshots of Sophos
2018-04-13 03:00:39.753467 INFO SNAPSHOT_CREATE Creating a new virtual machine snapshot for Sophos
2018-04-13 03:00:42.564397 INFO BACKUP_UPLOAD Uploaded file /vmfs/volumes/NFSFast/Sophos/Sophos.vmdk
2018-04-13 03:00:43.269040 INFO BACKUP_UPLOAD Uploaded file /vmfs/volumes/NFSFast/Sophos/Sophos_2.vmdk
2018-04-13 03:00:43.269797 INFO BACKUP_UPLOAD Uploading file Sophos-flat.vmdk
2018-04-13 03:00:43.270351 INFO RESTORE_THREAD Using 32 uploading threads
2018-04-13 03:01:13.165002 WARNING B2_CALL Failed to send request post https://api001.backblazeb2.com/b2api/v1/b2_list_file_names: ('Connection aborted.', BadStatusLine("''",))
2018-04-13 03:01:13.167896 WARNING B2_CALL Failed to send request post https://api001.backblazeb2.com/b2api/v1/b2_list_file_names: ('Connection aborted.', BadStatusLine("''",))
2018-04-13 03:01:13.183989 WARNING B2_CALL Failed to send request post https://api001.backblazeb2.com/b2api/v1/b2_list_file_names: ('Connection aborted.', BadStatusLine("''",))
2018-04-13 03:01:13.189305 WARNING B2_CALL Failed to send request post https://api001.backblazeb2.com/b2api/v1/b2_list_file_names: ('Connection aborted.', BadStatusLine("''",))
2018-04-13 03:01:35.992520 INFO BACKUP_UPLOAD Uploaded file Sophos-flat.vmdk 77.69MB/s 00:00:52
2018-04-13 03:01:35.992589 INFO BACKUP_UPLOAD Uploading file Sophos_2-flat.vmdk
2018-04-13 03:01:35.993695 INFO RESTORE_THREAD Using 32 uploading threads
2018-04-13 03:01:35.997267 INFO SNAPSHOT_REMOVE Removing all snapshots of Sophos
2018-04-13 03:01:36.165296 INFO COMMAND_FAILURE Failed to run command '/bin/vim-cmd vmsvc/snapshot.removeall 115': No space left on device
2018-04-13 03:01:36.165638 ERROR COMMAND_FAILURE Failed to run command '/bin/vim-cmd vmsvc/snapshot.removeall 115': No space left on device

esxcli system visorfs ramdisk list:

Ramdisk Name  System  Include in Coredumps   Reserved      Maximum       Used  Peak Used   Free  Reserved Free  Maximum Inodes  Allocated Inodes  Used Inodes  Mount Point                
------------  ------  --------------------  ---------  -----------  ---------  ---------  -----  -------------  --------------  ----------------  -----------  ---------------------------
root            true                  true  32768 KiB    32768 KiB   2000 KiB   2000 KiB   93 %           93 %           26624              5088         5073  /                          
etc             true                  true  28672 KiB    28672 KiB    408 KiB    440 KiB   98 %           98 %            4096              1024          648  /etc                       
opt             true                  true      0 KiB    32768 KiB      0 KiB      0 KiB  100 %            0 %            8192              1024           25  /opt                       
var             true                  true   5120 KiB    49152 KiB    392 KiB    396 KiB   99 %           92 %            8192               672          653  /var                       
tmp            false                 false   2048 KiB   262144 KiB  19536 KiB  39420 KiB   92 %            0 %            8192               256           80  /tmp                       
iofilters      false                 false      0 KiB    32768 KiB      0 KiB      0 KiB  100 %            0 %           10240                32            1  /var/run/iofilters         
hostdstats     false                 false      0 KiB  2102272 KiB   6348 KiB   6352 KiB   99 %            0 %            8192                32            5  /var/lib/vmware/hostd/stats
snmptraps      false                 false      0 KiB     1024 KiB      0 KiB      4 KiB  100 %            0 %            8192                32            1  /var/spool/snmp

df -h

Filesystem   Size   Used Available Use% Mounted on
NFS          1.0T 277.6G    785.4G  26% /vmfs/volumes/ZFS_SSD
VMFS-6     119.0G  66.9G     52.1G  56% /vmfs/volumes/NVMe
VMFS-6     999.8G 826.5G    173.3G  83% /vmfs/volumes/iSCSI
VMFS-6     260.8G  41.4G    219.3G  16% /vmfs/volumes/Datastore
vfat       249.7M 156.4M     93.3M  63% /vmfs/volumes/41626ce0-22067b1a-05bd-5d6d6ea5d533
vfat       249.7M 155.6M     94.2M  62% /vmfs/volumes/d6c39fe3-542b13dc-ef0a-e85e5a70813b
vfat       285.8M 232.2M     53.6M  81% /vmfs/volumes/5870d04e-78805b40-4538-0cc47a86750c

gchen · April 14, 2018, 2:46am

This error actually means out of memory. This is similar to the other issue reported last week: https://www.verticalbackup.com/issue?id=5726683906703360.

I’ll be working on the new version on Monday and will send you a new 30-day trial license.

gchen · April 18, 2018, 3:12am

I uploaded a new version 1.2.0 at http://acrosync.com/esxi/vertical.

This version should be much more memory efficient than previous versions.

If you log into your customer page you should also see a 30-day license there. You can activate it by running vertical license activate and then entering the license code.

Masen · February 11, 2019, 4:33am

We are seeing a similar issue - there is plenty of space left on the destination device (as you can see from the df at the bottom) but we get the errors below. Is this also a memory issue? It didn’t happen when we did a backup with 1 thread, but it failed when we tried to backup 2 VMs with 4 threads, a single VM using 8 threads and even a single VM using 4 threads. We are now trying a single VM with 2 threads.

Even backing up from one local datastore to another, at only 1 thread, it’s much slower than the capacity of the network or the read/write speeds of the respective datastores. With multiple threads, we get more acceptable performance but it appears to run out of memory. Is there a solution?

[root@esxi2:/vmfs/volumes/588be13f-2fe66c56-0bde-3863bb417370/verticalbackup] ./vertical backup optimistdaily --no-chunk-listing --threads 8
Vertical Backup 1.2.2
Trial license expires on 2019-03-13
Storage set to /vmfs/volumes/SATA_SAN-DataStore/verticalbackup
Listing all virtual machines
Backing up optimistdaily, id: 29, vmx path: /vmfs/volumes/SAS_SAN-Datastore-2/optimistdaily/optimistdaily.vmx, guest os: centos64Guest
No previous backup found
Virtual machine optimistdaily is powered on
Removing all snapshots of optimistdaily
Uploaded file /vmfs/volumes/SAS_SAN-Datastore-2/optimistdaily/optimistdaily.vmdk
Uploading file optimistdaily-flat.vmdk
Using 8 uploading threads
Uploading *******---------------------------------------------------------------------------------------------------------------------------------------------------- 118.11MB/s 02:20:39 4.9%
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/20/bc590daba9c5f0bee89b47558dffefb25c863122499ee1693d011f614b8632.7d2502dd’: No space left on device
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/69/a5a41ed7b4c5ba0f6777faf4943e0a033217c2f215fc06a9613ed4c12105af.fcaa0f7f’: No space left on device
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/b9/30fcdd7d086f924b3990c36f8330a8f07b1702cd3d40adc81c5b6988e6f83e.be9149c3’: No space left on device
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/d1/4c66c2f04e60ad670727ec86bc59c3259097ed0355236b5cc71c72ac00aaf4.8960732e’: No space left on device
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/45/aedfe21b7f3f5e688de68f8b6d3d42fcd700670ea79a35ccb04c73e468257e.899f8297’: No space left on device
Removing all snapshots of optimistdaily
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/78/27fbfcd5c10088b6406aa53354d57f6b46a437fa82debd8c681782b6f8c76b.1e9a2eed’: No space left on device
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/9e/2cb92eb5fdbbc300bc2513a6ee2b7e540ce1753802f94676880e607c65ed94.713a3665’: No space left on device
Failed to save ‘/vmfs/volumes/SATA_SAN-DataStore/verticalbackup/chunks/0f/4950972c1bf11fb6c0a88d185555e048d89aa68527ed1bbd654b8c2f4ab3de.1b0cd45e’: No space left on device

[root@esxi2:/vmfs/volumes/588be13f-2fe66c56-0bde-3863bb417370/verticalbackup] df -h
Filesystem Size Used Available Use% Mounted on
VMFS-5 4.0T 257.2G 3.7T 6% /vmfs/volumes/SATA_SAN-DataStore
VMFS-5 4.0T 3.7T 326.3G 92% /vmfs/volumes/SAS_SAN-Datastore-2
VMFS-5 4.0T 3.5T 470.1G 89% /vmfs/volumes/SAS_SAN-Datastore-3
VMFS-5 4.0T 88.8G 3.9T 2% /vmfs/volumes/SATA_SAN-Datastore-4
vfat 285.8M 209.1M 76.7M 73% /vmfs/volumes/58b10130-8b279d6a-048c-6c3be5a4a1a8
vfat 249.7M 172.0M 77.8M 69% /vmfs/volumes/5aff4bec-3adc3794-10f3-e0c242faeb60
vfat 249.7M 192.6M 57.1M 77% /vmfs/volumes/4db4bfe1-e77d9839-509c-5a451a5eed46

Masen · February 11, 2019, 5:07am

It’s now giving the “No space left on device” error with even a single thread. Such a bummer! We had really high hopes for this backup solution but it doesn’t seem like it’s production-ready yet. If there are solutions to the above that we can try, please let us know.

Masen · February 11, 2019, 2:47pm

FYI, the host this is being run from has 34GB of free RAM!

gchen · February 12, 2019, 3:49am

Unfortunately any process running inside the ESXi host can use only a very limited amount of memory (less than 1GB), no matter how much memory the host has. We already optimized the memory usage in 1.2.2, and the --no-chunk-listing is the only option that can help (although from your other post it looks like you already used this option).