Backup Failed: gpg: decrypt_message failed: Unknown system error

Bug #1728548 reported by Mathieu Leplatre
82
This bug affects 15 people
Affects Status Importance Assigned to Milestone
Duplicity
Medium
Unassigned
Déjà Dup
High
Unassigned

Bug Description

After upgrading to 17.10, an error window keeps showing during backup:

    GPGError: GPG Failed, see log below:
    ===== Begin GnuPG log =====
    gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect
    gpg: decrypt_message failed: Unknown system error
    ===== End GnuPG log =====

deja-dup:
  Installed: 36.2-0ubuntu1
  Candidate: 36.2-0ubuntu1
  Version table:
 *** 36.2-0ubuntu1 500
        500 http://es.archive.ubuntu.com/ubuntu artful/main amd64 Packages
        100 /var/lib/dpkg/status

Revision history for this message
Mark Stosberg (markstos) wrote :

This happened to me as well.

When I went to check the remote site where the backups were stored, I found they hadn't been running for some time.

So I'm not sure whether in my case:

  * The backups were already failing, but now the error is starting to be surfaced
  * The backups are actually starting to work now, but the delta since the last backup is so large, that this triggers a failure
  * There is a new bug that is unrelated to why my backups weren't working before.

At this point I'll probably try to just start over or use a different backup system-- clearly deja-dup / duplicity isn't performing the basic functionality for me and hasn't for some time.

Revision history for this message
Mark Stosberg (markstos) wrote :

When I try "deja-dup --backup" on the command line, I get a message that it is a "creating a fresh backup to protect against backup corruption. This will take longer than normal".

I ran the process with `strace`, saved the output to a logfile, and waited several hours for the crash to happen again. Then I went to review the 29G file that had been generated.

Ignoring the flood of polling related entries, I focused on noting the last files that were accessed before the process crashed. Here are those last related lines of the `strace` output:

```
statfs("/home/mark/.local/share/gvfs-metadata", {f_type=EXT2_SUPER_MAGIC, f_bsize=4096, f_blocks=50211842, f_bfree=9505
524, f_bavail=6949148, f_files=12763136, f_ffree=11482383, f_fsid={val=[3791877080, 1636325322]}, f_namelen=255, f_frsi
ze=4096, f_flags=ST_VALID|ST_RELATIME}) = 0
openat(AT_FDCWD, "/home/mark/.local/share/gvfs-metadata/home", O_RDONLY) = 16
fstat(16, {st_mode=S_IFREG|0600, st_size=337916, ...}) = 0
mmap(NULL, 337916, PROT_READ, MAP_SHARED, 16, 0) = 0x7fec716eb000
statfs("/home/mark/.local/share/gvfs-metadata", {f_type=EXT2_SUPER_MAGIC, f_bsize=4096, f_blocks=50211842, f_bfree=9505
524, f_bavail=6949148, f_files=12763136, f_ffree=11482383, f_fsid={val=[3791877080, 1636325322]}, f_namelen=255, f_frsi
ze=4096, f_flags=ST_VALID|ST_RELATIME}) = 0
openat(AT_FDCWD, "/home/mark/.local/share/gvfs-metadata/home-b5c635b8.log", O_RDONLY) = 18
fstat(18, {st_mode=S_IFREG|0644, st_size=32768, ...}) = 0
mmap(NULL, 32768, PROT_READ, MAP_SHARED, 18, 0) = 0x7fec80007000
eventfd2(0, EFD_CLOEXEC|EFD_NONBLOCK) = 20
write(6, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55972ecd5490, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55972ecc0810, FUTEX_WAKE_PRIVATE, 1) = 1
futex(0x55972eccc0c8, FUTEX_WAKE_PRIVATE, 1) = 1
read(20, "\1\0\0\0\0\0\0\0", 16) = 8
write(20, "\1\0\0\0\0\0\0\0", 8) = 8
futex(0x55972f0a0fe0, FUTEX_WAKE_PRIVATE, 2147483647) = 0
close(20) = 0
unlink("/home/mark/.cache/deja-dup/metadata") = -1 EISDIR (Is a directory)
rmdir("/home/mark/.cache/deja-dup/metadata") = 0
lstat("/home/mark/.cache/deja-dup", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/home/mark/.cache", {st_mode=S_IFDIR|0700, st_size=4096, ...}) = 0
lstat("/home/mark", {st_mode=S_IFDIR|0755, st_size=24576, ...}) = 0
lstat("/home", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
```

So it looks like the GVFS metadata file was the last one to be accessed. I presume the `unlink` and `rmdir` calls are part of a clean-up at the end and happened after the error.

Now I need to shop for a new backup solution!

Revision history for this message
Rusty Abbott (rustyabbott) wrote :

Matthew & Mark,

Did either of you find a solution to this? I had the same problem with 17.10. I've recently updated to 18.04 and still getting the same error message:

GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect
gpg: decrypt_message failed: Unknown system error
===== End GnuPG log =====

-Rusty

Revision history for this message
Mathieu Leplatre (mathieu.leplatre) wrote :

Sorry, I didn't.

I'm using Restic meanwhile... it works well, but I would really prefer Deja Dup since it was well integrated into the desktop

Revision history for this message
Vej (vej) wrote :

Hello everyone.

Thanks for reporting this bug. Can you please add the following informations, so the developers can figure out what exactly went wrong:

1. The distribution of Linux you're using:
    lsb_release -d

2. The version of deja-dup and duplicity:
    (if on Ubuntu or Debian:)
    dpkg-query -W deja-dup duplicity

    (if on Fedora or other RPM-based systems:)
    rpm -q deja-dup duplicity

3. The file /tmp/deja-dup.gsettings after running the following line (you may want to scrub the file of any incriminating file names or details):
    gsettings list-recursively org.gnome.DejaDup > /tmp/deja-dup.gsettings

4. The file /tmp/deja-dup.log after running the appropriate line below and replicating the problem (you may want to scrub the log of any incriminating file names or details):

 * If you're having problems backing up:
    DEJA_DUP_DEBUG=1 deja-dup --backup | tail -n 1000 > /tmp/deja-dup.log

 * If you're having problems restoring:
    DEJA_DUP_DEBUG=1 deja-dup --restore | tail -n 1000 > /tmp/deja-dup.log

Changed in deja-dup:
status: New → Confirmed
status: Confirmed → Incomplete
Revision history for this message
Launchpad Janitor (janitor) wrote :

[Expired for Déjà Dup because there has been no activity for 60 days.]

Changed in deja-dup:
status: Incomplete → Expired
Revision history for this message
Alessander Botti Benevides (alessanderbotti) wrote :

1. Description: Ubuntu 18.04.1 LTS
2. deja-dup 37.1-2fakesync1
   duplicity 0.7.17-0ubuntu1
3. attached

Revision history for this message
Alessander Botti Benevides (alessanderbotti) wrote :

4. attached

Changed in deja-dup:
status: Expired → Confirmed
Revision history for this message
Chris (fesoft) wrote :

Same here on 18.04 - deleting the backupo and starting over did not help as well.

Revision history for this message
Mortimer (blackpenguin) wrote :

I had the same problem after upgrading from 16.04 to 18.04.

1) Ubuntu 18.04.1 LTS

2)
deja-dup 37.1-2fakesync1ubuntu0.1
duplicity 0.7.17-0ubuntu1

--error message below--

Backup Failed

Error processing remote manifest (duplicity-inc.20181221T055818Z.to.20190111T064311Z.manifest.gpg): GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect
gpg: AES encrypted data
gpg: encrypted with 1 passphrase
gpg: decryption failed: Bad session key
===== End GnuPG log =====

Revision history for this message
Steven Palmer (celtaweb) wrote :

I also had the same problem after upgrading from 16.04 to 18.04.

-- system below --

Ubuntu 18.04.2 LTS
deja-dup 37.0
duplicity 0.7.17

-- error message below --

GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect
gpg: decrypt_message failed: Unknown system error
===== End GnuPG log =====

Revision history for this message
Laurenz (lalten) wrote :

I have the same problem. I don't remember updating anything special, my backups just started to fail last week with the error message

Error processing remote manifest (duplicity-inc.20190321T091744Z.to.20190328T012024Z.manifest.gpg): GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect
gpg: decrypt_message failed: Unknown system error
===== End GnuPG log =====

I tried to update all versions, but the error remains.
Ubuntu 18.04.2 LTS
deja-dup 39.1 (git 69b360b8)
duplicity 0.7.18.2 (ppa:duplicity-team/ppa)
gpg (GnuPG) 2.2.4 (https://gist.github.com/vt0r/a2f8c0bcb1400131ff51#gistcomment-2875945)

Revision history for this message
Laurenz (lalten) wrote :

I found my problem using

DEJA_DUP_DEBUG=1 deja-dup --backup

excerpt:

DUPLICITY: WARNING 1
DUPLICITY: . Attempt 1 failed. GSResponseError: GSResponseError: 403 Forbidden
DUPLICITY: . <?xml version='1.0' encoding='UTF-8'?><Error><Code>UserProjectAccountProblem</Code><Message>User project billing account not in good standing.</Message><Details>The billing account for project 226596391088 is disabled in state closed</Details></Error>

DUPLICITY: ERROR 1
DUPLICITY: . Error processing remote manifest (duplicity-inc.20190321T091744Z.to.20190328T012024Z.manifest.gpg): GPG Failed, see log below:
DUPLICITY: . ===== Begin GnuPG log =====
DUPLICITY: . gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect
DUPLICITY: . gpg: decrypt_message failed: Unknown system error
DUPLICITY: . ===== End GnuPG log =====
DUPLICITY: .

I guess it would be very helpful if deja-dup would propagate this warning to the user.

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

Mortimer, from comment 10: your problem is a recently fixed passphrase bug. See https://wiki.gnome.org/Apps/DejaDup/PassphraseProblems2019

I’d like to keep this bug focused on the “unknown system error” bug.

Unfortunately, I’m not sure how to proceed on that yet. If anyone knows how to reproduce it, please let me know.

I’ll add duplicity as an affected project, in case they’ve seen this error before.

Revision history for this message
Mortimer (blackpenguin) wrote :

Michael,

(re: comment 10, 14)
Thank you. It looks like that machine began backing up again, maybe 7 days ago. I have installed updates as they came up but did not make any modifications to try to address the issue.

That machine was using full disk encryption which may explain the different error message.

Revision history for this message
Vej (vej) wrote :

I added the "unknown system error" to the title to emphasize that this is not about ever GPG-bug, but about this issue (see comment #14).

summary: - Backup Failed: gpg: decrypt_message failed
+ Backup Failed: gpg: decrypt_message failed: Unknown system error
Changed in deja-dup:
importance: Undecided → High
Revision history for this message
Phil Ayres (ayres-phil) wrote :

This error appears for me too when the periodic secret validation occurs. The validation takes a long time and eventually times out.

Ubuntu 18.04.2 LTS
deja-dup 37.1-2fakesync1ubuntu0.1
duplicity 0.7.17-0ubuntu1.1
gpg (GnuPG) 2.2.4

Running `gpg --no-use-agent` on the command line returns
gpg: WARNING: "--no-use-agent" is an obsolete option - it has no effect

Presumably this is due to
https://github.com/deja-dup/deja-dup/blob/master/libdeja/tools/duplicity/DuplicityInstance.vala

Line 91: argv.append("--gpg-options=--no-use-agent");

OK, so the agent is always required with gpg 2.1+. So either it looks like deja shouldn't be passing the option, or should offer a way to specify the gpg version.

Since it takes ages to time out after I have entered the secret for validation, I'm guessing that it is more than a warning here, and that gpg is blocking the request.

A long way of say this is affecting me too.

Revision history for this message
Vadim Zeitlin (vz-ubuntu) wrote :
Download full text (5.7 KiB)

Just another failure report with Duplicity 0.7.18.2 included in Debian Buster:

# PASSPHRASE='xxx' /usr/bin/duplicity -v 6 --archive-dir /nobackup/duplicity/cache --name mail --full-if-older-than 3M /home/zeitlin/mail scp://xxx@xxx/xxx
Using archive dir: /nobackup/duplicity/cache/mail
Using backup name: mail
Import of duplicity.backends.acdclibackend Succeeded
Import of duplicity.backends.azurebackend Succeeded
Import of duplicity.backends.b2backend Succeeded
Import of duplicity.backends.botobackend Succeeded
Import of duplicity.backends.cfbackend Succeeded
Import of duplicity.backends.dpbxbackend Failed: No module named dropbox
Import of duplicity.backends.gdocsbackend Succeeded
Import of duplicity.backends.giobackend Succeeded
Import of duplicity.backends.hsibackend Succeeded
Import of duplicity.backends.hubicbackend Succeeded
Import of duplicity.backends.imapbackend Succeeded
Import of duplicity.backends.lftpbackend Succeeded
Import of duplicity.backends.localbackend Succeeded
Import of duplicity.backends.mediafirebackend Succeeded
Import of duplicity.backends.megabackend Succeeded
Import of duplicity.backends.multibackend Succeeded
Import of duplicity.backends.ncftpbackend Succeeded
Import of duplicity.backends.onedrivebackend Succeeded
Import of duplicity.backends.par2backend Succeeded
Import of duplicity.backends.pydrivebackend Succeeded
Import of duplicity.backends.rsyncbackend Succeeded
Import of duplicity.backends.ssh_paramiko_backend Succeeded
Import of duplicity.backends.ssh_pexpect_backend Succeeded
Import of duplicity.backends.swiftbackend Succeeded
Import of duplicity.backends.sxbackend Succeeded
Import of duplicity.backends.tahoebackend Succeeded
Import of duplicity.backends.webdavbackend Succeeded
ssh: Connected (version 2.0, client OpenSSH_7.6)
/usr/lib/python2.7/dist-packages/paramiko/kex_ecdh_nist.py:39: CryptographyDeprecationWarning: encode_point has been deprecated on EllipticCurvePublicNumbers and will be removed in a future version. Please use EllipticCurvePublicKey.public_bytes to obtain both compressed and uncompressed point encoding.
  m.add_string(self.Q_C.public_numbers().encode_point())
/usr/lib/python2.7/dist-packages/paramiko/kex_ecdh_nist.py:96: CryptographyDeprecationWarning: Support for unsafe construction of public numbers from encoded data will be removed in a future version. Please use EllipticCurvePublicKey.from_encoded_point
  self.curve, Q_S_bytes
/usr/lib/python2.7/dist-packages/paramiko/kex_ecdh_nist.py:111: CryptographyDeprecationWarning: encode_point has been deprecated on EllipticCurvePublicNumbers and will be removed in a future version. Please use EllipticCurvePublicKey.public_bytes to obtain both compressed and uncompressed point encoding.
  hm.add_string(self.Q_C.public_numbers().encode_point())
/usr/lib/python2.7/dist-packages/cryptography/hazmat/backends/openssl/ciphers.py:114: UserWarning: implicit cast from 'char *' to a different pointer type: will be forbidden in the future (check that the types are as you expect; use an explicit ffi.cast() if they are correct)
  operation
/usr/lib/python2.7/dist-packages/cryptography/hazmat/backends/openssl/ciphers.py:140: UserWarning: implicit cast fro...

Read more...

Changed in duplicity:
status: New → Confirmed
Revision history for this message
Cno (cno) wrote :

Same problem since a week or so on
- Ubuntu 20.04.1 LTS
- 20.04.1 LTS

Revision history for this message
Kenneth Loafman (kenneth-loafman) wrote : Update bug #1728548, status confirmed, importance medium

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

 status confirmed
 importance medium
 done
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEExwf+p6/3mDvUSsaGH1G0ZBEHM/EFAmBmFasACgkQH1G0ZBEH
M/GuUwgArql80v8xSW5jgLK+cSC+JqQFkqnBibXu4hJUAm8raNg3eX9c70lwEt6C
zcEwcReF5KWl4udmf+44dNfT1ERg0VNAOdFvg6UIqQ6dswQnaa5GKTWKMDTSx+9Z
bgQi9Kdri42xf+9kYvFp/qka6z+j9qv3E1l+KL4UzrbHeakqs10w5jY8vpTWY/EX
O3zxnZyshlxFf/EGqcCdc7g4m+2vx9SphtavVmgUJrCGKrRESy6bxodRSWt1u1SK
UXKHZYdpcRGjw+3H4CeLwPCrd4EmdGqRUBRCtcP1Ifeuvk8TrJn9UZ2eGocTD1Nz
kHSFVbfr4rTqKiZ/Xkk7HQldjWS7ig==
=gTQM
-----END PGP SIGNATURE-----

Changed in duplicity:
importance: Undecided → Medium
Revision history for this message
Thomas Hamilton Lipscomb (hari-seldon) wrote (last edit ):
Download full text (3.2 KiB)

QUESTION: How do I delete the corrupted Deja Dup backup to fix this bug? Which files do I delete? I see 3 folders in my backup drive:
$RECYCLE.BIN
System Volume Information
thomas-G752VL (my backup folder)
What about deleting ~/.cache/deja-dup/

I also have this bug. I think it happened when my laptop froze and I forced a shutdown. Even though I think Deja Dup was not backing up at the time that may have corrupted the backup.

GPGError: GPG Failed, see log below:
===== Begin GnuPG log =====
gpg: no valid OpenPGP data found.
gpg: decrypt_message failed: Unknown system error
===== End GnuPG log =====

1. The distribution of Linux you're using:
Ubuntu 20.04.3 LTS

2. The version of deja-dup and duplicity:
deja-dup 40.7-0ubuntu1
duplicity 0.8.11.1612-1

3. The file /tmp/deja-dup.gsettings after running the following line (you may want to scrub the file of any incriminating file names or details):
org.gnome.DejaDup exclude-list ['$TRASH', '$DOWNLOAD']
org.gnome.DejaDup allow-metered false
org.gnome.DejaDup root-prompt true
org.gnome.DejaDup periodic-period 1
org.gnome.DejaDup include-list ['/home/thomas', '/mnt/M2DATA/VirtualBoxVMs']
org.gnome.DejaDup prompt-check '2020-11-03T15:35:13+00'
org.gnome.DejaDup periodic true
org.gnome.DejaDup delete-after 0
org.gnome.DejaDup last-restore ''
org.gnome.DejaDup last-run '2021-10-06T17:35:36+00'
org.gnome.DejaDup full-backup-period 90
org.gnome.DejaDup last-backup '2021-10-06T17:35:36+00'
org.gnome.DejaDup backend 'drive'
org.gnome.DejaDup nag-check '2021-08-05T03:36:41+00'
org.gnome.DejaDup.S3 folder 'thomas-G752VL'
org.gnome.DejaDup.S3 bucket ''
org.gnome.DejaDup.S3 id ''
org.gnome.DejaDup.Rackspace container 'thomas-G752VL'
org.gnome.DejaDup.Rackspace username ''
org.gnome.DejaDup.OpenStack authurl ''
org.gnome.DejaDup.OpenStack tenant ''
org.gnome.DejaDup.OpenStack container 'thomas-G752VL'
org.gnome.DejaDup.OpenStack username ''
org.gnome.DejaDup.GCS folder 'thomas-G752VL'
org.gnome.DejaDup.GCS bucket ''
org.gnome.DejaDup.GCS id ''
org.gnome.DejaDup.Local folder 'thomas-G752VL'
org.gnome.DejaDup.Google folder 'thomas-G752VL'
org.gnome.DejaDup.GOA folder '$HOSTNAME'
org.gnome.DejaDup.GOA id ''
org.gnome.DejaDup.GOA type ''
org.gnome.DejaDup.GOA migrated false
org.gnome.DejaDup.Drive folder 'thomas-G752VL'
org.gnome.DejaDup.Drive uuid '5AE3-3A3B'
org.gnome.DejaDup.Drive name 'Samsung_T5'
org.gnome.DejaDup.Drive icon '. GThemedIcon drive-harddisk-solidstate-usb drive-harddisk-solidstate drive-harddisk drive drive-harddisk-solidstate-usb-symbolic drive-harddisk-solidstate-symbolic drive-harddisk-symbolic drive-symbolic'
org.gnome.DejaDup.File path ''
org.gnome.DejaDup.File relpath @ay []
org.gnome.DejaDup.File name ''
org.gnome.DejaDup.File migrated true
org.gnome.DejaDup.File type 'normal'
org.gnome.DejaDup.File uuid ''
org.gnome.DejaDup.File short-name ''
org.gnome.DejaDup.File icon ''
org.gnome.DejaDup.Remote folder 'thomas-G752VL'
org.gnome.DejaDup.Remote uri ''

4. The file /tmp/deja-dup.log after running the appropriate line below and replicating the problem (you may want to scrub the log of any incriminating file names or details):

 * If you're having problems backing up:
    DEJA_DUP_DEBUG=1 ...

Read more...

Revision history for this message
Kenneth Loafman (kenneth-loafman) wrote :

OK, from the description and the error message 'Unknown system error' I'm sure a backup file in the backup set is corrupted. There are dozens of reasons for file corruption not having to do with software malfunction. We need reproducible scenarios to find the malfunction if it's software.

To work around it, remove the last full or incremental backup from local cache and remote store. First find the manifest file, i.e. duplicity-full.20210826T184016Z.manifest.gpg, copy the timedate portion,20210826T184016Z, then:

$ rm <local-cache-path>/*20210826T184016Z*
$ <cli-tool-for-remote> rm *20210826T184016Z*

This will clean out the bad backup.

WARNING: on incremental backups make sure you do not remove a backup in the middle of the chain or you will break the chain and recovery will be impossible.

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

Duplicates of this bug

Other bug subscribers