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 * (7 + 10 * @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) {
 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             $rf0->update("$root_from/dirty$dirti","new","999.999");
 197             $recent_events = $rf0->recent_events;
 198             is $recent_events->[-1]{epoch}, "999.999", "found the dirty timestamp during dirti[$dirti]";
 199             printf "#test_counter[%d]\n", $test_counter+=1;
 200             $rf0->aggregate(force => 1);
 201             my $recc = File::Rsync::Mirror::Recent->new
 202                 (
 203                  localroot => $root_from,
 204                  local => "$root_from/RECENT.recent",
 205                 );
 206             my %seen;
 207             for my $rf (@{$recc->recentfiles}) {
 208                 my $isec = $rf->interval_secs;
 209                 my $re = $rf->recent_events;
 210                 is $re->[-1]{epoch}, "999.999", "found the dirty timestamp in isec[$isec]";
 211                 my $dirtymark = $rf->dirtymark;
 212                 ok $dirtymark, "dirtymark[$dirtymark]";
 213                 $seen{ $rf->dirtymark }++;
 214             }
 215             printf "#test_counter[%d]\n", $test_counter+=12;
 216             is scalar keys %seen, 1, "all recentfiles have the same dirtymark";
 217             printf "#test_counter[%d]\n", $test_counter+=1;
 218             sleep 0.2;
 219             $rf0->aggregate(force => 1);
 220             my $rfs = $recc->recentfiles;
 221             for my $i (0..$#$rfs) {
 222                 my $rf = $rfs->[$i];
 223                 my $re = $rf->recent_events;
 224                 if ($i == $#$rfs) {
 225                     is $re->[-1]{epoch}, "999.999", "found the dirty timestamp on i[$i]";
 226                 } else {
 227                     isnt $re->[-1]{epoch}, "999.999", "dirty timestamp gone on i[$i]";
 228                 }
 229                 my $dirtymark = $rf->dirtymark;
 230                 ok $dirtymark, "dirtymark[$dirtymark]";
 231                 $seen{ $rf->dirtymark }++;
 232             }
 233             printf "#test_counter[%d]\n", $test_counter+=12;
 234             is scalar keys %seen, 1, "all recentfiles have the same dirtymark";
 235             printf "#test_counter[%d]\n", $test_counter+=1;
 236         }
 237         # $DB::single++;
 238         rmtree [$root_from];
 239     }
 240 }
 241
 242 rmtree [$root_from, $root_to];
 243
 244 {
 245     # replay a short history, run aggregate on it, add files, aggregate again
 246     my $test_counter;
 247     BEGIN {
 248         $test_counter = $tests;
 249         $tests += 208;
 250     }
 251     printf "#test_counter[%d]\n", $test_counter;
 252     ok(1, "starting short history block");
 253     my $rf = File::Rsync::Mirror::Recentfile->new_from_file("t/RECENT-6h.yaml");
 254     my $recent_events = $rf->recent_events;
 255     my $recent_events_cnt = scalar @$recent_events;
 256     is (
 257         92,
 258         $recent_events_cnt,
 259         "found $recent_events_cnt events",
 260        );
 261     $rf->interval("5s");
 262     $rf->localroot($root_from);
 263     $rf->comment("produced during the test 02-operation.t");
 264     $rf->aggregator([qw(10s 30s 1m 1h Z)]);
 265     $rf->verbose(0);
 266     my $start = Time::HiRes::time;
 267     for my $e (@$recent_events) {
 268         for my $pass (0,1) {
 269             my $file = sprintf
 270                 (
 271                  "%s/%s",
 272                  $pass==0 ? $root_from : $root_to,
 273                  $e->{path},
 274                 );
 275             mkpath dirname $file;
 276             open my $fh, ">", $file or die "Could not open '$file': $!";
 277             print $fh time, ":", $file, "\n";
 278             close $fh or die "Could not close '$file': $!";
 279             if ($pass==0) {
 280                 $rf->update($file,$e->{type});
 281             }
 282         }
 283     }
 284     $rf->aggregate;
 285     my $took = Time::HiRes::time - $start;
 286     ok $took > 0, "creating the tree and aggregate took $took seconds";
 287     my $dagg1 = $rf->_debug_aggregate;
 288     for my $i (1..5) {
 289         my $file_from = "$root_from/anotherfilefromtesting$i";
 290         open my $fh, ">", $file_from or die "Could not open: $!";
 291         print $fh time, ":", $file_from;
 292         close $fh or die "Could not close: $!";
 293         $rf->update($file_from,"new");
 294     }
 295     $rf->aggregate;
 296     my $dagg2 = $rf->_debug_aggregate;
 297     undef $rf;
 298     ok($dagg1->[0]{size} < $dagg2->[0]{size}, "The second 5s file size larger: $dagg1->[0]{size} < $dagg2->[0]{size}");
 299     ok($dagg1->[1]{mtime} <= $dagg2->[1]{mtime}, "The second 30s file timestamp larger: $dagg1->[1]{mtime} <= $dagg2->[1]{mtime}");
 300     is $dagg1->[2]{size}, $dagg2->[2]{size}, "The 1m file size unchanged";
 301     is $dagg1->[3]{mtime}, $dagg2->[3]{mtime}, "The 1h file timestamp unchanged";
 302     ok -l "t/ta/RECENT.recent", "found the symlink";
 303     my $have_slept = my $have_worked = 0;
 304     $start = Time::HiRes::time;
 305     my $debug = +[];
 306     for my $i (0..99) {
 307         my $file = sprintf
 308             (
 309              "%s/secscnt%03d",
 310              $root_from,
 311              ($i<25) ? ($i%12) : $i,
 312             );
 313         open my $fh, ">", $file or die "Could not open '$file': $!";
 314         print $fh time, ":", $file, "\n";
 315         close $fh or die "Could not close '$file': $!";
 316         my $another_rf = File::Rsync::Mirror::Recentfile->new
 317             (
 318              interval => "5s",
 319              localroot => $root_from,
 320              aggregator => [qw(10s 30s 1m 1h Z)],
 321             );
 322         $another_rf->update($file,"new");
 323         my $should_have = 97 + (($i<25) ? ($i < 12 ? ($i+1) : 12) : ($i-12));
 324         my($news,$filtered_news);
 325         if ($i < 50) {
 326             $another_rf->aggregate;
 327         }
 328         {
 329             my $recc = File::Rsync::Mirror::Recent->new
 330                 (
 331                  local => "$root_from/RECENT-5s.yaml",
 332                 );
 333             $news = $recc->news ();
 334             $filtered_news = [ uniq map { $_->{path} } @$news ];
 335         }
 336         is scalar @$filtered_news, $should_have, "should_have[$should_have]" or die;
 337         $debug->[$i] = $news;
 338         my $rf2 = File::Rsync::Mirror::Recentfile->new_from_file("$root_from/RECENT-5s.yaml");
 339         my $rece = $rf2->recent_events;
 340         my $rececnt = @$rece;
 341         my $span = $rece->[0]{epoch} - $rece->[-1]{epoch};
 342         $have_worked = Time::HiRes::time - $start - $have_slept;
 343         ok($rececnt > 0
 344            && ($i<50 ? $span <= 5 # we have run aggregate, so it guaranteed(*)
 345                : $i < 90 ? 1      # we have not yet spent 5 seconds, so cannot predict
 346                : $span > 5        # we have certainly written enough files now, must happen
 347               ),
 348            sprintf
 349            ("i[%s]cnt[%s]span[%s]worked[%6.4f]",
 350             $i,
 351             $rececnt,
 352             $span,
 353             $have_worked,
 354            ));
 355         $have_slept += Time::HiRes::sleep 0.2;
 356     }
 357     # (*) "<=" instead of "<" because of rounding errors
 358 }
 359
 360 {
 361     # running mirror
 362     my $test_counter;
 363     BEGIN {
 364         $test_counter = $tests;
 365         $tests += 3;
 366     }
 367     printf "#test_counter[%d]\n", $test_counter;
 368     my $rf = File::Rsync::Mirror::Recentfile->new
 369         (
 370          filenameroot   => "RECENT",
 371          interval       => q(30s),
 372          localroot      => $root_to,
 373          max_rsync_errors  => 0,
 374          remote_dir     => $root_from,
 375          # verbose        => 1,
 376          max_files_per_connection => 512,
 377          rsync_options  => {
 378                             compress          => 0,
 379                             links             => 1,
 380                             times             => 1,
 381                             # not available in rsync 3.0.3: 'omit-dir-times'  => 1,
 382                             checksum          => 0,
 383                            },
 384         );
 385     my $somefile_epoch;
 386     for my $pass (0,1) {
 387         my $success;
 388         if (0 == $pass) {
 389             $success = $rf->mirror;
 390             my $re = $rf->recent_events;
 391             $somefile_epoch = $re->[24]{epoch};
 392         } elsif (1 == $pass) {
 393             $success = $rf->mirror(after => $somefile_epoch);
 394         }
 395         ok($success, "mirrored pass[$pass] without dying");
 396     }
 397     {
 398         my $recc = File::Rsync::Mirror::Recent->new
 399             (  # ($root_from, $root_to)
 400              local => "$root_from/RECENT-5s.yaml",
 401             );
 402         #diag "\n";
 403         #diag $recc->overview;
 404     }
 405     {
 406         my $recc = File::Rsync::Mirror::Recent->new
 407             (
 408              # ignore_link_stat_errors => 1,
 409              localroot => $root_to,
 410              remote => "$root_from/RECENT-5s.yaml",
 411              # verbose => 1,
 412              max_files_per_connection => 512,
 413              rsync_options => {
 414                                links => 1,
 415                                times => 1,
 416                                compress => 1,
 417                                checksum => 1,
 418                               },
 419             );
 420         $recc->rmirror;
 421     }
 422     {
 423         my $recc = File::Rsync::Mirror::Recent->new
 424             (  # ($root_from, $root_to)
 425              local => "$root_from/RECENT-5s.yaml",
 426             );
 427         #diag "\n";
 428         #diag $recc->overview;
 429     }
 430     {
 431         my $recc = File::Rsync::Mirror::Recent->new
 432             (
 433              # ignore_link_stat_errors => 1,
 434              localroot => $root_to,
 435              remote => "$root_from/RECENT.recent",
 436              verbose => $Opt{verbose},
 437              max_files_per_connection => 512,
 438              rsync_options => {
 439                                links => 1,
 440                                times => 1,
 441                                compress => 1,
 442                                checksum => 1,
 443                               },
 444              _runstatusfile => $statusfile,
 445             );
 446         $recc->rmirror;
 447         my $rf2 = File::Rsync::Mirror::Recentfile->new_from_file("$root_from/RECENT-5s.yaml");
 448         my $file = "$root_from/about-re-mirroring.txt";
 449         open my $fh, ">", $file or die "Could not open '$file': $!";
 450         print $fh time;
 451         close $fh or die "Could not close '$file': $!";
 452         $rf2->update($file, "new");
 453         $recc->rmirror;
 454     }
 455     {
 456         my $recc = File::Rsync::Mirror::Recent->new
 457             (
 458              # ignore_link_stat_errors => 1,
 459              localroot => $root_to,
 460              local => "$root_to/RECENT.recent",
 461             );
 462         my %seen;
 463         for my $rf (@{$recc->recentfiles}) {
 464             my $dirtymark = $rf->dirtymark or next;
 465             $seen{ $dirtymark }++;
 466         }
 467         is scalar keys %seen, 1, "all recentfiles have the same dirtymark or we don't know it";
 468     }
 469 }
 470
 471 rmtree [$root_from, $root_to, $statusfile] unless $Opt{verbose};
 472
 473 BEGIN {
 474     plan tests => $tests
 475 }
 476
 477 # Local Variables:
 478 # mode: cperl
 479 # cperl-indent-level: 4
 480 # End: