fix_s3_nonencrypted_to_encrypted_xva
Hello Florent,
Branch built and testing
Test procedure: removed the minPartSize=100000000 from remote definition, deleted the b2 backup and restarted the mirror backup. There are some other VMs that will also be uploaded to B2 so it will take a while. Expect feedback tomorrow.
Thank you,
Pedro
Hello!
So I created a new job and a small test vm to gather info. I did 3 replications runs and the last 2 failed. Backups are working thoug.
Since this would be a large post, I created a pdf with the test cycle.
...
Only to find out that those are not allowed on this forum! So I captured the pdf pages...
And the logs from the jobs:
{
"data": {
"mode": "delta",
"reportWhen": "always",
"backupReportTpl": "mjml"
},
"id": "1784293017099",
"jobId": "10d0331c-694e-4681-8860-33fef3790552",
"jobName": "TESTCRANDBK",
"message": "backup",
"scheduleId": "bc7b29ce-25b2-4c66-9186-b1d4c314b979",
"start": 1784293017099,
"status": "success",
"tasks": [
{
"id": "0mroxztk5-9yuipq34src",
"start": 1784293020005,
"status": "success",
"tasks": [
{
"id": "0mroxztkj-izqz7v0ufn",
"start": 1784293020019,
"status": "success",
"end": 1784293020027,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
},
{
"id": "0mroxztz1-v8ycdmtgo9k",
"start": 1784293020541,
"status": "success",
"end": 1784293036537,
"result": "20683621-7819-7661-91a2-93c377a7345a",
"message": "snapshot"
},
{
"id": "0mroy06bf-9frdqsgnpym",
"start": 1784293036539,
"status": "success",
"tasks": [
{
"id": "0mroy0aun-bscsuoyzrpu",
"start": 1784293042415,
"status": "success",
"tasks": [
{
"id": "0mroy3r14-2sk7dgyqrbl",
"start": 1784293203352,
"status": "success",
"end": 1784293207572,
"message": "target snapshot"
}
],
"end": 1784293207573,
"result": {
"size": 9254731776
},
"message": "transfer"
}
],
"end": 1784293207664,
"message": "export",
"data": {
"id": "a729e916-4cd8-2208-7dce-329e6b4af892",
"isFull": true,
"name_label": "xxxxx",
"type": "SR"
}
},
{
"id": "0mroy06bg-eyd2s4tidgg",
"start": 1784293036540,
"status": "success",
"end": 1784293207664,
"message": "export",
"data": {
"id": "b0b77301-4625-a13b-7022-9512f927944a",
"isFull": true,
"name_label": "xxxxxx",
"type": "SR"
}
},
{
"id": "0mroy06bh-ra3dxpusxr8",
"start": 1784293036541,
"status": "success",
"end": 1784293207664,
"message": "export",
"data": {
"id": "7054c407-d620-2c9f-5810-1e192a04ffe2",
"isFull": true,
"name_label": "xxxxxxxxx",
"type": "SR"
}
},
{
"id": "0mroy06bi-tdyzypsg58",
"start": 1784293036542,
"status": "success",
"end": 1784293207664,
"message": "export",
"data": {
"id": "621c9b87-4f58-987b-2c07-e8dee67da73a",
"isFull": true,
"name_label": "xxxxxxxxxx",
"type": "SR"
}
},
{
"id": "0mroy06be-u3p9nky3uwd",
"start": 1784293036538,
"status": "success",
"tasks": [
{
"id": "0mroy0aus-ax44kkpim1",
"start": 1784293042420,
"status": "success",
"end": 1784293200916,
"result": {
"size": 9257013760
},
"message": "transfer"
},
{
"id": "0mroy434q-md07n6vujw",
"start": 1784293219034,
"status": "success",
"end": 1784293219099,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
}
],
"end": 1784293219102,
"message": "export",
"data": {
"id": "c1fdab1d-5535-42e4-b282-1a0282df1081",
"isFull": true,
"type": "remote"
}
}
],
"infos": [
{
"message": "Transfer data using NBD"
},
{
"message": "will delete snapshot data"
},
{
"data": {
"vdiRef": "OpaqueRef:080d2018-c2a3-aa6f-89a1-b3eaf72c3de5"
},
"message": "Snapshot data has been deleted"
}
],
"end": 1784293219102,
"message": "backup VM",
"data": {
"id": "d771731a-f132-7365-be50-71f19424f96e",
"type": "VM",
"name_label": "TESTREPL",
"progress": 0
}
}
],
"end": 1784293219104,
"infos": [
{
"data": {
"vms": [
"d771731a-f132-7365-be50-71f19424f96e"
]
},
"message": "vms"
}
]
}
{
"data": {
"mode": "delta",
"reportWhen": "always",
"backupReportTpl": "mjml"
},
"id": "1784293990343",
"jobId": "10d0331c-694e-4681-8860-33fef3790552",
"jobName": "TESTCRANDBK",
"message": "backup",
"scheduleId": "bc7b29ce-25b2-4c66-9186-b1d4c314b979",
"start": 1784293990343,
"status": "success",
"tasks": [
{
"id": "0mroykonr-nktgebhtb4k",
"start": 1784293993431,
"status": "success",
"tasks": [
{
"id": "0mroykoo5-171n48gwq3r",
"start": 1784293993445,
"status": "success",
"end": 1784293993493,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
},
{
"id": "0mroykp31-4r5wrf9blru",
"start": 1784293993981,
"status": "success",
"end": 1784294007573,
"result": "9ff54ec5-0247-4692-945b-c183206ae6dd",
"message": "snapshot"
},
{
"id": "0mroykzkm-ykzk53um8l",
"start": 1784294007574,
"status": "success",
"tasks": [
{
"id": "0mroyl3qn-vzompxsw79o",
"start": 1784294012975,
"status": "success",
"end": 1784294018591,
"result": {
"size": 396481024
},
"message": "transfer"
},
{
"id": "0mroyljgo-nlch68rkbil",
"start": 1784294033352,
"status": "success",
"end": 1784294033444,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
}
],
"end": 1784294033446,
"message": "export",
"data": {
"id": "c1fdab1d-5535-42e4-b282-1a0282df1081",
"isFull": false,
"type": "remote"
}
}
],
"warnings": [
{
"message": "the writer AggregatedIncrementalXapiWriter has failed the step writer.checkBaseVdis() with error Cannot read properties of undefined (reading 'get'). It won't be used anymore in this job execution."
}
],
"infos": [
{
"message": "Transfer data using NBD"
},
{
"message": "will delete snapshot data"
},
{
"data": {
"vdiRef": "OpaqueRef:77605638-5e58-4a10-c2de-bc6e77f1ad61"
},
"message": "Snapshot data has been deleted"
}
],
"end": 1784294033447,
"message": "backup VM",
"data": {
"id": "d771731a-f132-7365-be50-71f19424f96e",
"type": "VM",
"name_label": "TESTREPL",
"progress": 0
}
}
],
"end": 1784294033449,
"infos": [
{
"data": {
"vms": [
"d771731a-f132-7365-be50-71f19424f96e"
]
},
"message": "vms"
}
]
}
{
"data": {
"mode": "delta",
"reportWhen": "always",
"backupReportTpl": "mjml"
},
"id": "1784295416670",
"jobId": "10d0331c-694e-4681-8860-33fef3790552",
"jobName": "TESTCRANDBK",
"message": "backup",
"scheduleId": "bc7b29ce-25b2-4c66-9186-b1d4c314b979",
"start": 1784295416670,
"status": "success",
"tasks": [
{
"id": "0mrozf8yr-lix8jxbm6pd",
"start": 1784295419428,
"status": "success",
"tasks": [
{
"id": "0mrozf8zg-zddbxm901mc",
"start": 1784295419452,
"status": "success",
"end": 1784295419537,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
},
{
"id": "0mrozf9dv-7nj082i92kp",
"start": 1784295419971,
"status": "success",
"end": 1784295426890,
"result": "18312e82-adb6-2dc5-b13e-2fd9a4b2bf77",
"message": "snapshot"
},
{
"id": "0mrozfeq3-w3y5xrwtqse",
"start": 1784295426891,
"status": "success",
"tasks": [
{
"id": "0mrozfrvy-4g1gefr14hx",
"start": 1784295443950,
"status": "success",
"end": 1784295445177,
"result": {
"size": 92319744
},
"message": "transfer"
},
{
"id": "0mrozfw5f-mx0xt5f7wjm",
"start": 1784295449475,
"status": "success",
"end": 1784295449563,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
}
],
"end": 1784295449565,
"message": "export",
"data": {
"id": "c1fdab1d-5535-42e4-b282-1a0282df1081",
"isFull": false,
"type": "remote"
}
}
],
"warnings": [
{
"message": "the writer AggregatedIncrementalXapiWriter has failed the step writer.checkBaseVdis() with error Cannot read properties of undefined (reading 'get'). It won't be used anymore in this job execution."
}
],
"infos": [
{
"message": "Transfer data using NBD"
},
{
"message": "will delete snapshot data"
},
{
"data": {
"vdiRef": "OpaqueRef:6a833d28-2d2c-5fe6-858b-02d2fd41b919"
},
"message": "Snapshot data has been deleted"
}
],
"end": 1784295449566,
"message": "backup VM",
"data": {
"id": "d771731a-f132-7365-be50-71f19424f96e",
"type": "VM",
"name_label": "TESTREPL",
"progress": 0
}
}
],
"end": 1784295449567,
"infos": [
{
"data": {
"vms": [
"d771731a-f132-7365-be50-71f19424f96e"
]
},
"message": "vms"
}
]
}
Hope it helps
Hello,
More info on this. I think this error is related with the recent "Distribute replication accross the storage repositories" option that I turned on. Before this option existed, I was splitting the VMs into groups, with tags, and using several jobs with "smart mode" to send each group to a specific SR on the destination replication pool. With this new option I didn't have to do this anymore, it would simplify my replication job.
That said, I still have a group that I want to replicate to a local host disk. This group doesn't fail with "checkBaseVdis() failed" but I do get duplicated VMs on the destination pool, even though the job's schedule is set to only 1 replications retention. Is XO failing to delete the previous VM replication ?
(The same VM duplicated on the replicated pool even though replication retention is set to 1)
(Job / schedule retention settings).
...So I have to prune the duplicated VMs to make sure I don't run out of space on the target pool repository.
I think I'll set up a new job with a single test VM so I can run it several times and try to gather more info.
Hi @Danp ,
I've updated XO to the latest commit and the error is still happening.
@Danp Hi!
Running Xen Orchestra, commit 44e5b (19 commits behind).
Here is a log
deltalog.txt
Thank you!
Hello forum,
Anyone else getting this warning / error on contionuos replication?
I think this is related to using "Distribute replication accross the storage repositories" option
This is happening on my daily replications using 4 storage repositories on the destination pool. The replicated VM snapshot doesn't get updated (at least the timestamp on the description doesn't). I also think that the replication is failing because the log does not show any data transfer to the storage repositories on the destination pool.
In case it has something to do with this: On the same job I'm also doing delta backups. Other options are NBD, CBT and merge backups sinchronously. Replication retention is set to 1 on the job schedule, which is called from a job sequence. Storage repositories are lvmoiscsi.
Thank you,
Pedro
@pierrebrunet Hello!
I've checked B2 logs and found some errors like you had foreseen. I had a look and this kind of 500 INTERNAL ERROR several times on other jobs that seem ok. How many retries does XO attempt to send the part when this happens?
I'll do another run that includes only a few large VMs. BTW, is there a way to interrupt the job withou restarting XO ?
REST.PUT.PART Weekly/xo-vm-backups/60b4d2a7-3f91-f0f9-b0a0-f834df3ff9ee/20260705T070618Z.xva "PUT /zzzzzkly/xo-vm-backups/60b4d2a7-3f91-f0f9-b0a0-f834df3ff9ee/20260705T070618Z.xva?partNumber=3954&uploadId=4_ze092693d1b65962e9fe6051b_f25969add7e42e384_d20260713_m140016_c003_v0312040_t0013_u01783951216751&x-id=UploadPart HTTP/1.1" 500 INTERNAL_ERROR 145 - 3762 3762 "-" "aws-sdk-js/3.1065.0 ua/2.1 os/linux#5.15.0-185-generic lang/js md/nodejs#24.18.0 api/s3#3.1065.0 m/N,a,c,E,e xen-orchestra-fs-4.9.2" - - - TLS_AES_256_GCM_SHA384 AuthHeader s3.eu-central-003.backblazeb2.com TLSv1.3 - -
@poddingue Hi!
Unfortunately, another error came up on the larger vms. The job also seems to be painfully slow. Slower than usual I mean.
Also, it seems that job changes are not being commited. I've changed the job so it wouldn't retry in case of failure and the log shows it still trying 3 times (that was the old setting, and probably explains the job taking longer than usual).
{
"id": "0mrjahr8e-ssawlbveq5",
"start": 1783951215134,
"status": "failure",
"tasks": [
{
"id": "0mrjahs3e-dbfaqajeze",
"start": 1783951216250,
"status": "failure",
"tasks": [
{
"id": "0mrjahs8s-2yb6i3fny6f",
"start": 1783951216444,
"status": "failure",
"end": 1783959266484,
"result": {
"$fault": "server",
"$metadata": {
"httpStatusCode": 500,
"requestId": "c0a9f30190109f99",
"extendedRequestId": "aMJgyljkPZEdiEDW0Nk9lTmbINpI1FGIP",
"attempts": 3,
"totalRetryDelay": 197
},
"name": "InternalError",
"Code": "InternalError",
"message": "internal incident",
"stack": "InternalError: internal incident\n at ProtocolLib.getErrorSchemaOrThrowBaseException (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/core/dist-cjs/submodules/protocols/index.js:70:67)\n at S3RestXmlProtocol.handleError (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/core/dist-cjs/submodules/protocols/index.js:1856:65)\n at S3RestXmlProtocol.deserializeResponse (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/protocols/index.js:341:24)\n at process.processTicksAndRejections (node:internal/process/task_queues:104:5)\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/schema/index.js:25:24\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:367:20\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/retry/index.js:172:50\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/checksums/dist-cjs/index.js:337:24\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:64:28\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:91:20"
},
"message": "transfer",
"data": {
"progress": 40
}
}
],
"end": 1783959266485,
"result": {
"$fault": "server",
"$metadata": {
"httpStatusCode": 500,
"requestId": "c0a9f30190109f99",
"extendedRequestId": "aMJgyljkPZEdiEDW0Nk9lTmbINpI1FGIP",
"attempts": 3,
"totalRetryDelay": 197
},
"name": "InternalError",
"Code": "InternalError",
"message": "internal incident",
"stack": "InternalError: internal incident\n at ProtocolLib.getErrorSchemaOrThrowBaseException (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/core/dist-cjs/submodules/protocols/index.js:70:67)\n at S3RestXmlProtocol.handleError (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/core/dist-cjs/submodules/protocols/index.js:1856:65)\n at S3RestXmlProtocol.deserializeResponse (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/protocols/index.js:341:24)\n at process.processTicksAndRejections (node:internal/process/task_queues:104:5)\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/schema/index.js:25:24\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:367:20\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/retry/index.js:172:50\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/checksums/dist-cjs/index.js:337:24\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:64:28\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:91:20"
},
"message": "export",
"data": {
"id": "14b59f44-4517-411e-9e39-4eb7136928d0",
"type": "remote",
"isFull": true
}
},
{
"id": "0mrjfabp3-c8mf2pnq8yf",
"start": 1783959266487,
"status": "success",
"warnings": [
{
"data": {
"path": "xo-vm-backups/60b4d2a7-3f91-f0f9-b0a0-f834df3ff9ee/cache.json.gz",
"actual": 0,
"expected": 1
},
"message": "unexpected number of entries in backup cache"
}
],
"end": 1783959266989,
"result": {
"merge": false,
"size": 0
},
"message": "clean-vm"
}
],
"end": 1783959266989,
"result": {
"$fault": "server",
"$metadata": {
"httpStatusCode": 500,
"requestId": "c0a9f30190109f99",
"extendedRequestId": "aMJgyljkPZEdiEDW0Nk9lTmbINpI1FGIP",
"attempts": 3,
"totalRetryDelay": 197
},
"name": "InternalError",
"Code": "InternalError",
"message": "internal incident",
"stack": "InternalError: internal incident\n at ProtocolLib.getErrorSchemaOrThrowBaseException (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/core/dist-cjs/submodules/protocols/index.js:70:67)\n at S3RestXmlProtocol.handleError (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/core/dist-cjs/submodules/protocols/index.js:1856:65)\n at S3RestXmlProtocol.deserializeResponse (/opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/protocols/index.js:341:24)\n at process.processTicksAndRejections (node:internal/process/task_queues:104:5)\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/schema/index.js:25:24\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:367:20\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@smithy/core/dist-cjs/submodules/retry/index.js:172:50\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/checksums/dist-cjs/index.js:337:24\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:64:28\n at async /opt/xo/xo-builds/xen-orchestra-202607120728/node_modules/@aws-sdk/middleware-sdk-s3/dist-cjs/submodules/s3/index.js:91:20"
},
"message": "backup VM",
"data": {
"id": "60b4d2a7-3f91-f0f9-b0a0-f834df3ff9ee",
"type": "VM",
"progress": 0
}
},
@poddingue Hi,
The backup mirror job is still running, and I'm waiting for the larger VMs to complete, but so far it looks good - one backup, larger than 50GB was successfully mirrored without specifying minPartSize.
Sorry, missed your previous post. I will return to master and test it (over the weekend).
Thank you!
@pierrebrunet Hi!
Replication is from local NFS (Ztsd compressed, not encripted) to a S3 Backblaze (with encription).