No token to close. path ”

jpschewe · April 28, 2020, 3:31pm

This is similar to No token to close. path '', however I have been running successful backups for some time.
I’m backing up to a local disk and it’s been backing up fine for 3 months. This past week I started getting this error message on the backups.

Newtonsoft.Json.JsonWriterException: No token to close. Path ''.
  at Newtonsoft.Json.JsonWriter.CalculateLevelsToComplete (Newtonsoft.Json.JsonContainerType type) [0x00056] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Newtonsoft.Json.JsonWriter.AutoCompleteClose (Newtonsoft.Json.JsonContainerType type) [0x00000] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Newtonsoft.Json.JsonWriter.InternalWriteEnd (Newtonsoft.Json.JsonContainerType container) [0x00000] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Newtonsoft.Json.JsonWriter.WriteEndArray () [0x00000] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Duplicati.Library.Main.Volumes.FilesetVolumeWriter.AddFilelistFile () [0x00000] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Volumes.FilesetVolumeWriter.Close () [0x00008] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Volumes.FilesetVolumeWriter.Dispose () [0x00000] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Operation.BackupHandler+<RunAsync>d__20.MoveNext () [0x00fbb] in <8f1de655bd1240739a78684d845cecc8>:0 
--- End of stack trace from previous location where exception was thrown ---
  at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw () [0x0000c] in <8f2c484307284b51944a1a13a14c0266>:0 
  at CoCoL.ChannelExtensions.WaitForTaskOrThrow (System.Threading.Tasks.Task task) [0x00050] in <9a758ff4db6c48d6b3d4d0e5c2adf6d1>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.Run (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00009] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Controller+<>c__DisplayClass14_0.<Backup>b__0 (Duplicati.Library.Main.BackupResults result) [0x0004b] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Controller.RunAction[T] (T result, System.String[]& paths, Duplicati.Library.Utility.IFilter& filter, System.Action`1[T] method) [0x0011c] in <8f1de655bd1240739a78684d845cecc8>:0

drwtsn32 · May 1, 2020, 1:08am

Hello, can you provide some details:

Version of Duplicati
Operating system and version
If not Windows, what version of mono

Thanks

jpschewe · May 1, 2020, 11:44am

Duplicati: 2.0.5.1_beta_2020-01-18
OS: Ubuntu Linux 18.04.4, kernel 5.3.0-46-generic
mono: 4.6.2

jpschewe · May 1, 2020, 11:47am

The job last night completed, this is the first one in a week.

drwtsn32 · May 1, 2020, 12:23pm

Duplicati 2.0.5.x and newer require at least Mono 5.x - using older versions can cause strange, sometimes intermittent issues.

Stop the Duplicati service and then upgrade mono by following these instructions:

https://www.mono-project.com/download/stable/#download-lin-ubuntu

Then start the Duplicati service again.

jpschewe · May 1, 2020, 1:20pm

Upgrade complete. I’ll watch how it behaves going forward.
I find it interesting that the run last night succeeded when the others for the past week failed. The main difference that I can think of is that there was less data to backup because I removed about 100GB of files.

drwtsn32 · May 1, 2020, 1:32pm

Yeah it is puzzling when the problem is intermittent. Hopefully this will resolve your issue!

jpschewe · May 3, 2020, 11:14am

The mono upgrade did not fix the issue. A backup automatically ran a few hours after the upgrade and I got the token close error again.

drwtsn32 · May 3, 2020, 3:01pm

Ok, you did restart Duplicati after upgrading mono, correct? Otherwise it may still be using the old mono libraries loaded into memory.

You absolutely needed to upgrade in any case, but if you still have the issue after restarting Duplicati we will need to continue troubleshooting.

jpschewe · May 3, 2020, 3:39pm

Yes, I restarted the duplicati service.

drwtsn32 · May 3, 2020, 9:25pm

I wonder if it would help to collect more logging information. Try setting:

--log-file=C:\Temp\duplicati.log
--log-file-log-level=Verbose

Run your backup job, and then turn off these logging options. We might be able to glean some detail from these logs to help identify the root cause.

jpschewe · May 5, 2020, 11:19am

I have a 35GB log file. I looked at the end of the file and don’t see much to help. Here is what I have. I can go farther back in the file to look, or grep for specific items. I’ve turned off the extra logging for future jobs.

...
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.MetadataPreProcess.FileEntry-AddDirectory]: Adding directory /usr/local/sbin/
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: /usr/local/sbin/backupDuplicatiDatabases.sh
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FilePreFilterProcess.FileEntry-CheckFileForChanges]: Checking file for changes /usr/local/sbin/backupDuplicatiDatabases.sh, new: False, timestamp changed: True, size changed: False, metadatachanged: True, 9/17/2019 10:07:32 AM vs 9/17/2019 10:07:32 AM
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileEnumerationProcess-IncludingPath]: Including path as no filters matched: /usr/local/sbin/systemd-email
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FilePreFilterProcess.FileEntry-CheckFileForChanges]: Checking file for changes /usr/local/sbin/systemd-email, new: False, timestamp changed: True, size changed: False, metadatachanged: True, 9/17/2019 10:04:39 AM vs 9/17/2019 10:04:39 AM
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-FileMetadataChanged]: File has only metadata changes /usr/local/sbin/backupDuplicatiDatabases.sh
2020-05-05 03:19:30 -05 - [Verbose-Duplicati.Library.Main.Operation.Backup.FileBlockProcessor.FileEntry-FileMetadataChanged]: File has only metadata changes /usr/local/sbin/systemd-email
2020-05-05 03:21:17 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-bf9852d8eedb54ad1aac08175dfdf84e0.dblock.zip (49.91 MB)
2020-05-05 03:21:21 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bf9852d8eedb54ad1aac08175dfdf84e0.dblock.zip (49.91 MB)
2020-05-05 03:21:21 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-id3a359125b9345779761457195d5ab60.dindex.zip (1.97 MB)
2020-05-05 03:21:21 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-id3a359125b9345779761457195d5ab60.dindex.zip (1.97 MB)
2020-05-05 03:21:32 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-b7c574d233b674c56ab84501ae209f22f.dblock.zip (31.94 MB)
2020-05-05 03:24:14 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b7c574d233b674c56ab84501ae209f22f.dblock.zip (31.94 MB)
2020-05-05 03:53:16 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Started: duplicati-i401c874d946c41669b032c9d56a8f073.dindex.zip (1.11 MB)
2020-05-05 03:53:16 -05 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i401c874d946c41669b032c9d56a8f073.dindex.zip (1.11 MB)
2020-05-05 03:56:02 -05 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error
Newtonsoft.Json.JsonWriterException: No token to close. Path ''.
  at Newtonsoft.Json.JsonWriter.CalculateLevelsToComplete (Newtonsoft.Json.JsonContainerType type) [0x00056] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Newtonsoft.Json.JsonWriter.AutoCompleteClose (Newtonsoft.Json.JsonContainerType type) [0x00000] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Newtonsoft.Json.JsonWriter.InternalWriteEnd (Newtonsoft.Json.JsonContainerType container) [0x00000] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Newtonsoft.Json.JsonWriter.WriteEndArray () [0x00000] in <d47de75a7e3f422ca4ca64a654c80495>:0 
  at Duplicati.Library.Main.Volumes.FilesetVolumeWriter.AddFilelistFile () [0x00000] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Volumes.FilesetVolumeWriter.Close () [0x00008] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Volumes.FilesetVolumeWriter.Dispose () [0x00000] in <8f1de655bd1240739a78684d845cecc8>:0 
  at Duplicati.Library.Main.Operation.BackupHandler.RunAsync (System.String[] sources, Duplicati.Library.Utility.IFilter filter, System.Threading.CancellationToken token) [0x00fbb] in <8f1de655bd1240739a78684d845cecc8>:0

ts678 · May 6, 2020, 12:50am

As a long shot, have you checked to make sure you’re not out of /tmp (or wherever yours lives) space?
Ordinarily I’d expect such an issue to cause issues with big files like the dblocks, but there are enough configuration options that one could probably set them to different spots to get different things failing…

–asynchronous-upload-folder
–tempdir and description of how Linux might use TMPDIR environment variable to move SQLite usage.

jpschewe · May 6, 2020, 10:16am

No, there is plenty of space in /tmp. That’s where I wrote the 35GB log file and still had another 35GB available.

drwtsn32 · May 6, 2020, 3:13pm

Thanks for posting your log snippet. Not really any clues there. Hopefully a dev with more knowledge of the fileset volume writer can offer some ideas.

jpschewe · May 15, 2020, 12:05pm

I tried starting a new backup and got the same error. I’m wondering if it has something to do with the number of files or files changing during the backup.

drwtsn32 · May 15, 2020, 2:49pm

I wonder if you have a filename with a character causing issues for the Json writer.

Can you try removing items from your backup selection list to see if the problem eventually goes away? It may help identify a problem folder/file, if this is indeed the issue.

jpschewe · May 15, 2020, 5:04pm

Nothing that I’ve been adding or removing lately has any special characters in the filenames. Doing a guess and check for this could take years with the amount of data being backed up. If I had a list of characters that are known to be good or known to be bad, I could check all of the filenames.

jpschewe · May 21, 2020, 10:51am

Not hearing anything back here I have opened a bug at No token to close. path ” · Issue #4206 · duplicati/duplicati · GitHub

drwtsn32 · May 21, 2020, 7:18pm

Good idea, hopefully someone with more development experience in this portion of the code can offer insights!