Re: [Duplicity-talk] Duplicity using 1.5 TB storage and loosing incremental backups?

[Remy van Elst]

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



On 05/29/2015 12:58 PM, address@hidden wrote:
> On 29.05.2015 12:44, Remy van Elst wrote:
>> 
>> 
>> On 05/29/2015 12:35 PM, address@hidden wrote:
>>> On 29.05.2015 04:41, Remy van Elst wrote:
>>>> 
>>>> 
>>>> On 05/29/2015 12:25 AM, address@hidden wrote:
>>>>> please do not top post if the answer was posted at the
>>>>> bottom.. i will continue below
>>>> 
>>>>> On 28.05.2015 19:47, Remy van Elst wrote:
>>>>>> Here's the first 31000 lines of the log: 
>>>>>> https://e75f5515c4f249ffa1122853af811b3e.objectstore.eu/duplicity
/d
>>
>>>>>> 
up
>>>> 
>>>>>> 
>> lic
>>>>>> 
>>>>>> 
>>>> ity.txt
>>>>>> 
>>>>>> After these, it is all lines comparing the files on the 
>>>>>> machine. That is still running. Is this helpfull?
>>>>>> 
>>>>>> On 05/28/2015 03:54 PM, address@hidden wrote:
>>>>>>> On 28.05.2015 15:28, Remy van Elst wrote:
>>>>>>>> Any suggestions or other help?
>>>>>>>> 
>>>>>>>> On 05/25/2015 11:04 AM, Remy van Elst wrote:
>>>>>>>>> Duplicity seems to loose it's status when trying to
>>>>>>>>> do a incremental backup set over 14 days. The
>>>>>>>>> backup has been running for a while now but it is
>>>>>>>>> using about 1.5 TB of backend storage since 2
>>>>>>>>> weeks. It is going to an Openstack swift object
>>>>>>>>> store as backend.
>>>>>>>> 
>>>>>>>>> This is the command line:
>>>>>>>> 
>>>>>>>>> duplicity --asynchronous-upload --verbosity 9 
>>>>>>>>> --log-file /var/log/duplicity.log --volsize 25 
>>>>>>>>> --tempdir="/tmp" 
>>>>>>>>> --file-prefix="vps1.sparklingclouds.nl." 
>>>>>>>>> --name="vps1.sparklingclouds.nl." 
>>>>>>>>> --exclude-device-files 
>>>>>>>>> --exclude-globbing-filelist=/etc/duplicity-backup/exclude.conf
>>>>>>>>>
>>>>>>>>>
>>>>
>>>>>>>>>
>>
>>>>>>>>> 
- --full-if-older-than="14D" --no-encryption  /
>>>>>>>>> swift://duplicity-backup
>>>>>>>> 
>>>>>>>>> This is what caught my eye in the verbose log
>>>>>>>>> file:
>>>>>>>> 
>>>>>>>>> File 
>>>>>>>>> vps1.sparklingclouds.nl.duplicity-full.20150430T034939Z.vol166
.d
>>
>>>>>>>>> 
if
>>>> 
>>>>>>>>> 
>> ft
>>>>>> 
>>>>>>>>> 
>>>> ar
>>>>>>>> 
>>>>>>>>> 
>>>>>> .g
>>>>>>>> 
>>>>>>>> 
>>>>>>>> z
>>>>>>>>> is part of known set File 
>>>>>>>>> vps1.sparklingclouds.nl.duplicity-full.20150430T034939Z.vol166
0.
>>
>>>>>>>>> 
di
>>>> 
>>>>>>>>> 
>> ff
>>>>>> 
>>>>>>>>> 
>>>> ta
>>>>>>>> 
>>>>>>>>> 
>>>>>> r.
>>>>>>>> 
>>>>>>>> 
>>>>>>>> gz
>>>>>>>>> is part of known set Found backup chain [Tue Mar 24
>>>>>>>>>  14:42:44 2015]-[Tue Mar 24 14:42:44 2015] Last
>>>>>>>>> full backup is too old, forcing full backup
>>>>>>>> 
>>>>>>>> 
>>>>>>>>> The last full backup is from yesterday, and it
>>>>>>>>> should only do a full backup every 14 days.
>>>>>>>> 
>>>>>>>>> When I do a collection status it seems all the 
>>>>>>>>> incremental backups are gone:
>>>>>>>> 
>>>>>>>>> Do note that I've got a wrapper script around 
>>>>>>>>> duplicity which outputs the status, storage used
>>>>>>>>> and config settings:
>>>>>>>> 
>>>>>>>> 
>>>>>>>>> # Hostname: vps1.sparklingclouds.nl # IP:
>>>>>>>>> 192.0.2.10 # Storage used: 1.5T # Full backups to
>>>>>>>>> keep: 4 # Create full backup if last full backup is
>>>>>>>>> older than: 14D 
>>>>>>>>> ----------------------------------------- #
>>>>>>>>> Duplicity collection status: # Local and Remote
>>>>>>>>> metadata are synchronized, no sync needed. # Last
>>>>>>>>> full backup date: Mon May 25 10:48:16 2015 #
>>>>>>>>> Collection Status # ----------------- # Connecting
>>>>>>>>> with backend: BackendWrapper # Archive dir: 
>>>>>>>>> /root/.cache/duplicity/vps1.sparklingclouds.nl. #
>>>>>>>>> Found 4 secondary backup chains. # Secondary chain
>>>>>>>>> 1 of 4: # ------------------------- # Chain start
>>>>>>>>> time: Tue Mar 24 14:42:44 2015 # Chain end time:
>>>>>>>>> Tue Mar 24 14:42:44 2015 # Number of contained
>>>>>>>>> backup sets: 1 # Total number of contained volumes:
>>>>>>>>> 3009 #  Type of backup set: Time: Num volumes: #
>>>>>>>>> Full Tue Mar 24 14:42:44 2015 3009 # 
>>>>>>>>> ------------------------- # Secondary chain 2 of 4:
>>>>>>>>> # ------------------------- # Chain start time: Wed
>>>>>>>>> Apr 8 05:49:18 2015 # Chain end time: Wed Apr  8
>>>>>>>>> 05:49:18 2015 # Number of contained backup sets: 1
>>>>>>>>> # Total number of contained volumes: 3104 #  Type
>>>>>>>>> of backup set: Time:      Num volumes: #
>>>>>>>>> Full Wed Apr 8 05:49:18 2015 3104 # 
>>>>>>>>> ------------------------- # Secondary chain 3 of 4:
>>>>>>>>> # ------------------------- # Chain start time: Thu
>>>>>>>>> Apr 16 05:49:37 2015 # Chain end time: Thu Apr 16
>>>>>>>>> 05:49:37 2015 # Number of contained backup sets: 1
>>>>>>>>> # Total number of contained volumes: 3128 #  Type
>>>>>>>>> of backup set: Time:      Num volumes: #
>>>>>>>>> Full Thu Apr 16 05:49:37 2015 3128 #
>>>>>>>>> ------------------------- # Secondary chain 4 of 4:
>>>>>>>>> # ------------------------- # Chain start time: Thu
>>>>>>>>> Apr 30 05:49:39 2015 # Chain end time: Thu Apr 30
>>>>>>>>> 05:49:39 2015 # Number of contained backup sets: 1
>>>>>>>>> # Total number of contained volumes: 736 # Type of
>>>>>>>>> backup set: Time:      Num volumes: # Full Thu Apr
>>>>>>>>> 30 05:49:39 2015 736 # ------------------------- #
>>>>>>>>> Found primary backup chain with matching signature
>>>>>>>>> chain: # ------------------------- # Chain start
>>>>>>>>> time: Mon May 25 10:48:16 2015 # Chain end time:
>>>>>>>>> Mon May 25 10:48:16 2015 # Number of contained
>>>>>>>>> backup sets: 1 # Total number of contained volumes:
>>>>>>>>> 0 #  Type of backup set: Time:      Num volumes: #
>>>>>>>>> ------------------------- # No orphaned or
>>>>>>>>> incomplete backup sets found.
>>>>>>>> 
>>>>>>>> 
>>>>>>>>> Why does this happen and how can I get this back to
>>>>>>>>>  normal?
>>>>>>>> 
>>>>>> 
>>>>>>> which duplicity version?
>>>>>> 
>>>>>>> please post (zip attach)or pastebin the complete
>>>>>>> console output of a max.verbosity '-v9' status run.
>>>>>>> obfuscate strings in it you deem private.
>>>>>> 
>>>>>>> ..ede/duply.net
>>>>>> 
>>>> 
>>>>> the log states
>>>> 
>>>>> --> DEBUG 1 . Found backup chain [Tue Mar 24 14:42:44 
>>>>> 2015]-[Tue Mar 24 14:42:44 2015]
>>>> 
>>>>> DEBUG 1 . Found backup chain [Wed Apr  8 05:49:18
>>>>> 2015]-[Wed Apr  8 05:49:18 2015]
>>>> 
>>>>> DEBUG 1 . Found backup chain [Thu Apr 16 05:49:37
>>>>> 2015]-[Thu Apr 16 05:49:37 2015]
>>>> 
>>>>> DEBUG 1 . Found backup chain [Thu Apr 30 05:49:39
>>>>> 2015]-[Thu Apr 30 05:49:39 2015]
>>>> 
>>>>> NOTICE 1 . Last full backup date: Thu Apr 30 05:49:39 2015
>>>> 
>>>>> NOTICE 1 . Last full backup is too old, forcing full
>>>>> backup <--
>>>> 
>>>>> which sounds reasonable.. there are no incremental backups
>>>>> on your backend.
>>>> 
>>>> There should be. There runs a cronjob every night with the
>>>> same command as I ran manually. It runs for about 3 to 5
>>>> hours just as now, and then fails. The backend keeps growing
>>>> in size.
>>>> 
>>>> 
>> 
>>> ok, please ensure that your manual full went through via
>>> 'status' command.
>> 
>> 
>> It is not listed in the output of collection-status. Should I
>> still run the backup again?
>> 
>>> then rerun the same backup cmd line you sent me before and send
>>> me the output up until the first 'Getting delta of ...'
>>> message.
>> 
> 
> weird, can you send a list of the files on your backend? looks like
> not all were uploaded successfully.
> 
> next step would be to try latest duplicity 0.6.x . maybe some bug
> crept in the 0.7 development line. here is a short howto install
> from tarball to a local folder (under INSTALL MULTIPLE VERSIONS). 
> http://duply.net/wiki/index.php/Duply-documentation you might wanna
> to install to /usr/local/duplicity-0.6.x instead.

I've tried the same machine backup, same command, with 0.6.26, and
that gives the same result as 0.7.03. Backend is now at 1.9 TB,
however a collection status does not show the files afterwards. I have
the -v9 logging if needed.

I also tried restoring a file, both with 0.6.26 and 0.7.03, and I do
get te file from 30 april back (the last full backup the
collection-status shows as succeeded).

I did notice a lot of large signature files:

# ls -larSh /root/.cache/duplicity/vps1.example.org./
- -rw-r--r-- 1 root root 827K May 27 15:21
vps1.example.org.duplicity-full.20150324T134244Z.manifest
- -rw-r--r-- 1 root root 857K May 27 15:21
vps1.example.org.duplicity-full.20150408T034918Z.manifest
- -rw-r--r-- 1 root root 864K May 27 15:21
vps1.example.org.duplicity-full.20150416T034937Z.manifest
- -rw-r--r-- 1 root root 888K May 27 15:21
vps1.example.org.duplicity-full.20150430T034939Z.manifest
- -rw-r--r-- 1 root root 1.3G May 27 10:50
vps1.example.org.duplicity-full-signatures.20150324T134244Z.sigtar.gz
- -rw-r--r-- 1 root root 1.3G May 27 11:07
vps1.example.org.duplicity-full-signatures.20150408T034918Z.sigtar.gz
- -rw-r--r-- 1 root root 1.3G May 27 11:22
vps1.example.org.duplicity-full-signatures.20150416T034937Z.sigtar.gz
- -rw-r--r-- 1 root root 1.3G May 27 11:39
vps1.example.org.duplicity-full-signatures.20150430T034939Z.sigtar.gz
- -rw-r--r-- 1 root root 1.3G May 27 11:57
vps1.example.org.duplicity-full-signatures.20150515T035013Z.sigtar.gz
- -rw-r--r-- 1 root root 1.3G May 27 12:15
vps1.example.org.duplicity-full-signatures.20150516T035123Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 12:32
vps1.example.org.duplicity-full-signatures.20150517T035207Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 12:51
vps1.example.org.duplicity-full-signatures.20150518T035213Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 13:11
vps1.example.org.duplicity-full-signatures.20150519T035027Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 13:31
vps1.example.org.duplicity-full-signatures.20150520T035034Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 13:50
vps1.example.org.duplicity-full-signatures.20150521T034933Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 14:08
vps1.example.org.duplicity-full-signatures.20150522T035150Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 14:27
vps1.example.org.duplicity-full-signatures.20150523T035052Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 14:45
vps1.example.org.duplicity-full-signatures.20150524T034921Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 15:04
vps1.example.org.duplicity-full-signatures.20150525T034942Z.sigtar.gz
- -rw-r--r-- 1 root root 1.4G May 27 15:21
vps1.example.org.duplicity-full-signatures.20150526T034916Z.sigtar.gz
- -rw------- 1 root root 1.4G May 28 20:30
vps1.example.org.duplicity-full-signatures.20150528T135952Z.sigtar.gz
- -rw------- 1 root root 1.5G May 29 18:30
vps1.example.org.duplicity-full-signatures.20150529T114911Z.sigtar.gz


Could that be an issue?

> 
> ..ede/duply.net
> 
> _______________________________________________ Duplicity-talk
> mailing list address@hidden 
> https://lists.nongnu.org/mailman/listinfo/duplicity-talk
> 
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQEcBAEBCAAGBQJVaLY8AAoJECtnVb0bf4jcNlkH/R5m9keaZpOgj12M0XrzIE38
MYiiul0KYwqJhBbE20Bt+LABfg6bzlc8D6WFHGfceBw+c9aOW2XhpX9+zLq0AScA
O1tVqQ4REDRz9P/KEXa3BM0LCfU4SEgBHTgMQf8L+siYnK8ztr2+REGcZaZgu/8x
AKe0h9cN94tIlplVtxFjSFGY7qQ5D8Uy61pV2RzAXX7TvO6al4WITS9xhImi08pc
A2QK75fEVfvsTHCxE19MBQ4pgA1MOSfsLQQttjKomfy3VVHzaoVNI0FAOJve+E56
Sj603BjGhfaVZOVK7lNsDzzXG/9NiaSmipgMQWh0I1woUvPcnufs0XIzgDNxce0=
=stn3
-----END PGP SIGNATURE-----

0x1B7F88DC.asc
Description: application/pgp-keys

0x1B7F88DC.asc.sig
Description: PGP signature