Jottacloud via Rclone started to fail since June 12

Hi, when Jottacloud integration started to cause troubles, I switched to rclone backed for it as recommended and it worked well until June 12, when midday it started to throw those errors, which it has been throwing since then. Half of the backups set before 1 p.m. CEST were completed fine, everything after failed.

LimitedErrors: [
2024-06-14 11:31:36 +02 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error
Exception: 2024/06/14 11:31:36 Failed to create file system for “jottacloud:BackupName”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”},
2024-06-14 11:31:36 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: Operace Backup se nezdařila s chybou: 2024/06/14 11:31:36 Failed to create file system for “jottacloud:BackupName”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”}
Exception: 2024/06/14 11:31:36 Failed to create file system for “jottacloud:BackupName”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”}
]

Log data:
2024-06-14 11:31:36 +02 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error
System.Exception: 2024/06/14 11:31:36 Failed to create file system for “jottacloud:BackupName”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”}
at Duplicati.Library.Main.BackendManager.List()
at Duplicati.Library.Main.Operation.FilelistProcessor.RemoteListAnalysis(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, IEnumerable1 protectedFiles) at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, IEnumerable1 protectedFiles)
at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile)
at Duplicati.Library.Main.Operation.BackupHandler.d__20.MoveNext()
2024-06-14 11:31:36 +02 - [Error-Duplicati.Library.Main.Controller-FailedOperation]: Operace Backup se nezdařila s chybou: 2024/06/14 11:31:36 Failed to create file system for “jottacloud:BackupName”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”}
System.Exception: 2024/06/14 11:31:36 Failed to create file system for “jottacloud:BackupName”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”}
at Duplicati.Library.Main.BackendManager.List()
at Duplicati.Library.Main.Operation.FilelistProcessor.RemoteListAnalysis(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, IEnumerable1 protectedFiles) at Duplicati.Library.Main.Operation.FilelistProcessor.VerifyRemoteList(BackendManager backend, Options options, LocalDatabase database, IBackendWriter log, IEnumerable1 protectedFiles)
at Duplicati.Library.Main.Operation.BackupHandler.PreBackupVerify(BackendManager backend, String protectedfile)
at Duplicati.Library.Main.Operation.BackupHandler.d__20.MoveNext()
— End of stack trace from previous location where exception was thrown —
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at CoCoL.ChannelExtensions.WaitForTaskOrThrow(Task task)
at Duplicati.Library.Main.Controller.<>c__DisplayClass14_0.b__0(BackupResults result)
at Duplicati.Library.Main.Controller.RunAction[T](T result, String& paths, IFilter& filter, Action`1 method)

I refreshed token per instruction, but nothing changed and when I run rclone directly, I get the expected results

rclone.exe lsf jottacloud:
BackupName/
(and the list continues)

Any idea what broke? I’m not aware of any configuration change on my side.

2.0.8.1_beta_2024-05-07 running as a service via nssm on Windows 10 Home 19045.4529

Note I have my Windows in English, I have no idea why it’s using Czech for some of the error messages.

Removing puncuation and using regular double quotes to prepare for Google with

"error invalid_grant error_description Session doesn’t have required client"

suggests that this is the kind of result that Keycloak can give. I don’t think we use it.
Maybe Jottacloud is starting to. I think it was an authentication change last time too.

I suppose you could ask, and then we’ll find out how much they dislike third parties.

If you don’t want to do that, maybe an OAuth 2 expert will arrive here to help debug.
Ideally it would be somebody with Jottacloud, but I don’t know if such person exists.

Meanwhile, you can try to isolate the problem with Export As Command-line URL in
Duplicati.CommandLine.BackendTool.exe to see if list works reliably run that way.

Another easy test is the GUI Test connection button, which is generally just list.
Verify files button is likely a list and three downloads. If it fails, where was it?
Watching action on About → Show log → Live → Retry might also get further clues.

I don’t understand what is causing this to be different. Based on the source code for the rclone backend, it runs:

rclone lsjson remote_repo:remote_path

This seems to be the exact same thing you are running that works without issues. There appears to be no special settings applied by Duplicati, so the rclone executable should communicate exactly the same with Jottacloud in both invocations.

I saw some reports on the rclone forum that indicates that the token can expire after 1h, but I did not understand if this was fixed. Could it be some time-related issue?

Is this still the case?

Hi, sorry, took me some time to get to it and do some testing.

When I run it from the command line using the recommended “Export as Command” option, the backup works (there were no files to backup in this one, it’s just the safest to possibly corrupt - I then ran more important backups with new files, those also completed successfully from CLI):

C:\Users\USERNAME>“C:\Program Files\Duplicati 2\Duplicati.CommandLine.exe” backup “rclone://jottacloud/REPONAME?rclone-local-repository=local” “C:\apps\” “D:\gitrepo\” “D:\install\” --snapshot-policy=Off --auto-cleanup=true --auto-vacuum=false --log-file=“c:\private\duplicati.log” --restore-permissions=true --allow-missing-source=false --log-file-log-level=Information --asynchronous-upload-folder=“d:\duplitemp” --tempdir=“d:\duplitemp” --send-mail-to=“EMAIL” --rclone-executable=“c:\Apps\rclone\rclone.exe” --send-http-url=https://ingress.duplicati.com/backupreports/APIKEY --send-http-result-output-format=Json --backup-name=Install --dbpath=“h:\duplibase\DBNAME.sqlite” --backup-id=DB-1 --encryption-module=aes --compression-module=zip --dblock-size=100MB --passphrase=“ENCRYPTIONKEY” --keep-versions=3 --disable-module=console-password-input --exclude=“*C:\apps\jdownloader\logs*\” --exclude=“C:\apps\jdownloader\JD2.lock”
Backup started at 07.07.2024 14:46:20
Checking remote backup …
Listing remote folder …
Scanning local files …
0 files need to be examined (0 bajtu)
20809 files need to be examined (816,83 MB) (still counting)
15736 files need to be examined (54,90 GB)
9675 files need to be examined (54,14 GB)
2735 files need to be examined (53,55 GB)
1564 files need to be examined (0 bajtu)
Uploading file duplicati-bed491ab06c2a49bc96bced7cb33809a7.dblock.zip.aes (31,94 MB) …
0 files need to be examined (0 bajtu)
Uploading file duplicati-i6c1947eae8ed4333b7aba44b4142e77c.dindex.zip.aes (73,39 KB) …
Uploading file duplicati-20240707T124621Z.dlist.zip.aes (2,55 MB) …
Deleting file duplicati-20240527T123000Z.dlist.zip.aes (2,54 MB) …
Checking remote backup …
Listing remote folder …
Verifying remote backup …
Remote backup verification completed
Downloading file duplicati-20240707T124621Z.dlist.zip.aes (2,55 MB) …
Downloading file duplicati-ib630dd85ba2c421d826a4b81ddf594b0.dindex.zip.aes (35,06 KB) …
Downloading file duplicati-b00c6f74f48e84de9857b485a1b7db539.dblock.zip.aes (100,09 MB) …
Duration of backup: 00:01:53
Remote files: 969
Remote size: 55,07 GB
Total remote quota: 0 bajtu
Available remote quota: 0 bajtu
Files added: 33
Files deleted: 86
Files changed: 313
Data uploaded: 34,56 MB
Data downloaded: 102,68 MB
Backup completed successfully!

Logfile:

2024-07-07 14:46:21 +02 - [Information-GetGpgProgramPath-gpg]: C:\Program Files\Duplicati 2\win-tools\gpg.exe
2024-07-07 14:46:21 +02 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: Operace Backup zahájena
2024-07-07 14:46:26 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2024-07-07 14:46:28 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (967 bajtĹŻ)
2024-07-07 14:46:55 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bed491ab06c2a49bc96bced7cb33809a7.dblock.zip.aes (31,94 MB)
2024-07-07 14:47:42 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bed491ab06c2a49bc96bced7cb33809a7.dblock.zip.aes (31,94 MB)
2024-07-07 14:47:42 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i6c1947eae8ed4333b7aba44b4142e77c.dindex.zip.aes (73,39 KB)
2024-07-07 14:47:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i6c1947eae8ed4333b7aba44b4142e77c.dindex.zip.aes (73,39 KB)
2024-07-07 14:47:44 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-20240707T124621Z.dlist.zip.aes (2,55 MB)
2024-07-07 14:47:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20240707T124621Z.dlist.zip.aes (2,55 MB)
2024-07-07 14:47:49 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) …
2024-07-07 14:47:56 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20240527T123000Z.dlist.zip.aes (2,54 MB)
2024-07-07 14:47:58 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20240527T123000Z.dlist.zip.aes (2,54 MB)
2024-07-07 14:47:58 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: Deleted 1 remote fileset(s)
2024-07-07 14:48:00 +02 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required
2024-07-07 14:48:00 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2024-07-07 14:48:01 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (969 bajtĹŻ)
2024-07-07 14:48:01 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20240707T124621Z.dlist.zip.aes (2,55 MB)
2024-07-07 14:48:03 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20240707T124621Z.dlist.zip.aes (2,55 MB)
2024-07-07 14:48:03 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-ib630dd85ba2c421d826a4b81ddf594b0.dindex.zip.aes (35,06 KB)
2024-07-07 14:48:04 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-ib630dd85ba2c421d826a4b81ddf594b0.dindex.zip.aes (35,06 KB)
2024-07-07 14:48:04 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b00c6f74f48e84de9857b485a1b7db539.dblock.zip.aes (100,09 MB)
2024-07-07 14:48:14 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b00c6f74f48e84de9857b485a1b7db539.dblock.zip.aes (100,09 MB)
2024-07-07 14:48:14 +02 - [Information-Duplicati.Library.Main.Operation.TestHandler-Test results]: Successfully verified 3 remote files
2024-07-07 14:48:19 +02 - [Information-Duplicati.Library.Modules.Builtin.SendMail-SendMailComplete]: E-mail byl úspěšně odeslán prostřednictvím serveru: smtp://in1-smtp.messagingengine.com

I still don’t understand why it’s using the Czech language for some lines, where the whole system is in English and only the browser has it as a second language option for sites. But it talks about starting the backup and sending the email.

When I try to launch the same backup via the web/service which is installed via nssm (as that was the only available option back in the days) and run under “Local System Account” to have access everywhere, it still returns the error:

Jul 7, 2024 2:56 PM: Operation List with file attempt 1 of 5 failed with message: 2024/07/07 14:56:59 Failed to create file system for “jottacloud:REPONAME”: couldn’t get customer info: Get “https://api.jottacloud.com/account/v1/customer”: couldn’t fetch token - maybe it has expired? - refresh with “rclone config reconnect jottacloud:”: oauth2: cannot fetch token: 400 Bad RequestResponse: {“error”:“invalid_grant”,“error_description”:“Session doesn’t have required client”}
{“ClassName”:“System.Exception”,“Message”:“2024/07/07 14:56:59 Failed to create file system for "jottacloud:REPONAME": couldn’t get customer info: Get "https://api.jottacloud.com/account/v1/customer\”: couldn’t fetch token - maybe it has expired? - refresh with "rclone config reconnect jottacloud:": oauth2: cannot fetch token: 400 Bad RequestResponse: {"error":"invalid_grant","error_description":"Session doesn’t have required client"}“,“Data”:null,“InnerException”:null,“HelpURL”:null,“StackTraceString”:” at Duplicati.Library.Backend.Rclone.d__18.MoveNext()\r\n— End of stack trace from previous location where exception was thrown —\r\n at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()\r\n at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)\r\n at Duplicati.Library.Backend.Rclone.d__19.MoveNext()\r\n at System.Collections.Generic.List1..ctor(IEnumerable1 collection)\r\n at System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source)\r\n at Duplicati.Library.Main.BackendManager.DoList(FileEntryItem item)\r\n at Duplicati.Library.Main.BackendManager.ThreadRun()",“RemoteStackTraceString”:null,“RemoteStackIndex”:0,“ExceptionMethod”:“8\nMoveNext\nDuplicati.Library.Backend.Rclone, Version=2.0.8.1, Culture=neutral, PublicKeyToken=null\nDuplicati.Library.Backend.Rclone+d__18\nVoid MoveNext()”,“HResult”:-2146233088,“Source”:“Duplicati.Library.Backend.Rclone”,“WatsonBuckets”:null}

Looks like the issue isn’t with JottaCloud, but with some communication between the service and rclone.

An interesting part, the web interface doesn’t recognize this CLI run backup and still reports Jun 10 as the last successful date.

I’m not sure how exactly rclone works, but maybe different user accounts have different settings or tokens? That could explain why it works when you do it in the command line.

That is a side effect of how the CLI works. It is fully separate from the server and doesn’t record those statistics. In the job log you should see the run.

These are using different users? The rclone config file location seems user-related, and also is configured from the command line as some user. If you change users, different results are very likely, but I’m not sure how it ever worked. Maybe you should ask rclone where its config file is:

Frequently Asked Questions

If you want to find this file, run rclone config file which will tell you where it is.

If I get a Command Prompt as SYSTEM using psexec, this says:

C:\Windows\system32\config\systemprofile\AppData\Roaming\rclone\rclone.conf

whereas my ordinary C:\Users accounts say C:\Users\USERNAME.config\rclone\rclone.conf

If you don’t want to set up the command prompt, you can probably have Duplicati run a script, redirect the rclone answer, and exit 0.

Another way to find all the rclone.conf files you have in the system is to use Everything search.

EDIT:

Config shows how file location is computed, and how you can use a different config if you wish:

--config string Config file (default "$HOME/.config/rclone/rclone.conf")

1 Like

It was always run under System account, so that the service could do snapshots (it cannot anyway, fails for some reason) and access all files (it can). My end-user account can elevate to it.

But, when looking for the file occurrences on my system via Everything (love that SW, using it on all my Windows), it shows the System’s file was modified at the exact time the error started to occur. Each morning backup set was completed fine, all afternoon included failed.

I’ve no idea what changed the file. Maybe some Windows restore mechanisms? Backups were running under that config for months (well, since issues with native JottaCloud integration, where rclone integration was the workaround).

Token was different (dunno if that was the source issue, as I regenerated the token as part of the fixing process, deleting the old one), and after I copied the user’s file to System’s directory, backups resumed to work via the web interface.

For some reason “Test Connection” via web reports “Failed to connect: The system cannot find the file specified”, the backup itself runs fine and it’s probably something I can live with.

I’ve indeed was able to find the freshest logs confirming the backup, as well as in app.duplicati.com :slight_smile:

1 Like

In Microsoft terminology, elevate means to switch security tokens, but not change the user.

How User Account Control Works

I’m not sure how one can elevate to SYSTEM. Maybe you mean you get a SYSTEM cmd?

I got mine with psexec -i -s cmd, and can confirm user (you can try what you got) using:

C:\Windows\system32>whoami
nt authority\system

(whoami /groups is a way to also see if you’re elevated – Task Manager also has a column)

Store tokens external to rclone.conf and other pages say rclone can store tokens there too.
rclone forum can advise with more authority, but may need a standalone reproducible case.
This is why I’m trying to see if you’re inadvertently comparing rclone under different users.

It was the root cause. Initially, when I was setting this up, I copied the rclone.conf from my user account’s folder to System’s and it was running fine. Then something I was unaware of changed the System’s version of the file and it ceased to work.

When I repeated the process with a fresh file with a recently generated token (maybe the CLI token has like 6-month expiration? Cannot check as they’re not displayed in Jottacloud ), it fixed the main issue.

1 Like