Differences

This shows you the differences between two versions of the page.

--- project:rsnapshot-backup [2017/08/10 17:48] – 95.208.70.15
+++ project:rsnapshot-backup [2018/01/23 14:04] (current) – [show how much time individual parts of the backup take] 88.65.214.4
@@ Line 104: / Line 104: @@
 as Extended Attributes.
-Rsync needs ''--acls --xattrs'' to handle ACLs and XATTRs.
+Rsync needs ''%%--%%acls %%--%%xattrs'' to handle ACLs and XATTRs.
 These parameters have to be added per backup job.
 The copy & paste code below adds these. It extends
-existing lines beginning with ''rsync_long_args ..'' or inserts ''rsync_long_args\t\t--delete --numeric-ids --relative --delete-excluded --acls --xattrs'' into the files ''/etc/rsnapshot-backup.d/conf.*'' after the last line
+existing lines beginning with ''rsync_long_args ..'' or inserts ''rsync_long_args\t\t%%--%%delete %%--%%numeric-ids %%--%%relative %%--%%delete-excluded %%--%%acls %%--%%xattrs'' into the files ''/etc/rsnapshot-backup.d/conf.*'' after the last line
 containing ''rsync_long_args'' which is usually found in a comment block.
 If these comments don't exist the code throws an error leaving it to the admin to insert the line into the file.
@@ Line 170: / Line 170: @@
 The situation:
-  * --fake-super stores information requiring privileges (e.g. capabilities, ownership) in extended attributes on the backup volume
+  * ''%%--%%fake-super'' stores information requiring privileges (e.g. capabilities, ownership) in extended attributes on the backup volume
   * notably **symlinks** are stored as **files** with the file content being the original link destination and additional metadata is stored inside an extended attribute e.g. ''user.rsync.%stat="120777 0,0 0:0"''
-To restore contents from this kind of backup you again need ''--fake-super'':
+To restore contents from this kind of backup you again need ''%%--%%fake-super'':
-  * use **''--fake-super''** for a **push** restore
+  * use **''%%--%%fake-super''** for a **push** restore
-  * use **''-M --fake-super''** for a **pull** restore
+  * use **''-M %%--%%fake-super''** for a **pull** restore
 ==== special considerations using a secondary backup server ====
@@ Line 183: / Line 183: @@
 backup clients) there are some things to consider on the secondary (ternary, etc) system(s):
-  * the default option **''--relative''** resp. **''-R''** has to be switched off. As the default options are ''--delete --numeric-ids --relative --delete-excluded'' you have to set ''rsync_long_args'' to ''--delete --numeric-ids --delete-excluded''.
+  * the default option **''%%--%%relative''** resp. **''-R''** has to be switched off. As the default options are ''%%--%%delete %%--%%numeric-ids %%--%%relative %%--%%delete-excluded'' you have to set ''rsync_long_args'' to ''%%--%%delete %%--%%numeric-ids %%--%%delete-excluded''.
-  * the conversion of critical metadata (xattrs, etc.) should have already been done by the primary backup server. So ''--fake-super'' does nothing helpful here, but is considered harmful (see below).
+  * the conversion of critical metadata (xattrs, etc.) should have already been done by the primary backup server. So ''%%--%%fake-super'' does nothing helpful here, but is considered harmful (see below).
-  * the converted metadata has to be replicated which is not done per default rsync/rsnapshot. Therefore ''--xattrs'' has to be called **twice** so rsync will replicate this information.
+  * the converted metadata has to be replicated which is not done per default rsync/rsnapshot. Therefore ''%%--%%xattrs'' has to be called **twice** so rsync will replicate this information.
-  * ''--fake-super'' and ''--xattrs --xattrs'' are mutual exclusive.
+  * ''%%--%%fake-super'' and ''%%--%%xattrs %%--%%xattrs'' are mutual exclusive.
-  * long story short: one a subsequent backup server use ''rsync_long_args'' [TABULATOR] ''--delete --numeric-ids --delete-excluded --hard-links --acls --xattrs --xattrs''
+  * long story short: on a subsequent backup server use ''rsync_long_args'' [TABULATOR] ''%%--%%delete %%--%%numeric-ids %%--%%delete-excluded %%--%%hard-links %%--%%acls %%--%%xattrs %%--%%xattrs''
 ==== draw a plot showing disk usage of a job ====
@@ Line 410: / Line 410: @@
 </code>
+==== show how much time individual parts of the backup took ====
+**rsnapshot-backup-timings**
+<code>
+#!/usr/bin/perl
+use strict;
+use POSIX;
+sub WAIT_FOR_RM    () { 1 };
+sub WAIT_FOR_MV0   () { 2 };
+sub WAIT_FOR_MVL   () { 3 };
+sub WAIT_FOR_CP    () { 4 };
+sub WAIT_FOR_RSYNC () { 5 };
+sub WAIT_FOR_TOUCH () { 6 };
+sub WAIT_FOR_END   () { 7 };
+sub decode_date ($) {
+        my ( $d ) = @_;
+        my ( $dd,$mmm,$yyyy,$hh,$mm,$ss ) = $d =~ m#(\d{2})/([A-Z][a-z][a-z])/(\d{4}):(\d{2}):(\d{2}):(\d{2})#;
+        my $m = {qw{Jan 1 Feb 2 Mar 3 Apr 4 May 5 Jun 6 Jul 7 Aug 8 Sep 9 Oct 10 Nov 11 Dec 12}}->{$mmm} - 1;
+        # print "$d = ( $yyyy,$mmm,$dd,$hh,$mm,$ss ) $m\n";
+        my $e = POSIX::mktime($ss, $mm, $hh, $dd, $m, $yyyy-1900);
+        # print scalar localtime $e,"\n";
+        return $e;
+}
+FILE: for my $filename ( @ARGV ) {
+        open F,$filename or do {
+                warn "Can't open '$filename': $!";
+                next FILE;
+        };
+        my $state = WAIT_FOR_RM;
+        my $d_rm;
+        my $d_mv0;
+        my $d_mvl;
+        my $d_cp;
+        my $d_rsync;
+        my $d_touch;
+        LINE: while (my $l = <F>) {
+                $state eq WAIT_FOR_RM and do {
+                        if ( $l =~ m#^\[(\d{2}/[A-Z][a-z][a-z]/\d{4}:\d{2}:\d{2}:\d{2})\] /bin/rm -rf # ) {
+                                my $d = $1;
+                                $d_rm = decode_date( $d ) ;
+                                $state = WAIT_FOR_MV0;
+                        }
+                        next LINE;
+                };
+                $state eq WAIT_FOR_MV0 and do {
+                #dev# print "L: $l";
+                        if ( $l =~ m#^\[(\d{2}/[A-Z][a-z][a-z]/\d{4}:\d{2}:\d{2}:\d{2})\] mv # ) {
+                                my $d = $1;
+                                $d_mv0 = decode_date( $d ) ;
+                                $state = WAIT_FOR_CP;
+                        }
+                        next LINE;
+                };
+                $state eq WAIT_FOR_CP and do {
+                #dev# print "L CP: $l";
+                        if ( $l =~ m#^\[(\d{2}/[A-Z][a-z][a-z]/\d{4}:\d{2}:\d{2}:\d{2})\] mv # ) {
+                                my $d = $1;
+                                $d_mvl = decode_date( $d ) ;
+                                $state = WAIT_FOR_CP;
+                        } elsif (  $l =~ m#^\[(\d{2}/[A-Z][a-z][a-z]/\d{4}:\d{2}:\d{2}:\d{2})\] /bin/cp # ) {
+                                my $d = $1;
+                                $d_cp = decode_date( $d ) ;
+                                $state = WAIT_FOR_RSYNC;
+                        }
+                        next LINE;
+                };
+                #dev# print "L: $l";
+                $state eq WAIT_FOR_RSYNC and do {
+                        if ( $l =~ m#^\[(\d{2}/[A-Z][a-z][a-z]/\d{4}:\d{2}:\d{2}:\d{2})\] /usr/bin/rsync # ) {
+                                my $d = $1;
+                                $d_rsync = decode_date( $d ) ;
+                                $state = WAIT_FOR_TOUCH;
+                        }
+                        next LINE;
+                };
+                $state eq WAIT_FOR_TOUCH and do {
+                #dev# print "L: $l";
+                        if ( $l =~ m#^\[(\d{2}/[A-Z][a-z][a-z]/\d{4}:\d{2}:\d{2}:\d{2})\] touch # ) {
+                                my $d = $1;
+                                $d_touch = decode_date( $d ) ;
+                                $state = WAIT_FOR_END;
+                        }
+                        last LINE;
+                };
+        } # /LINE:
+        close F;
+        if ( ! defined $d_touch or ! defined $d_rsync or ! defined $d_cp or ! defined $d_mv0 or ! defined $d_rm ) {
+                warn "incomplete log '$filename' (touch='$d_touch' rsync='$d_rsync' cp='$d_cp' mv0='$d_mv0' rm='$d_rm')";
+                next FILE;
+        }
+        #dev# print "RM    ",scalar localtime $d_rm,"\n";
+        #dev# print "MV0   ",scalar localtime $d_mv0,"\n";
+        #dev# print "CP    ",scalar localtime $d_cp,"\n";
+        #dev# print "RSYNC ",scalar localtime $d_rsync,"\n";
+        #dev# print "TOUCH ",scalar localtime $d_touch,"\n";
+        printf "%s %d T %d  RM %d %0.2f   MV %d %0.2f   CP %d %0.2f   RSYNC %d %0.2f\n",
+                $filename,
+                $d_rm,
+                $d_touch - $d_rm,
+                $d_mv0   - $d_rm,    ( $d_mv0   - $d_rm    ) * 100 / ( $d_touch - $d_rm ),
+                $d_cp    - $d_mv0,   ( $d_cp    - $d_mv0   ) * 100 / ( $d_touch - $d_rm ),
+                $d_rsync - $d_cp,    ( $d_rsync - $d_cp    ) * 100 / ( $d_touch - $d_rm ),
+                $d_touch - $d_rsync, ( $d_touch - $d_rsync ) * 100 / ( $d_touch - $d_rm ),
+        ;
+}
+</code>
+=== Usage per backup run ===
+<code>
+rsnapshot-backup-timings /var/log/rsnapshot-backup/<HOSTNAME>/log-2* > /tmp/backup-times-<HOSTNAME>
+gnuplot
+set xdata time
+set timefmt "%s"
+plot "backup-times-<HOSTNAME>" using 2:4 with linespoints
+plot "backup-times-<HOSTNAME>" using 2:6 with linespoints
+plot "backup-times-<HOSTNAME>" using 2:13 with linespoints
+# percentage:
+plot "backup-times-<HOSTNAME>" using 2:5 with linespoints
+plot "backup-times-<HOSTNAME>" using 2:7 with linespoints
+plot "backup-times-<HOSTNAME>" using 2:14 with linespoints
+</code>
+=== Usage per most recent backup runs ===
+<code>
+cd /var/log/rsnapshot-backup
+LATESTLOGS=$(
+for i in $( find . -maxdepth 1 -type d -mtime -2 ) ; do
+    for j in $( find $i -maxdepth 1 -type f -mtime -1 -name "log-2*" ) ; do
+        echo $j
+    done
+done
+)
+/usr/local/bin/rsnapshot-backup-timings $LATESTLOGS > /tmp/backup-times-latest
+gnuplot
+set xdata time
+set timefmt "%s"
+# total
+plot "backup-times-latest" using 2:4 with impulses
+# rm
+plot "backup-times-latest" using 2:6 with impulses
+# cp
+plot "backup-times-latest" using 2:12 with impulses
+# rsync
+plot "backup-times-latest" using 2:15 with impulses
+# rm %
+plot "backup-times-latest" using 2:7 with impulses
+# cp %
+plot "backup-times-latest" using 2:13 with impulses
+# rsync %
+plot "backup-times-latest" using 2:16 with impulses
+#sums:
+# T
+awk '{ s+= $4 ; $c++ }END{print s}' backup-times-latest
+# rm
+awk '{ s+= $6 ; $c++ }END{print s}' backup-times-latest
+# cp
+awk '{ s+= $12 ; $c++ }END{print s}' backup-times-latest
+# rsync
+awk '{ s+= $15 ; $c++ }END{print s}' backup-times-latest
+</code>
 ===== development information =====