Re: Dar architecture questions

Denis Corbin <[email protected]> Tue, 16 Oct 2012 21:42:59 +0200
Newsgroups gmane.comp.sysutils.backup.dar.general
Message-ID <[email protected]>
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 16/10/2012 17:07, Kevin Wormington wrote:
>> Le 16/10/2012 00:30, Kevin Wormington a =E9crit :
>>> I strace'd the small backup (14k files) both with and without
>>> --disable-special-alloc and it appears the difference is in the huge
>>> number of rt_sigprocmask calls made by special-alloc.
>>
>> interesting... I have tests currently running on my side...

The so far ran tests also reported huge number of rt_sigprocmask calls
but they did not have a big impact (see below). I do not know yet
whether this is caused by the --empty argument or by the 64 bits flavor
of dar used here. I will do additional tests on Saturday. The used
system is a Debian stable one with a slightly tuned kernel (kernel with
less modules and many unused features disabled, but I do not see how
this may have any concern here).

# ./configure --enable-mode=3D64 && make
  [...]
# time strace -c src/dar_suite/dar -c test -R /var/spool --empty
 --------------------------------------------
 87498 inode(s) saved
   including 77600 hard link(s) treated
 0 inode(s) changed at the moment of the backup and could not be saved
properly
 0 byte(s) have been wasted in the archive to resave changing files
 0 inode(s) not saved (no inode/file change)
 65456 inode(s) failed to be saved (filesystem error)
 0 inode(s) ignored (excluded by filters)
 0 inode(s) recorded as deleted from reference backup
 --------------------------------------------
 Total number of inode(s) considered: 152954
 --------------------------------------------
 EA saved for 0 inode(s)
 --------------------------------------------

% time     seconds  usecs/call     calls    errors syscall
- ------ ----------- ----------- --------- --------- ----------------
 75.14    4.029661          12    347083           read
 23.03    1.235008          24     51899           getdents
  1.42    0.076154           0    292562           lstat
  0.19    0.010107           0  10931327           rt_sigprocmask
  0.08    0.004211           0    462010           llistxattr
  0.08    0.004111          10       421           brk
  0.05    0.002876           0    153402     65900 open
  0.01    0.000451           0     87502           close
  0.00    0.000203           0     65907           write
  0.00    0.000118           0     63805           lseek
  0.00    0.000008           0        18           mprotect
  0.00    0.000000           0        19           fstat
  0.00    0.000000           0        43           mmap
  0.00    0.000000           0         5           munmap
  0.00    0.000000           0         8           rt_sigaction
  0.00    0.000000           0        10           ioctl
  0.00    0.000000           0        15        15 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         3           fcntl
  0.00    0.000000           0         7           getcwd
  0.00    0.000000           0         8           readlink
  0.00    0.000000           0         1           gettimeofday
  0.00    0.000000           0         1           getrlimit
  0.00    0.000000           0         3           getuid
  0.00    0.000000           0         1           geteuid
  0.00    0.000000           0         1           getppid
  0.00    0.000000           0         1           mlock
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         5         1 futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
- ------ ----------- ----------- --------- --------- ----------------
100.00    5.362908              12456071     65916 total
169.502u 39.310s 26:47.77 12.9% 0+0k 0+0io 0pf+0w
#

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D

I get a quite equivalent time of execution without special-alloc (I've
not checked memory usage):

# ./configure --enable-mode=3D64 --disable-special-alloc && make
  [...]
# time strace -c src/dar_suite/dar -c test -R /var/spool --empty

 --------------------------------------------
 87509 inode(s) saved
   including 77612 hard link(s) treated
 0 inode(s) changed at the moment of the backup and could not be saved
properly
 0 byte(s) have been wasted in the archive to resave changing files
 0 inode(s) not saved (no inode/file change)
 65477 inode(s) failed to be saved (filesystem error)
 0 inode(s) ignored (excluded by filters)
0 inode(s) recorded as deleted from reference backup
 --------------------------------------------
 Total number of inode(s) considered: 152986
 --------------------------------------------
 EA saved for 0 inode(s)
 --------------------------------------------

% time     seconds  usecs/call     calls    errors syscall
- ------ ----------- ----------- --------- --------- ----------------
 74.77    4.140217          12    347093           read
 23.71    1.312996          25     51899           getdents
  1.28    0.070775           0    292607           lstat
  0.15    0.008279           0    462094           llistxattr
  0.06    0.003357           0    153441     65936 open
  0.02    0.000846           0    509853           rt_sigprocmask
  0.01    0.000547           0     87505           close
  0.01    0.000363           0     65943           write
  0.00    0.000203           0     63808           lseek
  0.00    0.000000           0        19           fstat
  0.00    0.000000           0        43           mmap
  0.00    0.000000           0        18           mprotect
  0.00    0.000000           0         5           munmap
  0.00    0.000000           0       734           brk
  0.00    0.000000           0         8           rt_sigaction
  0.00    0.000000           0        10           ioctl
  0.00    0.000000           0        15        15 access
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         3           fcntl
  0.00    0.000000           0         7           getcwd
  0.00    0.000000           0         8           readlink
  0.00    0.000000           0         1           gettimeofday
  0.00    0.000000           0         1           getrlimit
  0.00    0.000000           0         3           getuid
  0.00    0.000000           0         1           geteuid
  0.00    0.000000           0         1           getppid
  0.00    0.000000           0         1           mlock
  0.00    0.000000           0         1           arch_prctl
  0.00    0.000000           0         5         1 futex
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           set_robust_list
- ------ ----------- ----------- --------- --------- ----------------
100.00    5.537583               2035130     65952 total


161.218u 33.406s 24:50.65 13.0% 0+0k 0+0io 0pf+0w
#

> I have also included a patch below that prints some status info before =

> the memory frees/on-fly-catalog since these can take several minutes to =

> complete after the archive stats print.
> =

> diff -c dar.cpp.orig dar.cpp
> *** dar.cpp.orig	2012-10-16 09:51:37.157093322 -0500
> --- dar.cpp	2012-10-16 09:55:24.467092154 -0500
> ***************
> *** 270,275 ****
> --- 270,277 ----
> =

>    		    // making some room in memory
> =

> + 		if(!param.quiet)
> + 		    dialog.warning(gettext("Making room in memory..."));

Here I would display this message only if -v option has been set
(param.info_details is true)

>    		if(arch !=3D NULL)
>    		{
>    		    delete arch;
> ***************
> *** 295,301 ****
>    			throw SRC_BUG;
>    		    if(param.op =3D=3D create)
>    		    {
> ! 			if(param.info_details)
>    			    dialog.warning(gettext("Now performing on-fly isolation..."));
>    			if(cur =3D=3D NULL)
>    			    throw SRC_BUG;
> --- 297,303 ----
>    			throw SRC_BUG;
>    		    if(param.op =3D=3D create)
>    		    {
> ! 		        if(!param.quiet)
>    			    dialog.warning(gettext("Now performing on-fly isolation..."));

I completely agree with this change, I take it as is.

>    			if(cur =3D=3D NULL)
>    			    throw SRC_BUG;
> ***************
> *** 609,614 ****
> --- 611,618 ----
>    	}
>    	catch(...)
>    	{
> + 	    if(!param.quiet)
> + 	        dialog.warning(gettext("Final memory cleanup..."));

I would not report here anything, because this statement is reached is
only reached in case of major problem. I would not add the risk to hide
a problem by another one.

>    	    if(arch !=3D NULL)
>    	    {
>    		delete arch;
> ***************
> *** 626,631 ****
> --- 630,637 ----
>    	    }
>    	    throw;
>    	}
> + 	if(!param.quiet)
> + 	    dialog.warning(gettext("Final memory cleanup..."));

Here I agree but only when param.info_details is true

>    	if(arch !=3D NULL)
>    	{
>    	    delete arch;
> =


Your patch (adapted) is now in GIT on the branch_2.4.x :)

> =

>> However, I must document the result of your tests (and mine) about this
>> subject. This might be of interest for the ones that are not concerned
>> by memory limitation and want to speed up their backup.
>>
>>   Perhaps someone else on the list that
>>> makes large backups either in size or number of files could confirm if
>>> they see the same behavior.
>>>
> =

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.10 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iQIVAwUBUH24uwgxsL0D2LGCAQLCHxAAtOubNT2HF9L47bdQrZtCZ4BxOoM7VVx1
denZGca1ZokPDxJGeEweVdAOXumsGVoVRnnERPuBTa+Fd9jezISe13yc14cJ3iKk
jbgiii6mXDKi4AU2vh8QnY1VRUIIzkZZr7gDQ6Stcnim3nb061+yx2o/sEMj07L7
uwybe8klnnrA/hKZkXfl1oZqCNpdk4Trp7BogWxtwZhjPoGWnVQe0joNkrn7gdYU
bPH5rjdl60lwDNtjthUgtVHgFGH7zCgwMVXwIyk/U7xa1nnTlZW3bcjnBzEUQbzn
eRlMTg2sQHzpkW9cQM+EkgpNNjwsXot2Nx0E0ov2Ee2N24WGGFo9mI1GSj/4OMZs
hvj4giiakZt3t0Fn+Ij8MbFYE0hXq8CBvcTu9wh4cpIqapiIg0m9b+3xgi38ZZp5
8zFTUgB+r/d+VzucfXjOkZDx00Hw7s9aoDp8dsRVZ0YwS5Hm3632jwJO3L/F8l0O
C9IJ3Ut7nnTtBg3e8UtWI7D6Y1EB2IfAzwYbZzDctFVmWhdIzyo8n26CHf0pMFDj
PdDriuprlT400t4pgYsodUu6KYwIFYNGmFOAyJJsL0X2O6/NJRpJWgmsd7TZDwQB
fGKqUrPtyCefbZWmbE+TaOh/tb3N4lZrULpnaUSlp9r8z6EabM0BTivGFjmjShlj
je2+2GzoHc0=3D
=3DdMdR
-----END PGP SIGNATURE-----

---------------------------------------------------------------------------=
---
Don't let slow site performance ruin your business. Deploy New Relic APM
Deploy New Relic app performance management and know exactly
what is happening inside your Ruby, Python, PHP, Java, and .NET app
Try New Relic at no cost today and get our sweet Data Nerd shirt too!
http://p.sf.net/sfu/newrelic-dev2dev