Backups fail, Cannot figure out why I always get PathTooLongException - FIXED

Jeremy · January 19, 2019, 2:40am

2.0.4.5_beta_2018-11-28
Every time I run a backup now, it fails with this Exception. I’ve scanned my whole hard drive to find any files or paths that are too long, and I fixed a few and cannot find any more. But I still get this error during every backup. I wonder if Duplicati’s database is remembering a long file path that I’ve already fixed, but how can I fix Duplicati so it will run backups again without error?

Here’s a snippet from the Live Profiling Log:

Jan 18, 2019 9:24 PM: Fatal error
{"ClassName":"System.IO.PathTooLongException","Message":"The specified path, file name, or both are too long. The fully qualified file name must be less than 260 characters, and the directory name must be less than 248 characters.","Data":null,"InnerException":null,"HelpURL":null,"StackTraceString":"   at System.IO.Path.LegacyNormalizePath(String path, Boolean fullCheck, Int32 maxPathLength, Boolean expandShortPaths)\r\n   at System.IO.Path.GetPathRoot(String path)\r\n   at Duplicati.Library.Snapshots.UsnJournalService.IsPathEnumerated(String path)\r\n   at Duplicati.Library.Main.Operation.BackupHandler.<>c__DisplayClass12_0.<RunMainOperation>b__2(String path, Int64 fileSize)\r\n   at Duplicati.Library.Main.Database.LocalBackupDatabase.AppendFilesFromPreviousSetWithPredicate(IDbTransaction transaction, Func`3 exclusionPredicate, Int64 fileSetId, Int64 prevFileSetId, DateTime timestamp)\r\n   at Duplicati.Library.Main.Database.LocalBackupDatabase.AppendFilesFromPreviousSetWithPredicate(IDbTransaction transaction, Func`3 exclusionPredicate)\r\n   at Duplicati.Library.Main.Operation.Common.SingleRunner.<>c__DisplayClass3_0.<RunOnMain>b__0()\r\n   at Duplicati.Library.Main.Operation.Common.SingleRunner.<DoRunOnMain>d__2`1.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.Main.Operation.BackupHandler.<RunMainOperation>d__12.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.Main.Operation.BackupHandler.<RunAsync>d__19.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 CoCoL.ChannelExtensions.WaitForTaskOrThrow(Task task)\r\n   at Duplicati.Library.Main.Controller.<>c__DisplayClass13_0.<Backup>b__0(BackupResults result)\r\n   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)\r\n   at Duplicati.Library.Main.Controller.Backup(String[] inputsources, IFilter filter)\r\n   at Duplicati.Server.Runner.Run(IRunnerData data, Boolean fromQueue)","RemoteStackTraceString":null,"RemoteStackIndex":0,"ExceptionMethod":"8\nLegacyNormalizePath\nmscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089\nSystem.IO.Path\nSystem.String LegacyNormalizePath(System.String, Boolean, Int32, Boolean)","HResult":-2147024690,"Source":"mscorlib","WatsonBuckets":null}

Jan 18, 2019 9:24 PM: ExecuteScalarInt64: SELECT "ID" FROM "Remotevolume" WHERE "Name" = "duplicati-bca869d1e377546a681d2959273c12e16.dblock.zip.aes" took 0:00:00:00.000
Jan 18, 2019 9:24 PM: Starting - ExecuteScalarInt64: SELECT "ID" FROM "Remotevolume" WHERE "Name" = "duplicati-bca869d1e377546a681d2959273c12e16.dblock.zip.aes"
Jan 18, 2019 9:24 PM: CommitAfterUpload took 0:00:00:00.015
Jan 18, 2019 9:24 PM: Starting - CommitAfterUpload
Jan 18, 2019 9:24 PM: Backend event: Put - Completed: duplicati-ieac03165118b4aa9874f699e21fc1c15.dindex.zip.aes (47.97 KB)
Jan 18, 2019 9:24 PM: Uploaded 47.97 KB in 00:00:00, -8,388,608.00 TB/s
Jan 18, 2019 9:24 PM: Backend event: Put - Started: duplicati-ieac03165118b4aa9874f699e21fc1c15.dindex.zip.aes (47.97 KB)
Jan 18, 2019 9:24 PM: ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (468, "duplicati-ieac03165118b4aa9874f699e21fc1c15.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid(); took 0:00:00:00.330
Jan 18, 2019 9:24 PM: Starting - ExecuteScalarInt64: INSERT INTO "Remotevolume" ("OperationID", "Name", "Type", "State", "Size", "VerificationCount", "DeleteGraceTime") VALUES (468, "duplicati-ieac03165118b4aa9874f699e21fc1c15.dindex.zip.aes", "Index", "Temporary", -1, 0, 0); SELECT last_insert_rowid();
Jan 18, 2019 9:24 PM: CommitAfterUpload took 0:00:00:00.443
Jan 18, 2019 9:24 PM: Starting - CommitAfterUpload
Jan 18, 2019 9:24 PM: Backend event: Put - Completed: duplicati-bca869d1e377546a681d2959273c12e16.dblock.zip.aes (36.49 MB)
Jan 18, 2019 9:24 PM: Uploaded 36.49 MB in 00:00:00.9061543, 40.27 MB/s
Jan 18, 2019 9:24 PM: Backend event: Put - Started: duplicati-bca869d1e377546a681d2959273c12e16.dblock.zip.aes (36.49 MB)
Jan 18, 2019 9:24 PM: BackupMainOperation took 0:00:42:28.849
Jan 18, 2019 9:21 PM: ExecuteReader: SELECT
 f."Path", fs."FileID", fs."Lastmodified", COALESCE(bs."Length", -1)
 FROM ( SELECT DISTINCT "FileID", "Lastmodified"
 FROM "FilesetEntry"
 WHERE "FilesetID" = 300
 AND "FileID" NOT IN (
 SELECT "FileID"
 FROM "FilesetEntry"
 WHERE "FilesetID" = 301
 )) AS fs
 LEFT JOIN "File" AS f ON fs."FileID" = f."ID"
 LEFT JOIN "Blockset" AS bs ON f."BlocksetID" = bs."ID"; took 0:00:00:01.140

And here is the email I receive when the error happens:

Failed: The specified path, file name, or both are too long. The fully qualified file name must be less than 260 characters, and the directory name must be less than 248 characters.
Details: System.IO.PathTooLongException: The specified path, file name, or both are too long. The fully qualified file name must be less than 260 characters, and the directory name must be less than 248 characters.
   at System.IO.Path.LegacyNormalizePath(String path, Boolean fullCheck, Int32 maxPathLength, Boolean expandShortPaths)
   at System.IO.Path.GetPathRoot(String path)
   at Duplicati.Library.Snapshots.UsnJournalService.IsPathEnumerated(String path)
   at Duplicati.Library.Main.Operation.BackupHandler.<>c__DisplayClass12_0.<RunMainOperation>b__2(String path, Int64 fileSize)
   at Duplicati.Library.Main.Database.LocalBackupDatabase.AppendFilesFromPreviousSetWithPredicate(IDbTransaction transaction, Func`3 exclusionPredicate, Int64 fileSetId, Int64 prevFileSetId, DateTime timestamp)
   at Duplicati.Library.Main.Database.LocalBackupDatabase.AppendFilesFromPreviousSetWithPredicate(IDbTransaction transaction, Func`3 exclusionPredicate)
   at Duplicati.Library.Main.Operation.Common.SingleRunner.<>c__DisplayClass3_0.<RunOnMain>b__0()
   at Duplicati.Library.Main.Operation.Common.SingleRunner.<DoRunOnMain>d__2`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Main.Operation.BackupHandler.<RunMainOperation>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__19.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__DisplayClass13_0.<Backup>b__0(BackupResults result)
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)

Log data:
2019-01-18 20:41:10 -05 - [Warning-Duplicati.Library.Main.Operation.Backup.UploadSyntheticFilelist-MissingTemporaryFilelist]: Expected there to be a temporary fileset for synthetic filelist (301, duplicati-i746131144acb44d8af770db1568446f0.dindex.zip.aes), but none was found?
2019-01-18 21:24:29 -05 - [Error-Duplicati.Library.Main.Operation.BackupHandler-FatalError]: Fatal error
System.IO.PathTooLongException: The specified path, file name, or both are too long. The fully qualified file name must be less than 260 characters, and the directory name must be less than 248 characters.
   at System.IO.Path.LegacyNormalizePath(String path, Boolean fullCheck, Int32 maxPathLength, Boolean expandShortPaths)
   at System.IO.Path.GetPathRoot(String path)
   at Duplicati.Library.Snapshots.UsnJournalService.IsPathEnumerated(String path)
   at Duplicati.Library.Main.Operation.BackupHandler.<>c__DisplayClass12_0.<RunMainOperation>b__2(String path, Int64 fileSize)
   at Duplicati.Library.Main.Database.LocalBackupDatabase.AppendFilesFromPreviousSetWithPredicate(IDbTransaction transaction, Func`3 exclusionPredicate, Int64 fileSetId, Int64 prevFileSetId, DateTime timestamp)
   at Duplicati.Library.Main.Database.LocalBackupDatabase.AppendFilesFromPreviousSetWithPredicate(IDbTransaction transaction, Func`3 exclusionPredicate)
   at Duplicati.Library.Main.Operation.Common.SingleRunner.<>c__DisplayClass3_0.<RunOnMain>b__0()
   at Duplicati.Library.Main.Operation.Common.SingleRunner.<DoRunOnMain>d__2`1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Main.Operation.BackupHandler.<RunMainOperation>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Duplicati.Library.Main.Operation.BackupHandler.<RunAsync>d__19.MoveNext()

ts678 · January 19, 2019, 4:17pm

I see Duplicati.Library.Snapshots.UsnJournalService and wonder if that might mean you’re using –usn-policy or –snapshot-policy or both. I’m not expert in this, but I think snapshots need paths longer than would be normally seen because they get some extra components before the normally visible ones appear. Example that adds something like \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy12617 in front.

Regarding USN, there’s this fix that did not make it into 2.0.4.5 beta (which has its roots in 2.0.3.14 canary):

Issue 3311 PathTooLongException when using USNJournal #3456 (issue)
Issue 3311 PathTooLongException when using USNJournal #3456 (pull request)
Release: 2.0.4.3 (canary) 2018-11-13

Rewrote path handling across the project to better support long paths, thanks @verhoek

Maybe more aggressive trimming to allow room for snapshot extras, or turn snapshots off, or turn USN off?
Running canary might help, but it’s less predictable. It adds known fixes (e.g. to paths) and unknown bugs.

Jeremy · January 19, 2019, 4:33pm

Yes, usn-policy and snapshot-policy are both “on”, and vss-exclude-writers is “{e8132975-6f93-4464-a53e-1050253ae220}”. Thanks for the direction; I’ll read about those. I have gotten our longest paths down to 242 characters now, but interestingly, this PathTooLong problem didn’t start happening until I updated Duplicati a few days ago.

FYI, I also created a Github ticket requesting that all PathTooLong exceptions in the logs should specify the path that caused the problem: PathTooLongException - Log should specify which file caused the error · Issue #3613 · duplicati/duplicati · GitHub

Jeremy · January 19, 2019, 9:52pm

I updated to 2.0.4.12_canary_2019-01-16, and now it all works well. I ran two backups in a row to make sure the errors were gone. Updating fixed the error about PathTooLong, an error about a shadow copy already being in progress, and a warning about MissingTemporaryFilelist. Plus, the new web GUI log viewer is much improved!

Thanks for your help, ts678. And congrats, Duplicati, for adding some great polish to the log viewer.