Fixed:
It was the files prior to encryption that were not correctly removed.
Version 2.0.3.8 canary has been release which includes the fix mentioned above.
If you currently have this issue and are interested in testing, please update to 2.0.3.8 and let us know if it solves the problem. Thanks!
Note that I believe this fix will correctly clean up temp files moving forward, I donāt think it will clean up old onesā¦
Hello,
Because my system cannot use the precompiled assemblies, Iām using a self compiled version of Duplicati from vanillas 2.0.3.6 sources.
I had the same issue where the /tmp folder would get filled up, and so I applied that patch to my sources.
I can say that this fixes the issue nicely, the temp files are now cleared properly.
1 Like
Not fixed for me
Temp folder full of temp files and consuming large portion of that drive.
There should be some cleaning routing at end of job.
Running 2.0.3.10_canary_2018-08-30
For those affected, add after backup batch file with this content:
del %tmp%\dup-???-???-???-???-???
It cleans leftovers.
Not fixed for me on 2.0.3.11_canary_2018-09-05 on Windows 10, although possibly itās better now (canāt say).
Here, the leftovers from the daily backup (based on timestamp of leftover tmp files) have only appeared today which happens to be when Duplicati decided to compact. Maybe backup is fixed, but compact still has issues?
Job log has FilesUploaded: 7
Server log backend events:
2018-09-19 13:01:10 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bfbacccc9339e41b6b9cb2e7e5dea56a3.dblock.zip.aes (1.38 MB)
2018-09-19 13:01:11 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i898454fc9fbc4bb0b717416f841c44a8.dindex.zip.aes (3.45 KB)
2018-09-19 13:01:11 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-20180919T170000Z.dlist.zip.aes (31.65 KB)
2018-09-19 13:03:01 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-bae59c06d1c28406182de0ca9070a22ba.dblock.zip.aes (50.04 MB)
2018-09-19 13:03:02 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i0c586925541a4f4d804f8d74f1fd0083.dindex.zip.aes (51.28 KB)
2018-09-19 13:03:52 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-b429246f467134958a7d89ea2caafce11.dblock.zip.aes (14.92 MB)
2018-09-19 13:03:53 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Put - Completed: duplicati-i3e51ef5336d34671834d19ffe6be6e81.dindex.zip.aes (10.47 KB)
2018-09-19 13:03:18 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-bfbacccc9339e41b6b9cb2e7e5dea56a3.dblock.zip.aes (1.38 MB)
2018-09-19 13:03:57 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-i898454fc9fbc4bb0b717416f841c44a8.dindex.zip.aes (3.45 KB)
2018-09-19 13:03:57 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-bfbacccc9339e41b6b9cb2e7e5dea56a3.dblock.zip.aes (1.38 MB)
2018-09-19 13:04:01 -04 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20180919T170000Z.dlist.zip.aes (31.65 KB)
Bucket listing confirming:
duplicati-20180919T170000Z.dlist.zip.aes 32.4 KB 09/19/2018 13:01
duplicati-bae59c06d1c28406182de0ca9070a22ba.dblock.zip.aes 52.5 MB 09/19/2018 13:01
duplicati-i0c586925541a4f4d804f8d74f1fd0083.dindex.zip.aes 52.5 KB 09/19/2018 13:03
duplicati-b429246f467134958a7d89ea2caafce11.dblock.zip.aes 15.6 MB 09/19/2018 13:03
duplicati-i3e51ef5336d34671834d19ffe6be6e81.dindex.zip.aes 10.7 KB 09/19/2018 13:03
C:\Windows\Temp leftovers:
09/19/2018 01:01 PM 52,472,021 dup-3c7c2f2a-95fc-43de-b6db-8cb83f339b33
09/19/2018 01:01 PM 52,201 dup-70f899d8-79af-4221-b85c-6c722650436c
09/19/2018 01:03 PM 15,641,138 dup-95504a79-97be-49b7-a02a-4f1321ecdc3c
09/19/2018 01:03 PM 10,405 dup-5d004d59-a2ad-4b70-99f5-fb2eed477a8f
Selected time information:
2018-09-19 13:01:12 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 21 small volumes and the maximum is 20
2018-09-19 13:03:56 -04 - [Information-Duplicati.Library.Main.Operation.CompactHandler-CompactResults]: Downloaded 22 file(s) with a total size of 89.78 MB, deleted 44 file(s) with a total size of 89.91 MB, and compacted to 4 file(s) with a size of 65.00 MB, which reduced storage by 40 file(s) and 24.91 MB
2018-09-19 13:01:03 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-PreBackupVerify]: PreBackupVerify took 0:00:00:02.416
2018-09-19 13:01:05 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-BackupMainOperation]: BackupMainOperation took 0:00:00:01.081
2018-09-19 13:01:05 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-VerifyConsistency]: VerifyConsistency took 0:00:00:00.119
2018-09-19 13:01:05 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Backup.UploadRealFilelist-UpdateChangeStatistics]: UpdateChangeStatistics took 0:00:00:00.010
2018-09-19 13:01:07 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.Backup.UploadRealFilelist-UploadNewFileset]: Uploading a new fileset took 0:00:00:01.911
2018-09-19 13:03:57 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-CommitFinalizingBackup]: CommitFinalizingBackup took 0:00:00:00.200
2018-09-19 13:04:00 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Operation.BackupHandler-AfterBackupVerify]: AfterBackupVerify took 0:00:00:02.523
2018-09-19 13:04:18 -04 - [Profiling-Timer.Finished-Duplicati.Library.Main.Controller-RunBackup]: Running Backup took 0:00:04:17.683
Getting a bit rougher, here are earlier compact times. They mostly line up with the sorted leftovers list.
2018-09-15 18:47:01 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 1 fully deletable volume(s)
2018-09-16 08:21:57 -04 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting because there are 8 fully deletable volume(s)
09/15/2018 06:44 PM 339 dup-edf67c5c-2d98-462f-bcf1-5bd7a6e159e6
09/15/2018 06:45 PM 339 dup-48789543-07c2-4181-9d41-096a8f88a02a
09/15/2018 06:47 PM 339 dup-27a0fe3c-542f-4585-8b1f-ecb9f3d4681d
09/15/2018 06:48 PM 245 dup-056642d1-b23b-4ee7-bd24-c720af4a6d4d
09/15/2018 07:25 PM 157 dup-ab61e2be-841a-48a3-ba5c-394a1697d81a
09/16/2018 08:24 AM 245 dup-d44a04a1-5e9a-49b1-ac5f-8a0f64396d24
09/16/2018 08:24 AM 157 dup-7b10399a-a909-44c5-824b-7e02195fce96
09/16/2018 08:36 AM 245 dup-cd89f06b-b4b7-4739-bb10-29e14dbc2b88
09/16/2018 08:36 AM 157 dup-dc4d1ba2-3183-43c7-9b66-f7a704f85273Iāll see if I can remember to test a 2.0.3.11 ok Windows compact with before/after temp file count checks.
2.0.3.11_canary_2018-09-05 is probably fixed on Linux. Iām not using /tmp/ but alternate path, which only used by Duplicati. Iāve got dup-* files in the path for several months, but not any recent files since Iāve upgraded the version.
For me it seems to be still an issue on 2.0.3.11 under linux.
@ts678ās left over files on Windows seem to have been generated as part of the compact process (at least based on timestamps).
Can you tell if your temp file times align with the compacting step in your logs?
Itās possible there were multiple temp cleanup bugs and only the main one was addressedā¦
here is my log
2018-09-30 01:21:03 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted:
2018-09-30 01:21:03 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: 27/09/2018 01:16:00
2018-09-30 01:21:03 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...
2018-09-30 01:21:17 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Started: duplicati-20180926T231600Z.dlist.zip.aes (8.15 MB)
2018-09-30 01:21:19 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Delete - Completed: duplicati-20180926T231600Z.dlist.zip.aes (8.15 MB)
2018-09-30 01:21:19 +02 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteResults]: Deleted 1 remote fileset(s)
2018-09-30 01:21:43 +02 - [Information-Duplicati.Library.Main.Database.LocalDeleteDatabase-CompactReason]: Compacting not required
2018-09-30 01:21:43 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Started: ()
2018-09-30 01:21:45 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: List - Completed: (3.93 KB)
2018-09-30 01:21:47 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-20180921T205023Z.dlist.zip.aes (8.05 MB)
2018-09-30 01:21:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-20180921T205023Z.dlist.zip.aes (8.05 MB)
2018-09-30 01:21:49 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-i691d7e93598240c287d4b34b48faa12f.dindex.zip.aes (13.79 KB)
2018-09-30 01:21:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-i691d7e93598240c287d4b34b48faa12f.dindex.zip.aes (13.79 KB)
2018-09-30 01:21:50 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Started: duplicati-b364e3a8c256c42079543cee574a50d19.dblock.zip.aes (199.91 MB)
2018-09-30 01:22:32 +02 - [Information-Duplicati.Library.Main.BasicResults-BackendEvent]: Backend event: Get - Completed: duplicati-b364e3a8c256c42079543cee574a50d19.dblock.zip.aes (199.91 MB)
2018-09-30 01:24:42 +02 - [Information-Duplicati.Library.Modules.Builtin.SendMail-SendMailComplete]: Email sent successfully using server: smtp://gamliel.lan:25/?starttls=never
the dup file time is 01:24:41
Compact process indeed seems not to remove the newly created dblock/dindex files. My /tmp folder has filled up completely (21G) as part of a (big) compact operation.
extract:
251M /tmp/dup-d78111d1-dacc-4fee-9e79-c9a94cb41391
251M /tmp/dup-d7b11f65-5f58-49ae-991c-d06d9cf78287
96K /tmp/dup-d9569068-7135-4023-9906-62d201755013
251M /tmp/dup-d96b990a-b7bb-4917-8029-030300db7f2e
251M /tmp/dup-db1918da-a1d4-41ca-ae10-dacf70729d1f
251M /tmp/dup-dbb2bad1-967c-4db7-a2e0-e3cab150c30e
104K /tmp/dup-dc995795-531f-4803-b9f4-e5e8204ed46a
251M /tmp/dup-e01ad7e7-d0c6-451d-8386-9784f4d45159
96K /tmp/dup-e13f6404-9cb0-4ed4-b80f-da1b94a8d638
296K /tmp/dup-e2021c0c-5665-492f-a7b9-c70bf44e8a66
251M /tmp/dup-e23a5481-d76a-41cc-a6f3-7d8547151e3b
96K /tmp/dup-e2738ed2-3b18-44fc-8a28-73e997c9a5d0
92K /tmp/dup-e30d9adc-16b7-4c80-8b05-e4bdec5f574c
251M /tmp/dup-e8ac8898-9be3-426e-bcb4-81a8dafee714
251M /tmp/dup-ea5e9ec1-582c-4a2b-b7c4-f9e0ea4e7741
251M /tmp/dup-ea894338-7c54-46d0-8988-569dd0d2bc6e
251M /tmp/dup-ed20371d-52a6-4a9c-a776-bb9b9f883812
251M /tmp/dup-f44e78bc-2a9c-4f47-9da3-23f5b3d4bf80
100K /tmp/dup-f7ea5f33-7687-4e92-b2c8-116204f7232a
251M /tmp/dup-f8210760-0ef5-4ee7-84e1-739347daf6bd
96K /tmp/dup-f8dfdac2-b048-423b-936f-92f0df0f3e64
251M /tmp/dup-fa373cb8-5365-4506-b8b0-da38c29f2ce1
104K /tmp/dup-fb8258ff-a791-4250-825d-90f29b5d7cc5
104K /tmp/dup-fd84abc5-dafd-4b76-b5f9-cee44c1aca93
251M /tmp/dup-fdf43dc5-5296-439b-9a19-1836ee323d8b
100K /tmp/dup-ff5a7e74-2bcf-4e18-ad97-a2f91c63ffe2
What version were you using and was it native or in Docker container?
native, experimental release of last week
was running in a Ubuntu environment
1 Like
This is probably a stupid question, but did running out of space kill the compact or did it finish?
I wonder if the cleanup happens at the very end so if the task is interrupted it never gets cleaned up.
compact never finished (process got killed due to disk space issues IIRC)
Running another compact from dblock size 25mb to 1gb and see the same effect. A cronjob to remove old tmp files seems to work as a workaround.
I didnāt want to use a cron job since Iāve got backups running throughout the day (sometimes delayed if a lot of files change or something goes wrong) and I didnāt want the removal to cause problems with any running backup operations, so I set up a shell script:
#!/bin/bash
rm /mnt/ramdisk/*
exit
and I just call /usr/local/bin/clear-ramdisk.sh with the ārun-script-afterā option after my backups.
1 Like
Just noticed this as well on 2.0.4.5_beta_2018-11-28, linux native (Fedora 29)ā¦ no disk filling and no job failure, just /tmp/dup-* files left behind. Donāt think it happened on the previous beta.
Sorry to bring up an oldish thread, but Iām seeing the same thing with all my Windows installations of 2.0.4.10_canary_2018-12-29 - I moved the temp folder to another drive to avoid it ever crashing the system drive, but the files just continue to accumulate. Most are just 1Kb, but every week a bunch of 50Mb files get left.
As a test I deleted some that were over 7 days old and the next backup did throw a warning about missing temporary files:
LimitedWarnings: [
2019-01-14 06:37:16 +01 - [Warning-Duplicati.Library.Main.Operation.Backup.UploadSyntheticFilelist-MissingTemporaryFilelist]: Expected there to be a temporary fileset for synthetic filelist (92, duplicati-b96debd057c84453783d8f323c25da14d.dblock.zip.aes), but none was found?
]
LimitedErrors: []
Log data:
2019-01-14 06:37:16 +01 - [Warning-Duplicati.Library.Main.Operation.Backup.UploadSyntheticFilelist-MissingTemporaryFilelist]: Expected there to be a temporary fileset for synthetic filelist (92, duplicati-b96debd057c84453783d8f323c25da14d.dblock.zip.aes), but none was found?