Delta Backup Changes in 5.66 ?

jedimarcus

I updated XOA to 5.66 2 days ago and it messed up with my delta backups.

Instead of 2 hours it took 20 hours yesterday and same thing again today.

I don't see any notes in the changelogs that would explain this.

Anyone else?

julien-f

@jedimarcus Yes, we got some reports on this, we're investigating

julien-f

We discussed this issue in a support ticket but for everyone else: it was a bug and a fix was shipped in XO 5.66.1 yesterday

mtitservices

Can confirm. All is well now.

Customer's XenOrchestra backup was performing a full backup everytime even with a delta backup job.

Now it works as it is supposed to.

Good work you guys

MT-ITServices

Danp

Currently on commit 5bc4436, I'm still experiencing repeated full backups but this isn't occurring on all VMs.

@julien-f Any suggestions on how to diagnose the cause?

olivierlambert

Thanks for the feedback @Danp XO team is investigating as we speak

julien-f

@danp We were not able to reproduce the issue on our side, what's the config of your backup job?

Danp

@julien-f It's the same delta backup job that I've been using forever --

It uses smart mode to backup all running VMs. Scheduled to run daily at midnight, backup retention is set to 12.

Danp

Unsure if this is related, but I've found some errors in the logs that I don't believe occurred prior to the most recent updates --

Dec 28 00:19:10 xo-server[257773]: 2021-12-28T06:19:10.418Z xo:main WARN WebSocket send: {
Dec 28 00:19:10 xo-server[257773]:   error: Error: Cannot call write after a stream was destroyed
Dec 28 00:19:10 xo-server[257773]:       at new NodeError (node:internal/errors:371:5)
Dec 28 00:19:10 xo-server[257773]:       at errorBuffer (node:internal/streams/writable:517:14)
Dec 28 00:19:10 xo-server[257773]:       at afterWrite (node:internal/streams/writable:501:5)
Dec 28 00:19:10 xo-server[257773]:       at onwrite (node:internal/streams/writable:477:7)
Dec 28 00:19:10 xo-server[257773]:       at WriteWrap.onWriteComplete [as oncomplete] (node:internal/stream_base_commons:91:12)
Dec 28 00:19:10 xo-server[257773]:       at WriteWrap.callbackTrampoline (node:internal/async_hooks:130:17) {
Dec 28 00:19:10 xo-server[257773]:     code: 'ERR_STREAM_DESTROYED'
Dec 28 00:19:10 xo-server[257773]:   }
Dec 28 00:19:10 xo-server[257773]: }

Also this --

Dec 28 00:00:13 xo-server[360334]: 2021-12-28T06:00:13.194Z xo:xapi:vm WARN HANDLE_INVALID(VDI, OpaqueRef:83be31a3-81d7-4be3-9714-0ad1fa034d20) {
Dec 28 00:00:13 xo-server[360334]:   error: XapiError: HANDLE_INVALID(VDI, OpaqueRef:83be31a3-81d7-4be3-9714-0ad1fa034d20)
Dec 28 00:00:13 xo-server[360334]:       at Function.wrap (/opt/xen-orchestra/packages/xen-api/dist/_XapiError.js:26:12)
Dec 28 00:00:13 xo-server[360334]:       at /opt/xen-orchestra/packages/xen-api/dist/transports/json-rpc.js:58:30
Dec 28 00:00:13 xo-server[360334]:       at runMicrotasks (<anonymous>)
Dec 28 00:00:13 xo-server[360334]:       at processTicksAndRejections (node:internal/process/task_queues:96:5) {
Dec 28 00:00:13 xo-server[360334]:     code: 'HANDLE_INVALID',
Dec 28 00:00:13 xo-server[360334]:     params: [ 'VDI', 'OpaqueRef:83be31a3-81d7-4be3-9714-0ad1fa034d20' ],
Dec 28 00:00:13 xo-server[360334]:     call: { method: 'VDI.get_record', params: [Array] },
Dec 28 00:00:13 xo-server[360334]:     url: undefined,
Dec 28 00:00:13 xo-server[360334]:     task: undefined
Dec 28 00:00:13 xo-server[360334]:   }
Dec 28 00:00:13 xo-server[360334]: }
Dec 28 00:00:13 xo-server[360334]: 2021-12-28T06:00:13.393Z xo:xapi:vm WARN HANDLE_INVALID(VDI, OpaqueRef:83be31a3-81d7-4be3-9714-0ad1fa034d20) {
Dec 28 00:00:13 xo-server[360334]:   error: XapiError: HANDLE_INVALID(VDI, OpaqueRef:83be31a3-81d7-4be3-9714-0ad1fa034d20)
Dec 28 00:00:13 xo-server[360334]:       at Function.wrap (/opt/xen-orchestra/packages/xen-api/dist/_XapiError.js:26:12)
Dec 28 00:00:13 xo-server[360334]:       at /opt/xen-orchestra/packages/xen-api/dist/transports/json-rpc.js:58:30
Dec 28 00:00:13 xo-server[360334]:       at runMicrotasks (<anonymous>)
Dec 28 00:00:13 xo-server[360334]:       at processTicksAndRejections (node:internal/process/task_queues:96:5) {
Dec 28 00:00:13 xo-server[360334]:     code: 'HANDLE_INVALID',
Dec 28 00:00:13 xo-server[360334]:     params: [ 'VDI', 'OpaqueRef:83be31a3-81d7-4be3-9714-0ad1fa034d20' ],
Dec 28 00:00:13 xo-server[360334]:     call: { method: 'VDI.get_record', params: [Array] },
Dec 28 00:00:13 xo-server[360334]:     url: undefined,
Dec 28 00:00:13 xo-server[360334]:     task: undefined
Dec 28 00:00:13 xo-server[360334]:   }
Dec 28 00:00:13 xo-server[360334]: }

julien-f

@danp I don't think these are new or related to this issue.

julien-f

@danp Which type of remote are you using for this job? SMB? NFS?

Danp

@julien-f NFS

Forza

@julien-f said in Delta Backup Changes in 5.66 ?:

We discussed this issue in a support ticket but for everyone else: it was a bug and a fix was shipped in XO 5.66.1 yesterday

We're on 5.66.1 and incrememntal backups still make full backups. This is now eating up quite a lot of storage space.

julien-f

@s-pam we were not able to reproduce so far on our side. Also, most of the XO team (myself included) is on holidays until next week, thus I'm not sure we'll be able to fix it before.

If you are using an official XO appliance, you can rollback to the stable channel and if you are using XO from the sources, you can go back to a previous commit.

Forza

@julien-f said in Delta Backup Changes in 5.66 ?:

@s-pam we were not able to reproduce so far on our side. Also, most of the XO team (myself included) is on holidays until next week, thus I'm not sure we'll be able to fix it before.

If you are using an official XO appliance, you can rollback to the stable channel and if you are using XO from the sources, you can go back to a previous commit.

Yea, I have a support ticket active for another issue, but this popped up now in the middle of it. But then I'll wait until next week before downgrating so you can have a chance to look at it through the support tunnel. I've changed the backup schedule to daily instead of hourly to save some space on the remote .

pnunn

Not wanting to be a "me too" but I'm seeing exactly the same thing.

Some VM's (unfortunately in my case large ones) and doing daily fulls rather than deltas.

Backup taking 14 hours instead of 2 or 3.

Similar etup to @S-Pam with nfs as the remote target.

olivierlambert

We are doing progress in the investigation. @florent will keep you posted!

florent

@pnunn @S-Pam If you use the sources, can you try to use this branch feat-add-debug-backup it's master with additionnal debug and a potential fix ( potential , because I can't reproduce it regularly in our lab)

Then you can activate more debug by this

[logs]
# Display all logs matching this filter, regardless of their level
filter = 'xo:backups'

# Display all logs with level >=, regardless of their namespace
level = 'debug'

in your config file ( should be in ~/.config/xo-server/config.toml

Forza

@florent unfortunately not. We use XOA.

florent

@s-pam it's a great choice
If you can launch a backup , I can connect through a support tunnel and deploy the fix

then you can launch the backup and we can celebrate the success of this fix