Delta backup footer1 !== footer2 error
-
Since I upgraded XOA to 5.56.2 I have started to see this error on some of y daily backups.
Restarting backup job seems help but it is huge problem when every morning I see backup errors.
There is full log of one such backup:{ "data": { "mode": "delta", "reportWhen": "always" }, "id": "1618426800008", "jobId": "9f8c13d8-cf2b-4f55-aadc-788c3fc43254", "jobName": "DC-2_Daily_backup", "message": "backup", "scheduleId": "6b7d1739-11b4-4c8f-a1cc-ceaf64fc40a3", "start": 1618426800008, "status": "failure", "infos": [ { "data": { "vms": [ "928a1a84-a72d-4648-2781-96296bf28459" ] }, "message": "vms" } ], "tasks": [ { "data": { "type": "VM", "id": "928a1a84-a72d-4648-2781-96296bf28459" }, "id": "1618426804302", "message": "backup VM", "start": 1618426804302, "status": "failure", "tasks": [ { "id": "1618426807376", "message": "snapshot", "start": 1618426807376, "status": "success", "end": 1618426812653, "result": "1c74aaec-9b64-8719-8da7-633382e0938c" }, { "data": { "id": "df7361d2-509b-46fe-bf12-d63fc6d93524", "isFull": false, "type": "remote" }, "id": "1618426812653:0", "message": "export", "start": 1618426812653, "status": "failure", "tasks": [ { "id": "1618426812767", "message": "transfer", "start": 1618426812767, "status": "failure", "end": 1618426903073, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/opt/xen-orchestra/packages/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/opt/xen-orchestra/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/opt/xen-orchestra/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1618426903074, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/opt/xen-orchestra/packages/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/opt/xen-orchestra/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/opt/xen-orchestra/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1618426904454, "result": { "message": "task has already ended", "name": "Error", "stack": "Error: task has already ended\n at Task.logAfterEnd (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:5:9)\n at Task.onLog (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:59:37)\n at Task.#log (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:139:16)\n at new Task (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:75:14)\n at Function.run (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:33:12)\n at DeltaBackupWriter._deleteOldEntries (/opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:115:17)\n at DeltaBackupWriter.cleanup (/opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:110:18)\n at /opt/xen-orchestra/@xen-orchestra/backups/Task.js:129:32\n at /opt/xen-orchestra/@xen-orchestra/backups/Task.js:103:24\n at Zone.run (/opt/xen-orchestra/node_modules/node-zone/index.js:80:23)" } } ], "end": 1618426904454 }
-
If you have XOA, please open a support ticket
-
@olivierlambert I'm using community edition.
That's why I'm writing problem here. -
Oh okay, so you are not using XOA then Just "XO" (XOA stands for Xen Orchestra virtual Appliance), the thing Vates distribute as turnkey + support
So you don't have any specific version, as usual in that case, be sure to run on the latest
master
commit. -
@olivierlambert I updated it Yesterday.
-
Good. So you have a corrupted VHD in your backup (transfer interrupted at some point).
I think @badrAZ is working on something that would automatically deal with it. You can remove your VM snapshot so it will recreate a full.
-
@olivierlambert I have remade backup when I saw the problem.
It went without problems.
I will monitor this further and report if it occurs on other VM's -
Two more VM's with error this night.
{ "data": { "mode": "delta", "reportWhen": "always" }, "id": "1618522200008", "jobId": "c7f542ad-07f2-45c9-9002-bf7169d90a14", "jobName": "discourse-BUp", "message": "backup", "scheduleId": "9dbda6ce-0118-41b6-b357-dcf080318ec1", "start": 1618522200008, "status": "failure", "infos": [ { "data": { "vms": [ "a1a3832c-b16a-a85e-2fdd-ae585087f629" ] }, "message": "vms" } ], "tasks": [ { "data": { "type": "VM", "id": "a1a3832c-b16a-a85e-2fdd-ae585087f629" }, "id": "1618522200629", "message": "backup VM", "start": 1618522200629, "status": "failure", "tasks": [ { "id": "1618522205326", "message": "snapshot", "start": 1618522205326, "status": "success", "end": 1618522210762, "result": "be5287a0-a956-81bc-87fa-e840be406cd4" }, { "data": { "id": "df7361d2-509b-46fe-bf12-d63fc6d93524", "isFull": false, "type": "remote" }, "id": "1618522210762:0", "message": "export", "start": 1618522210762, "status": "failure", "tasks": [ { "id": "1618522210931", "message": "transfer", "start": 1618522210931, "status": "failure", "end": 1618522235395, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/opt/xen-orchestra/packages/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/opt/xen-orchestra/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/opt/xen-orchestra/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1618522235396, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/opt/xen-orchestra/packages/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/opt/xen-orchestra/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/opt/xen-orchestra/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1618522237312, "result": { "message": "task has already ended", "name": "Error", "stack": "Error: task has already ended\n at Task.logAfterEnd (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:5:9)\n at Task.onLog (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:59:37)\n at Task.#log (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:139:16)\n at new Task (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:75:14)\n at Function.run (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:33:12)\n at DeltaBackupWriter._deleteOldEntries (/opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:115:17)\n at DeltaBackupWriter.cleanup (/opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:110:18)\n at /opt/xen-orchestra/@xen-orchestra/backups/Task.js:129:32\n at /opt/xen-orchestra/@xen-orchestra/backups/Task.js:103:24\n at Zone.run (/opt/xen-orchestra/node_modules/node-zone/index.js:80:23)" } } ], "end": 1618522237313 }
{ "data": { "mode": "delta", "reportWhen": "always" }, "id": "1618502400009", "jobId": "2cdd42b8-8961-400d-9a6c-4c10b008c010", "jobName": "devart_jenkins", "message": "backup", "scheduleId": "18f81e07-5ed9-4b02-a707-bd3c5100861d", "start": 1618502400009, "status": "failure", "infos": [ { "data": { "vms": [ "3581d5ca-2c13-31f1-d552-7382aa343804" ] }, "message": "vms" } ], "tasks": [ { "data": { "type": "VM", "id": "3581d5ca-2c13-31f1-d552-7382aa343804" }, "id": "1618502400600", "message": "backup VM", "start": 1618502400600, "status": "failure", "tasks": [ { "id": "1618502401839", "message": "snapshot", "start": 1618502401839, "status": "success", "end": 1618502407288, "result": "8734319d-91da-88a0-c81b-5ce9a67edefb" }, { "data": { "id": "df7361d2-509b-46fe-bf12-d63fc6d93524", "isFull": false, "type": "remote" }, "id": "1618502407288:0", "message": "export", "start": 1618502407288, "status": "failure", "tasks": [ { "id": "1618502407325", "message": "transfer", "start": 1618502407325, "status": "failure", "end": 1618502425566, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/opt/xen-orchestra/packages/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/opt/xen-orchestra/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/opt/xen-orchestra/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1618502425566, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/opt/xen-orchestra/packages/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/opt/xen-orchestra/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/opt/xen-orchestra/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1618502426837, "result": { "message": "task has already ended", "name": "Error", "stack": "Error: task has already ended\n at Task.logAfterEnd (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:5:9)\n at Task.onLog (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:59:37)\n at Task.#log (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:139:16)\n at new Task (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:75:14)\n at Function.run (/opt/xen-orchestra/@xen-orchestra/backups/Task.js:33:12)\n at DeltaBackupWriter._deleteOldEntries (/opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:115:17)\n at DeltaBackupWriter.cleanup (/opt/xen-orchestra/@xen-orchestra/backups/_DeltaBackupWriter.js:110:18)\n at /opt/xen-orchestra/@xen-orchestra/backups/Task.js:129:32\n at /opt/xen-orchestra/@xen-orchestra/backups/Task.js:103:24\n at Zone.run (/opt/xen-orchestra/node_modules/node-zone/index.js:80:23)" } } ], "end": 1618502426839 }
-
@olivierlambert Yesterday I deleted snapshots of delta backups and it made full backups successful. Today I see errors again with incremental.
-
Please rebuild everything on
master
and try again. It's hard to investigate when we do not control entirely the environment. -
@olivierlambert I have rebuild xen orchestra with last master.
Now I recreating backup job. Will see if there will be same issues. -
@olivierlambert and today I have first failed backup with same error.
-
To rule out an XO problem (but something specific on your setup), please try with an XOA on
latest
If you need another trial round for that, let me know I'll unlock it! -
@olivierlambert I see today's commit with changes to merge process.
May this help? -
Feel free to try and report then thanks!
-
@olivierlambert I've set up XOA trial. Will see if problem appear.
-
@olivierlambert
I got the same error on XOA appliance.{ "data": { "mode": "delta", "reportWhen": "always" }, "id": "1620250200011", "jobId": "f44dc556-32ba-4bbc-8568-06d5d26b6835", "jobName": "discourse-BUp", "message": "backup", "scheduleId": "bb7b53e4-ca32-48f8-afbb-1ce36ddc84f2", "start": 1620250200011, "status": "failure", "infos": [ { "data": { "vms": [ "a1a3832c-b16a-a85e-2fdd-ae585087f629" ] }, "message": "vms" } ], "tasks": [ { "data": { "type": "VM", "id": "a1a3832c-b16a-a85e-2fdd-ae585087f629" }, "id": "1620250200710", "message": "backup VM", "start": 1620250200710, "status": "failure", "tasks": [ { "id": "1620250205577", "message": "snapshot", "start": 1620250205577, "status": "success", "end": 1620250210934, "result": "569701f3-2665-32c1-ef1c-2b8b1377d88b" }, { "data": { "id": "84dd7240-14e8-4233-befa-f95e7d62e74e", "isFull": false, "type": "remote" }, "id": "1620250210935", "message": "export", "start": 1620250210935, "status": "failure", "tasks": [ { "id": "1620250211055", "message": "transfer", "start": 1620250211055, "status": "failure", "end": 1620250232442, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/usr/local/lib/node_modules/xo-server/node_modules/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1620250232442, "result": { "generatedMessage": false, "code": "ERR_ASSERTION", "actual": false, "expected": true, "operator": "==", "message": "footer1 !== footer2", "name": "AssertionError", "stack": "AssertionError [ERR_ASSERTION]: footer1 !== footer2\n at Vhd.readHeaderAndFooter (/usr/local/lib/node_modules/xo-server/node_modules/vhd-lib/dist/vhd.js:118:27)\n at async checkVhd (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_checkVhd.js:4:3)\n at async RemoteAdapter.outputStream (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/RemoteAdapter.js:517:7)\n at async /usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_DeltaBackupWriter.js:196:11\n at async Promise.all (index 0)\n at async /usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_DeltaBackupWriter.js:171:7" } } ], "end": 1620250233919, "result": { "message": "task has already ended", "name": "Error", "stack": "Error: task has already ended\n at Task.logAfterEnd (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:5:9)\n at Task.onLog (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:59:37)\n at Task.#log (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:139:16)\n at new Task (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:75:14)\n at Function.run (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:33:12)\n at DeltaBackupWriter._deleteOldEntries (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_DeltaBackupWriter.js:115:17)\n at DeltaBackupWriter.cleanup (/usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/_DeltaBackupWriter.js:110:18)\n at /usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:129:32\n at /usr/local/lib/node_modules/xo-server/node_modules/@xen-orchestra/backups/Task.js:103:24\n at Zone.run (/usr/local/lib/node_modules/xo-server/node_modules/node-zone/index.js:80:23)" } } ], "end": 1620250233919 }
I have created a bug ticket with a link to this topic.
-
@olivierlambert problem was fixed. Thank you for help.
-
@alexander-0
I am having this exact same issue. Can you tell me what you did to fix it? Or was it fixed when you updated to the latest version? -
@mrnaz the fixed it in version 5.58.1. So update helped.