Backup fails with unknown error

Bug #324531 reported by Tobias Baldauf
38
This bug affects 8 people
Affects Status Importance Assigned to Milestone
Déjà Dup
Fix Released
High
Michael Terry

Bug Description

I apologize beforehand for submitting such an incomplete bug-report. I essentially have no data to show for it.

In the last couple of days, Deja-Dup / Duplicity doesn't work anymore for me: Each scheduled backup via SSH switches between the modes "Preparing..." and "Cleaning up..." and generates a duplicity-zombie-process on each turn. The external server returns:

Month 0 00:00:00 servername sshd[1234]: Failed password for username from 12.34.56.789 port 12345 ssh2

on each turn (logfile-output stripped of private data).

I deleted my saved ssh-password from the keychain and re-entered it, reinstalled duplicity and deja-dup, upgraded duplicity manually and even deleted all my backup data on the remote server and tried to create a new complete backup. All to no avail. After many hours of "Preparing..." and backing up almost half of all my data, Deja-Dup exited with an unknown error and is now back to its old behavior of "Preparing..." and "Cleaning up..." and creating lots of zombie-processes.

The strangest thing is that it worked until a few days ago. So my guess is either that something is messed up in the current release (unlikely) or that something on my harddrive is now confusing duplicity that was not on it a few days ago. But these are just wild speculations...

I'll gladly provide you with logfile-data if you let me know how to collect it! I really want my super-simple 24h auto-backup back! :)

Revision history for this message
Michael Terry (mterry) wrote :

Thank you for the bug report!

Hmm, it stops halfway through? Here's a way to get a log: set the DEJA_DUP_DEBUG environment variable to 1:

export DEJA_DUP_DEBUG=1
deja-dup > /tmp/deja-dup.log

Now, that will create a giant, incredibly verbose log with lots of information about your files. Only the very end is probably interesting. Last 50 lines or so? Almost certainly, duplicity is aborting with a Python exception. I should probably make the exception visible so users like you that have a problem can more easily report it.

It's also bad that we create zombie duplicities... Hrm.

Changed in deja-dup:
importance: Undecided → Medium
status: New → Incomplete
importance: Medium → High
Revision history for this message
Tobias Baldauf (technopagan) wrote :

Here's the logfile (stripped of sensitive data):

All that the GUI does is initializing and then claiming to clean up. After a while, duplicity becomes a zombie and the whole thing starts over again. Given time, the zombie-processes accumulate.

There's an interesting error-report on lines 1108-1123 of the logfile.

I hope this helps! Let me know if / how I can provide you with more info! Thank you!

Revision history for this message
Michael Terry (mterry) wrote :

OK, I think I understand the sequence now.

It seems you have files left over from an incomplete/cancelled backup on your sever.
When Deja Dup starts up, it first connects and scans the files in the target location.
Seeing unused backup files (from the cancelled backup), it initiates a 'cleanup' operation before continuing with the backup.
For some reason, it can't connect to the SSH server for the 'cleanup' operation, and bails on you.

You say you cleaned up the files on the backend and tried again, with a fresh slate. Then, Deja Dup stopped halfway through with an error. I'd also be interested in a log for this error. It may be a different problem than this one.

But after it stopped halfway through on that fresh backup, the next time Deja Dup runs, it will try to clean up those leftover files (since it can't resume currently), and thus you get back into the cleanup loop.

Basically, it seems Deja Dup isn't correctly passing the password that it clearly knows (because it can log in to do the initial 'ls'). I'm looking into it. It's conceivable I introduced this in a recent version, which explains why it used to work for you.

Thanks for the log, and if you could get me a log for the other stops-halfway-through issue, I'd appreciate it!

Changed in deja-dup:
assignee: nobody → mterry
status: Incomplete → Confirmed
Revision history for this message
Michael Terry (mterry) wrote :

OK, I found the problem. I had made a change in 7.0 that caused the SSH backend to not correctly tell duplicity the SSH password. I need better testing before a release. :-/

I just released 7.3 to fix it. That may have also fixed your 'halfway' issue, because that may have been when we stopped preparing and start backing up. That would also have run into this bug. Let me know if you have further issues.

Changed in deja-dup:
milestone: none → 7.0
status: Confirmed → Fix Released
Revision history for this message
Tobias Baldauf (technopagan) wrote :

Thanks so much, Michael!

I've upgraded to the newest version, performed a full backup as well as an incremental one - all without a fuss now! This bug is fixed! Great work!

Revision history for this message
PatrickMULOT (pm-r) wrote :

hello, I encountered this problem while wanting to make my automatic backup:

Traceback (innermost last):
  File "/usr/bin/duplicity", line 1555, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1541, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1393, in main
    do_backup(action)
  File "/usr/bin/duplicity", line 1511, in do_backup
    full_backup(col_stats)
  File "/usr/bin/duplicity", line 572, in full_backup
    globals.backend)
  File "/usr/bin/duplicity", line 454, in write_multivol
    (tdp, dest_filename, vol_num)))
  File "/usr/lib/python2.7/dist-packages/duplicity/asyncscheduler.py", line 146, in schedule_task
    return self.__run_synchronously(fn, params)
  File "/usr/lib/python2.7/dist-packages/duplicity/asyncscheduler.py", line 172, in __run_synchronously
    ret = fn(*params)
  File "/usr/bin/duplicity", line 453, in <lambda>
    vol_num: put(tdp, dest_filename, vol_num),
  File "/usr/bin/duplicity", line 342, in put
    backend.put(tdp, dest_filename)
  File "/usr/lib/python2.7/dist-packages/duplicity/backend.py", line 395, in inner_retry
    % (n, e.__class__.__name__, util.uexc(e)))
  File "/usr/lib/python2.7/dist-packages/duplicity/util.py", line 79, in uexc
    return ufn(unicode(e).encode('utf-8'))
 UnicodeDecodeError: 'ascii' codec can't decode byte 0xe2 in position 37: ordinal not in range(128)

I have deleted the packages deja-dup and dupicity, and re-install them, but i have the same error!
Want have I to do?

Patrick MULOT.

Revision history for this message
Michael Terry (mterry) wrote :

Hello, Patrick! I'm sorry you're having trouble with Deja Dup.

Looks like you're running an older version of duplicity, which has some problems with ascii and unicode characters.

I'd recommend either (A) you update to a newer version of your distro to get newer software or (B) you update deja-dup to a flatpak or snap install, which will get you the latest deja-dup & duplicity releases.

Are you on Ubuntu? Then try the snap:
snap install deja-dup --classic

And you might want to remove the normal deja-dup package just so you only have one copy lying around:
sudo apt-get remove deja-dup

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Bug attachments

Remote bug watches

Bug watches keep track of this bug in other bug trackers.