"Backup Failed" since the last Cloudron Update
-
Again today. And i changed the S3 from AWS to Backblaze. Manual backup is working but automatic doesn't work. But since the change have been done, it is like automatic update doesn't trigger all the time.. (The successful backup has been triggered by me manualy).
Full logs of the last automatic failed backup (from today).
Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/EM/M1-S2/Rapport d'Activité/Rapport d'Activité n°2.docx file Aug 14 04:04:12 box:backupformat/tgz tarPack: processing /mnt/volumes/6e6d77d1ac41447da93a95677f20c922/Drive/data/admin/files/IA Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/IA/Ressources directory Aug 14 04:04:12 box:backupformat/tgz tarPack: processing /mnt/volumes/6e6d77d1ac41447da93a95677f20c922/Drive/data/admin/files/IA/Ressources Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/IA/Ressources/SOP pour Vérifier l'Activité d'une Application sur GitHub.docx file Aug 14 04:04:12 box:backupformat/tgz tarPack: processing /mnt/volumes/6e6d77d1ac41447da93a95677f20c922/Drive/data/admin/files/Perso Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Articles A Acheter directory Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Cadeaux Idées directory Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Casquettes directory Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Dress 15-06-24 directory Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Elle.docx file Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Jeux Vidéos directory Aug 14 04:04:12 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Logo Propal 2 A-One.png file Aug 14 04:04:13 box:storage/s3 Upload progress: {"loaded":3221225472,"part":2,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:04:13 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 4539M@44MBps (drive.example.com)"} Aug 14 04:04:14 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Monologue Rayane Insta.mp4 file Aug 14 04:04:14 box:backupformat/tgz addToPack: added ./data/data/admin/files/Perso/Musiques directory Aug 14 04:04:23 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 5009M@47MBps (drive.example.com)"} Aug 14 04:04:33 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 5400M@39MBps (drive.example.com)"} Aug 14 04:04:43 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 5860M@46MBps (drive.example.com)"} Aug 14 04:04:53 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6144M@28MBps (drive.example.com)"} Aug 14 04:04:53 box:storage/s3 Upload progress: {"loaded":4294967296,"part":5,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:05:03 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6144M@0MBps (drive.example.com)"} Aug 14 04:05:13 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6144M@0MBps (drive.example.com)"} Aug 14 04:05:19 box:storage/s3 Upload progress: {"loaded":4294967296,"part":5,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:05:23 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6144M@0MBps (drive.example.com)"} Aug 14 04:05:33 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6144M@0MBps (drive.example.com)"} Aug 14 04:05:34 box:storage/s3 Upload progress: {"loaded":4294967296,"part":1,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:05:34 box:storage/s3 Upload progress: {"loaded":5368709120,"part":4,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:05:44 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6144M@0MBps (drive.example.com)"} Aug 14 04:05:52 box:storage/s3 Upload progress: {"loaded":5368709120,"part":5,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:05:54 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 6583M@44MBps (drive.example.com)"} Aug 14 04:06:04 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 7038M@46MBps (drive.example.com)"} Aug 14 04:06:14 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 7420M@38MBps (drive.example.com)"} Aug 14 04:06:23 box:storage/s3 Upload progress: {"loaded":5368709120,"part":5,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:06:24 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 7891M@47MBps (drive.example.com)"} Aug 14 04:06:34 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8192M@30MBps (drive.example.com)"} Aug 14 04:06:44 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8192M@0MBps (drive.example.com)"} Aug 14 04:06:54 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8192M@0MBps (drive.example.com)"} Aug 14 04:07:04 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8192M@0MBps (drive.example.com)"} Aug 14 04:07:14 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8192M@0MBps (drive.example.com)"} Aug 14 04:07:16 box:storage/s3 Upload progress: {"loaded":6442450944,"part":6,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:07:24 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8435M@24MBps (drive.example.com)"} Aug 14 04:07:34 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 8894M@46MBps (drive.example.com)"} Aug 14 04:07:43 box:storage/s3 Upload progress: {"loaded":7516192768,"part":8,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:07:44 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 9216M@32MBps (drive.example.com)"} Aug 14 04:07:54 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 9216M@0MBps (drive.example.com)"} Aug 14 04:08:01 box:storage/s3 Upload progress: {"loaded":7516192768,"part":5,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:08:04 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 9217M@0MBps (drive.example.com)"} Aug 14 04:08:14 box:storage/s3 Upload progress: {"loaded":7516192768,"part":8,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:08:14 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 9685M@47MBps (drive.example.com)"} Aug 14 04:08:24 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10143M@46MBps (drive.example.com)"} Aug 14 04:08:34 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10240M@10MBps (drive.example.com)"} Aug 14 04:08:44 box:storage/s3 Upload progress: {"loaded":7516192768,"part":8,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:08:44 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10240M@0MBps (drive.example.com)"} Aug 14 04:08:54 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10240M@0MBps (drive.example.com)"} Aug 14 04:09:04 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10240M@0MBps (drive.example.com)"} Aug 14 04:09:05 box:storage/s3 Upload progress: {"loaded":8589934592,"part":7,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:09:14 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10240M@0MBps (drive.example.com)"} Aug 14 04:09:24 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 10554M@31MBps (drive.example.com)"} Aug 14 04:09:32 box:storage/s3 Upload progress: {"loaded":9663676416,"part":9,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Aug 14 04:09:34 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 11023M@47MBps (drive.example.com)"} Aug 14 04:09:44 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 11416M@39MBps (drive.example.com)"} Aug 14 04:09:54 box:tasks update 3103: {"percent":28.450980392156865,"message":"Uploading backup 11864M@45MBps (drive.example.com)"} Aug 14 04:09:59 box:storage/s3 Upload progress: {"loaded":10737418240,"part":10,"key":"snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872.tar.gz.enc"} Jan 01 00:00:00 node:events:496 [no timestamp] throw er; // Unhandled 'error' event [no timestamp] ^ [no timestamp] [no timestamp] write EPIPE [no timestamp] at WriteWrap.onWriteComplete [as oncomplete] (node:internal/stream_base_commons:94:16) [no timestamp] 'error' event on TLSSocket instance at: [no timestamp] at emitErrorNT (node:internal/streams/destroy:169:8) [no timestamp] at emitErrorCloseNT (node:internal/streams/destroy:128:3) [no timestamp] at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { [no timestamp] errno: -32, [no timestamp] code: 'EPIPE', [no timestamp] syscall: 'write' [no timestamp] } [no timestamp] [no timestamp] v20.12.2 Aug 14 04:09:59 box:shell backup-snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872: /usr/bin/sudo -S -E --close-from=4 /home/yellowtent/box/src/scripts/backupupload.js snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872 tgz {"localRoot":"/home/yellowtent/appsdata/370be07e-c281-4d35-95a1-5c9984f72872","layout":[{"localDir":"/mnt/volumes/6e6d77d1ac41447da93a95677f20c922/Drive","remoteDir":"data"}]} errored BoxError: backup-snapshot/app_370be07e-c281-4d35-95a1-5c9984f72872 exited with code 1 signal null [no timestamp] at ChildProcess.<anonymous> (/home/yellowtent/box/src/shell.js:122:19) [no timestamp] at ChildProcess.emit (node:events:518:28) [no timestamp] at ChildProcess.emit (node:domain:488:12) [no timestamp] at ChildProcess._handle.onexit (node:internal/child_process:294:12) { [no timestamp] reason: 'Shell Error', [no timestamp] details: {}, [no timestamp] code: 1, [no timestamp] signal: null [no timestamp] } Aug 14 04:09:59 box:taskworker Task took 598.935 seconds Aug 14 04:09:59 box:tasks setCompleted - 3103: {"result":null,"error":{"stack":"BoxError: Backuptask crashed\n at runBackupUpload (/home/yellowtent/box/src/backuptask.js:164:15)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async uploadAppSnapshot (/home/yellowtent/box/src/backuptask.js:361:5)\n at async backupAppWithTag (/home/yellowtent/box/src/backuptask.js:383:5)\n at async fullBackup (/home/yellowtent/box/src/backuptask.js:504:29)","name":"BoxError","reason":"Internal Error","details":{},"message":"Backuptask crashed"}} Aug 14 04:09:59 box:tasks update 3103: {"percent":100,"result":null,"error":{"stack":"BoxError: Backuptask crashed\n at runBackupUpload (/home/yellowtent/box/src/backuptask.js:164:15)\n at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n at async uploadAppSnapshot (/home/yellowtent/box/src/backuptask.js:361:5)\n at async backupAppWithTag (/home/yellowtent/box/src/backuptask.js:383:5)\n at async fullBackup (/home/yellowtent/box/src/backuptask.js:504:29)","name":"BoxError","reason":"Internal Error","details":{},"message":"Backuptask crashed"}} [no timestamp] Backuptask crashed [no timestamp] at runBackupUpload (/home/yellowtent/box/src/backuptask.js:164:15) [no timestamp] at process.processTicksAndRejections (node:internal/process/task_queues:95:5) [no timestamp] at async uploadAppSnapshot (/home/yellowtent/box/src/backuptask.js:361:5) [no timestamp] at async backupAppWithTag (/home/yellowtent/box/src/backuptask.js:383:5) [no timestamp] at async fullBackup (/home/yellowtent/box/src/backuptask.js:504:29) -
I have noticed that the backup issue affects also the app updates, as the app is backed up before it is updated. Last night the Immich app started scheduled update 2 times from v1.68.1, but never updated to v1.69.0. I have then started the update manually this morning and it was completed.
-
I have noticed that the backup issue affects also the app updates, as the app is backed up before it is updated. Last night the Immich app started scheduled update 2 times from v1.68.1, but never updated to v1.69.0. I have then started the update manually this morning and it was completed.
-
J joseph marked this topic as a question on
-
@joseph I have verified that the app data were uploaded to the backup backend. Let's wait for tonight scheduled update to v1.69.1.
-
Just looked into this. I think there is a regression in Cloudron 8. We fixed the backup cleaner to work properly but in the process it cleans up the backup entry in the database that is being created. https://git.cloudron.io/cloudron/box/-/commit/9704eefc21af313a4239e74999186ae44a43ed46 is the fix for that. @kubasbimbas can you try that one line change? You have to add that line to the file
/home/yellowtent/box/src/backupcleaner.json the server . No need to restart anything after applying the patch. -
Just looked into this. I think there is a regression in Cloudron 8. We fixed the backup cleaner to work properly but in the process it cleans up the backup entry in the database that is being created. https://git.cloudron.io/cloudron/box/-/commit/9704eefc21af313a4239e74999186ae44a43ed46 is the fix for that. @kubasbimbas can you try that one line change? You have to add that line to the file
/home/yellowtent/box/src/backupcleaner.json the server . No need to restart anything after applying the patch.@girish Hi,
What do I have to do to fix it ? I don't understand what I have to do with the git link you sent.
Thanks
-
@Dont-Worry no worries. if you send us a mail to support@cloudron.io , we can apply the patch on your server . (We debugged the issue on somebody's server, but we cannot match forum username and support requests... If you had sent us a mail ealier, we already patched your server)
-
@girish You patched my server. I confirm that automatic Cloudron backup as well as app update worked correctly. Thank you for your support.
-
Same here on multiple servers backing up against S3. What's an ETA for the hotfix release?
-
G girish has marked this topic as solved on
-
If that's not too much, I would appreciate if you could ping this thread, once the new version released.
-
Thank you!
-
@girish , Cloudron v8.0.4, backups are still failing:
Aug 28 03:00:04 box:backupformat/tgz tarPack: processing /home/yellowtent/appsdata/<...> [no timestamp] /home/yellowtent/box/node_modules/aws-sdk/lib/services/s3.js:712 [no timestamp] resp.error = AWS.util.error(new Error(), { [no timestamp] ^ [no timestamp] [no timestamp] The specified method is not allowed against this resource. [no timestamp] at Request.extractError (/home/yellowtent/box/node_modules/aws-sdk/lib/services/s3.js:712:35) [no timestamp] at Request.callListeners (/home/yellowtent/box/node_modules/aws-sdk/lib/sequential_executor.js:106:20) [no timestamp] at Request.emit (/home/yellowtent/box/node_modules/aws-sdk/lib/sequential_executor.js:78:10) [no timestamp] at Request.emit (/home/yellowtent/box/node_modules/aws-sdk/lib/request.js:686:14) [no timestamp] at Request.transition (/home/yellowtent/box/node_modules/aws-sdk/lib/request.js:22:10) [no timestamp] at AcceptorStateMachine.runTo (/home/yellowtent/box/node_modules/aws-sdk/lib/state_machine.js:14:12) [no timestamp] at /home/yellowtent/box/node_modules/aws-sdk/lib/state_machine.js:26:10 [no timestamp] at Request.<anonymous> (/home/yellowtent/box/node_modules/aws-sdk/lib/request.js:38:9) [no timestamp] at Request.<anonymous> (/home/yellowtent/box/node_modules/aws-sdk/lib/request.js:688:12) [no timestamp] at Request.callListeners (/home/yellowtent/box/node_modules/aws-sdk/lib/sequential_executor.js:116:18) { [no timestamp] code: 'MethodNotAllowed', [no timestamp] region: null, [no timestamp] time: 2024-08-28T01:00:04.170Z, [no timestamp] requestId: '45dc6280-1336-4ef2-82df-8bf7545a1d89', [no timestamp] extendedRequestId: '45dc6280-1336-4ef2-82df-8bf7545a1d89', [no timestamp] cfId: undefined, [no timestamp] statusCode: 405, [no timestamp] retryable: false, [no timestamp] retryDelay: 20000 [no timestamp] } [no timestamp] [no timestamp] v20.12.2The provider is Exoscale's SOS.
-
@girish , I'm sorry, is there any news on that? I still can't backup my instance.
-
It seems to crash within the AWS SDK itself, I guess your S3 storage has some compatibility issues there, we have seen such problem in the past where the storage endpoint was flaky.
Maybe you can contact exoscale about this?
MethodNotAllowedmight indicate that they don't implement/support some required API? -
It seems to crash within the AWS SDK itself, I guess your S3 storage has some compatibility issues there, we have seen such problem in the past where the storage endpoint was flaky.
Maybe you can contact exoscale about this?
MethodNotAllowedmight indicate that they don't implement/support some required API?@nebulon thank you! My other instance is running perfectly fine against the same endpoint and it was working fine on the same endpoint from the same instance before the update, so I'm not sure - how / why it could be an issue outside of Cloudron?
-
That I don't know either, but if I interpret the error correctly the AWS SDK gets a 405 error status contacting the storage backend. Which is the HTTP error for "Method Not Allowed" so that lines up at least. I would have no clue to even start debugging this from our side to be honest. Also I don't think this is related to this initial forum thread at all. Maybe you can create a new forum thread with as much info as possible to track this.
-
I have provider 'Exoscale' in both cases and the backup stopped working immediately after 8.0.3, and it doesn't yet.
It seems to be an issue on topic and I really can't do match - as everything is packed inside Exoscale module of Cloudron.
