Déjà Dup

Deja Dup "spins" for a long time, seems to hang on .vdi files, does not write restorable backup

Asked by koanhead

I'm trying DD again after having trouble with it in the past.
I have a homedir of about 160GB which I'm trying to back up to a local 250GB SATA disk. I use VirtualBox OSE, and my homedir contains several .vdi files. After letting DD run for several hours it wrote a mess of files to the destination disk representing about 12GB, and the GUI screen showed "backing up somevirtualdiskimage.vdi" with a small sliver of the progress bar filled, where it stayed for another hour or so until I clicked the "Resume Later" button, upon which DD quit entirely. I started the program again and started the backup using the same parameters (I never altered these) and it started over, apparently from the beginning instead of "Resuming".
The above-described behavior persisted across three trials, the last one lasting 16 hours. On the last trial the progress bar got about 15% across, and destination disk shows about 30GB used. It looks like two of the .vdi files were "backed up" but the program was still sitting on a third one (there are three in the directory, 2, 8, and 30GB respectively).

I understand that encrypting and transferring 160GB of data takes a while, but 16 hours seems extreme. IIRC it takes only about 3 hours to do a straight copy.
I'm going to try DD again from a terminal to see if I can capture some useful error messages, which I'll add here.

Question information

Language:
English Edit question
Status:
Solved
For:
Déjà Dup Edit question
Assignee:
No assignee Edit question
Solved by:
Michael Terry
Solved:
Last query:
Last reply:
Revision history for this message
koanhead (googoleyes) said : 		#1

I don't find anything informative in this output, but I'll post it here for the sake of completeness.
I'm going to assume that DD can't cope with .vdi files for some reason, exclude the directory they are in, and try again.

Oh, also I forgot to mention: running Ubuntu 10.04 on Athlon X2 64 4800+, 3GB RAM, nVidia G80.

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed

** (deja-dup:17242): CRITICAL **: deja_dup_duplicity_cmp_prefix: assertion `b != NULL' failed
** (deja-dup:17242): DEBUG: DuplicityInstance.vala:199: Running the following duplicity (17249) command: duplicity collection-status --exclude=/media/backupland --exclude=~/bup --exclude=~/.local/share/Trash --exclude=~/.Private --exclude=~/.recent-applications.xbel --exclude=~/.recently-used.xbel --exclude=~/.xsession-errors --exclude=~/.gvfs --exclude=~/.thumbnails --exclude=~/.cache --include=~ --exclude=/sys --exclude=/proc --exclude=/tmp --exclude=** --gio file:///media/backupland --verbosity=9 --gpg-options= --archive-dir=~/.cache/deja-dup --log-file=/tmp/deja-dup-UR1H1V

** (deja-dup:17242): DEBUG: DuplicityInstance.vala:552: duplicity (17249) exited with value 0

** (deja-dup:17242): DEBUG: DuplicityInstance.vala:199: Running the following duplicity (17254) command: duplicity --exclude=/media/backupland --exclude=~/bup --exclude=~/.local/share/Trash --exclude=~/.Private --exclude=~/.recent-applications.xbel --exclude=~/.recently-used.xbel --exclude=~/.xsession-errors --exclude=~/.gvfs --exclude=~/.thumbnails --exclude=~/.cache --include=~ --exclude=/sys --exclude=/proc --exclude=/tmp --exclude=** --dry-run --gio --volsize=30 / file:///media/backupland --verbosity=9 --gpg-options= --archive-dir=~/.cache/deja-dup --log-file=/tmp/deja-dup-I65I1V

** (deja-dup:17242): DEBUG: DuplicityInstance.vala:552: duplicity (17254) exited with value 0

** (deja-dup:17242): DEBUG: DuplicityInstance.vala:199: Running the following duplicity (17306) command: duplicity full --exclude=/media/backupland --exclude=~/bup --exclude=~/.local/share/Trash --exclude=~/.Private --exclude=~/.recent-applications.xbel --exclude=~/.recently-used.xbel --exclude=~/.xsession-errors --exclude=~/.gvfs --exclude=~/.thumbnails --exclude=~/.cache --include=~ --exclude=/sys --exclude=/proc --exclude=/tmp --exclude=** --gio --volsize=30 / file:///media/backupland --verbosity=9 --gpg-options= --archive-dir=~/.cache/deja-dup --log-file=/tmp/deja-dup-H4BO1V

Revision history for this message
Best Michael Terry (mterry) said : 		#2

I suspect it was resuming. It just didn't look like it, because Deja Dup will sit at 0% while it scans, then jump to where you were before after the next volume is uploaded. I believe that would explain what you saw?

Deja Dup is slow. It's true. It's also not super efficient for compressing large binaries like vdi files. And you're right that your backup is going to not be restorable until it can complete.

But correctness has been my focus so far, more than efficiency. It's a known problem, but I haven't spent much time working on it.

Revision history for this message
koanhead (googoleyes) said : 		#3

From memory, it looked like it was backing up some of the same files on the subsequent goes round. I can't swear to it since I didn't save the output and I'm at a different computer now. If I can scare up the relevant information tomorrow I'll add it here or confirm what you are saying.

I did start it over again, excluding the .VirtualBox directory (where the .vdi files are) and left it going when I went to work. Excluding those files made a huge difference. Why there's a problem with .vdi and not some of the other giant files I have is a mystery. It's a drag that I'll have to back up my VMs separately, but hardly a deal-breaker. I'm happy that it seems to be slurping everything else up ok and wanted to put it out there that there's apparently a problem with this filetype.

I'm not fussed about the slowness, I didn't actually find it slow until it looked like it had stopped. It takes a long time to process 160GB of stuff, but not much longer than just copying a big directory in GNOME. And of course I only have to do it this once. If I wind up with deltas that size, well I guess I need to back up more often!

Anyway, thanks for the quick reply. I'll mark this solved since I haven't found any reference to others having the same problem.

Thanks for making this thing. rsync wasn't really doing for me any more, and I don't really have time to learn duplicity, so it's nice to be able to get an encrypted backup going with a few clicks.

Revision history for this message
koanhead (googoleyes) said : 		#4

Thanks Michael Terry, that solved my question.