Fischglas

User Tools

Site Tools

Trace:
project:rsnapshot-backup

Differences

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

Link to this comparison view

Both sides previous revisionPrevious revision
Next revision		Previous revision
project:rsnapshot-backup [2017/08/10 17:55] – 95.208.70.15project:rsnapshot-backup [2018/01/23 14:04] (current) – [show how much time individual parts of the backup take] 88.65.214.4
Line 410: Line 410:
 </code> </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 ===== ===== development information =====
  
project/rsnapshot-backup.1502380543.txt.gz · Last modified: 2017/08/10 17:55 by 95.208.70.15