# Release: 2.1.0.104 (Canary) 2024-12-31

**URL:** <https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804>\
**Category:** Releases\
**Created:** [December 31, 2024, 5:31pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804 "2024-12-31T17:31:51Z")\
**Posts on this page:** 20\
**Page:** 1

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [December 31, 2024, 5:31pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/1 "2024-12-31T17:31:51Z")

</div>

# [2.1.0.104\_canary\_2024-12-31](https://github.com/duplicati/duplicati/releases/tag/v2.1.0.104_canary_2024-12-31)

This release is a canary release intended to be used for testing.

**Note that this build is using .NET8, unlike the 2.0.8.1 build**

**Note that this build has a redesigned restore flow**  
Should issues arise, the previous restore engine can be enabled with `--restore-legacy=true`.

## Detailed list of changes:

- Fixed issue with launchAgent for CLI server not taking an argument
- Added simultaneous file processors, thanks @gpatel-fr
- Updated translations, thansk to many contributors!
- Added NOOP Daemon for FTP backend
- Excluded Google Drive and GCS from timeout streams
- Fixed an issue with the TrayIcon being disconnected after 15 minutes
- Removed the captcha fro full backup removal
- Reduced number of backend instances created
- Removed Windows-only options on the File backend on non-Windows
- Added option to log FTP messages to regular log

---

<div class="post-metadata">

**Author:** ![ollibraun](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/o/df705f/32.png) [@ollibraun](https://forum.duplicati.com/u/ollibraun)\
**Post date:** [January 1, 2025, 4:10pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/2 "2025-01-01T16:10:02Z")

</div>

Thank you for the new version, and a happy new year 2025. Unfortunately, the Windows service is not working for me. Version 2.1.0.102 works, but .103 and .104 do not.

```plaintext
MSIexec /i duplicati-2.1.0.104_canary_2024-12-31-win-x64-gui.msi FORSERVICE=true ADDLOCAL=ALL REMOVE=DuplicatiDesktopShortCutFeature,DuplicatiProgramMenuShortCutFeature,DuplicatiStartupShortCutFeature /Quiet

"C:\Program Files\Duplicati 2\Duplicati.WindowsService.exe" install --log-retention=1D --server-datafolder=%ALLUSERSPROFILE%\Duplicati --disable-db-encryption --webservice-password=password
Duplicati service installation failed. Exception: Win32 error 1073 during install service (CreateService)

```

In the event log, I have two entries:

```plaintext
Application: Duplicati.WindowsService.exe
CoreCLR Version: 8.0.624.26715
.NET Version: 8.0.6
Description: The process was terminated due to an unhandled exception.
Exception Info: System.ArgumentException: Log Duplicati 2 has already been registered as a source on the local computer.
   at System.Diagnostics.EventLog.CreateEventSource(EventSourceCreationData sourceData)
   at Duplicati.WindowsService.ServiceControl..ctor(String[] args, NamedExecutable executable)
   at Duplicati.WindowsService.Program.Main(String[] args)
   at Duplicati.WindowsService.Net8.Program.<>c __DisplayClass0_0.<Main>b__ 0()
   at Duplicati.Library.Crashlog.CrashlogHelper.WrapWithCrashLog[T](Func`1 method, String logdir, String applicationName)
   at Duplicati.WindowsService.Net8.Program.Main(String[] args)

Fehlerhafter Anwendungsname: Duplicati.WindowsService.exe, Version: 2.1.0.104, Zeitstempel: 0x66470000
Fehlerhafter Modulname: KERNELBASE.dll, Version: 10.0.27764.1000, Zeitstempel: 0xed180e69
Ausnahmecode: 0xe0434352
Fehleroffset: 0x00000000000ce2bc
Fehlerhafte Prozess-ID: 0x69D4
Fehlerhafte Anwendungsstartzeit: 0x1DB5C66AC127AF8
Fehlerhafter Anwendungspfad: C:\Program Files\Duplicati 2\Duplicati.WindowsService.exe
Fehlerhafter Modulpfad: C:\WINDOWS\System32\KERNELBASE.dll
Berichts-ID: 6775bbb0-bf54-4a1d-91b7-80a8e36d20db
Vollständiger Name des fehlerhaften Pakets: 
Fehlerhafte paketbezogene Anwendungs-ID:

Fehlerbucket 0, Typ 4
Ereignisname: APPCRASH
Antwort: Nicht verfügbar
CAB-Datei-ID: 0

Problemsignatur:
P1: Duplicati.WindowsService.exe
P2: 2.1.0.104
P3: 66470000
P4: KERNELBASE.dll
P5: 10.0.27764.1000
P6: ed180e69
P7: e0434352
P8: 00000000000ce2bc
P9: 
P10: 

Angefügte Dateien:
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER.c684a50c-a720-44b5-bcca-59c1d2b43f57.tmp.dmp
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER.757c7a6a-5abe-4715-bf75-775ada7f680d.tmp.WERInternalMetadata.xml
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER.68646407-7e0b-4dff-afc1-470061bcdc2a.tmp.csv
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER.fc70496e-c53a-41fd-8156-ea645371852b.tmp.txt
\\?\C:\ProgramData\Microsoft\Windows\WER\Temp\WER.abe2346b-6989-495d-825d-bae645877314.tmp.xml

Diese Dateien befinden sich möglicherweise hier:
\\?\C:\ProgramData\Microsoft\Windows\WER\ReportArchive\AppCrash_Duplicati.Window_735016c6443ba5c5fa473c7b1af57b2d9eea75_b0a7d6fe_486735d3-7c1d-497a-a393-b5caef6f75ba

Analysesymbol: 
Es wird erneut nach einer Lösung gesucht: 0
Berichts-ID: 6775bbb0-bf54-4a1d-91b7-80a8e36d20db
Berichtstatus: 268435456
Bucket mit Hash: b622e08f422e2c81acd6177930e9857e
CAB-Datei-Guid: 0

```

---

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [January 1, 2025, 4:14pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/3 "2025-01-01T16:14:55Z")

</div>

> [@ollibraun](#):
>
> `System.ArgumentException: Log Duplicati 2 has already been registered as a source on the local computer.`

I assume you have not created this source yourself?  
Previous Duplicati would create a **source** named “Duplicati” and for that reason the new version uses a **log** named “Duplicati 2”.

The error indicates that there is a **source** named “Duplicati 2”, which I don’t understand the reason for.

You can manually work around it with Power Shell as Administrator:

```plaintext
Remove-EventLog -Source "Duplicati 2"

```

After this, you should be able to run the install command again.  
If it works, could you please try to uninstall and install again, to see if it is a problem with Duplicati not detecting the existing log?

---

<div class="post-metadata">

**Author:** ![ollibraun](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/o/df705f/32.png) [@ollibraun](https://forum.duplicati.com/u/ollibraun)\
**Post date:** [January 1, 2025, 6:02pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/4 "2025-01-01T18:02:45Z")

</div>

Thank you very much for the quick feedback. This may be due to the installation of new Canary versions and also switching back in the last few months.

I deliberately didn’t create a source with any name, I don’t even know how to do that.

In a first test, the installation worked after the Powershell command. But I’ll have another look at it in the next few days.

---

<div class="post-metadata">

**Author:** ![Taomyn](https://forum.duplicati.com/user_avatar/forum.duplicati.com/taomyn/32/2665_2.png) [@Taomyn](https://forum.duplicati.com/u/Taomyn)\
**Post date:** [January 2, 2025, 10:04am UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/5 "2025-01-02T10:04:16Z")

</div>

Happy New Year. I upgraded all my .103 to .104 yesterday and all seemed fine. However, this morning one of my machines, 32bit RPi-4, was stuck on a job for over 9 hours and nothing seemed to be progressing.

 ![image](https://forum.duplicati.com/uploads/default/original/2X/1/1f3032e64bdc63ae39df1fb4b25a5037870eca12.png)

It’s 10:58 at the moment I took the above screenshot and this is a very small backup normally. There are two other jobs that run just before it and they both ran without issue.

I tried the Stop button choosing terminate, and here’s something I’ve meant to query - why doesn’t this ever work, at least for me? Anyway, it doesn’t have any effect even after about 30min.

 ![image](https://forum.duplicati.com/uploads/default/original/2X/6/608f4c0e891845709203495aa59cd2e0addb97a9.png)

Other than a high load average which I cannot see the cause for, nothing else is looking bad:

 ![image](https://forum.duplicati.com/uploads/default/original/2X/9/9a83b640a63735fc0947256adc6d68f845b00a2d.png)

 ![image](https://forum.duplicati.com/uploads/default/original/2X/a/aaeff6e3a373aa7fd64e15a2176866993f183bef.png)

Any ideas before I restart the service or the RPi itself?

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 2, 2025, 5:50pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/6 "2025-01-02T17:50:17Z")

</div>

> [@Taomyn](#):
>
> Other than a high load average which I cannot see the cause for, nothing else is looking bad:

This is more of a Linux topic, but your `24.6 wa` is probably processes in `D` state, raising that.  
Perhaps you can find some way to sort by state. If that fails, start with a `ps -e -ostate,args`

---

<div class="post-metadata">

**Author:** ![Taomyn](https://forum.duplicati.com/user_avatar/forum.duplicati.com/taomyn/32/2665_2.png) [@Taomyn](https://forum.duplicati.com/u/Taomyn)\
**Post date:** [January 2, 2025, 6:09pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/7 "2025-01-02T18:09:51Z")

</div>

I checked with htop as I worked out how to sort by state and it showed me that the Zabbix agent had many of those:

 ![image](https://forum.duplicati.com/uploads/default/original/2X/f/fdba4d112bea54f2d55f156495bc30157894f466.png)

I stopped the service and they went away but nothing has changed, duplicati remains stuck

 ![image](https://forum.duplicati.com/uploads/default/original/2X/6/6a2451c5717295d1acfea322db549c133f83de3c.png)

Although, it remains as the only `D` state now:

 ![image](https://forum.duplicati.com/uploads/default/original/2X/b/bb9d94af1706c35674f4c85d6488f75f913e48cf.png)

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 2, 2025, 6:21pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/8 "2025-01-02T18:21:10Z")

</div>

> [@Taomyn](#):
>
> Although, it remains as the only `D` state now:

I don’t generally look at the state, but FWIW the duplicati-server I just started is in S state.  
I don’t know if `D` might mean waiting for disk I/O. You could get its PID to fish with lsof -p.

> `# lsof -p12903 | grep -v /usr/lib`

for example, assuming there’s nothing of interest in /usr/lib besides Duplicati executables.  
The only sqlite, temp file, or destination I get is the server database and a nearby lock file.

---

<div class="post-metadata">

**Author:** ![Taomyn](https://forum.duplicati.com/user_avatar/forum.duplicati.com/taomyn/32/2665_2.png) [@Taomyn](https://forum.duplicati.com/u/Taomyn)\
**Post date:** [January 2, 2025, 8:36pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/9 "2025-01-02T20:36:15Z")

</div>

I ran lsof against the PID of the duplicati server and it comes back empty. I also checked the destination, a Windows SMB share, and there are no open file handles coming from the the machine. I then tried to dismount the SMB share and get this:

```plaintext
root@OTTO:/home/pi# umount //192.168.1.30/OTTO
umount: /srv/smb: target is busy.

```

This turned out to be the Zabbix agent as I have a check of the mount to alert me of any problems. I then stopped the agent and tried the umount again but it was still busy - lsof showed nothing. I tried a few different grep on lsof and nothing seemed to be using the SMB mount, yet the OS would not let me umount it.

So for now, I have restarted the machine - it never came back until I bounced the power. I reran the same backup job and it completed just fine. Very strange, but it’s not the first time as I’m sure this has happened before on another machine but it was a long time ago.

---

<div class="post-metadata">

**Author:** ![Taomyn](https://forum.duplicati.com/user_avatar/forum.duplicati.com/taomyn/32/2665_2.png) [@Taomyn](https://forum.duplicati.com/u/Taomyn)\
**Post date:** [January 2, 2025, 8:39pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/10 "2025-01-02T20:39:06Z")

</div>

Is this a bug? Running backups and repair updates the screen correctly, but the verify was stayed like this after it finished according to the log until I refreshed:

 ![image](https://forum.duplicati.com/uploads/default/original/2X/e/e27ce9243ce6e4943ecc79064320d389b8659a24.png)

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 2, 2025, 8:59pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/11 "2025-01-02T20:59:52Z")

</div>

> [@Taomyn](#):
>
> Is this a bug?

Assuming you mean the status bar still saying `Verifying files`, it’s similar to my report that:

> [@Release: 2.1.0.102 (Canary) 2024-12-12](https://forum.duplicati.com/t/release-2-1-0-102-canary-2024-12-12/19669/29):
>
> Tiny backup while trying to reproduce restore problem of uncreated folders has stuck status.  
> I’ve seen other small backups stick at Backup complete!, but it’s rare. Maybe time for report.

and the conclusion seemed inconclusive. Next time, maybe you can look at the browser traffic.

> [@Release: 2.1.0.102 (Canary) 2024-12-12](https://forum.duplicati.com/t/release-2-1-0-102-canary-2024-12-12/19669/31):
>
> But, since the “stuck status” has been a problem before, there is likely still some related issue where the progress is not propagated correctly in all cases.

is the last word for my report, so sounds like possibly the fixes so far have not resolved that bug.

---

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [January 3, 2025, 4:52pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/12 "2025-01-03T16:52:13Z")

</div>

> [@Taomyn](#):
>
> I tried the Stop button choosing terminate, and here’s something I’ve meant to query - why doesn’t this ever work, at least for me? Anyway, it doesn’t have any effect even after about 30min.

It has been broken for a long time, because it was originally implemented with thread interrupts, but this failed due to a lot of the code using tasks that are not bound to threads.

For 2.1.0.104 I have made most of the code use CancellationToken, so it should work better, but it is a cooperative stop. If the code hangs, it will never check for the stop.

My long-term plan to fix it is to have interprocess communication so we can run the backends in isolated processes and stop the process from the OS.

> [@Taomyn](#):
>
> Very strange, but it’s not the first time as I’m sure this has happened before on another machine but it was a long time ago.

From the logs messages I can see that it has done `CommitUpdateRemoteVolume` and then it _should_ do `CommitAfterUpload`, but that does not happen.

This indicates that it is stuck in `FlushBackend` which really just waits for the uploads to complete. But from the logs, it is obvious that the transfer is already completed, so there is nothing to wait for.

I will have a look.

> [@ts678](#):
>
> is the last word for my report, so sounds like possibly the fixes so far have not resolved that bug.

It looks very much like there is a race somewhere in the server/UI where it does not get the last report in the correct state.

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 4, 2025, 2:54pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/13 "2025-01-04T14:54:27Z")

</div>

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

```plaintext
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.

 ![image](https://forum.duplicati.com/uploads/default/original/2X/2/2bce0f8192c23a1a5cd7851c7ccf4c2fd8f85050.png)

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:

```plaintext
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](https://forum.duplicati.com/t/release-2-0-9-107-canary-2024-09-11/18983/75) 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

```plaintext
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.

---

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [January 6, 2025, 2:13pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/14 "2025-01-06T14:13:38Z")

</div>

> [@ts678](#):
>
> About → Show log → Stored
> 
> ```plaintext
> 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.

It could be some kind of race in the shutdown. The error message indicates that the log itself has been removed (so there is no where the log messages can go). But the call stack looks like the call originates from the log dispose call, which is shutting it down 😕 .

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 6, 2025, 2:27pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/15 "2025-01-06T14:27:19Z")

</div>

> [@kenkendk](#):
>
> the log itself has been removed (so there is no where the log messages can go)

I guess I can try to see if I can get it again. Which sort of logs are these? I’m probably running the automatic default log that the job log shows, and a server log, and a job log, and maybe old live…

---

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [January 6, 2025, 3:28pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/16 "2025-01-06T15:28:40Z")

</div>

> [@ts678](#):
>
> Which sort of logs are these?

The logs here are (most likely) the backup job logs that are closed as the job is done.

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 6, 2025, 7:37pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/17 "2025-01-06T19:37:45Z")

</div>

> [@ts678](#):
>
> I guess I can try to see if I can get it again.

It turned out I didn’t have to do anything, as my scheduled backups on Jan 5 and 6 failed too:

 ![image](https://forum.duplicati.com/uploads/default/original/2X/6/6294220617a729cc0c064d1ec5fa4d69c53c96f1.png)

I think some of my tabs reconnected on their own, and I did Dismiss the red popup notification.  
Maybe I’ll wait a little longer in case there’s something else that can be gleaned from this case.

EDIT 1:

Stacks are different. Original looks like on the way out. Next two on the way in. Nothing in logs, including the Application event log.

EDIT 2:

```plaintext
Since scheduled backups failed reliably, I tried one manually with breakpoint at StartScope.
	
Looking further got stack below, and it's about to throw new ArgumentNullException("entry");

>	Duplicati.Library.Logging.dll!Duplicati.Library.Logging.FunctionLogDestination.FunctionLogDestination(System.Action<Duplicati.Library.Logging.LogEntry> entry) (IL≈0x0016, Native=0x00007FFED807D280+0x83)
 	Duplicati.Library.Logging.dll!Duplicati.Library.Logging.Log.StartScope(System.Action<Duplicati.Library.Logging.LogEntry> log, System.Func<Duplicati.Library.Logging.LogEntry, bool> filter) (IL≈0x0000, Native=0x00007FFED807D160+0x4C)
 	Duplicati.Library.RestAPI.dll!Duplicati.Server.Runner.Run(Duplicati.Server.Runner.IRunnerData data, bool fromQueue) (IL≈0x016D, Native=0x00007FFED81398C0+0x78D)
 	Duplicati.Server.Implementation.dll!Duplicati.Server.Program.<>c.<SetWorkerThread>b__62_0(Duplicati.Server.Runner.IRunnerData x) (IL=epilog, Native=0x00007FFE66506300+0x21)
 	Duplicati.Library.Utility.dll!Duplicati.Library.Utility.WorkerThread<Duplicati.Server.Runner.IRunnerData>.Runner() (IL≈0x0191, Native=0x00007FFE664F24D0+0x503)
 	System.Private.CoreLib.dll!System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext executionContext, System.Threading.ContextCallback callback, object state) (IL≈0x0040, Native=0x00007FFEC1246420+0x7D)
 	[Native to Managed Transition]

```

---

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [January 10, 2025, 4:59pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/18 "2025-01-10T16:59:33Z")

</div>

> [@ts678](#):
>
> It turned out I didn’t have to do anything, as my scheduled backups on Jan 5 and 6 failed too:

I managed to reproduce this by accident today. It seems to happen when two threads are setting up scopes. In this case, there can be cases where the log-scopes are not correctly following their parent scopes. When it is time to shut down, there is a single log statement (the “CompletedOperation” message) that is logged after the inner log scope is disposed.

For most cases this works fine, but there is something weird happening with multi-threaded scope usage that I have not been able to figure out.

I have added an issue with details of what I managed to figure out:

> <https://github.com/duplicati/duplicati/issues/5864>
>
> With the log scopes in Duplicati, the idea is to use the call context, to avoid …cluttering the code with references to the current log.
> This works with \`AsyncLocal\` keeping track of the current scope.
> 
> When a new scope is created, it will reference the parent:
> \`\`\`
> Current = RootScope
> 
> CreateScope():
> Scope = new Scope()
> Scope.Parent = Current
> Current = Scope
> 
> CloseScope():
> Current = Current.Parent
> \`\`\`
> 
> In normal cases this will create a chain:
> \`\`\`
> Root -\> Scope1 -\> Scope2 -\> Scope3
> \`\`\`
> 
> Disposing the scope, jumps "up" one scope.
> 
> But for multithreading, it is a bit different:
> \`\`\`
> Root -\> Scope1 -\> Scope2 -\> Scope3
> -\> Scope4 -\> Scope5
> \`\`\`
> 
> What seems to happen is that code such as this:
> \`\`\`
> using (CreateScope()) // Scope1
> {
> Log("1");
> using (CreateScope()) // Scope2
> {
> DoWorkAndLog();
> }
> Log("2");
> }
> \`\`\`
> 
> Here the log used for logging "1" and "2" should be Scope1, but for some reason, the closing of Scope2 fails in multi-threaded calls (at least that is how I can force it). Because of this, the statement \`Log("2");\` is done on the disposed \`Scope2\` which fails.

And a somewhat useable PR that fixes it, but probably still has an underlying issue.

> <https://github.com/duplicati/duplicati/pull/5863>
>
> This simplifies the logging by only keeping the object instance, not the key-dic…tionary that was needed in .NET4.
> 
> It also allows writing logs directly to the desired scope.
> 
> There appears to be some quirk with the logging and call context, when invoked by multiple threads in the same area.
> 
> This commit fixes it, but most likely just masks the underlying issue.

---

<div class="post-metadata">

**Author:** ![ts678](https://forum.duplicati.com/letter_avatar_proxy/v4/letter/t/8491ac/32.png) [@ts678](https://forum.duplicati.com/u/ts678)\
**Post date:** [January 10, 2025, 5:14pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/19 "2025-01-10T17:14:48Z")

</div>

> [@kenkendk](#):
>
> When it is time to shut down

Does that explain the sticky error I have, where backups fail repeatedly?  
Mine’s still in StartScope in the debugger, but I might let it loose, for test.

---

<div class="post-metadata">

**Author:** ![kenkendk](https://forum.duplicati.com/user_avatar/forum.duplicati.com/kenkendk/32/5305_2.png) [@kenkendk](https://forum.duplicati.com/u/kenkendk)\
**Post date:** [January 10, 2025, 5:32pm UTC](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804/20 "2025-01-10T17:32:18Z")

</div>

> [@ts678](#):
>
> Does that explain the sticky error I have, where backups fail repeatedly?  
> Mine’s still in StartScope in the debugger, but I might let it loose, for test.

Not sure. The code has been there for at least 6 years, so no idea why it is suddenly causing trouble.

[Next page](https://forum.duplicati.com/t/release-2-1-0-104-canary-2024-12-31/19804.md?page=2)
