how to run script continuously despite errors

[Laffreux-dev]

Hello,

Despite the max-retries at -1 by default, the sync cuts out on various errors such as the one below after less than 10/20 minutes.

• If I pass the cron to "* * * * *" do I have a chance of having the script running continuously?
• Is the lock released after a fatal error?
• If I run the script with the --force param every minute and the script actually runs without crashing, what happens?

Thanks !

[steilerDev]

I don't think '* * * * *' would work, but the daemon mode should recover from those errors, however I'm already clasifying errors during the sync process as 'recoverable' and 'non-recoverable' - this one seems to be non recoverable (based on the metadata received by the Apple backend, the file downloaded does not match)

Could you check out the file in question (should be AeF8pJwiYWcDWdcL2ED0csfK1fOn.mov in your _All Photos folder) and see what size and modified date it has (those are the two things that are verified)

The lock should be released

Yeah, I would not do that - the lock is the only thing stopping the program from overwriting itself.

[Laffreux-dev]

what is your schedule config advice for run in daemon mode ? every hour?

[steilerDev]

I've got it currently running once a day at 2am in the morning - I dont have much going on in my Lybrary that would need an hourly run.

[Laffreux-dev]

I found the file and it seems ok, I can play the video without worry

After near one hour of sync I have this new error, it seem to be retying but get stuck, I have to kill and relaunch docker exec -t photos-sync icloud-photos-sync sync

I look at the doc to launch in daemon mode

[steilerDev]

hmmm - he should retry automatically (if saying it's 'recoverable').... do you happen to have the log of this run?

[steilerDev]

What's the size on disk for the file and the exact modification date?

If verification fails, either of those two does not match with the backend metadata - I already saw that node's implementation of setting modification time is a bit inprecise, which is why I'm fine if the timestamp is off by 10ms, maybe I need to have this to be a little bit less strict

[Laffreux-dev]

new error with sync script

i'm launching a new try in daemon mode with SCHEDULE=*/5 * * * * and FORCE=false

[steilerDev]

I'm using commanderjs for parsing CLI and environment arguments - when using environmental variables for boolean flags (like force), the flag will be set to true if the env variable is set (independent of the value of the flag)

This means to disable the force flag, you need to remove the FORCE env variable completely (setting it to false will not do anything) - I will try and make this more clear in the docs.

And the error you are seeing there is exactly what I was expecting when having concurrent syncs that ignore the Library lock ;)

[Laffreux-dev]

ok thanks, for now i'm just using sync --force command, i didn't put any env variable in my docker-compose.yml.

Concurrent syncs!? It's possible ? I thought it would download the same assets if I launched several syncs in parallel, no ? How did you do that ?

[steilerDev]

--force should not be necessary, once the app properly works :D

The lock gets removed once the sync completes / should also remove in case the error is properly handled (which it currently is not) - the lock is necessary to avoid concurrent syncs when running scheduled (if two syncs are happening at the same time, they will try to write the same files and I'm not sure what will happen next :D )

[Laffreux-dev]

Ok it's more clear, sorry, I confused concurrent sync and sync in parallel

[Laffreux-dev]

it seem to be ok with daemon mode :)

[Laffreux-dev]

bad news, the daemon was stuck all night :'(

i have to remove .library.lock manually to let the daemon run again

[steilerDev]

hmpf :'(

'CLI-Interface: undefined' does not look good...

Could you try and get the log file (and maybe set log-level to debug) once the engine gets stuck again - I'm currently a little bit unsure whats happening there (keep in mind the log file is truncated once you start again - I probably should implement log rotation)

[Laffreux-dev]

here is the debug log when my daemon is in stuck loop

icloud-photos-sync.log.txt

to avoid getting stuck, I run a cron every minute with find /volume1/photo/icloud-photos-library/.library.lock -mmin +10 -delete
it checks if the .library.lock file has not been modified for 10 minutes and deletes it if necessary

[Laffreux-dev]

ok i'm not getting stuck, but the daemon seems to be looping on the same error over and over.

I go back to the sync command to see if i can catch the exact error

[steilerDev]

It's the verification error right?

Could you get me the exact size and modified date of the file on disk? I got a hunch....

[Laffreux-dev]

about the "CLI-Interface" line, I better understand the difference when I run the sync command, indeed my daemon seems to have a problem

[steilerDev]

Yeah, let's get the initial sync working for now and then look at why the dameon is failing :D (also you should really not need to remove the lock manually :D)

[steilerDev]

Could you firstly try and change this line and increase the acceptable range for 'modified'?

Maybe something like this:

return this.withinRange(fileStats.mtimeMs, this.modified, 1000);

(this would allow the local 'modified' timestamp to be off by 1000ms compared to the metadata provided by iCloud)

[steilerDev]

I'm going to rework the error messages in this area to make it more easy to debug later

[Laffreux-dev]

also you should really not need to remove the lock manually :D

ok, disabled :X

Could you firstly try and change this line and increase the acceptable range for 'modified'?

ok, modified !

I try a new sync

[Laffreux-dev]

last run results
0% | Elapsed: 3m41s | 15/60811 assets downloaded
0% | Elapsed: 58m29s | 429/60796 assets downloaded
0% | Elapsed: 41m56s | 392/60367 assets downloaded

Is it possible to handle file larger than 2GiB ?

[2023-01-09T14:00:51.380Z] INFO CLI-Interface: SyncWarning (WARN): Error while writing state caused by File size (2387209258) is greater than 2 GiB
[2023-01-09T14:00:51.380Z] WARN Error-Handler: SyncWarning (WARN): Error while writing state caused by File size (2387209258) is greater than 2 GiB
[2023-01-09T14:00:52.430Z] DEBUG Photos-Library: Writing asset ARCv8Z3JSEgBaRFgOJghRDIW9FKX
[2023-01-09T14:00:55.101Z] INFO CLI-Interface: undefined
[2023-01-09T14:00:55.390Z] INFO CLI-Interface: Experienced fatal error at 1/9/2023, 3:00:55 PM: SyncError (FATAL): Sync failed caused by SyncError (FATAL): Unknown error, aborting! caused by File size (2387209258) is greater than 2 GiB (Error Code: 989aac0b-2a56-4aea-acc3-0fd8bb922c31)
[2023-01-09T14:00:55.390Z] INFO CLI-Interface: undefined
[2023-01-09T14:00:55.390Z] ERROR Error-Handler: SyncError (FATAL): Sync failed caused by SyncError (FATAL): Unknown error, aborting! caused by File size (2387209258) is greater than 2 GiB (Error Code: 989aac0b-2a56-4aea-acc3-0fd8bb922c31)

Thanks !

[Laffreux-dev]

i don't know if it's the right file

ls -lh _All-Photos/ARCv8Z3JSEgBaRFgOJghRDIW9FKX.mov
-rw-r--r-- 1 admin users 103M Aug 19 06:58 _All-Photos/ARCv8Z3JSEgBaRFgOJghRDIW9FKX.mov

[steilerDev]

Hm - something I've never checked - don't have a file of this size in my Library. I'll try to check this.

[steilerDev]

Need to see what part of the app is causing the Warning

[Laffreux-dev]

happy to find new cases to study ^^

[Laffreux-dev]

Nice 2.5 hour non-stop runtime with sync command

[steilerDev]

Awesome - yeah the tool SHOULD handle failures - it sometimes just does not do it :D

I've created #155 for the 2GB problem and also #156 for better error output :)

[Laffreux-dev]

Great !

[Laffreux-dev]

new error

[2023-01-10T07:35:08.910Z] INFO CLI-Interface: SyncWarning (WARN): Error while writing state caused by getaddrinfo EAI_AGAIN cvws.icloud-content.com
[2023-01-10T07:35:08.910Z] WARN Error-Handler: SyncWarning (WARN): Error while writing state caused by getaddrinfo EAI_AGAIN cvws.icloud-content.com
[2023-01-10T07:35:18.567Z] INFO Sync-Engine: Adding asset Aa0I7lX+4DYj39jrCpvDhXPDwW4Y
[2023-01-10T07:35:18.823Z] INFO CLI-Interface: undefined
[2023-01-10T07:35:19.049Z] INFO CLI-Interface: Experienced fatal error at 1/10/2023, 8:35:18 AM: SyncError (FATAL): Sync failed caused by SyncError (FATAL): Unknown error, aborting! caused by getaddrinfo EAI_AGAIN cvws.icloud-content.com (Error Code: 9d8bbeec-adb2-4894-a4fe-11235f94eb3c)
[2023-01-10T07:35:19.049Z] INFO CLI-Interface: undefined
[2023-01-10T07:35:19.050Z] ERROR Error-Handler: SyncError (FATAL): Sync failed caused by SyncError (FATAL): Unknown error, aborting! caused by getaddrinfo EAI_AGAIN cvws.icloud-content.com (Error Code: 9d8bbeec-adb2-4894-a4fe-11235f94eb3c)

[steilerDev]

Okay it seems that the DNS record for iCloud expires after some time.... I've added 'EAI_AGAIN' as a 'recoverable' error in the sync process.

[Laffreux-dev]

A new error with sync command, the script exit after the last line

[2023-01-10T17:21:07.701Z] INFO CLI-Interface: SyncWarning (WARN): Error while writing state caused by Request failed with status code 503
[2023-01-10T17:21:07.701Z] WARN Error-Handler: SyncWarning (WARN): Error while writing state caused by Request failed with status code 503
[2023-01-10T17:21:07.702Z] DEBUG Sync-Engine: Detected Axios error
[2023-01-10T17:21:07.702Z] DEBUG Sync-Engine: Bad server response (503), retrying...
[2023-01-10T17:21:07.703Z] INFO CLI-Interface: Detected recoverable error, refreshing iCloud connection & retrying (#2)...
[2023-01-10T17:21:07.703Z] INFO CLI-Interface: undefined
[2023-01-10T17:21:07.704Z] DEBUG Sync-Engine: Preparing retry...
[2023-01-10T17:21:07.704Z] INFO Sync-Engine: Error occurred with 52680 asset(s) left in the download queue, clearing queue...
[2023-01-10T17:21:07.705Z] INFO Sync-Engine: Error occurred with 4 pending job(s), waiting for queue to settle...
[2023-01-10T17:21:08.331Z] DEBUG Photos-Library: Writing asset Aco7Rpv7EfhvPxM/x25BLeTcCNyN
[2023-01-10T17:21:19.691Z] DEBUG Photos-Library: Verifying asset Aco7Rpv7EfhvPxM/x25BLeTcCNyN
[2023-01-10T17:21:19.988Z] DEBUG Photos-Library: Asset Aco7Rpv7EfhvPxM/x25BLeTcCNyN successfully downloaded

[Laffreux-dev]

While waiting for more advanced error management, I run a simple shell script every minute that restarts the sync command when the process is no longer running, I'll see tomorrow morning if it works better than the previous nights

#!/bin/bash
if ps aux | grep -v grep | grep "docker exec -t photos-sync icloud-photos-sync sync"
then
        echo 'found'
else
        echo 'not found'
        docker exec -t photos-sync icloud-photos-sync sync --force --enable-crash-reporting
fi

[Laffreux-dev]

the container does not crash, it's the sync command who fail on various not recoverable error after random time or file or icloud availability

[Laffreux-dev]

well it won't be for tonight I think :(

[Laffreux-dev]

maybe a rate limit with icloud api, i try 30min interval

[steilerDev]

that could be

[Laffreux-dev]

This is the report of the night, I receive a mail when the script is restarted.

I will add to the mail a report of the last errors before the restart of the script to collect more information.