Backblaze B2: local tmp files fills up entire disk / ramdrive with 2.0.3.6

I have some issues with duplicati and large backup sets. It just fills up my disk / tmp drive.

Some infos about the config:

  • I have /tmp on my local disk. (20GB free)
  • Memory is 4 GB
  • 4 virtual KVM CPUs
  • Running on latest antergos / arch with XFCE
  • Duplicati - 2.0.3.6_canary_2018-04-23
  • Volume Size: 500 MB(not GB!)
  • asynchronous-upload-limit: 6 (as global option, not overriden in backup job)
  • Backupset is 1600 files using 26GB (this is the smaller -> the larger sets include 50k+ files with 800+GB)

Here is how my /tmp folder looks like after an hour of backup.

-rw-r--r-- 1 duplicati duplicati 462448133  7. Mai 14:28 /tmp/dup-b078c5e1-4765-4d6e-abad-b885b46d6210
-rw-r--r-- 1 duplicati duplicati    177119  7. Mai 14:28 /tmp/dup-ea5053bc-24c7-44ac-a490-1e7cb5cc881b
-rw-r--r-- 1 duplicati duplicati 503890789  7. Mai 14:28 /tmp/dup-213407ad-8454-4b83-a541-397a28a7dfbd
-rw-r--r-- 1 duplicati duplicati    289556  7. Mai 14:26 /tmp/dup-a0e4ba2a-8e5d-44dc-b3f3-a6db15f3e11e
-rw-r--r-- 1 duplicati duplicati 524191359  7. Mai 14:19 /tmp/dup-19cf7909-572f-4d08-98f9-f7b93be672ad
-rw-r--r-- 1 duplicati duplicati 524190834  7. Mai 14:19 /tmp/dup-0bb80f43-4d6f-48da-ae3a-2e0ee38e23a8
-rw-r--r-- 1 duplicati duplicati    346625  7. Mai 14:19 /tmp/dup-1db6cec0-7ab3-4134-9a63-5c257374ee14
-rw-r--r-- 1 duplicati duplicati    356518  7. Mai 14:13 /tmp/dup-2f6eda88-813a-4995-9bf5-ddef6c0428c8
-rw-r--r-- 1 duplicati duplicati 524267036  7. Mai 14:06 /tmp/dup-063a95cf-caee-45bc-832c-db60b8a87755
-rw-r--r-- 1 duplicati duplicati 524189381  7. Mai 14:06 /tmp/dup-25b4ce31-2e5c-488b-b2b4-12101d6a99ef
-rw-r--r-- 1 duplicati duplicati    337489  7. Mai 14:05 /tmp/dup-a718dc63-019d-47fa-8a8b-a650e0011acc
-rw-r--r-- 1 duplicati duplicati    347815  7. Mai 14:00 /tmp/dup-7361b3cb-52fe-4fd4-b2ae-0bfd4e95f282
-rw-r--r-- 1 duplicati duplicati    318347  7. Mai 13:54 /tmp/dup-d16e9cf5-2adc-4d7d-8151-87886ea13dcc
-rw-r--r-- 1 duplicati duplicati 524200040  7. Mai 13:49 /tmp/dup-1dcadf4b-e3cf-4c1d-a9b8-55defe892d2d
-rw-r--r-- 1 duplicati duplicati    361906  7. Mai 13:49 /tmp/dup-fc3c5571-a519-4863-8145-20637dc600db
-rw-r--r-- 1 duplicati duplicati 524190159  7. Mai 13:44 /tmp/dup-eabd74de-efe5-4556-9134-cff2d28a4e50
-rw-r--r-- 1 duplicati duplicati 524267334  7. Mai 13:43 /tmp/dup-6a2e4fdb-d5aa-4c72-b63e-8db5187a330f
-rw-r--r-- 1 duplicati duplicati 524216692  7. Mai 13:43 /tmp/dup-dbed4df6-182d-4349-a68e-aba19c1fc4f5
-rw-r--r-- 1 duplicati duplicati    396478  7. Mai 13:43 /tmp/dup-bdf9d8ac-fa56-4460-8f32-6d623a6f69cf
-rw-r--r-- 1 duplicati duplicati    337448  7. Mai 13:39 /tmp/dup-7ebe3064-288e-4c08-9a09-6aed0b1ef562
-rw-r--r-- 1 duplicati duplicati 524278083  7. Mai 13:34 /tmp/dup-865cb8a2-5550-45e7-be93-beb82212c9cf
-rw-r--r-- 1 duplicati duplicati 524207884  7. Mai 13:34 /tmp/dup-674d8e54-02eb-4789-9a75-9b83b61e4229
-rw-r--r-- 1 duplicati duplicati    189621  7. Mai 13:33 /tmp/dup-08e36bc6-b324-4808-822e-13d102d41697
-rw-r--r-- 1 duplicati duplicati       156  7. Mai 13:31 /tmp/dup-78db3772-29ae-4d28-a908-e1b46f09de89

To me it looks, like the files do not get cleaned as I would expect maximum 6 probably 8 files. My firewall also shows me that the breaks between two file uploads are quite big. As I see enough files ready here, I would expec a more continous upload load.

I do not see any errors or warnings in the logs.

Any hints or inputs to this?

Update 1:
It still fills up the disk. Currently over 14 dup-files with the volumesize of 500MB

Update 2:
After separating temp and upload ready directory -> They are scheduled for upload and the uploader is unable to catch up. The funny part is that it has a 1GBit Upstream to satisfy. There have to be some limitations I do not see. Between one file and the next it takes up to 10 minutes (looking at my WAN Port Statistics). If an Upload happens it goes up to 100MBit.

Update 3:
Downgraded to 2.0.3.5 and now it looks like it works again. Upload has no gaps and is quite consistent at 100MBit. Disk usage dropped to 1.2 GB. And there are no files left in the temp folder.

I think there is an issue in the new codebase of 2.0.3.6.

Thanks for the great work on Duplicati!

Greets Philipp

1 Like

@kenkendk could there be a problem with the compressor threads overwriting each other’s “asynchronous-upload count” variable in some cases?

Yes - 2.0.3.6 was a pretty big rewrite and there is already 1 known performance hit that’s being addressed.

Of course there could certainly be more than one so thanks for sharing your temp folder experience!

In response to @Pectojin’s suggestion that there might be an issue with each thread possibly getting it’s own set of parameters, were you using any of the new threading parameters added to 2.0.3.6?

  • --concurrency-block-hashers (default 2)
  • --concurrency-compressors (default 2)
  • --concurrency-max-threads (default 0, aka dynamic based on hardware)

You are welcome. I hope my information point to the right direction to locate the issues :slight_smile:

I just used the default values and did not cconfigure anything by myself.

There is no time this week, but next week I should be able to upgrade again and reduce the threads to 1 of each type. So this would confirm or eliminate the theory of a concurrency issue.

Keep up the great work!

Great! I’m looking forward to your test results! :slight_smile:

I ran into similar issues when using 2.0.3.6, except I was backing up over 1TB of into and the Os drive is only 40GB, with 15Gb free so it filled it up, which caused Duplicati to fail to continue doing backups, but after rolling back to 2.0.3.5 and clearing out the old temp files and unneeded/bloated database files, it cleared up and has been running since.

2 Likes

That should not happen. The new code has a single upload process that keeps track of pending uploads. However, it will create a temporary file inside each of the --concurrency-compressors, and then the --asynchronous-upload-count is only applied to the “finished” volumes, so default could create quite some files, but 14 files sounds like something else is happening as well.

This happens because Duplicati generates the dindex files from the database, which is much slower for some users. I am working on a fix for this, which generates the dindex files “on-the-fly” so they are ready for upload immediately after the dblock has uploaded.

Sorry for the delay but it was not possible to do the testing earlier.

Here is a short update:

  • Upgraded my system again
  • set concurrency-compressors=1
  • set concurrency-block-hashers=1
  • left max threads to default → I guess 8 base on i7-2700k → 4 cores + HT

Then I used a successful backup and included another folder to get a bigger set.
I left it running for some hours and checking now I see the tmp folder still grows and I see the same behaviour.

So my conclusion is that the hashers and compressors should not be the reason of this issue.

I can also see in the live verbose log that there are huge breaks (around 20 minutes from checking for changes to the next statement)

May 31, 2018 9:30 PM: Backend event: Put - Started: duplicati-ie9b…f01be.dindex.zip.aes (34.59 KB)
May 31, 2018 9:09 PM: Checking file for changes /media/na…

I’ll downgrade my machine again.

Are there any specific tests I could do to get you more information?

Thanks for the testing - and confirming that going back to 2.0.3.5 “fixes” the problem.

I hope you don’t mind but I went ahead and updated the topic title to better reflect that your issue seems to be specific to 2.0.3.6. :slight_smile: