t/02-operation.t

   1 use Getopt::Long;
   2 use Test::More;
   3 use strict;
   4 my $tests;
   5 BEGIN { $tests = 0 }
   6 use lib "lib";
   7
   8 my %Opt;
   9 GetOptions(
  10            "verbose!",
  11           ) or die;
  12 $Opt{verbose} ||= $ENV{PERL_RERSYNCRECENT_TEST_VERBOSE};
  13
  14 my $HAVE;
  15 BEGIN {
  16     # neither LibMagic nor MMagic tell them apart
  17     for my $package (
  18                      # "File::LibMagic",
  19                      "File::MMagic",
  20                     ) {
  21         $HAVE->{$package} = eval qq{ require $package; };
  22     }
  23 }
  24
  25 use Dumpvalue;
  26 use File::Basename qw(dirname);
  27 use File::Copy qw(cp);
  28 use File::Path qw(mkpath rmtree);
  29 use File::Rsync::Mirror::Recent;
  30 use File::Rsync::Mirror::Recentfile;
  31 use List::MoreUtils qw(uniq);
  32 use Storable;
  33 use Time::HiRes qw(time sleep);
  34 use YAML::Syck;
  35
  36 my $root_from = "t/ta";
  37 my $root_to = "t/tb";
  38 my $statusfile = "t/recent-rmirror-state.yml";
  39 rmtree [$root_from, $root_to];
  40
  41 {
  42     my @serializers;
  43     my $test_counter;
  44     BEGIN {
  45         $test_counter = $tests;
  46         @serializers = (
  47                         ".yaml",
  48                         ".json",
  49                         ".sto",
  50                         ".dd",
  51                        );
  52         $tests += @serializers;
  53         if ($HAVE->{"File::LibMagic"}||$HAVE->{"File::MMagic"}) {
  54             $tests += @serializers;
  55         }
  56     }
  57     printf "#test_counter[%d]\n", $test_counter;
  58     mkpath $root_from;
  59     my $ttt = "$root_from/ttt";
  60     open my $fh, ">", $ttt or die "Could not open: $!";
  61     print $fh time;
  62     close $fh or die "Could not close: $!";
  63     my $fm;
  64     if ($HAVE->{"File::LibMagic"}) {
  65         $fm = File::LibMagic->new();
  66     } elsif ($HAVE->{"File::MMagic"}) {
  67         $fm = File::MMagic->new();
  68     }
  69     for my $s (@serializers) {
  70         my $rf = File::Rsync::Mirror::Recentfile->new
  71             (
  72              filenameroot   => "RECENT",
  73              interval       => q(1m),
  74              localroot      => $root_from,
  75              serializer_suffix => $s,
  76             );
  77         $rf->update($ttt,"new");
  78         if ($fm) {
  79             my $magic = $fm->checktype_filename("$root_from/RECENT-1m$s");
  80             ok($magic, sprintf
  81                ("Got a magic[%s] for s[%s]: [%s]",
  82                 ref $fm,
  83                 $s,
  84                 $magic,
  85                ));
  86         }
  87         my $content = do {open my $fh, "$root_from/RECENT-1m$s";local $/;<$fh>};
  88         $content = Dumpvalue->new()->stringify($content);
  89         my $want_length = 42; # or maybe 3 more
  90         substr($content,$want_length) = "..." if length $content > 3+$want_length;
  91         ok($content, "Got a substr for s[$s]: [$content]");
  92     }
  93 }
  94
  95 rmtree [$root_from, $root_to];
  96
  97 {
  98     # very small tree, aggregate it
  99     my @intervals;
 100     my $test_counter;
 101     BEGIN {
 102         $test_counter = $tests;
 103         @intervals = qw( 2s 4s 8s 16s 32s Z );
 104         $tests += 2 + 2 * (10 + 14 * @intervals); # test_counter
 105     }
 106     printf "#test_counter[%d]\n", $test_counter;
 107     ok(1, "starting smalltree block");
 108     is 6, scalar @intervals, "array has 6 elements: @intervals";
 109     printf "#test_counter[%d]\n", $test_counter+=2;
 110     for my $pass (0,1) {
 111         my $rf0 = File::Rsync::Mirror::Recentfile->new
 112             (
 113              aggregator     => [@intervals[1..$#intervals]],
 114              interval       => $intervals[0],
 115              localroot      => $root_from,
 116              rsync_options  => {
 117                                 compress          => 0,
 118                                 links             => 1,
 119                                 times             => 1,
 120                                 checksum          => 0,
 121                                },
 122             );
 123         my $timestampfutured = 0;
 124         for my $iv (@intervals) {
 125             for my $i (0..3) {
 126                 my $file = sprintf
 127                     (
 128                      "%s/A%s-%02d",
 129                      $root_from,
 130                      $iv,
 131                      $i,
 132                     );
 133                 mkpath dirname $file;
 134                 open my $fh, ">", $file or die "Could not open '$file': $!";
 135                 print $fh time, ":", $file, "\n";
 136                 close $fh or die "Could not close '$file': $!";
 137                 $rf0->update($file,"new");
 138                 if ($pass==1 && !$timestampfutured) {
 139                     my $recent_events = $rf0->recent_events;
 140                     $recent_events->[0]{epoch} += 987654321;
 141                     $rf0->write_recent($recent_events);
 142                     $timestampfutured++;
 143                 }
 144             }
 145         }
 146         my $recent_events = $rf0->recent_events;
 147         # faking internals as if the contents were wide-spread in time
 148         for my $evi (0..$#$recent_events) {
 149             my $ev = $recent_events->[$evi];
 150             $ev->{epoch} -= 2**($evi*.25);
 151         }
 152         $rf0->write_recent($recent_events);
 153         $rf0->aggregate;
 154         my $filesize_threshold = 1750; # XXX may be system dependent
 155         my %size_before;
 156         for my $iv (@intervals) {
 157             my $rf = "$root_from/RECENT-$iv.yaml";
 158             my $filesize = -s $rf;
 159             $size_before{$iv} = $filesize;
 160             # now they have $filesize_threshold+ bytes because they were merged for the
 161             # first time ever and could not be truncated for this reason.
 162             ok( $filesize > $filesize_threshold, "file $iv (before merging) has good size[$filesize]");
 163             utime 0, 0, $rf; # so that the next aggregate isn't skipped
 164         }
 165         printf "#test_counter[%d]\n", $test_counter+=6;
 166         open my $fh, ">", "$root_from/finissage" or die "Could not open: $!";
 167         print $fh "fin";
 168         close $fh or die "Could not close: $!";
 169         $rf0->update("$root_from/finissage","new");
 170         $rf0 = File::Rsync::Mirror::Recentfile->new_from_file("$root_from/RECENT-2s.yaml");
 171         $rf0->aggregate;
 172         for my $iv (@intervals) {
 173             my $filesize = -s "$root_from/RECENT-$iv.yaml";
 174             # now they have <$filesize_threshold bytes because the second aggregate could
 175             # truncate them
 176             ok($iv eq "Z" || $filesize<$size_before{$iv}, "file $iv (after merging) has good size[$filesize<$size_before{$iv}]");
 177         }
 178         printf "#test_counter[%d]\n", $test_counter+=6;
 179         my $dagg1 = $rf0->_debug_aggregate;
 180         Time::HiRes::sleep 1.2;
 181         $rf0->aggregate;
 182         my $dagg2 = $rf0->_debug_aggregate;
 183         {
 184             my $recc = File::Rsync::Mirror::Recent->new
 185                 (
 186                  local => "$root_from/RECENT-2s.yaml",
 187                 );
 188             ok $recc->overview, "overview created";
 189             # diag $recc->overview;
 190         }
 191         printf "#test_counter[%d]\n", $test_counter+=1;
 192         for my $dirti (0,1,2) {
 193             open my $fh2, ">", "$root_from/dirty$dirti" or die "Could not open: $!";
 194             print $fh2 "dirty$dirti";
 195             close $fh2 or die "Could not close: $!";
 196             my $timestamp = $dirti <= 1 ? "999.999" : "1999.999";
 197             my $becomes_i = $dirti <= 1 ? -1 : -3;
 198             $rf0->update("$root_from/dirty$dirti","new",$timestamp);
 199             $recent_events = $rf0->recent_events;
 200             is $recent_events->[-1]{epoch}, $timestamp, "found the dirty timestamp during dirti[$dirti]";
 201             printf "#test_counter[%d]\n", $test_counter+=1;
 202             $rf0->aggregate(force => 1);
 203             my $recc = File::Rsync::Mirror::Recent->new
 204                 (
 205                  localroot => $root_from,
 206                  local => "$root_from/RECENT.recent",
 207                 );
 208             my %seen;
 209             for my $rf (@{$recc->recentfiles}) {
 210                 my $isec = $rf->interval_secs;
 211                 my $re = $rf->recent_events;
 212                 like $re->[-1]{epoch}, qr/999\.999/, "found some dirty timestamp[$re->[-1]{epoch}] in isec[$isec]";
 213                 my $dirtymark = $rf->dirtymark;
 214                 ok $dirtymark, "dirtymark[$dirtymark]";
 215                 $seen{ $rf->dirtymark }++;
 216             }
 217             printf "#test_counter[%d]\n", $test_counter+=12;
 218             is scalar keys %seen, 1, "all recentfiles have the same dirtymark";
 219             printf "#test_counter[%d]\n", $test_counter+=1;
 220             sleep 0.2;
 221             $rf0->aggregate(force => 1);
 222             my $rfs = $recc->recentfiles;
 223             for my $i (0..$#$rfs) {
 224                 my $rf = $rfs->[$i];
 225                 my $re = $rf->recent_events;
 226                 if ($i == 0) {
 227                     unlike $re->[-1]{epoch}, qr/999\.999/, "dirty file events already moved up i[$i]";
 228                 } elsif ($i == $#$rfs) {
 229                     is $re->[$becomes_i]{epoch}, $timestamp, "found the dirty timestamp on i[$i]";
 230                 } else {
 231                     isnt $re->[-1]{epoch}, $timestamp, "dirty timestamp gone on i[$i]";
 232                 }
 233                 my $dirtymark = $rf->dirtymark;
 234                 ok $dirtymark, "dirtymark[$dirtymark]";
 235                 $seen{ $rf->dirtymark }++;
 236             }
 237             printf "#test_counter[%d]\n", $test_counter+=12;
 238             is scalar keys %seen, 1, "all recentfiles have the same dirtymark";
 239             printf "#test_counter[%d]\n", $test_counter+=1;
 240         }
 241         # $DB::single++;
 242         rmtree [$root_from];
 243     }
 244 }
 245
 246 rmtree [$root_from, $root_to];
 247
 248 {
 249     # replay a short history, run aggregate on it, add files, aggregate again
 250     my $test_counter;
 251     BEGIN {
 252         $test_counter = $tests;
 253         $tests += 208;
 254     }
 255     printf "#test_counter[%d]\n", $test_counter;
 256     ok(1, "starting short history block");
 257     my $rf = File::Rsync::Mirror::Recentfile->new_from_file("t/RECENT-6h.yaml");
 258     my $recent_events = $rf->recent_events;
 259     my $recent_events_cnt = scalar @$recent_events;
 260     is (
 261         92,
 262         $recent_events_cnt,
 263         "found $recent_events_cnt events",
 264        );
 265     $rf->interval("5s");
 266     $rf->localroot($root_from);
 267     $rf->comment("produced during the test 02-operation.t");
 268     $rf->aggregator([qw(10s 30s 1m 1h Z)]);
 269     $rf->verbose(0);
 270     my $start = Time::HiRes::time;
 271     for my $e (@$recent_events) {
 272         for my $pass (0,1) {
 273             my $file = sprintf
 274                 (
 275                  "%s/%s",
 276                  $pass==0 ? $root_from : $root_to,
 277                  $e->{path},
 278                 );
 279             mkpath dirname $file;
 280             open my $fh, ">", $file or die "Could not open '$file': $!";
 281             print $fh time, ":", $file, "\n";
 282             close $fh or die "Could not close '$file': $!";
 283             if ($pass==0) {
 284                 $rf->update($file,$e->{type});
 285             }
 286         }
 287     }
 288     $rf->aggregate;
 289     my $took = Time::HiRes::time - $start;
 290     ok $took > 0, "creating the tree and aggregate took $took seconds";
 291     my $dagg1 = $rf->_debug_aggregate;
 292     for my $i (1..5) {
 293         my $file_from = "$root_from/anotherfilefromtesting$i";
 294         open my $fh, ">", $file_from or die "Could not open: $!";
 295         print $fh time, ":", $file_from;
 296         close $fh or die "Could not close: $!";
 297         $rf->update($file_from,"new");
 298     }
 299     $rf->aggregate;
 300     my $dagg2 = $rf->_debug_aggregate;
 301     undef $rf;
 302     ok($dagg1->[0]{size} < $dagg2->[0]{size}, "The second 5s file size larger: $dagg1->[0]{size} < $dagg2->[0]{size}");
 303     ok($dagg1->[1]{mtime} <= $dagg2->[1]{mtime}, "The second 30s file timestamp larger: $dagg1->[1]{mtime} <= $dagg2->[1]{mtime}");
 304     is $dagg1->[2]{size}, $dagg2->[2]{size}, "The 1m file size unchanged";
 305     is $dagg1->[3]{mtime}, $dagg2->[3]{mtime}, "The 1h file timestamp unchanged";
 306     ok -l "t/ta/RECENT.recent", "found the symlink";
 307     my $have_slept = my $have_worked = 0;
 308     $start = Time::HiRes::time;
 309     my $debug = +[];
 310     for my $i (0..99) {
 311         my $file = sprintf
 312             (
 313              "%s/secscnt%03d",
 314              $root_from,
 315              ($i<25) ? ($i%12) : $i,
 316             );
 317         open my $fh, ">", $file or die "Could not open '$file': $!";
 318         print $fh time, ":", $file, "\n";
 319         close $fh or die "Could not close '$file': $!";
 320         my $another_rf = File::Rsync::Mirror::Recentfile->new
 321             (
 322              interval => "5s",
 323              localroot => $root_from,
 324              aggregator => [qw(10s 30s 1m 1h Z)],
 325             );
 326         $another_rf->update($file,"new");
 327         my $should_have = 97 + (($i<25) ? ($i < 12 ? ($i+1) : 12) : ($i-12));
 328         my($news,$filtered_news);
 329         if ($i < 50) {
 330             $another_rf->aggregate;
 331         }
 332         {
 333             my $recc = File::Rsync::Mirror::Recent->new
 334                 (
 335                  local => "$root_from/RECENT-5s.yaml",
 336                 );
 337             $news = $recc->news ();
 338             $filtered_news = [ uniq map { $_->{path} } @$news ];
 339         }
 340         is scalar @$filtered_news, $should_have, "should_have[$should_have]" or die;
 341         $debug->[$i] = $news;
 342         my $rf2 = File::Rsync::Mirror::Recentfile->new_from_file("$root_from/RECENT-5s.yaml");
 343         my $rece = $rf2->recent_events;
 344         my $rececnt = @$rece;
 345         my $span = $rece->[0]{epoch} - $rece->[-1]{epoch};
 346         $have_worked = Time::HiRes::time - $start - $have_slept;
 347         ok($rececnt > 0
 348            && ($i<50 ? $span <= 5 # we have run aggregate, so it guaranteed(*)
 349                : $i < 90 ? 1      # we have not yet spent 5 seconds, so cannot predict
 350                : $span > 5        # we have certainly written enough files now, must happen
 351               ),
 352            sprintf
 353            ("i[%s]cnt[%s]span[%s]worked[%6.4f]",
 354             $i,
 355             $rececnt,
 356             $span,
 357             $have_worked,
 358            ));
 359         $have_slept += Time::HiRes::sleep 0.2;
 360     }
 361     # (*) "<=" instead of "<" because of rounding errors
 362 }
 363
 364 {
 365     # running mirror
 366     my $test_counter;
 367     BEGIN {
 368         $test_counter = $tests;
 369         $tests += 3;
 370     }
 371     printf "#test_counter[%d]\n", $test_counter;
 372     my $rf = File::Rsync::Mirror::Recentfile->new
 373         (
 374          filenameroot   => "RECENT",
 375          interval       => q(30s),
 376          localroot      => $root_to,
 377          max_rsync_errors  => 0,
 378          remote_dir     => $root_from,
 379          # verbose        => 1,
 380          max_files_per_connection => 512,
 381          rsync_options  => {
 382                             compress          => 0,
 383                             links             => 1,
 384                             times             => 1,
 385                             # not available in rsync 3.0.3: 'omit-dir-times'  => 1,
 386                             checksum          => 0,
 387                            },
 388         );
 389     my $somefile_epoch;
 390     for my $pass (0,1) {
 391         my $success;
 392         if (0 == $pass) {
 393             $success = $rf->mirror;
 394             my $re = $rf->recent_events;
 395             $somefile_epoch = $re->[24]{epoch};
 396         } elsif (1 == $pass) {
 397             $success = $rf->mirror(after => $somefile_epoch);
 398         }
 399         ok($success, "mirrored pass[$pass] without dying");
 400     }
 401     {
 402         my $recc = File::Rsync::Mirror::Recent->new
 403             (  # ($root_from, $root_to)
 404              local => "$root_from/RECENT-5s.yaml",
 405             );
 406         #diag "\n";
 407         #diag $recc->overview;
 408     }
 409     {
 410         my $recc = File::Rsync::Mirror::Recent->new
 411             (
 412              # ignore_link_stat_errors => 1,
 413              localroot => $root_to,
 414              remote => "$root_from/RECENT-5s.yaml",
 415              # verbose => 1,
 416              max_files_per_connection => 512,
 417              rsync_options => {
 418                                links => 1,
 419                                times => 1,
 420                                compress => 1,
 421                                checksum => 1,
 422                               },
 423             );
 424         $recc->rmirror;
 425     }
 426     {
 427         my $recc = File::Rsync::Mirror::Recent->new
 428             (  # ($root_from, $root_to)
 429              local => "$root_from/RECENT-5s.yaml",
 430             );
 431         #diag "\n";
 432         #diag $recc->overview;
 433     }
 434     {
 435         my $recc = File::Rsync::Mirror::Recent->new
 436             (
 437              # ignore_link_stat_errors => 1,
 438              localroot => $root_to,
 439              remote => "$root_from/RECENT.recent",
 440              verbose => $Opt{verbose},
 441              max_files_per_connection => 512,
 442              rsync_options => {
 443                                links => 1,
 444                                times => 1,
 445                                compress => 1,
 446                                checksum => 1,
 447                               },
 448              _runstatusfile => $statusfile,
 449             );
 450         $recc->rmirror;
 451         my $rf2 = File::Rsync::Mirror::Recentfile->new_from_file("$root_from/RECENT-5s.yaml");
 452         my $file = "$root_from/about-re-mirroring.txt";
 453         open my $fh, ">", $file or die "Could not open '$file': $!";
 454         print $fh time;
 455         close $fh or die "Could not close '$file': $!";
 456         $rf2->update($file, "new");
 457         $recc->rmirror;
 458     }
 459     {
 460         my $recc = File::Rsync::Mirror::Recent->new
 461             (
 462              # ignore_link_stat_errors => 1,
 463              localroot => $root_to,
 464              local => "$root_to/RECENT.recent",
 465             );
 466         my %seen;
 467         for my $rf (@{$recc->recentfiles}) {
 468             my $dirtymark = $rf->dirtymark or next;
 469             $seen{ $dirtymark }++;
 470         }
 471         is scalar keys %seen, 1, "all recentfiles have the same dirtymark or we don't know it";
 472     }
 473 }
 474
 475 rmtree [$root_from, $root_to, $statusfile] unless $Opt{verbose};
 476
 477 BEGIN {
 478     plan tests => $tests
 479 }
 480
 481 # Local Variables:
 482 # mode: cperl
 483 # cperl-indent-level: 4
 484 # End: