Repeated backup failures with an app
-
Hello,
I'm facing a lot of stability issues with a specific app and its backups, and I'm not sure if it's a general issue or app-specific one, hence the request for support here instead of in the very app specific forum section. Anyway feel free to move this topic elsewhere if it's too specific.So the last backup is from 1 week ago (Sept 19) for some app (changedetection).
Since then, all dedicated backups tasks for this very app are stuck, the status in Cloudron app page is stuck atBacking up - Removing 1000 files from ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/MsI8IMR7IMRPS7aT5qvcrpnlBR5Kr7AXggLB1fSpWiLhLhDz6ZAaO7JlAWcyusUYdHs8pfzWlS+IJCDgs-OW5Q/htrH97oS6J-iUgci3AdbFaVs3ZyELXy66BI2YXJ1U06wow5BL8fIEf5jpq2J54n8aKl5nV2e3srnAn-RTE6PQw to ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/rBCzp6YXZGsVK1NCh2FcIgOxZaOt-dzi7yEkQuNJHSHbkjmDbFE7VImvgqRrejeQA7rRolHTSpnqpWLfo+TQaQ/EZEn5RmKuVdu2sZycxslrr3S6pDwqOuMzUXdPvywo5j23h5aSQBC170tpPgNk8FgeQsGuixv+EfX4vxWczC90A (changedetection.***REDACTED***)
The app logs :
Sep 23 19:35:41 box:syncer sync: processing 1 deletes and 2620 additions Sep 23 19:35:41 box:backupformat/rsync sync: processing task: {"operation":"removedir","path":"","reason":"crash"} Sep 23 19:35:41 box:backupformat/rsync Removing directory ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 23 19:35:41 box:tasks update 2597: {"percent":30,"message":"Removing 1000 files from ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/MsI8IMR7IMRPS7aT5qvcrpnlBR5Kr7AXggLB1fSpWiLhLhDz6ZAaO7JlAWcyusUYdHs8pfzWlS+IJCDgs-OW5Q/htrH97oS6J-iUgci3AdbFaVs3ZyELXy66BI2YXJ1U06wow5BL8fIEf5jpq2J54n8aKl5nV2e3srnAn-RTE6PQw to ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/qYg8hLFfuEaGNVX3ZKX3DrVkG8mWDN83C-NzACUML6cRrmWBooz0zE7zgEnO1Hd--I-j+ZMcp5rJVQbUJkM+fw/4regPhKR4Ihxc7GYD172dZnDwukxgrjNRTXlJaYk2rke6rXoi5DwzSl5AUQsSSowSNPF4gduz4kqjGJnUl8R9w (***REDACTED***)"} Sep 25 09:13:28 box:taskworker Starting task 2610. Logs are at /home/yellowtent/platformdata/logs/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/apptask.log Sep 25 09:13:28 box:apptask run: startTask installationState: pending_configure runState: running Sep 25 09:13:28 box:tasks update 2610: {"percent":10,"message":"Deleting old containers"} Sep 25 09:13:28 box:shell reload /usr/bin/sudo -S /home/yellowtent/box/src/scripts/restartservice.sh nginx Sep 25 09:13:28 box:apptask deleteContainer: deleting app containers (app, scheduler) Sep 25 09:13:28 box:shell removeLogrotateConfig /usr/bin/sudo -S /home/yellowtent/box/src/scripts/configurelogrotate.sh remove 7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 25 09:13:28 box:tasks update 2610: {"percent":20,"message":"Downloading icon"} Sep 25 09:13:28 box:apptask downloadIcon: Downloading icon of io.changedetection.cloudronapp@1.11.4 Sep 25 09:13:29 box:tasks update 2610: {"percent":40,"message":"Downloading image"} Sep 25 09:13:29 box:shell file execArgs: df ["-B1","--output=source,fstype,size,used,avail,pcent,target","/var/lib/docker"] Sep 25 09:13:29 box:docker downloadImage cloudron/io.changedetection.cloudronapp:20240904-130305-8085b47c8 Sep 25 09:13:29 box:tasks update 2610: {"percent":45,"message":"Ensuring app data directory"} Sep 25 09:13:29 box:tasks update 2610: {"percent":50,"message":"Setting up addons"} Sep 25 09:13:29 box:services setupAddons: Setting up ["localstorage"] Sep 25 09:13:29 box:services setupAddons: setting up addon localstorage with options {} Sep 25 09:13:29 box:services setupLocalStorage Sep 25 09:13:29 box:shell createVolume /usr/bin/sudo -S /home/yellowtent/box/src/scripts/mkdirvolume.sh /home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/data Sep 25 09:13:29 box:tasks update 2610: {"percent":60,"message":"Creating container"} Sep 25 09:13:29 box:apptask createContainer: creating container Sep 25 09:13:31 box:shell addLogrotateConfig /usr/bin/sudo -S /home/yellowtent/box/src/scripts/configurelogrotate.sh add 7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d /tmp/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d.logrotate Sep 25 09:13:31 box:apptask startApp: starting container Sep 25 09:13:31 box:tasks update 2610: {"percent":90,"message":"Configuring reverse proxy"} Sep 25 09:13:31 box:shell providerMatches execArgs: openssl ["x509","-noout","-subject","-issuer"] Sep 25 09:13:31 box:reverseproxy providerMatches: subject=CN = ***REDACTED*** domain=***REDACTED*** issuer=C = US, O = Let's Encrypt, CN = E5 wildcard=false/false prod=true/true issuerMismatch=false wildcardMismatch=false match=true Sep 25 09:13:31 box:shell getCertificateDates execArgs: openssl ["x509","-startdate","-enddate","-subject","-noout"] Sep 25 09:13:31 box:reverseproxy ensureCertificate: ***REDACTED*** acme cert exists and is up to date Sep 25 09:13:31 box:reverseproxy expiryDate: subject=CN = ***REDACTED*** notBefore=Aug 8 05:12:02 2024 GMT notAfter=Nov 6 05:12:01 2024 GMT daysLeft=41.91561716435185 Sep 25 09:13:31 box:reverseproxy needsRenewal: false. force: false Sep 25 09:13:31 box:shell isOscpEnabled execArgs: openssl ["x509","-in","/home/yellowtent/platformdata/nginx/cert/***REDACTED***.cert","-noout","-ocsp_uri"] Sep 25 09:13:31 box:reverseproxy writeAppLocationNginxConfig: writing config for "***REDACTED***" to /home/yellowtent/platformdata/nginx/applications/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/***REDACTED***.conf with options {"sourceDir":"/home/yellowtent/box","vhost":"***REDACTED***","hasIPv6":true,"ip":"172.18.18.205","port":5000,"endpoint":"app","redirectTo":null,"certFilePath":"/home/yellowtent/platformdata/nginx/cert/***REDACTED***.cert","keyFilePath":"/home/yellowtent/platformdata/nginx/cert/***REDACTED***.key","robotsTxtQuoted":null,"cspQuoted":null,"hideHeaders":[],"proxyAuth":{"enabled":false,"id":"7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","location":"/"},"upstreamUri":"","ocsp":true,"hstsPreload":false} Sep 25 09:13:31 box:shell reload /usr/bin/sudo -S /home/yellowtent/box/src/scripts/restartservice.sh nginx Sep 25 09:13:31 box:tasks update 2610: {"percent":100,"message":"Done"} Sep 25 09:13:31 box:tasks setCompleted - 2610: {"result":null,"error":null} Sep 25 09:13:31 box:tasks update 2610: {"percent":100,"result":null,"error":null} Sep 25 09:13:31 box:taskworker Task took 3.554 seconds Sep 25 09:15:58 box:taskworker Starting task 2633. Logs are at /home/yellowtent/platformdata/logs/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/apptask.log Sep 25 09:15:58 box:apptask run: startTask installationState: pending_backup runState: running Sep 25 09:15:58 box:tasks update 2633: {"percent":10,"message":"Backing up"} Sep 25 09:15:58 box:backuptask backupApp: backing up ***REDACTED*** with tag 2024-09-25-071558-705 Sep 25 09:15:58 box:tasks update 2633: {"percent":30,"message":"Snapshotting app ***REDACTED***"} Sep 25 09:15:58 box:services backupAddons Sep 25 09:15:58 box:services backupAddons: backing up ["localstorage"] Sep 25 09:15:58 box:backuptask snapshotApp: ***REDACTED*** took 0.009 seconds Sep 25 09:15:58 box:tasks update 2633: {"percent":30,"message":"Uploading app snapshot ***REDACTED***"} Sep 25 09:15:58 box:shell backup-snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d /usr/bin/sudo -S -E --close-from=4 /home/yellowtent/box/src/scripts/backupupload.js snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d rsync {"localRoot":"/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","layout":[]} Sep 25 09:15:59 box:backupupload Backing up {"localRoot":"/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","layout":[]} to snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 25 09:15:59 box:backuptask upload: path snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d format rsync dataLayout {"localRoot":"/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","layout":[]} Sep 25 09:15:59 box:backuptask upload: mount point status is {"state":"active"} Sep 25 09:15:59 box:backuptask checkPreconditions: getting disk usage of /home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 25 09:15:59 box:shell checkPreconditions execArgs: du ["-Dsb","--exclude=*.lock","--exclude=dovecot.list.index.log.*","/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d"] Sep 25 09:15:59 box:backuptask checkPreconditions: total required=190917728 available=Infinity Sep 25 09:15:59 box:shell saveFsMetadata execArgs: find ["/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","-type","d","-empty"] Sep 25 09:15:59 box:shell saveFsMetadata execArgs: find ["/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","-type","f","-executable"] Sep 25 09:15:59 box:shell safeFsMetadata execArgs: find ["/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","-type","l"] Sep 25 09:16:00 box:syncer sync: processing 1 deletes and 2668 additions Sep 25 09:16:00 box:backupformat/rsync Removing directory ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 25 09:16:00 box:backupformat/rsync sync: processing task: {"operation":"removedir","path":"","reason":"crash"} Sep 25 09:16:02 box:tasks update 2633: {"percent":30,"message":"Removing 1000 files from ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/MsI8IMR7IMRPS7aT5qvcrpnlBR5Kr7AXggLB1fSpWiLhLhDz6ZAaO7JlAWcyusUYdHs8pfzWlS+IJCDgs-OW5Q/htrH97oS6J-iUgci3AdbFaVs3ZyELXy66BI2YXJ1U06wow5BL8fIEf5jpq2J54n8aKl5nV2e3srnAn-RTE6PQw to ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/rBCzp6YXZGsVK1NCh2FcIgOxZaOt-dzi7yEkQuNJHSHbkjmDbFE7VImvgqRrejeQA7rRolHTSpnqpWLfo+TQaQ/EZEn5RmKuVdu2sZycxslrr3S6pDwqOuMzUXdPvywo5j23h5aSQBC170tpPgNk8FgeQsGuixv+EfX4vxWczC90A (***REDACTED***)"} Sep 25 09:16:17 2024-09-25 07:16:17.844 | INFO | __main__:stats_thread_func:320 - Connections: Active count 0 of max 10, Total processed: 0. Sep 25 09:16:17 2024-09-25 07:16:17.845 | INFO | __main__:stats_thread_func:325 - Memory: Used 24.9% (Limit 90%) - Available 11191.7MB. ... Sep 25 09:17:17 2024-09-25 07:17:17.896 | INFO | __main__:stats_thread_func:320 - Connections: Active count 0 of max 10, Total processed: 0. Sep 25 09:17:17 2024-09-25 07:17:17.897 | INFO | __main__:stats_thread_func:325 - Memory: Used 24.8% (Limit 90%) - Available 11163.4MB. Sep 25 09:17:26 2024-09-25 07:17:26.086 | DEBUG | changedetectionio.flask_app:ticker_thread_check_time_launch_checks:1875 - > Queued watch UUID ee0f357e-591a-4d49-bfb2-2cd8a922bcf3 last checked at 1727241446 queued at 1727248646.08 priority 1727248646 jitter -0.46s, 7200.08s since last checked Sep 25 09:17:26 2024-09-25 07:17:26.693 | INFO | changedetectionio.update_worker:run:255 - Processing watch UUID ee0f357e-591a-4d49-bfb2-2cd8a922bcf3 Priority 1727248646 URL https://wttr.in/Anderlecht?m2&lang=fr&format=%C+%t%c%f Sep 25 09:17:26 2024-09-25 07:17:26.893 | DEBUG | changedetectionio.update_worker:run:576 - Watch ee0f357e-591a-4d49-bfb2-2cd8a922bcf3 done in 0.20s Sep 25 09:17:27 2024-09-25 07:17:27.898 | INFO | __main__:stats_thread_func:320 - Connections: Active count 0 of max 10, Total processed: 0. Sep 25 09:17:27 2024-09-25 07:17:27.899 | INFO | __main__:stats_thread_func:325 - Memory: Used 24.8% (Limit 90%) - Available 11157.5MB. ... Sep 25 09:24:48 2024-09-25 07:24:48.301 | INFO | __main__:stats_thread_func:320 - Connections: Active count 0 of max 10, Total processed: 0. Sep 25 09:24:48 2024-09-25 07:24:48.302 | INFO | __main__:stats_thread_func:325 - Memory: Used 25.0% (Limit 90%) - Available 11024.5MB.
So at this point I'm not sure what is being wrong since all other application backups are succeeding (18 out of 19) and what is even more strange, the global backup pages indicates that recent backups are all running fine for 19 apps out of 19, with changedetection taken into account.
But we can observe that for some days, the global backups were failing
I'm using Contabo box storage as backup, with rsync.
Backup Details Id:box_v8.0.4_2eb8547e Label: Remote Path:2024-09-24-230036-619/box_v8.0.4 Date:25 septembre 2024 09:09 Version:v8.0.4 Format:rsync
the last global backup log with a failure, is from Sept 23, 2024, here is the log
Sep 23 13:35:14 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/c+jYf5xr76gq81FCK1fDUc4UaSVhb4WTTO6cglNK4GqIiyQ5p5WJWcMhPDFEHreldB-rSc7EC9fYqPXOsvILjjszUIM13ZuWGWH2wPpJLms"} .... Sep 23 13:35:19 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/yzdVWvLnGqInmgV0iowUzBvONIIXYy5sS6Y00BrktlA/fafVDHFEC340ZL84sxiaFRKMKXw+e14CPiOSN0z1XHc/hjprtoxKXNgOmdTlxxgOkStBpUEoqHPmpJem9G0675M"} Sep 23 13:35:19 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copying 9zpGQTS3UZche6GQ47tXzP7EaJyoUuGEs+fostTm5XI"} Sep 23 13:35:19 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copying YNoW6AzegoTKzJYHs7mb9rQsTMo8spRfLSOjQJy70Mk"} Sep 23 13:35:19 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copying fQ+nHrDglHMMUKO1bl2UGlC-rBFqid8BdQ7cnt3Jruo"} Sep 23 13:35:19 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copying qX62gAiu+qMWjZ5PzbJ2ULUUL335FloZ0tg9dFGlVDA"} Sep 23 13:35:53 box:tasks update 2595: {"percent":46.45454545454546,"message":"Copied 119 files with error: null"} Sep 23 13:35:53 box:backuptask copy: copied successfully to 2024-09-23-102858-983/app_***REDACTED***_v1.14.25. Took 40.568 seconds Sep 23 13:35:53 box:backuptask fullBackup: app ***REDACTED*** backup finished. Took 43.455 seconds Sep 23 13:35:53 box:tasks update 2595: {"percent":46.45454545454546,"message":"Backing up ***REDACTED*** (11/19)"} Sep 23 13:35:53 box:tasks update 2595: {"percent":51.00000000000001,"message":"Snapshotting app ***REDACTED***"} Sep 23 13:35:53 box:services backupAddons Sep 23 13:35:53 box:services backupAddons: backing up ["localstorage"] Sep 23 13:35:53 box:backuptask snapshotApp: ***REDACTED*** took 0.004 seconds Sep 23 13:35:53 box:tasks update 2595: {"percent":51.00000000000001,"message":"Uploading app snapshot ***REDACTED***"} Sep 23 13:35:53 box:shell backup-snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d /usr/bin/sudo -S -E --close-from=4 /home/yellowtent/box/src/scripts/backupupload.js snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d rsync {"localRoot":"/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","layout":[]} Sep 23 13:35:54 box:backupupload Backing up {"localRoot":"/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","layout":[]} to snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 23 13:35:54 box:backuptask upload: path snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d format rsync dataLayout {"localRoot":"/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","layout":[]} Sep 23 13:35:54 box:backuptask upload: mount point status is {"state":"active"} Sep 23 13:35:54 box:backuptask checkPreconditions: getting disk usage of /home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 23 13:35:54 box:shell checkPreconditions execArgs: du ["-Dsb","--exclude=*.lock","--exclude=dovecot.list.index.log.*","/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d"] Sep 23 13:35:54 box:backuptask checkPreconditions: total required=177430791 available=Infinity Sep 23 13:35:54 box:shell saveFsMetadata execArgs: find ["/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","-type","d","-empty"] Sep 23 13:35:54 box:shell saveFsMetadata execArgs: find ["/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","-type","f","-executable"] Sep 23 13:35:54 box:shell safeFsMetadata execArgs: find ["/home/yellowtent/appsdata/7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d","-type","l"] Sep 23 13:35:55 box:syncer sync: processing 1 deletes and 2609 additions Sep 23 13:35:55 box:backupformat/rsync sync: processing task: {"operation":"removedir","path":"","reason":"crash"} Sep 23 13:35:55 box:backupformat/rsync Removing directory ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Sep 23 13:35:55 box:tasks update 2595: {"percent":51.00000000000001,"message":"Removing 1000 files from ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/MsI8IMR7IMRPS7aT5qvcrpnlBR5Kr7AXggLB1fSpWiLhLhDz6ZAaO7JlAWcyusUYdHs8pfzWlS+IJCDgs-OW5Q/htrH97oS6J-iUgci3AdbFaVs3ZyELXy66BI2YXJ1U06wow5BL8fIEf5jpq2J54n8aKl5nV2e3srnAn-RTE6PQw to ***REDACTED***/snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d/+-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/l5gkgMssQV3WZN4rGfLDET6XHh1q-3NvNH24UfTUuKI/nlJDfKdTrFn-Vx1W9Lrwlbp5+j++b+8dzgPo8B4cQKmbOg9S7T1HL8sEjCLJzer8V7QDYNQTHv3e5FINzNbNhA/sxlvwh-XcCwCh9vVfEinWuEPT6gODiTTry7AVlRIT2Q (***REDACTED***)"}
I'm really confused, and at this point I'm not confident to restore changedetection from a previous state.
I've at least been able to download a Changedetection backup zip file thanks to their Admin UI. But I'd like ideally to fix the whole situation at the root cause level or at least understand what is happening and troubleshoot it step by step.
The backup tasks are just stuck unless I cancel them which anyway is not making progress
Extra context :
- I'm running Cloudron v8.0.6 (automatically updated this morning).
- version of Changedetection:
App Info App Title and Versionchangedetection.io 0.46.04 App ID7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d Package Version io.changedetection.cloudronapp@1.11.4 Installed At 11/12/2023 Last Updated 04/09/2024
- Also Contabo had a big outage at the beginning of september at their Nuremberg DC, which was solved "quickly" (within 1-2 days) but a few days later I noticed a problem specific the availability of my Contabo Box storage a few days after, which they also have solved, so my backups were also blocked for 1 week from from Sept 10 to Sept 17.
Thanks for your help !
-
I would expect changedetection not having huge amounts of data, and if other apps backup fine, this is indeed strange. Do you see anything obvious around the app related backup folders via SSH on the mounted storage?
Like are attributes and permissions ok for example for
.../snapshot/app_7dc1c994-f6f8-4b3b-b3ed-0bb7097bb83d
? Can you delete that folder via SSH (only delete stuff in.../snapshot/
!) -
Thanks for the feedback !
For now after purging the path to this specific app snapshot through rclone purge command (and, in the middle of my way, use Cloudron admin UI to cancel the stuck backup task), I could rerun a new backup from a clean state which worked 🥳.
I've attempted a second backup which also worked.
I'll wait til the next day to see if the automatic backup succeed. -
-
So far the problem seems gone. Backups take quite some time and make me thing the process is sometimes stuck but that's likely related to the storage speed, I guess.
Anyway I consider the situation resolved, for now. -
-
Having a look at the global backup task log now it seems to take hours and seems stuck.
... Sep 27 01:44:36 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/el1yUFt9q+vF7wU+PUorQh+bug+RPb4XPDCqGBLTBwNqqV9oaNgs7sod7Zdv2SS04cAaBlBBAsdoO7YCQNPWoH9hAFMgN1t8IgsSXIGJA+E"} Sep 27 01:44:36 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/gR0FKpwmXOTt448s20n9Vdx9u6+X6MkYRsXhspsAlpBk3FiDd2J-KAzccYVT7KBvHDPpJte97we20tfT+68tnMgiqocFrVAFafDmK9IZht0"} Sep 27 01:44:38 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/h6ktzTFHvXAhKQZ+Rpo3kADFcNS8datgzudLKX-sLCRuE1tVqUy32talVF9iDgdncfA6pTlC775D2O2A9BNobAnOKSTDdwoMbAxzbygYVSQ"} Sep 27 01:44:40 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/hPzcGoNkm2GxUeaTMkz1IiWPuEmsRThMX8c3UfmPrm290IRjwX0rtpRlwdaQSehxB0lcf6iITQjgiq1vkgpmmwyhSoQ17IlyhsM5-1qo6gk"} ... Sep 27 01:44:52 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/wgORAkMQVHW4qqcDF08dDJNd5-2MLWPgoCHrqp-QyQy-++08LktkkrBcwMqEuOy4BCrwNKcWGqcD+fiHjdE7RRyNT-i6HpJaVTPoG-O4F04"} Sep 27 01:44:52 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/wizHcd-CKCvyUKH4svkmfrplXa-60Z-HA5NkCt71xKlSup+UWMWYLH37Ns086sRdmbPj+YMICTzZ5O6jAK9xn1CG1HuClQe9uHaY5kEY-YU"} Sep 27 01:44:52 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/yMYYgXsnQ8fAlolxbAQa0iTygfSYXFFIap2ANUDZFyjwOqxo8SKkBRVDUXMkGXy9FtFgltKqACBLEpry90N8PaItwL4hGcEXIMVvDOUSLh4"} Sep 27 01:44:52 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/zad6Ziin-IUOOGGk-bgP4Awxl59Xz4lsVVLBG7u7JVRSzMRktpSo+ecRzP-qlIThIVUgs8sNg6JNgDUfyFYiSw-NZPgKi4z+Gw4Uhp56mfc"} Sep 27 01:44:52 box:tasks update 2644: {"percent":46.45454545454546,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/zj5fRln7KTdIyTG6J1TCBWdxezzyVEJDSFoOqzTI94dnO6Riatt5CRcbYUNo53lh3FOy5AmtJBvpfg7Z+oKFv+SZ4L9qRaMyxoXDgIBo7KE"} ... Sep 27 03:14:36 box:tasks update 2644: {"percent":46.45454545454546,"message":"Retrying (1) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/c+jYf5xr76gq81FCK1fDUc4UaSVhb4WTTO6cglNK4GqIiyQ5p5WJWcMhPDFEHreldB-rSc7EC9fYqPXOsvILjjszUIM13ZuWGWH2wPpJLms. Error: 504: null 504"} ... Sep 27 04:45:17 box:tasks update 2644: {"percent":46.45454545454546,"message":"Retrying (2) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/U58FuxWQmXM04fxhZkwwPmOrt7d3+rOSLfCHv07RhU2zX-4cA2Wj-QxqshI1UxxaqIQ7Re4iFVBC+VBOcdleWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/YFtYX5hLWzIKz8PIqgtS216yGWBtdNs0+u9PEsKHYgyW9MQdpYxKvHFXWqGiElQnE3EiLZAl2DOVzWrHFGPBhEh9LQLkjK+J24WNb8qcEtI. Error: 504: null 504"} Sep 27 06:15:15 box:tasks update 2644: {"percent":46.45454545454546,"message":"Retrying (3) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/c+jYf5xr76gq81FCK1fDUc4UaSVhb4WTTO6cglNK4GqIiyQ5p5WJWcMhPDFEHreldB-rSc7EC9fYqPXOsvILjjszUIM13ZuWGWH2wPpJLms. Error: 504: null 504"} Sep 27 06:15:15 box:tasks update 2644: {"percent":46.45454545454546,"message":"Retrying (3) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/1Ff2uDiq0FJBiCASx828-rX19mPZIlvvTv9KasnL+Mvpze7LPXu-Aa5KDMUAKrsv2IsmgXUH+SrWKbG2G8cmWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/ed9-XRtQPFH6Pf9GgV8TPUZWfSTmtHIIxWvxApn-MgMGDN7hu64edxFVB7KVKXfbctH0mKpX3NjzOHT5Z+xQfawNBGLjZNQqrN0LmpY4AGU. Error: 504: null 504"} Sep 27 06:15:34 box:tasks update 2644: {"percent":46.45454545454546,"message":"Retrying (3) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/U58FuxWQmXM04fxhZkwwPmOrt7d3+rOSLfCHv07RhU2zX-4cA2Wj-QxqshI1UxxaqIQ7Re4iFVBC+VBOcdleWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/KySiM+lFfMMIsqgY0F6zzeH46Aqt8xCkFCfzuN0odSLoxdyIcZTwiZcAi3FZ3hdrAA-OoG4LkTwcapOtohQCzvjssKpo4dmSeBRLY8rEJDM. Error: 504: null 504"} Sep 27 06:15:36 box:tasks update 2644: {"percent":46.45454545454546,"message":"Retrying (3) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWTRVg8zyOQHxFtrW9PSg/U58FuxWQmXM04fxhZkwwPmOrt7d3+rOSLfCHv07RhU2zX-4cA2Wj-QxqshI1UxxaqIQ7Re4iFVBC+VBOcdleWg/GVjP4aiFVvSHFik-l75pxFHEU5NkaRki6FhmG+jhGMs/YFtYX5hLWzIKz8PIqgtS216yGWBtdNs0+u9PEsKHYgyW9MQdpYxKvHFXWqGiElQnE3EiLZAl2DOVzWrHFGPBhEh9LQLkjK+J24WNb8qcEtI. Error: 504: null 504"}
Not having my laptop with me to look further until Monday, only other thing I notice is the increasing huge size of backups on remote storage, like 90-100GB of backups for maybe a few hundred MBs worth of data for some apps.
Current status is Retrying (4) copy of +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/oHYKKHsp5nbpcywk51Jh-qadnitsJW2gf8LvyNVo0p4/JFrg5i70q68kJ2fb9TRxQhKuzyM8e7TIid8hUpVNUnTUO2OC0n9TVKwiecXpntDKgFWT
-
So far it's progressing again, around 20% further, after 3 hours
Sep 27 09:34:54 box:tasks update 2644: {"percent":64.63636363636364,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/bCsBHeTNFOA0PMfeHwtd1DqpwCaS0XLjnW+4F8ZpP4g/OZ18TuP+eoUKZmW0j54+-6KQXwFof55visHM89cem4A/kMAZeKzls8+PKNLMRAfK8MAGYpb9DqXiZHcZPkdUaSA/5pa6SeARNoGyhcT1VO4sfWspp5yLCxPK5JkT6fEId9s/hLfwbzJOjjuoazhfyFRSV+OeZ78xlTbZId3UjUrO6aw"} Sep 27 09:34:55 box:tasks update 2644: {"percent":64.63636363636364,"message":"Copying +-SqAUe7wm42qtKljEa0rA5Org2aerAP0dRZ+xrfGA8/bCsBHeTNFOA0PMfeHwtd1DqpwCaS0XLjnW+4F8ZpP4g/OZ18TuP+eoUKZmW0j54+-6KQXwFof55visHM89cem4A/kMAZeKzls8+PKNLMRAfK8MAGYpb9DqXiZHcZPkdUaSA/5pa6SeARNoGyhcT1VO4sfWspp5yLCxPK5JkT6fEId9s/hunSoQUKa6Z9QyvaoUtpCzgW5vTHNO6PTJhlSF1vqaQ"} S ...