Re: [rdiff-backup-users] Slowdown from a few mins to >8 hours backup time due to one large log file

[Dominic Raferd]

That seems extraordinarily slow for rdiff-backup to backup a text file 
to a local disk, even a file that is 3.9GB. Was the file changing 
(additional log entries, maybe?) while rdiff-backup was trying to back 
it up?

Dominic

On 01/02/2011 06:33, Patrick Nagel wrote:
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA1
>
> Hi,
>
> I have rdiff-backup running nightly on my home server. It keeps a versioned
> backup of all relevant data on the second HDD.
>
> I didn't monitor the backup too closely, because I didn't get any alarm that
> the backup had failed. Today I looked at the logs, and noticed, that the
> backup time went up from a few minutes a while back, to>8 hours.
>
> 2010-11-23T03:00: ElapsedTime 277.51 (4 minutes 37.51 seconds)
> 2010-11-24T03:00: ElapsedTime 438.69 (7 minutes 18.69 seconds)
> 2010-11-25T03:00: ElapsedTime 321.99 (5 minutes 21.99 seconds)
> 2010-11-26T03:00: ElapsedTime 2848.57 (47 minutes 28.57 seconds)
> 2010-11-27T03:00: ElapsedTime 3358.68 (55 minutes 58.68 seconds)
> 2010-11-28T03:00: ElapsedTime 2876.65 (47 minutes 56.65 seconds)
> 2010-11-29T03:00: ElapsedTime 2834.06 (47 minutes 14.06 seconds)
> 2010-11-30T03:00: ElapsedTime 3553.56 (59 minutes 13.56 seconds)
> 2010-12-01T03:00: ElapsedTime 3549.67 (59 minutes 9.67 seconds)
> 2010-12-02T03:00: ElapsedTime 3555.71 (59 minutes 15.71 seconds)
> [...]
> 2010-12-10T03:00: ElapsedTime 8015.67 (2 hours 13 minutes 35.67 seconds)
> 2010-12-11T03:00: ElapsedTime 9066.51 (2 hours 31 minutes 6.51 seconds)
> [...]
> 2011-01-30T03:00: ElapsedTime 28665.77 (7 hours 57 minutes 45.77 seconds)
> 2011-01-31T03:00: ElapsedTime 31093.79 (8 hours 38 minutes 13.79 seconds)
> 2011-02-01T03:00: ElapsedTime 31489.30 (8 hours 44 minutes 49.30 seconds)
>
> By tracking what rdiff-backup was doing ('strace -p<rdiff-backup's PID>' on
> another terminal), I quickly found out that it spent huge amounts of time
> diffing one big file. The file was a log file, written to by a script I
> wrote just around the time the backup time started to increase. I guess I
> overdid it with the logging a bit, since the log file had 3.9 GB by now.
> After removing the oversized log file, the backup times dropped back to
> normal again:
>
> 2011-02-01T12:22: ElapsedTime 685.87 (11 minutes 25.87 seconds)
> 2011-02-01T13:57: ElapsedTime 468.25 (7 minutes 48.25 seconds)
>
> Maybe the diff-algorithm used can be improved to not take so long on large
> text files, especially since this one only grew into one direction, and the
> other content never changed.
>
> In any case, I'm glad the backup doesn't take the whole night any more.
>
> Patrick.