Unable to resume backup due to gnupg issue.

Asked by Chris Stankaitis on 2012-01-04

Running a rather large full backup around 350GB as it's the beginning of the month. backup kacked out. When trying to resume it I get the following error.

Found primary backup chain with matching signature chain:
-------------------------
Chain start time: Tue Jan 3 09:58:12 2012
Chain end time: Tue Jan 3 09:58:12 2012
Number of contained backup sets: 1
Total number of contained volumes: 4633
 Type of backup set: Time: Num volumes:
                Full Tue Jan 3 09:58:12 2012 4633
-------------------------
No orphaned or incomplete backup sets found.
RESTART: Volumes 4633 to 4633 failed to upload before termination.
         Restarting backup at volume 4633.
GPG error detail: Traceback (most recent call last):
  File "/usr/bin/duplicity", line 1377, in <module>
    with_tempdir(main)
  File "/usr/bin/duplicity", line 1370, in with_tempdir
    fn()
  File "/usr/bin/duplicity", line 1340, in main
    full_backup(col_stats)
  File "/usr/bin/duplicity", line 500, in full_backup
    globals.backend)
  File "/usr/bin/duplicity", line 338, in write_multivol
    validate_encryption_settings(globals.restart.last_backup, mf)
  File "/usr/bin/duplicity", line 326, in validate_encryption_settings
    fileobj.close()
  File "/usr/lib64/python2.6/site-packages/duplicity/dup_temp.py", line 222, in close
    assert not self.fileobj.close()
  File "/usr/lib64/python2.6/site-packages/duplicity/gpg.py", line 239, in close
    self.gpg_failed()
  File "/usr/lib64/python2.6/site-packages/duplicity/gpg.py", line 206, in gpg_failed
    raise GPGError, msg
GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: encrypted with 4096-bit ELG key, ID AA5ACFC9, created 2010-12-14
"FM Duplicity (Backup Key) <email address hidden>"
gpg: public key decryption failed: Bad passphrase
gpg: decryption failed: No secret key
can't connect to `/root/.gnupg/S.gpg-agent': No such file or directory
===== End GnuPG log =====

GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: encrypted with 4096-bit ELG key, ID AA5ACFC9, created 2010-12-14
"FM Duplicity (Backup Key) <email address hidden>"
gpg: public key decryption failed: Bad passphrase
gpg: decryption failed: No secret key
can't connect to `/root/.gnupg/S.gpg-agent': No such file or directory
===== End GnuPG log =====

My Passphrase is exported in the same manor as any other backup which I have done. please advise how I can get this backup to resume, It was nearly done and I would like to finish it off rather then have to start it again since it takes over 24 hours for duplicity to backup that much data.

Thanks

OS: RHEL6
Dup ver: 0.6.17
Python 2.6.6

Question information

Language:
English Edit question
Status:
Answered
For:
Duplicity Edit question
Assignee:
No assignee Edit question
Last query:
2012-01-06
Last reply:
2015-08-19
Douglas Choma (doug-inertiaim) said : #1

I'm also experiencing this same issue. I even attempted sending the passphrase through to GPG with the --gpg-options parameter.

When attempting to resume from an incomplete backup, I always get this error...

gpg: public key decryption failed: bad passphrase
gpg: decryption failed: secret key not available

Just to confirm that the problem isn't with GPG, I downloaded the difftar.gpg file and decrypted it with the same passphrase exported for my duplicity script.

edso (ed.so) said : #2

On 06.01.2012 09:05, Douglas Choma wrote:
> Question #183711 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/183711
>
> Douglas Choma posted a new comment:
> I'm also experiencing this same issue. I even attempted sending the
> passphrase through to GPG with the --gpg-options parameter.
>
> When attempting to resume from an incomplete backup, I always get this
> error...
>
> gpg: public key decryption failed: bad passphrase
> gpg: decryption failed: secret key not available
>
> Just to confirm that the problem isn't with GPG, I downloaded the
> difftar.gpg file and decrypted it with the same passphrase exported for
> my duplicity script.
>

for some reason ken's answer didn't went through.. so here it is again.. ede
-->

Try restarting your gpg-agent. It's not talking to duplicity.

gpg: encrypted with 4096-bit ELG key, ID AA5ACFC9, created 2010-12-14
"FM Duplicity (Backup Key) <email address hidden>"
gpg: public key decryption failed: Bad passphrase
gpg: decryption failed: No secret key
can't connect to `/root/.gnupg/S.gpg-agent': No such file or directory <<<------ HERE!

...Ken

Chris Stankaitis (cstankaitis) said : #3

right so if duplicity needs gpg-agent to run to work then why isn't it launching it? I don't have to do anything like this when starting a backup with duplicity so why do I need to when resuming one? shouldn't duplicity be smart enough to do this if it has to do it in the first place to start the full? why is resuming the backup such a different process.

Also given that we don't need to do this for running inital backups and restores only resuming interrupted ones how would you recommend restarting gpg-agent in a duplicity friendly way?

Douglas Choma (doug-inertiaim) said : #4

I've attempted resuming my backup with and without the gpg-agent running. I get the same error message either way...

gpg: public key decryption failed: bad passphrase
gpg: decryption failed: secret key not available
===== End GnuPG log =====

rax (rax-free) said : #5

Chris, Douglas,

I'm having unrelated but similar issues in just getting duplicity to play with gpg-agent. I'm just a newbie so I might not be able to add much - or you may know a lot more than me, in which case just ignore this.

From what I've been able to deduce, it's not enough to have gpg-agent running. The passphrase needs to be loaded into the cache in order for gpg-agent to actually have the passphrase available. Since you had a long backup, after the backup broke, the passphrase might have timed out of the cache.

Try the following to get the passphrase into the cache (I'm assuming this is an encryption key and not a signing key - although you don't need to use the former to encrypt, duplicity might need it to decrypt the archive to see where it got up to with an interrupted backup - I'm guessing);

$ touch dummy.in
$ gpg --output dummy.asc --encrypt dummy.in

Give your backup encryption key ID when prompted. Once the encryption process is complete, decrypt.

$ gpg --output dummy.out --decrypt dummy.asc

You will now be prompted for your encryption passphrase. It is this process which should load the passphrase back into the cache.

Now try your backup again.

rax (rax-free) said : #6

Sorry - when I talked about getting the passphrase in the cache, I meant getting the decrypted private key into the cache, which is what supplying your passphrase does

Douglas Choma (doug-inertiaim) said : #7

Thanks for the suggestion, but still no luck...

RESTART: Volumes 135 to 136 failed to upload before termination.
         Restarting backup at volume 135.
GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: encrypted with 2048-bit ELG-E key, ID 3D9164F3, created 2012-01-04
gpg: public key decryption failed: bad passphrase
gpg: decryption failed: secret key not available
===== End GnuPG log =====

gpg: decryption failed: secret key not available

Is this an artifact of the passphrase issue or is the secret key not available?

You will need the secret key to decrypt the partial backup and allow duplicity to continue.

Douglas Choma (doug-inertiaim) said : #9

It appears that the passphrase is not being used by whatever process duplicity uses to resume a backup operation. I can encrypt and decrypt without any issues using gpg. I can even download a difftar.gpg file created by duplicity and decrypt it using gpg and the same passphrase.

edso (ed.so) said : #10

douglas, chris,

could you please try to run a test backup in debug verbosity using PASSPHRASE e.g.

PASSPHRASE=secret duplicity -v9 ~/testfolder file:///tmp/testbkp

and

rerun your failing resumes without gpg-agent but PASSPHRASE in debug verbosity?

For both runs we need the commandline and the resulting output, make sure you *obfuscate* private data in it. please upload these to pastebin or the like and post the links here.

ede/duply.net

Dominik Leonhardt (dleo-a) said : #11

It seems like this issue was introduced with this patch: https://code.launchpad.net/~mterry/duplicity/check-passphrase-on-restart/+merge/80007

After reverting this patch i could pick up an existing backup.

Michael Terry (mterry) said : #12

Douglas, Dominik: Can you manually decrypt volume 1 of your latest backup chain (full or incremental) using gpg?

That's what my branch that Dominik points to does. It tries to decrypt volume 1 with the given password to verify that it's the same password used in the past.

StalkR (stalkr) said : #13

Same issue while resuming a full backup that did not finish:
* duplicity-0.6.17 (stable version from official website)
* running on Cygwin
* GPG key for backup encryption, protected with passphrase
* no gpg-agent, using export PASSPHRASE=xxx
* same error:
RESTART: Volumes xxx to xxx failed to upload before termination.
         Restarting backup at volume xxx.
GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: encrypted with xxxxxxxxxxxxxx key, ID xxxxxxxx, created xxxxxxxxx
"xxxxxxxxxxxxxxxxxxxxx <xxxxxxxxxxxxxxxxxxxxx>"
gpg: public key decryption failed: bad passphrase
gpg: decryption failed: secret key not available
===== End GnuPG log =====

I confirm that I can manually decrypt volume 1 of my last full backup chain using gpg and manually entering the passphrase.
I reverted the patch pointed by Dominik (good find thanks!), it resumed fine and completed without error.

Let me know if you need any other information to fix the bug, good luck and thank you!

Fredrik (cfeckardt) said : #14

I can confirm this issue, and also that the solution by #11 Dominik #13 Stalkr solved the problem for me.

smu (smu) said : #15

is this bug already reported or maybe even fixed?
I experience the same behaviour with 0.6.18-2 on arch linux.

smu (smu) said : #16

I'm sorry, I found the bug report: https://bugs.launchpad.net/duplicity/+bug/946988

Tobias Mieth (tobias-mieth) said : #17

Hi,

I ran into that very same issue recently and found this thread via google. However, from my point that duplicity patch isn't neccessarily causing the gpg error. The reason why gpg complains is that it needs the secret key to decrypt duplicity's volume 1.

Excerpt from that duplicity patch:
https://code.launchpad.net/~mterry/duplicity/check-passphrase-on-restart/+merge/80007

+ This is because the local copy of the manifest is unencrypted and we
13 + don't need to decrypt the existing volumes on the backend. To ensure
14 + that we are using the same passphrase, we manually download volume 1
15 + and decrypt it with the current passphrase.

So, if you didn't supply your private key's passphrase gpg/duplicity will be unable to decrypt volume 1 and thus it fail. After I had exported PASSPHRASE in my shell script duplicity went back to normal and the gpg error disappered.

Cheers Tobias

Scott (firecat53) said : #18

@Tobias: I believe the OP and others here were having issues with 0.6.18 being able to effectively retrieve the encryption passphrase from gpg-agent. Yes, it does work by exporting your PASSPHRASE within the script; however it doesn't seem to work with gpg-agent (even with a key cached and tested) unless that patch is removed. I actually downgraded to 0.6.17 and also removed that patch (to fix some other SSH issues with the new paramenko backend) in order to be able to resume a failed backup using keys solely from gpg-agent.

Scott

edso (ed.so) said : #19

i just checked the code and cannot see why gpg-agent with duplicity shouldn't work (make sure to use --gpg-agent and to monitor your backup if gpg-agent asks for the passphrase). the patch mentioned above actually only uses an old proven to work routine to decrypt the first volume to make sure encryption settings are still identical to the existing first volume on the backend.

could we please get a wrap overview of who still has issues using
 gpg-agent
and who uses
 ordinary PASSPHRASE env var
?

as it looks like using PASSPHRASE works sometimes i like to single out the gpg agent issue into a new bug and treat issues with that there.

a Note on gpg-agent: i hope all of you using it are aware that it has a hardcoded maximum cache time (i recall 4h) meaning that passphrases time out pretty fast, even if you give it a very long timeout time. so it actually does not allow for unattended backups.

..ede/duply.net

Scott (firecat53) said : #20

Well, I've done some more testing and I think I need to retract a couple of my earlier issues.

1. I've now tested duplicity 0.6.18 and pinentry 0.8.1 (on Archlinux) and I can successfully authenticate a full backup, an incremental backup, and a restarted backup using gpg-agent as the root user from a cron job on a remote server. I'm using separate keys for encryption and signing. I believe the reason this was causing me such huge issues before was because of a. a pinentry bug that doesn't allow passphrase entry as root from an su - session, and b. environment issues when trying to run a duplicity script using either su or sudo. I can only reliable get duplicity scripts to work from cron. If you have local root access then this should not be an issue.

2. pinentry still needs to be patched in order to use gpg-agent as root on a headless server where direct root login from ssh is neither desired nor allowed.

3. My root gpg-agent has been running for 4 days now with the passphrases still cached and being used by my nightly backup script. I have these values in my /root/.gnupg/gpg-agent.conf:
max-cache-ttl 60480000
default-cache-ttl 60480000

4. I believe you said in a previous post of mine that 0.6.18 didn't seem to be respecting the --num-retries parameter

5. I use keychain to start my gpg-agent, so I use this line in my script to source the keys for cron:
eval `keychain --eval web_rsa 42A79D21 E6C991E3` || exit 1

I apologize if I've caused a little extra noise here over the past several days!! I was getting pretty frustrated until I hit on the right combo of bugfixes and script parameters to get everything working right. Let me know if I can provide any additional information.

Scott

edso (ed.so) said : #21

On 16.05.2012 02:01, Scott wrote:
> Question #183711 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/183711
>
> Scott posted a new comment:
> Well, I've done some more testing and I think I need to retract a couple
> of my earlier issues.
>

good to hear

> 3. My root gpg-agent has been running for 4 days now with the passphrases still cached and being used by my nightly backup script. I have these values in my /root/.gnupg/gpg-agent.conf:
> max-cache-ttl 60480000
> default-cache-ttl 60480000

could you doublecheck that it indeed hasn't lost the passphrase for the encryption key. during normal operation duplicity actually never needs it except when
- archive dir is out of sync
- backup is to be resumed

so it is absolutely feasible that everything works ok until one of the above happens

> 4. I believe you said in a previous post of mine that 0.6.18 didn't seem
> to be respecting the --num-retries parameter

only the ssh paramiko backend in case you happen to use it. this will be fixed in 0.6.19

> 5. I use keychain to start my gpg-agent, so I use this line in my script to source the keys for cron:
> eval `keychain --eval web_rsa 42A79D21 E6C991E3` || exit 1

never knew it existed. it makes sure that one instance of the agents is running per user and put this into your environment when run in .profile, right?

> I apologize if I've caused a little extra noise here over the past
> several days!! I was getting pretty frustrated until I hit on the right
> combo of bugfixes and script parameters to get everything working right.

no worries, you actually shed some pretty important light on the issue

> Let me know if I can provide any additional information.

last but not least, thanks for the exhaustive analysis shared with us today.

i am ede, i am using duplicity ;) ... ede/duply.net

ben (ben-chgtaa3qpp) said : #22

Hello Guys,

Any more progress on this one? I have to revert the patch metioned by Dominik as well in order to make things work. I am also running 0.6.18
It seems to be an old bug and needs to be fixed

regards,
ben

ben (ben-chgtaa3qpp) said : #23

Just want to add another note so that others will not waste time.

I have just downloaded the latest version 1.6.9, compiled it and run. I got the same problem. so i comes back to the 1.6.8 rpm and modify /usr/bin/duplicity to remove the patch

William Orr (worr) said : #24

I'm still having this issue with 0.6.19 on FreeBSD, and had to revert the patch to be able to successfully resume.

I was encountering this issue as well; I'm not using gpg-agent, just exporting PASSPHRASE.

I dug around a little bit and cobbled a patch together that modifies the validate_encryption_settings function, instead of ripping it out. Details are here:

https://bugs.launchpad.net/duplicity/+bug/946988/comments/8

Hope that helps!

edso (ed.so) said : #26

hey brock,

thanks for the contribution. your approach looks healthy to me. i forwarded it to mterry, who implemented validate_encryption_settings, for validation.

.. thanks ede/duply.net

Soren Bjornstad (sobjornstad) said : #27

As a quick temporary solution, I added the --use-agent switch to the end of my normal backup command. Gpg-agent popped up and asked me for my passphrase and thereafter it worked fine. The caching and PASSPHRASE= approaches didn't work for me, but this did.

edso (ed.so) said : #28

On 19.11.2012 02:45, Soren Bjornstad wrote:
> Question #183711 on Duplicity changed:
> https://answers.launchpad.net/duplicity/+question/183711
>
> Soren Bjornstad posted a new comment:
> As a quick temporary solution, I added the --use-agent switch to the end
> of my normal backup command. Gpg-agent popped up and asked me for my
> passphrase and thereafter it worked fine. The caching and PASSPHRASE=
> approaches didn't work for me, but this did.
>

nice catch..

Mike upped a branch which probably fixes this one for good when merged into the next release..
http://bazaar.launchpad.net/~mterry/duplicity/946988/revision/896
@Mike: correct?

..ede/duply.net

Michael Terry (mterry) said : #29

Yes. You might try using the daily testing build and seeing if that also fixes the problem:
https://launchpad.net/~duplicity-team/+archive/daily

jas (jaspers) said : #30

I have thrown away the directory ~/.cache/duplicity and started duply again. It detects an incomplete backup after downloading some files from the backup location. From there on it runs the backup.

The issue is still there in 0.6.22, and I also confirm the workaround shown in comment #11 solved my problem.

It would be nice to be able to optionally ignore that check, to me it's more important that(especially full) backups are always resume-able and I know for sure the passphrase is the same one I used when first creating the backup.

Artur Bodera (abodera) said : #33

Encrypted full backup resume still broken on 7.04.

I've fixed it by adding an additional check in the password prompting routine:
https://gist.github.com/Thinkscape/981972eb531042a4e627

Fix committed to trunk with the following:

* Fixed Bug 1438170 duplicity crashes on resume when using gpg-agent with
  patch from Artur Bodera (abodera). Applied the same patch to incremental
  resumes as well.

Can you help with this problem?

Provide an answer of your own, or ask Chris Stankaitis for more information if necessary.

To post a message you must log in.