Xen Orchestra ebadf: bad file descriptor, write

wessel1512 · November 26, 2019, 3:01pm

What is the problem you are having with rclone?

if i try to make a backup on Xen Orchestra of my vm i get a ebadf: bad file descriptor, write

What is your rclone version (output from `rclone version`)

rclone v1.50.1

os/arch: linux/amd64
go version: go1.13.4

Which OS you are using and how many bits (eg Windows 7, 64 bit)

ubuntu 18.04.3

Which cloud storage system are you using? (eg Google Drive)

private ftp share white crypto mounted

my service config

[Unit]
Description=RClone Service
Wants=network-online.target
After=network-online.target

[Service]
Type=notify
Environment=RCLONE_CONFIG=/opt/rclone/rclone.conf
KillMode=none
RestartSec=5
ExecStart=/usr/bin/rclone mount secure: /mnt/secure \
--allow-other \
--buffer-size 256M \
--dir-cache-time 1000h \
--log-level INFO \
--log-file /opt/rclone/logs/rclone.log \
--poll-interval 15s \
--timeout 1h \
--umask 002 \
--rc \
--rc-addr 127.0.0.1:5572
ExecStop=/bin/fusermount -uz /GD
Restart=on-failure

[Install]
WantedBy=multi-user.target

A log from the command with the `-vv` flag (eg output from `rclone -vv copy /tmp remote:tmp`)

2019/11/26 13:59:36 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/683490ee-1b82-4b45-9c45-0f000e
2b064f/.20191126T135928Z.vhd: WriteFileHandle.Write: error: Bad file descriptor
2019/11/26 13:59:36 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642e
f572a3/.20191126T135930Z.vhd: WriteFileHandle.Write: error: Bad file descriptor
2019/11/26 13:59:36 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/0bc0ca1d-b44f-4ec4-889b-142386
463100/.20191126T135932Z.vhd: WriteFileHandle.Write: error: Bad file descriptor
2019/11/26 13:59:42 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3
077136/.20191126T135934Z.vhd: WriteFileHandle.Write: error: Bad file descriptor
2019/11/26 13:59:42 ERROR : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/cf6cbbe3-4503-43bf-bfd4-817021
adc773/.20191126T135940Z.vhd: WriteFileHandle.Write: error: Bad file descriptor
2019/11/26 14:05:23 INFO  : full/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/.20191126T140522Z.xva: Copied (new)
2019/11/26 14:05:23 ERROR : full/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/.20191126T140522Z.xva: WriteFileHandle.Write: error: Bad file descriptor
2019/11/26 14:05:26 ERROR : full/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/.20191126T140523Z.xva: WriteFileHandle.Write: error: Bad file descriptor

error discrption

Macro: int EBADF

Bad file descriptor; for example, I/O on a descriptor that has been closed or reading from a descriptor open only for writing (or vice versa).

thestigma · November 26, 2019, 3:18pm

I have no experience whatsoever with Xen Orchestra, but as far as rclone goes I would highly recommend using write caching to provide the highest level of compatibility for write operations. Without this you are rather limited to uncomplicated straight copies and many programs will have issues using the clouddrive directly.

Try adding these:

--cache-dir "/some/path/to/cachefolder"
--vfs-cache-mode writes

wessel1512 · November 26, 2019, 6:07pm

that works soft of

2019/11/26 15:27:32 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191126T152729Z.vhd: WriteFileHandle.New Rcat failed: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/
2sml683qro6ktqneqdnrevmim0/4vihnnvj8vsd000j0qpmh5qprehh7f12kcl2738li8upeibchsl3kpekr5nlj3rdd26e32hcg5v40/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/et1ds72r6nrcb7t2pujl1hh1mbgh1crvu1hbal3mkv069ij33s6qjn7qphs6fqfno8244kg4kq382"
failed: write tcp 10.10.50.15:45914->192.168.1.103:21: write: broken pipe
2019/11/26 15:27:32 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191126T152729Z.vhd: WriteFileHandle.Write error: io: read/write on closed pipe
2019/11/26 15:27:32 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191126T152729Z.vhd: WriteFileHandle.Flush error: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/2sml
683qro6ktqneqdnrevmim0/4vihnnvj8vsd000j0qpmh5qprehh7f12kcl2738li8upeibchsl3kpekr5nlj3rdd26e32hcg5v40/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/et1ds72r6nrcb7t2pujl1hh1mbgh1crvu1hbal3mkv069ij33s6qjn7qphs6fqfno8244kg4kq382" fail
ed: write tcp 10.10.50.15:45914->192.168.1.103:21: write: broken pipe
2019/11/26 15:27:33 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191126T152732Z.vhd: WriteFileHandle.New Rcat failed: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/
2sml683qro6ktqneqdnrevmim0/cvu17dfu403cmitl8uqhsjdan2vgaed1ofork795s1o63vjmg108ofues6gtimr6573d86efl9l5q/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/t1ladlttj3g9tmliqm3o9hptfarvthi80mi82jr00ima3rh1r0igq7oa7m6tminge5km0g22ons4q"
failed: write tcp 10.10.50.15:46254->192.168.1.103:21: write: broken pipe
2019/11/26 15:27:33 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191126T152732Z.vhd: WriteFileHandle.Write error: io: read/write on closed pipe
2019/11/26 15:27:33 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191126T152732Z.vhd: WriteFileHandle.Flush error: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/2sml
683qro6ktqneqdnrevmim0/cvu17dfu403cmitl8uqhsjdan2vgaed1ofork795s1o63vjmg108ofues6gtimr6573d86efl9l5q/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/t1ladlttj3g9tmliqm3o9hptfarvthi80mi82jr00ima3rh1r0igq7oa7m6tminge5km0g22ons4q" fail
ed: write tcp 10.10.50.15:46254->192.168.1.103:21: write: broken pipe
2019/11/26 15:27:35 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191126T152734Z.vhd: WriteFileHandle.New Rcat failed: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/
2sml683qro6ktqneqdnrevmim0/7h1e5e4otlhrqdlted95ljrvsi0ci9nd3s803raja51sfh19jhe5hfk6miom2u70ku1qhahf3fqag/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/dl6d2d04a1e49dmbpc9lf05b7jkrtqnok1sgid3hb13i29muac01f8c0fmcndghu9amiqc51rjb0a"
failed: write tcp 10.10.50.15:46172->192.168.1.103:21: write: broken pipe
2019/11/26 15:27:35 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191126T152734Z.vhd: WriteFileHandle.Write error: io: read/write on closed pipe
2019/11/26 15:27:35 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191126T152734Z.vhd: WriteFileHandle.Flush error: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/2sml
683qro6ktqneqdnrevmim0/7h1e5e4otlhrqdlted95ljrvsi0ci9nd3s803raja51sfh19jhe5hfk6miom2u70ku1qhahf3fqag/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/dl6d2d04a1e49dmbpc9lf05b7jkrtqnok1sgid3hb13i29muac01f8c0fmcndghu9amiqc51rjb0a" fail
ed: write tcp 10.10.50.15:46172->192.168.1.103:21: write: broken pipe
2019/11/26 15:39:31 INFO  : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/.20191126T152735Z.vhd: Moved (server side)
2019/11/26 15:39:33 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/.20191126T152735Z.vhd: ReadFileHandle.Release error: EOF
2019/11/26 15:39:34 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/20191126T152735Z.vhd: ReadFileHandle.Release error: EOF
2019/11/26 15:39:34 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/20191126T152735Z.vhd: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= write
s
2019/11/26 15:39:34 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/20191126T152735Z.vhd: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= write
s
2019/11/26 15:42:47 INFO  : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191126T152746Z.vhd: Moved (server side)
2019/11/26 15:45:32 ERROR : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/cf6cbbe3-4503-43bf-bfd4-817021adc773/20191126T152746Z.vhd: ReadFileHandle.Release error: EOF
2019/11/26 16:05:54 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/.20191126T154521Z.vhd: WriteFileHandle.New Rcat failed: update getinfo: write tcp 10.10.50.15:52476->192.168.1.103:21: write:
broken pipe
2019/11/26 16:05:54 ERROR : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/64e13671-0250-473b-862d-cd00e3077136/.20191126T154521Z.vhd: WriteFileHandle.Flush error: update getinfo: write tcp 10.10.50.15:52476->192.168.1.103:21: write: brok
en pipe
2019/11/26 16:30:14 INFO  : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191126T154517Z.vhd: Moved (server side)
2019/11/26 16:30:16 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191126T154517Z.vhd: ReadFileHandle.Release error: EOF
2019/11/26 16:30:17 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191126T154517Z.vhd: ReadFileHandle.Release error: EOF
2019/11/26 16:30:18 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191126T154517Z.vhd: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= write
s
2019/11/26 16:30:18 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191126T154517Z.vhd: WriteFileHandle: Can't open for write without O_TRUNC on existing file without --vfs-cache-mode >= write
s
2019/11/26 16:47:16 ERROR : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191126T154531Z.vhd: WriteFileHandle.New Rcat failed: update getinfo: write tcp 10.10.50.15:59068->192.168.1.103:21: write:
broken pipe
2019/11/26 16:47:16 ERROR : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191126T154531Z.vhd: WriteFileHandle.Flush error: update getinfo: write tcp 10.10.50.15:59068->192.168.1.103:21: write: brok
en pipe
2019/11/26 17:05:19 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191126T154515Z.vhd: WriteFileHandle.New Rcat failed: update getinfo: write tcp 10.10.50.15:52388->192.168.1.103:21: write:
broken pipe
2019/11/26 17:05:19 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191126T154515Z.vhd: WriteFileHandle.Flush error: update getinfo: write tcp 10.10.50.15:52388->192.168.1.103:21: write: brok
en pipe
2019/11/26 17:23:56 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191126T154519Z.vhd: WriteFileHandle.New Rcat failed: update getinfo: write tcp 10.10.50.15:50802->192.168.1.103:21: write:
broken pipe
2019/11/26 17:23:56 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191126T154519Z.vhd: WriteFileHandle.Flush error: update getinfo: write tcp 10.10.50.15:50802->192.168.1.103:21: write: brok
en pipe

Animosity022 · November 26, 2019, 6:08pm

You haven't put on --vfs-cache-mode writes

If you can include the full log, which has the mount flags as well, that's helpful . rather than pieces of the log.

Also, please run the mount in debug mode so we have the full error messages. You can change INFO to DEBUG for that.

wessel1512 · November 26, 2019, 6:19pm

its in the config

i have set the info to debug

running a new backup to se wast gowning wrong

Animosity022 · November 26, 2019, 6:21pm

The error indicates it not set based on your logs you shared.

Right there.

thestigma · November 26, 2019, 6:30pm

This flag can not be set in the config.
Currently, only backend-flags can be set in the config (and mind you that these also use a slightly different format).

So for example you can set chuk_size on a Google Drive remote, as the setting is for a backend.
But you can not set --fast-list as it is a general flag for rclone. All VFS flags are similarly general flags and can not be set in config. (NCW has indicated this will eventually get improved, but for now we have to deal with it).

TLDR: You are not actually using --vfs-cache-mode-writes . If you set this in the config as-is it will either error or just be ignored.

This is why it is nice to be able to see the start of logs because they show us for sure what flags are actually being used - ie. we don't have to to blindly trust the user that they did it right

wessel1512 · November 27, 2019, 8:55am

it is running but i still get file system errors

i have rebooted the hole system ant that enabled everything
only Xen Orchestra is still not happy

systemctl status rclone-mount

● rclone-mount.service - RClone Service
   Loaded: loaded (/etc/systemd/system/rclone-mount.service; enabled; vendor preset: enabled)
   Active: active (running) since Wed 2019-11-27 08:22:16 UTC; 21min ago
 Main PID: 975 (rclone)
    Tasks: 18 (limit: 4623)
   CGroup: /system.slice/rclone-mount.service
           └─975 /usr/bin/rclone mount secure: /mnt/secure --allow-other --buffer-size 256M --dir-cache-time 1000h --log-level DEBUG --log-file /opt/rclone/logs/rclone.log --cache-dir /cache/rclone --vfs-cache-mode writes --poll-interval 15s --timeout 1h --umask 002 --rc --rc-addr 127.0.0

Nov 27 08:22:06 xenorchestra systemd[1]: Starting RClone Service...
Nov 27 08:22:16 xenorchestra systemd[1]: Started RClone Service.

part of the fog file

2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=16384, offset=9995369472
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=16384, offset=9995385856
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=16384, offset=9995402240
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=16384, offset=9995418624
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=16384, offset=9995435008
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=16384, offset=9995451392
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Write: len=6144, offset=9995467776
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: >Write: written=6144, err=<nil>
2019/11/27 08:30:26 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd (rw)}: Flush: 
2019/11/27 08:30:26 DEBUG : /: Lookup: name="daly"
2019/11/27 08:30:26 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/11/27 08:30:26 DEBUG : daly/: Attr: 
2019/11/27 08:30:26 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: Need to transfer - File not found at Destination
2019/11/27 08:30:26 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : /: Lookup: name="daly"
2019/11/27 08:30:27 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/: Attr: 
2019/11/27 08:30:27 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/: Lookup: name="xo-vm-backups"
2019/11/27 08:30:27 DEBUG : daly/: >Lookup: node=daly/xo-vm-backups/, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/: Attr: 
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/: Lookup: name="e327caf5-ade2-4d0a-d3db-c5661dd8ff2f"
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: Attr: 
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: Lookup: name="vdis"
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: Attr: 
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: Lookup: name="b73b50d3-4597-4583-b799-ff78a8cfbda2"
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: Attr: 
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: Lookup: name="b246d730-53dc-4eaf-bc39-0f642ef572a3"
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Attr: 
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Lookup: name=".20191127T082353Z.vhd"
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: Attr: 
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: >Attr: a=valid=1s ino=0 size=9995473920 mode=-rw-rw-r--, err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Lookup: name="20191127T082353Z.vhd"
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Lookup: node=<nil>, err=no such file or directory
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Rename: oldName=".20191127T082353Z.vhd", newName="20191127T082353Z.vhd", newDir=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/
2019/11/27 08:30:27 DEBUG : File is currently open, delaying rename 0xc00024e5a0
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Rename: err=<nil>
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: Open: flags=OpenReadOnly
2019/11/27 08:30:27 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: Open: flags=O_RDONLY
2019/11/27 08:30:27 DEBUG : ftp://192.168.1.103:21/rclone/xen: Connection failed, closing: write tcp 10.10.50.15:53402->192.168.1.103:21: write: broken pipe
2019/11/27 08:30:31 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: Received error: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/2sml683qro6ktqneqdnrevmim0/cvu17dfu403cmitl8uqhsjdan2vgaed1ofork795s1o63vjmg108ofues6gtimr6573d86efl9l5q/7f6tg5s1n4ur5rtu54ksd4o574/vvogte6he1ff37f90cvnbqcjicm6insh19itsnlrb1g9tsq3gkjd0255ssh5qi1772me8cbjjgude/t1ladlttj3g9tmliqm3o9hptfarvthi80mi82jr00ima3rh1r0igq7oa7m6tminge5km0g22ons4q" failed: write tcp 10.10.50.15:53402->192.168.1.103:21: write: broken pipe - low level retry 1/10
2019/11/27 08:30:31 DEBUG : ftp://192.168.1.103:21/rclone/xen: Connecting to FTP server
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: >Open: fd=<nil *ReadFileHandle>, err=file does not exist
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: >Open: fh=<nil>, err=no such file or directory
2019/11/27 08:30:32 DEBUG : /: Lookup: name="daly"
2019/11/27 08:30:32 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : /: Lookup: name="daly"
2019/11/27 08:30:32 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : /: Lookup: name="daly"
2019/11/27 08:30:32 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/: Lookup: name="xo-vm-backups"
2019/11/27 08:30:32 DEBUG : daly/: >Lookup: node=daly/xo-vm-backups/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/: Lookup: name="e327caf5-ade2-4d0a-d3db-c5661dd8ff2f"
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: Lookup: name="vdis"
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: Lookup: name="b73b50d3-4597-4583-b799-ff78a8cfbda2"
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: Lookup: name="b246d730-53dc-4eaf-bc39-0f642ef572a3"
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Attr: 
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Lookup: name="20191127T082353Z.vhd.checksum"
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Lookup: node=<nil>, err=no such file or directory
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Lookup: name="20191127T082353Z.vhd"
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Lookup: node=daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: Attr: 
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: >Attr: a=valid=1s ino=0 size=9995473920 mode=-rw-rw-r--, err=<nil>
2019/11/27 08:30:32 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: Remove: name="20191127T082353Z.vhd"
2019/11/27 08:31:14 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: updateTime: setting atime to 2019-11-27 08:30:27.091082032 +0000 UTC
2019/11/27 08:31:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 8.956G)
2019/11/27 08:32:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)
2019/11/27 08:33:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)
2019/11/27 08:34:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)
2019/11/27 08:35:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)
2019/11/27 08:35:28 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: corrupted on transfer: sizes differ 9995473920 vs 9734382592
2019/11/27 08:35:28 INFO  : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: Removing failed copy
2019/11/27 08:35:28 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd(0xc00003cc00): failed to transfer file from cache to remote: corrupted on transfer: sizes differ 9995473920 vs 9734382592
2019/11/27 08:35:28 ERROR : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd(0xc00003cc00): RWFileHandle.Flush error: failed to transfer file from cache to remote: corrupted on transfer: sizes differ 9995473920 vs 9734382592
2019/11/27 08:35:28 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd (rw)}: >Flush: err=failed to transfer file from cache to remote: corrupted on transfer: sizes differ 9995473920 vs 9734382592
2019/11/27 08:35:28 INFO  : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd: Removed from cache
2019/11/27 08:35:28 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/: >Remove: err=<nil>
2019/11/27 08:35:28 DEBUG : &{daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd (rw)}: Release: 
2019/11/27 08:35:28 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd(0xc00003cc00): RWFileHandle.Release closing
2019/11/27 08:35:28 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd(0xc00003cc00): close: 
2019/11/27 08:35:28 DEBUG : File.delWriter couldn't find handle
2019/11/27 08:35:28 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T082353Z.vhd: Need to transfer - File not found at Destination
2019/11/27 08:36:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)
2019/11/27 08:37:14 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)
2019/11/27 08:38:15 INFO  : Cleaned the cache: objects 8 (was 8), total size 9.309G (was 9.309G)

the error in Xen Orchestra

ENOENT: no such file or directory, open '/mnt/secure/daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b73b50d3-4597-4583-b799-ff78a8cfbda2/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T082353Z.vhd'

wessel1512 · November 27, 2019, 11:47am

cud it be that the cache is to small, it i bakup the smallest vm it works fine but if i try one of the bigger wants it fails

my biggest vm is 300 GB and the Xen Orchestra disk is only 60 GB

ncw · November 27, 2019, 12:02pm

Can you give this a go with the latest beta to see if it is any different?

wessel1512 · November 27, 2019, 12:31pm

status update

upgraded to the latest beta version

version

rclone v1.50.2-070-g705e4694-beta

os/arch: linux/amd64
go version: go1.13.4

service config

[Unit]
Description=RClone Service
Wants=network-online.target
After=network-online.target

[Service]
Type=notify
Environment=RCLONE_CONFIG=/opt/rclone/rclone.conf
KillMode=none
RestartSec=5
ExecStart=/usr/bin/rclone mount secure: /mnt/secure \
--allow-other \
--buffer-size 256M \
--dir-cache-time 1000h \
--log-level DEBUG \
--log-file /opt/rclone/logs/rclone.log \
--cache-dir "/cache/rclone" \
--vfs-cache-mode writes \
--poll-interval 15s \
--timeout 1h \
--umask 002 \
--rc \
--rc-addr 127.0.0.1:5572
ExecStop=/bin/fusermount -uz /GD
Restart=on-failure

[Install]
WantedBy=multi-user.target

wessel1512 · November 27, 2019, 3:37pm

its not working

log file

2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: Write: len=16384, offset=11887873536
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: Write: len=16384, offset=12482913792
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: Write: len=16384, offset=11887889920
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: Write: len=16384, offset=9560228864
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: Write: len=16384, offset=12482930176
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: Write: len=16384, offset=11887906304
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: Write: len=16384, offset=9560245248
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: Write: len=16384, offset=12482946560
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: Write: len=16384, offset=11887922688
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: Write: len=16384, offset=9560261632
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: Write: len=16384, offset=12482962944
2019/11/27 13:55:18 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: Write: len=16384, offset=11887939072
2019/11/27 13:55:19 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: >Write: written=0, err=write /cache/rclone/vfs/secure/daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd: no space left on device
2019/11/27 13:55:19 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: >Write: written=0, err=write /cache/rclone/vfs/secure/daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: no space left on device
2019/11/27 13:55:19 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Write: written=0, err=write /cache/rclone/vfs/secure/daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd: no space left on device
2019/11/27 13:55:19 DEBUG : &{daly/xo-vm-backu2019/11/27 14:06:16 DEBUG : /: Lookup: name="daly"
2019/11/27 14:06:16 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/: Attr: 
2019/11/27 14:06:16 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/: Lookup: name="xo-vm-backups"
2019/11/27 14:06:16 DEBUG : daly/: >Lookup: node=daly/xo-vm-backups/, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/: Attr: 
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/: Lookup: name="00b20a0c-d128-e30e-dd3e-f7e5f933b468"
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: Attr: 
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: Lookup: name="vdis"
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: Attr: 
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: Lookup: name="b140e895-898d-4aa3-bfbf-71e593e42cce"
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/: Attr: 
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/: Lookup: name="0bc0ca1d-b44f-4ec4-889b-142386463100"
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/: Attr: 
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/: Lookup: name=".20191127T123923Z.vhd"
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: Attr: 
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: >Attr: a=valid=1s ino=0 size=12482965504 mode=-rw-rw-r--, err=<nil>
2019/11/27 14:06:16 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/: Remove: name=".20191127T123923Z.vhd"
2019/11/27 14:06:30 ERROR : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd(0xc00003da40): failed to find cache file: object not found
2019/11/27 14:06:30 DEBUG : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd(0xc00003da40): >close: err=failed to find cache file: object not found
2019/11/27 14:06:30 ERROR : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd(0xc00003da40): RWFileHandle.Release error: failed to find cache file: object not found
2019/11/27 14:06:30 DEBUG : &{daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773/.20191127T123944Z.vhd (rw)}: >Release: err=failed to find cache file: object not found
2019/11/27 14:07:02 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: updateTime: setting atime to 2019-11-27 14:06:16.033300279 +0000 UTC
2019/11/27 14:07:02 DEBUG : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/cf6cbbe3-4503-43bf-bfd4-817021adc773: Removed empty directory
2019/11/27 14:07:02 DEBUG : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce: Removed empty directory
2019/11/27 14:07:02 DEBUG : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d/vdis: Removed empty directory
2019/11/27 14:07:02 DEBUG : daly/xo-vm-backups/dae96110-289f-7fab-d83e-9f5fec24480d: Removed empty directory
2019/11/27 14:07:02 INFO  : Cleaned the cache: objects 24 (was 28), total size 38.731G (was 47.634G)
2019/11/27 14:08:02 INFO  : Cleaned the cache: objects 24 (was 24), total size 38.731G (was 38.731G)
2019/11/27 14:08:30 INFO  : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd: Copied (new)
2019/11/27 14:08:30 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd: transferred to remote
2019/11/27 14:08:30 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Flush: err=<nil>
2019/11/27 14:08:30 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: Release: 
2019/11/27 14:08:30 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd(0xc000116fc0): RWFileHandle.Release closing
2019/11/27 14:08:30 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd(0xc000116fc0): close: 
2019/11/27 14:08:30 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd: File.delWriter couldn't find handle
2019/11/27 14:08:30 INFO  : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd: Removed from cache
2019/11/27 14:08:30 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/: >Remove: err=<nil>
2019/11/27 14:08:31 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd(0xc000116fc0): failed to find cache file: object not found
2019/11/27 14:08:31 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd(0xc000116fc0): >close: err=failed to find cache file: object not found
2019/11/27 14:08:31 ERROR : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd(0xc000116fc0): RWFileHandle.Release error: failed to find cache file: object not found
2019/11/27 14:08:31 DEBUG : &{daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f/.20191127T123918Z.vhd (rw)}: >Release: err=failed to find cache file: object not found
2019/11/27 14:09:02 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/683490ee-1b82-4b45-9c45-0f000e2b064f: Removed empty directory
2019/11/27 14:09:02 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce: Removed empty directory
2019/11/27 14:09:02 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943/vdis: Removed empty directory
2019/11/27 14:09:02 DEBUG : daly/xo-vm-backups/e90f77af-5350-b128-78c0-14b39e58c943: Removed empty directory
2019/11/27 14:09:02 INFO  : Cleaned the cache: objects 20 (was 24), total size 27.659G (was 38.731G)
2019/11/27 14:10:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:11:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:12:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:13:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:14:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:14:59 DEBUG : ftp://192.168.1.103:21/rclone/xen: Connection failed, closing: write tcp 10.10.50.15:35966->192.168.1.103:21: write: broken pipe
2019/11/27 14:14:59 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: Received error: update getinfo: write tcp 10.10.50.15:35966->192.168.1.103:21: write: broken pipe - low level retry 1/10
2019/11/27 14:14:59 DEBUG : ftp://192.168.1.103:21/rclone/xen: Connection failed, closing: write tcp 10.10.50.15:36436->192.168.1.103:21: write: broken pipe
2019/11/27 14:14:59 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: Received error: Put mkParentDir failed: mkdir "/rclone/xen/5dubqmm63g1vf2glf5msmtav10/2sml683qro6ktqneqdnrevmim0/7h1e5e4otlhrqdlted95ljrvsi0ci9nd3s803raja51sfh19jhe5hfk6miom2u70ku1qhahf3fqag/7f6tg5s1n4ur5rtu54ksd4o574/tnavesh0rm0v1j33d824d59b03oapeh8pq02gks0qk8khpt8b5170pfio9g9tkca4u78jjk96m2dg/dl6d2d04a1e49dmbpc9lf05b7jkrtqnok1sgid3hb13i29muac01f8c0fmcndghu9amiqc51rjb0a" failed: write tcp 10.10.50.15:36436->192.168.1.103:21: write: broken pipe - low level retry 2/10
2019/11/27 14:15:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:16:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:17:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:18:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:19:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:20:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:21:02 INFO  : Cleaned the cache: objects 20 (was 20), total size 27.659G (was 27.659G)
2019/11/27 14:21:12 INFO  : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: Copied (new)
2019/11/27 14:21:12 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: transferred to remote
2019/11/27 14:21:12 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: >Flush: err=<nil>
2019/11/27 14:21:12 INFO  : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: Removed from cache
2019/11/27 14:21:12 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Remove: err=<nil>
2019/11/27 14:21:12 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: Release: 
2019/11/27 14:21:12 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd(0xc00003c9c0): RWFileHandle.Release closing
2019/11/27 14:21:12 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd(0xc00003c9c0): close: 
2019/11/27 14:21:12 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd: File.delWriter couldn't find handle
2019/11/27 14:21:13 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd(0xc00003c9c0): failed to find cache file: object not found
2019/11/27 14:21:13 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd(0xc00003c9c0): >close: err=failed to find cache file: object not found
2019/11/27 14:21:13 ERROR : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd(0xc00003c9c0): RWFileHandle.Release error: failed to find cache file: object not found
2019/11/27 14:21:13 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191127T123923Z.vhd (rw)}: >Release: err=failed to find cache file: object not found
2019/11/27 14:22:02 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/0bc0ca1d-b44f-4ec4-889b-142386463100: Removed empty directory
2019/11/27 14:22:02 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce: Removed empty directory
2019/11/27 14:22:02 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis: Removed empty directory
2019/11/27 14:22:02 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468: Removed empty directory
2019/11/27 14:22:02 INFO  : Cleaned the cache: objects 16 (was 20), total size 16.033G (was 27.659G)
2019/11/27 14:23:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:24:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:25:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:26:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:27:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:28:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:29:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:30:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:31:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:32:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:33:02 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:34:03 INFO  : Cleaned the cache: objects 16 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:35:03 INFO  : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/64e13671-0250-473b-862d-cd00e3077136/.20191127T123925Z.vhd: Removed from cache
2019/11/27 14:35:03 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/64e13671-0250-473b-862d-cd00e3077136: Removed empty directory
2019/11/27 14:35:03 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce: Removed empty directory
2019/11/27 14:35:03 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis: Removed empty directory
2019/11/27 14:35:03 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6: Removed empty directory
2019/11/27 14:35:03 INFO  : Cleaned the cache: objects 11 (was 16), total size 16.033G (was 16.033G)
2019/11/27 14:36:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 16.033G)
2019/11/27 14:37:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:38:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:39:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:40:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:41:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:42:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:43:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:44:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:45:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:46:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:47:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:48:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:49:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:50:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:51:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:52:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:53:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:54:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:55:02 INFO  : Cleaned the cache: objects 11 (was 11), total size 9.309G (was 9.309G)
2019/11/27 14:56:02 INFO  : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/b246d730-53dc-4eaf-bc39-0f642ef572a3/.20191127T123920Z.vhd: Removed from cache
2019/11/27 14:56:02 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/b246d730-53dc-4eaf-bc39-0f642ef572a3: Removed empty directory
2019/11/27 14:56:02 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce: Removed empty directory
2019/11/27 14:56:02 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis: Removed empty directory
2019/11/27 14:56:02 DEBUG : daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f: Removed empty directory
2019/11/27 14:56:02 DEBUG : daly/xo-vm-backups: Removed empty directory
2019/11/27 14:56:02 DEBUG : daly: Removed empty directory
2019/11/27 14:56:02 DEBUG : : Removed empty directory
2019/11/27 14:56:02 INFO  : Cleaned the cache: objects 3 (was 11), total size 9.309G (was 9.309G)

error in Xen Orchestra

ENOENT: no such file or directory, open '/mnt/secure/daly/xo-vm-backups/e327caf5-ade2-4d0a-d3db-c5661dd8ff2f/vdis/b140e895-898d-4aa3-bfbf-71e593e42cce/b246d730-53dc-4eaf-bc39-0f642ef572a3/20191127T123920Z.vhd'

and

EIO: i/o error, write

Animosity022 · November 27, 2019, 3:40pm

You ran out of space on your cache drive so you need to use a bigger cache area.

wessel1512 · November 27, 2019, 4:22pm

aa

what I thought

than i need to get a new hdd for the server

ncw · November 27, 2019, 4:24pm

Setting one or both of these may be helpful to reduce the amount of stuff on disk.

  --vfs-cache-max-age duration             Max age of objects in the cache. (default 1h0m0s)
  --vfs-cache-max-size SizeSuffix          Max total size of objects in the cache. (default off)

However if you haven't got enough disk space for a temporary copy of the .xva then you are out of luck.

wessel1512 · December 4, 2019, 12:44pm

i have upgraded to more storage fixed only part of the problem
if i try to run a Delta Backup its failed probably on the check the disk and get the following error

ENOENT: no such file or directory, open '/mnt/secure/daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/64e13671-0250-473b-862d-cd00e3077136/20191204T114721Z.vhd'

is this a problem that can be fixend ore am i out of lock

it seems to me that the cash is not 100% transparent in the file system

ncw · December 4, 2019, 1:04pm

Can you paste the log with -vv when it is doing that?

The cache should be 100% transparent. That said there are a few corner cases - maybe this is hitting one of them.

Does that file already exist, or was it a new one created as part of the backup?

wessel1512 · December 4, 2019, 1:46pm

for testing i removed the old backup and setup a new one for testing in a clean directory

it was just created not more than an couple of minutes old

log file

2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616435712
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616452096
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616468480
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616484864
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616501248
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616517632
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616534016
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616550400
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616566784
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616583168
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616599552
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616615936
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=16384, offset=64616632320
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=16384, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Write: len=512, offset=64616648704
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: >Write: written=512, err=<nil>
2019/12/04 13:23:43 DEBUG : &{daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd (rw)}: Flush: 
2019/12/04 13:23:44 DEBUG : /: Lookup: name="daly"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd: Need to transfer - File not found at Destination
2019/12/04 13:23:44 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : /: Lookup: name="daly"
2019/12/04 13:23:44 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/: Lookup: name="xo-vm-backups"
2019/12/04 13:23:44 DEBUG : daly/: >Lookup: node=daly/xo-vm-backups/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/: Lookup: name="00b20a0c-d128-e30e-dd3e-f7e5f933b468"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: Lookup: name="vdis"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: Lookup: name="de3d3552-5704-4d12-af10-01d1643fb1e5"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: Lookup: name="0bc0ca1d-b44f-4ec4-889b-142386463100"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Attr: 
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Lookup: name=".20191204T114717Z.vhd"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd: Attr: 
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd: >Attr: a=valid=1s ino=0 size=64616649216 mode=-rw-rw-r--, err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Lookup: name="20191204T114717Z.vhd"
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Lookup: node=<nil>, err=no such file or directory
2019/12/04 13:23:44 DEBUG : ftp://192.168.1.103:21/rclone/xen: Connecting to FTP server
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Rename: oldName=".20191204T114717Z.vhd", newName="20191204T114717Z.vhd", newDir=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/
2019/12/04 13:23:44 DEBUG : File is currently open, delaying rename 0xc0002fa000
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Rename: err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: Open: flags=OpenReadOnly
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: Open: flags=O_RDONLY
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: >Open: fd=<nil *ReadFileHandle>, err=file does not exist
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: >Open: fh=<nil>, err=no such file or directory
2019/12/04 13:23:49 DEBUG : /: Lookup: name="daly"
2019/12/04 13:23:49 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : /: Lookup: name="daly"
2019/12/04 13:23:49 DEBUG : /: >Lookup: node=daly/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/: Lookup: name="xo-vm-backups"
2019/12/04 13:23:49 DEBUG : daly/: >Lookup: node=daly/xo-vm-backups/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/: Lookup: name="00b20a0c-d128-e30e-dd3e-f7e5f933b468"
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: Lookup: name="vdis"
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: Lookup: name="de3d3552-5704-4d12-af10-01d1643fb1e5"
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: Lookup: name="0bc0ca1d-b44f-4ec4-889b-142386463100"
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Attr: 
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Lookup: name="20191204T114717Z.vhd.checksum"
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Lookup: node=<nil>, err=no such file or directory
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Lookup: name="20191204T114717Z.vhd"
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Lookup: node=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: Attr: 
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: >Attr: a=valid=1s ino=0 size=64616649216 mode=-rw-rw-r--, err=<nil>
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Remove: name="20191204T114717Z.vhd"
2019/12/04 13:24:12 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/.20191204T114717Z.vhd: updateTime: setting atime to 2019-12-04 13:23:44.245236946 +0000 UTC
2019/12/04 13:24:12 INFO  : Cleaned the cache: objects 28 (was 28), total size 111.827G (was 110.854G)
2019/12/04 13:25:16 INFO  : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/64e13671-0250-473b-862d-cd00e3077136/.20191204T114721Z.vhd: Removed from cache
2019/12/04 13:25:16 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/64e13671-0250-473b-862d-cd00e3077136: Removed empty directory
2019/12/04 13:25:16 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5: Removed empty directory
2019/12/04 13:25:16 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6/vdis: Removed empty directory
2019/12/04 13:25:16 DEBUG : daly/xo-vm-backups/e702fa49-6630-2db5-77d6-fcd085bae3f6: Removed empty directory
2019/12/04 13:25:16 INFO  : Cleaned the cache: objects 23 (was 28), total size 111.827G (was 111.827G)
2019/12/04 13:26:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 111.827G)
2019/12/04 13:27:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G)
2019/12/04 13:28:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G)
2019/12/04 13:29:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G)
2019/12/04 13:30:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G)
2019/12/04 13:31:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G)
2019/12/04 13:32:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G)
2019/12/04 13:33:12 INFO  : Cleaned the cache: objects 23 (was 23), total size 103.937G (was 103.937G

feature request: a option to set maximum lines in log file

ncw · December 5, 2019, 1:01pm

Ahh, here is the problem

2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: Rename: oldName=".20191204T114717Z.vhd", newName="20191204T114717Z.vhd", newDir=daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/
2019/12/04 13:23:44 DEBUG : File is currently open, delaying rename 0xc0002fa000
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/: >Rename: err=<nil>
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: Open: flags=OpenReadOnly
2019/12/04 13:23:44 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: Open: flags=O_RDONLY
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: >Open: fd=<nil *ReadFileHandle>, err=file does not exist
2019/12/04 13:23:49 DEBUG : daly/xo-vm-backups/00b20a0c-d128-e30e-dd3e-f7e5f933b468/vdis/de3d3552-5704-4d12-af10-01d1643fb1e5/0bc0ca1d-b44f-4ec4-889b-142386463100/20191204T114717Z.vhd: >Open: fh=<nil>, err=no such file or directory

So what happens is that the file gets renamed to its new name. Rclone delays that renaming since the file is open (the file is being uploaded at this point). Then it tries to open the file at its new location and fails because rclone hasn't renamed it yet.

It is the renaming the open file that is the problem here - is it possible to turn off that behaviour?

The other alternative would be that I rework what rclone does on a rename of an open file when the cache is active so that it

without cache: on rename of open file

rename file in directory listing
delay rename of file on cloud storage until file is closed

with cache: on rename of open file

rename file in cache
rename file in directory listing
delay rename of file on cloud storage until file is closed

currently rclone does

on rename of open file:

delay the rename of the file in the cache
delay the rename of the file in the cloud storage
delay update of the file name in the directory

I had a go at fixing it like this - can you see if it helps?

https://beta.rclone.org/branch/v1.50.2-081-g5de0d439-fix-vfs-rename-beta/ (uploaded in 15-30 mins)

wessel1512 · December 9, 2019, 9:54am

sorry for my delay
bin sike form a coppel of days

but i cant se any version for ubuntu | debian
on https://beta.rclone.org/branch/v1.50.2-081-g5de0d439-fix-vfs-rename-beta/

Xen Orchestra ebadf: bad file descriptor, write

What is the problem you are having with rclone?

What is your rclone version (output from rclone version)

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Which cloud storage system are you using? (eg Google Drive)

my service config

A log from the command with the -vv flag (eg output from rclone -vv copy /tmp remote:tmp)

error discrption

status update

version

service config

log file

error in Xen Orchestra

log file

What is your rclone version (output from `rclone version`)

A log from the command with the `-vv` flag (eg output from `rclone -vv copy /tmp remote:tmp`)