Got a red popup error titled “Error while running <job name>” with the popup contents saying:
Unable to find log in lookup table, this may be caused by attempting to transport call contexts between AppDomains (e.g. with remoting calls)
About → Show log → Stored
Jan 4, 2025 7:39 AM: Failed while executing Backup "<job name>" (id: 1)
System.Exception: Unable to find log in lookup table, this may be caused by attempting to transport call contexts between AppDomains (e.g. with remoting calls)
at Duplicati.Library.Logging.Log.get_CurrentScope()
at Duplicati.Library.Logging.Log.CloseScope(LogScope scope)
at Duplicati.Library.Logging.LogScope.Dispose()
at Duplicati.Server.Runner.Run(IRunnerData data, Boolean fromQueue)
Job log completed successfully, but time of error looks like when the run-script-after finished.
The run-script-after does some tests, leaving logs. The last file timestamps were at 7:39:15.
Profiling log shows usual end-of-backup-itself, but not the later error or end of full operation.
2025-01-04 07:25:05 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:05:02.550
Server log end:
2025-01-04 07:25:05 -05 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:05:02.550
Status bar and Server state properties look like the backup operation has completed though.
Early morning weirdness on PC wake (or at least first Duplicati use) was a Connection lost
Connection to server was rejected due to invalid authentication.
Log in again, or re-open the page from the TrayIcon (if applicable)
If it’s relevant, this one (not yet fixed) is at http://localhost:8200/ngax/index.html#/log/1
Console which launched Duplicati kept nice and quiet yesterday, but now has this and more:
fail: Microsoft.AspNetCore.Server.Kestrel[13]
Connection id "0HN9BVKTBTP75", Request id "0HN9BVKTBTP75:0000002F": An unhandled exception was thrown by the application.
Duplicati.WebserverCore.Exceptions.UnauthorizedException: Token family not found
at Duplicati.WebserverCore.Middlewares.JWTTokenProvider.ValidateAccessToken(TokenValidatedContext context, ITokenFamilyStore store)
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
at Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler.HandleAuthenticateAsync()
at Microsoft.AspNetCore.Authentication.AuthenticationHandler`1.AuthenticateAsync()
at Microsoft.AspNetCore.Authentication.AuthenticationService.AuthenticateAsync(HttpContext context, String scheme)
at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context)
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)
These are in the Application event log, but whatever happened at 7:39 is not (that I could find).
EDIT:
The logout might just be the usual old problem still hanging around. I think I have four tabs, and
Release: 2.0.9.107 (Canary) 2024-09-11 talks about how Duplicati tends to do this around then.
A tab was http://localhost:8200/ngax/index.html#/log which is live log. I copied by Ctrl-A
Top entry was “Jan 3, 2025 8:17 PM: The operation List has completed”. In server log, it may be
2025-01-03 20:17:04 -05 - [Information-Duplicati.Library.Main.Controller-CompletedOperation]: The operation List has completed
2025-01-04 07:20:02 -05 - [Information-Duplicati.Library.Main.Controller-StartingOperation]: The operation Backup has started
where one also sees the scheduled backup starting. The above description says how that ended.
This TrayIcon started at 8:47:37 AM 1/3/2025. Not sure what else to add. I’ll leave it up for awhile.