Failed S3 backup success, should recover
-
@olivierlambert
I'm running XO source (commit d3077) with XCP 8.2.1. S3 delta backups have been working great for a long time. Recently Wasabi has been having problems and some backups fail. Manually restarting the failed back normally works and things are fine.This one VM backup runs and fails but this delta backup shows in the Restore menu with the correct date.
The restore health check for this failed backup is Successful (so, it's good, right?).
This backup does not auto-recover and fix the S3 data storage like most others do. Maybe XO should automatically run a full backup because it fails... XO should do something other than keep failing.
Failure log:
{ "data": { "type": "VM", "id": "00371171-0a0b-f32f-916e-a79e8f8a98d4", "name_label": "billing" }, "id": "1691298603892", "message": "backup VM", "start": 1691298603892, "status": "failure", "tasks": [ { "id": "1691298604051", "message": "clean-vm", "start": 1691298604051, "status": "failure", "tasks": [ { "id": "1691298632353", "message": "merge", "start": 1691298632353, "status": "failure", "end": 1691298637075, "result": { "code": "ENOENT", "path": "/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat", "message": "ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'", "name": "Error", "stack": "Error: ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'\n at S3Handler._createReadStream (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/s3.js:214:23)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async S3Handler.__readFile (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/abstract.js:255:18)" } } ], "end": 1691298637075, "result": { "code": "ENOENT", "path": "/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat", "message": "ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'", "name": "Error", "stack": "Error: ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'\n at S3Handler._createReadStream (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/s3.js:214:23)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async S3Handler.__readFile (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/abstract.js:255:18)" } }, { "id": "1691298658567", "message": "snapshot", "start": 1691298658567, "status": "success", "end": 1691298661961, "result": "9645b1d8-3e12-dfad-5d13-d378d5fb5ca9" }, { "data": { "id": "db9ad0a8-bce6-4a2b-b9fd-5c4cecf059c4", "isFull": false, "type": "remote" }, "id": "1691298661962", "message": "export", "start": 1691298661962, "status": "failure", "tasks": [ { "id": "1691298664803", "message": "transfer", "start": 1691298664803, "status": "success", "end": 1691298692985, "result": { "size": 249655296 } }, { "id": "1691298696693", "message": "clean-vm", "start": 1691298696693, "status": "failure", "tasks": [ { "id": "1691298729796", "message": "merge", "start": 1691298729796, "status": "failure", "end": 1691298734169, "result": { "code": "ENOENT", "path": "/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat", "message": "ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'", "name": "Error", "stack": "Error: ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'\n at S3Handler._createReadStream (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/s3.js:214:23)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async S3Handler.__readFile (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/abstract.js:255:18)" } } ], "end": 1691298734170, "result": { "code": "ENOENT", "path": "/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat", "message": "ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'", "name": "Error", "stack": "Error: ENOENT: no such file '/xo-vm-backups/00371171-0a0b-f32f-916e-a79e8f8a98d4/vdis/f9405e51-da48-4eb1-980d-99da34359b3c/b6834642-beb3-49d5-aaf2-bcf09ba79eef/data/9e0089e5-6e24-4861-b229-5fd70a98abff.vhd/bat'\n at S3Handler._createReadStream (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/s3.js:214:23)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async S3Handler.__readFile (/opt/xo/xo-builds/xen-orchestra-202307311131/@xen-orchestra/fs/dist/abstract.js:255:18)" } } ], "end": 1691298734171 } ], "end": 1691298734171 },
The directory is there, but no bat file:
drwxr-x--- 1 root root 0 Dec 31 1969 blocks -rw-r----- 1 root root 10 Jul 22 01:11 chunk-filters.json -rw-r----- 1 root root 162 Jul 22 01:11 footer -rw-r----- 1 root root 201 Jul 22 01:11 header -rw-r----- 1 root root 56 Jul 22 01:11 parentLocatorEntry0 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry1 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry2 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry3 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry4 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry5 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry6 -rw-r----- 1 root root 1 Jul 22 01:11 parentLocatorEntry7
-
-
@olivierlambert XO source update done (commit 5bef8). Same problem.
I thought it would be a chance for the team to look a real world failure before I delete it and start the backup over, if they are around.
-
We see occasional VM backup failures that match the above pattern (ENOENT on a "path" in a S3 bucket remote destination during a VM delta backup). We are running a backup of a large VM (200GB disk) to S3 bucket in Ceph Object Gateway. Our current XO is this commit https://github.com/vatesfr/xen-orchestra/commit/da51b1649c65d7d78a4eb25cc46c488ce2552800 from 2024-03-04.
The failure is intermittent.
Example failure log:
{ "data": { "mode": "delta", "reportWhen": "always" }, "id": "1712008868496", "jobId": "49c2634a-f281-46b7-9192-aea8c786f3d4", "jobName": "ZABBIX VM to ceph02 Delta Backup", "message": "backup", "scheduleId": "6b1280f0-21e7-475c-9af3-330726108568", "start": 1712008868496, "status": "failure", "infos": [ { "data": { "vms": [ "c020890b-c1a7-79cf-0b55-aa340ba9226b" ] }, "message": "vms" } ], "tasks": [ { "data": { "type": "VM", "id": "c020890b-c1a7-79cf-0b55-aa340ba9226b", "name_label": "zabbix" }, "id": "1712008870266", "message": "backup VM", "start": 1712008870266, "status": "failure", "tasks": [ { "id": "1712008870283", "message": "clean-vm", "start": 1712008870283, "status": "success", "end": 1712008872364, "result": { "merge": false } }, { "id": "1712008872791", "message": "snapshot", "start": 1712008872791, "status": "success", "end": 1712008873901, "result": "902d65f0-8c9b-2460-dad7-d041ceefebdc" }, { "data": { "id": "d8d6a743-8c15-4b9a-baf4-df5d7d379b6e", "isFull": false, "type": "remote" }, "id": "1712008873919", "message": "export", "start": 1712008873919, "status": "failure", "tasks": [ { "id": "1712008875215", "message": "transfer", "start": 1712008875215, "status": "success", "end": 1712009333076, "result": { "size": 35343973376 } }, { "id": "1712009335152", "message": "clean-vm", "start": 1712009335152, "status": "failure", "tasks": [ { "id": "1712009336153", "message": "merge", "start": 1712009336153, "status": "failure", "end": 1712009585029, "result": { "cause": { "name": "NoSuchKey", "$fault": "client", "$metadata": { "httpStatusCode": 404, "requestId": "tx00000c27bed21222dc684-00660b3170-302aa3c-s3", "attempts": 1, "totalRetryDelay": 0 }, "Code": "NoSuchKey", "BucketName": "xcp-ng-mama-pool-vm-backup", "RequestId": "tx00000c27bed21222dc684-00660b3170-302aa3c-s3", "HostId": "302aa3c-s3-s3", "message": "UnknownError" }, "code": "ENOENT", "path": "/xo-vm-backups/c020890b-c1a7-79cf-0b55-aa340ba9226b/vdis/49c2634a-f281-46b7-9192-aea8c786f3d4/378753c5-9072-47b7-b879-0488a86e85ba/data/b70bc690-28c7-440a-8147-bf6d61c179de.vhd/blocks/10/52", "message": "ENOENT: no such file or directory '/xo-vm-backups/c020890b-c1a7-79cf-0b55-aa340ba9226b/vdis/49c2634a-f281-46b7-9192-aea8c786f3d4/378753c5-9072-47b7-b879-0488a86e85ba/data/b70bc690-28c7-440a-8147-bf6d61c179de.vhd/blocks/10/52'", "name": "Error", "stack": "Error: ENOENT: no such file or directory '/xo-vm-backups/c020890b-c1a7-79cf-0b55-aa340ba9226b/vdis/49c2634a-f281-46b7-9192-aea8c786f3d4/378753c5-9072-47b7-b879-0488a86e85ba/data/b70bc690-28c7-440a-8147-bf6d61c179de.vhd/blocks/10/52'\n at S3Handler._copy (/opt/xo/xo-builds/xen-orchestra-202403041050/@xen-orchestra/fs/dist/s3.js:157:23)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)" } } ], "end": 1712009585029, "result": { "cause": { "name": "NoSuchKey", "$fault": "client", "$metadata": { "httpStatusCode": 404, "requestId": "tx00000c27bed21222dc684-00660b3170-302aa3c-s3", "attempts": 1, "totalRetryDelay": 0 }, "Code": "NoSuchKey", "BucketName": "xcp-ng-mama-pool-vm-backup", "RequestId": "tx00000c27bed21222dc684-00660b3170-302aa3c-s3", "HostId": "302aa3c-s3-s3", "message": "UnknownError" }, "code": "ENOENT", "path": "/xo-vm-backups/c020890b-c1a7-79cf-0b55-aa340ba9226b/vdis/49c2634a-f281-46b7-9192-aea8c786f3d4/378753c5-9072-47b7-b879-0488a86e85ba/data/b70bc690-28c7-440a-8147-bf6d61c179de.vhd/blocks/10/52", "message": "ENOENT: no such file or directory '/xo-vm-backups/c020890b-c1a7-79cf-0b55-aa340ba9226b/vdis/49c2634a-f281-46b7-9192-aea8c786f3d4/378753c5-9072-47b7-b879-0488a86e85ba/data/b70bc690-28c7-440a-8147-bf6d61c179de.vhd/blocks/10/52'", "name": "Error", "stack": "Error: ENOENT: no such file or directory '/xo-vm-backups/c020890b-c1a7-79cf-0b55-aa340ba9226b/vdis/49c2634a-f281-46b7-9192-aea8c786f3d4/378753c5-9072-47b7-b879-0488a86e85ba/data/b70bc690-28c7-440a-8147-bf6d61c179de.vhd/blocks/10/52'\n at S3Handler._copy (/opt/xo/xo-builds/xen-orchestra-202403041050/@xen-orchestra/fs/dist/s3.js:157:23)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)" } } ], "end": 1712009585031 } ], "end": 1712009585032 } ], "end": 1712009585032 }
I know I should be on the current XO to report a problem. Not asking for a fix now, just trying to document that this defect still exists.