0.6.25->0.7.05 fatal performance regression

[Jan Kratochvil]

Running on updated Fedora 23 x86_64:
duplicity-0.7.05-1.fc23.x86_64
21:57:20 lstat("/etc/rc.d/rc4.d/K74gfs2", {st_mode=S_IFLNK|0777, st_size=14, ...}) = 0
21:57:20 readlink("/etc/rc.d/rc4.d/K74gfs2", "../init.d/gfs2", 4096) = 14
21:57:24 lstat("/etc/rc.d/rc4.d/K85ebtables", {st_mode=S_IFLNK|0777, st_size=18, ...}) = 0
21:57:24 readlink("/etc/rc.d/rc4.d/K85ebtables", "../init.d/ebtables", 4096) = 18
21:57:28 lstat("/etc/rc.d/rc4.d/K90network", {st_mode=S_IFLNK|0777, st_size=17, ...}) = 0
21:57:28 readlink("/etc/rc.d/rc4.d/K90network", "../init.d/network", 4096) = 17
21:57:33 lstat("/etc/rc.d/rc4.d/S01sandbox", {st_mode=S_IFLNK|0777, st_size=17, ...}) = 0
21:57:33 readlink("/etc/rc.d/rc4.d/S01sandbox", "../init.d/sandbox", 4096) = 17
 - it was running for 2 hours and reading each file for 4 seconds is unusable.
  26.69% duplicity libpython2.7.so.1.0 [.] PyEval_EvalFrameEx
   4.73% duplicity libc-2.22.so [.] vfprintf
   3.70% duplicity libpython2.7.so.1.0 [.] lookdict_string
   3.70% duplicity libpython2.7.so.1.0 [.] PyUnicodeUCS4_DecodeUTF8Stateful
   3.47% duplicity libpython2.7.so.1.0 [.] PyString_Format
   3.11% duplicity libpython2.7.so.1.0 [.] _PyObject_GenericGetAttrWithDict
   3.09% duplicity libpython2.7.so.1.0 [.] PyEval_EvalCodeEx
   1.85% duplicity libpython2.7.so.1.0 [.] convertitem
   1.85% duplicity libpython2.7.so.1.0 [.] PyFrame_New

After downgrading just the package duplicity to 0.6.25 the backup was successfuly done in 4 minutes, like always before:
duplicity-0.6.25-3.fc21.x86_64
--------------[ Backup Statistics ]--------------
StartTime 1447707702.06 (Mon Nov 16 22:01:42 2015)
EndTime 1447707987.63 (Mon Nov 16 22:06:27 2015)
ElapsedTime 285.57 (4 minutes 45.57 seconds)
SourceFiles 92925
SourceFileSize 2516870978 (2.34 GB)
NewFiles 51428
NewFileSize 179314732 (171 MB)
DeletedFiles 22722
ChangedFiles 1196
ChangedFileSize 284383140 (271 MB)
ChangedDeltaSize 0 (0 bytes)
DeltaEntries 75346
RawDeltaSize 210169249 (200 MB)
TotalDestinationSizeChange 54708267 (52.2 MB)
Errors 0
-------------------------------------------------
11G host1-backup

Unaware how to do Python-source-level performance monitoring.

duplicity --archive-dir /root/backup/host2-signature2 --allow-source-mismatch --encrypt-key 1F0D6D7B --sign-key 1F0D6D7B --exclude-other-filesystems --exclude-filelist /tmp/host2-run.rpmsafe --exclude /var/spool/squid [...] --exclude '/usr/lib/jvm/*/jre/lib/amd64/server/classes.jsa' / file:///host1/root/backup/host2-backup2
3.0G /root/backup/host2-signature2
68G /host1/root/backup/host2-backup2
wc -l:
558303 /tmp/host2-run.rpmsafe

python-2.7.10-8.fc23.x86_64
Linux ext4

[Jan Kratochvil (jan-kratochvil)]

When I remove that --exclude-filelist /tmp/host2-run.rpmsafe with 558303 entries the performance is OK even with 0.7.05. That worked fine in 0.6.25.

The reason for it is to exclude unchanged system files which make no sense to backup:
rpm -Vva 2>/dev/null|perl -ne 's/^[.]{7}[.T][.] . // or next;chomp;use Cwd qw(realpath);print "- ".realpath($_)."\n" if -f;' >/tmp/host2-run.rpmsafe