Duplicati skipping lots of files/folders

Support
1

One of my customer’s computers got a rootkit infection last week. Rather than reinstalling windows, I replaced the entire computer. I decided to put duplicati to the test and restore the user’s data from duplicati instead of copying their data from the infected computer. The restore completed without errors or warnings. A few days later, the user pointed out some missing folders, so I plugged their infected computer in (without network) and confirmed that there are a some files/folders on it that duplicati isn’t showing in the restore tree. I can confirm via “shadow copy / restore previous versions” that the folders in question had been there for at least a week, and they aren’t flagged system or hidden, and duplicati backs up daily, and the folders were in the DOCUMENTS folder, which duplicati was supposed to be backing up, and the ntfs permissions allow SYSTEM to read/write them. I see some warnings in the backup report about SOME of the files/folders in question, but nowhere close to all of them. I don’t understand why duplicati was skipping these files/folders, but I’d REALLY like to get to the bottom of it because now I’m concerned about my other customer computers.

The customer’s new computer is now backing up the same files/folders successfully.

I haven’t touched the backblaze folder since I replaced the infected computer, nor have I modified anything on the infected computer, so we should be able to reproduce this problem and get to the bottom of it. This customer’s data contains sensitive payroll information so I can’t share the backblaze data directly with anybody but i’d be happy to gather any additional non-sensitive info needed.

Infected computer was:
Windows 7 pro 32bit
Duplicati 2.0.4.5_beta_2018-11-28
Running as service (user=local system account)
source 8.55GB
backup 14.91GB / 114 Versions
The customer has an extremely reliable 500mb/s symmetrical fiber internet connection.

“C:\Program Files\Duplicati 2\Duplicati.CommandLine.exe” backup “b2://…/Kim?auth-username=…&auth-password=…” “C:\EACH\” “C:\Users\” “C:\Transfer\” --snapshot-policy=Auto --send-http-url=http://… --send-http-any-operation=true --send-http-message-parameter-name=message --send-http-level=all --send-http-message=“Duplicati %OPERATIONNAME% report for %backup-name% %PARSEDRESULT% %RESULT%” --backup-name=“Kim to Backblaze” --dbpath=“C:\Program Files\Duplicati 2\data\YZJGXCNJEE.sqlite” --encryption-module=aes --compression-module=zip --dblock-size=50mb --passphrase="…" --retention-policy=“2Y:1W,3M:1D” --exclude-files-attributes=“temporary,system,hidden” --disable-module=console-password-input

Here’s screenshots comparing c:\users\kim\documents\kim\ to dulicati’s restore tree:
https://f000.backblazeb2.com/file/dZB9B7/kim1.PNG
https://f000.backblazeb2.com/file/dZB9B7/kim2.PNG
(Duplicati skipped 15 of the 35 files)

Some other files/folders that duplicati was ignoring are:

c:\users\kim\documents\backup folder
which has a single folder, “kim”, which has 12 XLS files, and 14 folders that have a total of 1,934 files and 167 folders.

c:\users\kim\documents\audit
which has a single XLS file.

The last backup report in duplicati:
Rather than clutter this post, i’m going to make it available to download from:
https://f000.backblazeb2.com/file/dZB9B7/kim.txt

(my next post might be why my http reporting server didn’t get the warnings/errors that the local report shows)

2

First thing to try might be to backup with a –log-file to (hopefully) see the whole warning list, with details on what the issue was. The summary lines are line-limited and are superficial in terms of the level of detail… Possibly –log-file-log-filter=Verbose would be worth the extra output, to see it walk (or not) through all files. Starting at the default of Warning could be tried first if you prefer. It should at least give some more details.

If you’re able to obtain the database from the computer then look at that yourself (I can give guidance), the File table would say whether the files had ever been backed up. You could also survey inside old dlist files, or (easier) survey in old restores, or even run a find in Commandline to check history of some missing file.

Any backup after the infection set in could conceivably have been affected by that, or by antivirus behavior. Rock-solid reliable persistent failures would be the easiest to examine, but developer help may be needed.

3

I doubt this is related but your retention policy jumped out at me. It is not valid as defined here. The timeframes are supposed to be in increasing order, so you probably wanted “3M:1D,2Y:1W”.

4

That might just be an input style convention. I haven’t tested operations, but the code looks like its intention is to set order the way it needs it (which is just as you said) regardless of the order from the input specification.

Thanks for your interest in this situation though. Feel free to hang around. I’m not sure how tough this will get.

5

Ok, I created a new job in duplicati that sends data to the C drive, so I wouldn’t have to plug this computer into the internet, since it is still infected.

Here’s the new job:
“C:\Program Files\Duplicati 2\Duplicati.CommandLine.exe” backup “file://c:\duplicati” “C:\Users\kim\Documents\” --snapshot-policy=Auto --backup-name=Kim --dbpath=“C:\Program Files\Duplicati 2\data\90897182698588678783.sqlite” --encryption-module= --compression-module=zip --dblock-size=50mb --retention-policy=“2Y:1W,3M:1D” --no-encryption=true --log-file=“c:\duplicati.txt” --log-file-log-filter=true --log-file-log-level=Verbose --exclude-files-attributes=“hidden,system,temporary” --disable-module=console-password-input

I confirmed it has the same issue of not backing up a lot of the files.

Here’s the log file with log-file-log-level=Warning
https://f000.backblazeb2.com/file/dZB9B7/kim-warning.txt

log-file-log-level=Verbose
https://f000.backblazeb2.com/file/dZB9B7/kim-verbose.txt

6

I ran
chkdsk c: /r
on this infected SSD, and it found hundreds of bad sectors, and now windows won’t even boot on it. It was a samsung MLC drive - i’m surprised it failed.

SO, i’m assuming this is why duplicati was failing.

Now I just need to figure out why I wasn’t seeing the errors in my reporting server. I will be creating a new thread soon for that.

7

Ah, makes sense that a hardware issue is causing the problem.
Might try the Samsung Magician software to see what it thinks about that SSD.

8

For a quick look at S.M.A.R.T. values you could try smartctl from smartmontools on SystemRescueCD.

On the reporting server issue, please report any prior successful reports and how long they were. This current issue looks from the end of both of your logs like it hit a length issue, e.g. Duplicati hit this issue.

System.UriFormatException: Invalid URI: The Uri string is too long.
   at System.UriHelper.EscapeString(String input, Int32 start, Int32 end, Char[] dest, Int32& destPos, Boolean isUriString, Char force1, Char force2, Char rsvd)
   at System.Uri.EscapeDataString(String stringToEscape)
   at Duplicati.Library.Modules.Builtin.SendHttpMessage.SendMessage(String subject, String body)
   at Duplicati.Library.Modules.Builtin.ReportHelper.OnFinish(Object result)
9

It’s an oem drive, not retail, so samsung magician doesn’t fully support it.

I’m a huge fan of SmartmonTools. I actually wrote a program that runs smartmon reports daily and emails me if it finds bad sectors creeping up. I’m running it on hundreds of computers. The SSD in question has 0 CurrentPendingSectors, which is the first time i’ve ever seen chkdsk mark bad clusters when s.m.a.r.t. stats shows no CurrentPendingSectors. I’ll be looking into this more if I get time.

As for the duplicati report length limit… I have about 325 computers reporting to my duplicati reporting server. I just opened the last 15 reports and noticed most of them are cut off after the DURATION line, and are missing the MESSAGES section. I’m going to try to recover the duplicati log from the crashed SSD so i can do more comparing with the data in my reporting server because my reporting server doesn’t show any records for that user matching the log I posted in the original post, and i’m not sure why.

10

Ok, I recovered the duplicati logs from the bad SSD and verified that those reports and the http reports both say “ParsedResult: Success” up until 2 days before I unplugged the SSD due to the virus. The last 2 reports show “ParsedResult: Warning”, and didn’t transmit to my http server, but that’s not the end of the world for me because my reporting server tells me if reports are missing for over 3 days, and I would have been checking it out.

The only thing that still concerns me is when I click restore, and select restore from april 1st, (way before duplicati started reporting warnings), the missing files are still missing from that, but that’s with the database from the bad ssd, so i’m about to setup up a fresh duplicati job and rebuild the database from the backblaze destination, and i’ll let ya’ll know if the missing files are actually there.

11

The files were there, and I was able to restore them! Now I can sleep at night! Thanks for the help everybody!

1 Like
12

I’m not sure of it all but

The final reason would seem to be in the SendHttpMessage failure posted earlier, and in both of your logs. What takes some guesses is why that happened, and my guess (confessing I’m not familiar with how the reports are built, including what lines go into for “Log data:” if it’s present), the kim-warning.txt was 82,142 bytes (cut-and-pasted) and I think .NET has a length limit of 0xFFF0, or 65,520. Some reports claim less.

Duplicati code I linked to earlier runs EscapeDataString, and here’s how it looks in MS Reference Source:

System.Uri.EscapeDataString calls
System.UriHelper.EscapeString compares length to
System.Uri.c_MaxUriBufferSize 0xFFF0

System.System.Net.Http.FormUrlEncodedContent(…) can’t handle very long parameters/values #1936 talks about this known (at least to the .NET developers) limitation, and how one might code a workaround.

In order to know that this is actually what happened, you could create a test case that sends a long report into your reporting server (for example a per-file warning), and search (maybe binary search) for fail point. That can then become a Duplicati Issue to await its turn. Could take awhile. Your checking on non-reports would be wanted anyway, and might suffice if a flood of warnings manages to break the report of the flood.

New log system with filters was a report of the same exception, so I might point back at the theory here…

Whether or not you feel like an extra chase, I’m glad the rest turned out well, including chasing loose ends.

13

SELECT top 10
Len(report)
FROM Reports
order by len(report) desc

65031
64062
63682
63459
62932
62676
62360
62350
60955
60827

I think it’s safe to say you are right about the limit. I’m going to create a html form that will transmit a 100KB report to my server and we’ll see if my server handles it.